hectic-lab/util.nix
2
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix: hectic C: impruve logging guidelines

Browse Source
This commit is contained in:
yukkop
2025-04-07 05:26:30 +00:00
parent 11150151f9
commit 98a26f1f61
9 changed files with 1205 additions and 122 deletions
Download Patch File Download Diff File Expand all files Collapse all files

153
package/c/hectic/docs/logging.md Executable file
View File

@@ -0,0 +1,153 @@
# Hectic Library Logging System
This document provides guidelines on how to use the logging system in the Hectic library effectively.
## Log Levels
The Hectic library implements a graduated severity-based logging system with the following levels (from lowest to highest severity):
### TRACE
**Purpose**: Most detailed information for in-depth debugging
- Use for: Deep diagnostic details, function entry/exit, variable dumps
- Visibility: Development environments only
- Performance Impact: High
- Example: `raise_trace("Entering function with value=%d, ptr=%p", value, ptr);`
### DEBUG
**Purpose**: Detailed information useful during development
- Use for: Development-time debugging, showing variable states, internal flows
- Visibility: Development and debugging environments
- Performance Impact: Medium-High
- Example: `raise_debug("Buffer allocated with size %zu bytes at %p", size, buffer);`
### LOG
**Purpose**: General operational events
- Use for: Runtime events worth logging but not requiring attention
- Visibility: Always written to logs, useful for auditing/diagnostics
- Performance Impact: Medium
- Example: `raise_log("Processing file %s, size: %zu bytes", filename, file_size);`
### INFO
**Purpose**: Informational messages highlighting progress
- Use for: Normal but noteworthy events, state changes, startup/shutdown events
- Visibility: Visible to client applications if configured
- Performance Impact: Low-Medium
- Example: `raise_info("Connection established to %s, session ID: %s", host, session_id);`
### NOTICE
**Purpose**: More important events than INFO, but not warnings
- Use for: Important state changes, significant operations, configuration changes
- Visibility: Displayed to client by default
- Performance Impact: Low
- Example: `raise_notice("Switching to backup server due to high load");`
### WARN
**Purpose**: Potential problems that don't prevent normal operation
- Use for: Unexpected behaviors, deprecated feature usage, recoverable errors
- Visibility: Alerts both client and server logs
- Performance Impact: Low
- Example: `raise_warn("API call retry limit (%d) reached for endpoint %s", retries, endpoint);`
### EXCEPTION
**Purpose**: Serious errors requiring immediate attention
- Use for: Critical failures, data loss risks, business rule violations
- Visibility: Highest priority, often leads to operation termination
- Performance Impact: Low
- Example: `raise_exception("Failed to open database: %s", error_msg);`
## Setting the Log Level
You can control the verbosity of logs in three ways:
1. **Environment Variable**: Set `LOG_LEVEL` environment variable
```sh
export LOG_LEVEL=DEBUG
```
2. **Programmatically**: Use the `logger_level()` function
```c
logger_level(LOG_LEVEL_DEBUG);
```
3. **Compile-Time**: Define `PRECOMPILED_LOG_LEVEL` before including hectic.h
```c
#define PRECOMPILED_LOG_LEVEL LOG_LEVEL_INFO
#include <hectic.h>
```
## Logging Best Practices
### DO
- **Be specific and concise**: Include relevant details but avoid verbose descriptions
- **Include context**: Add identifiers (IDs, filenames, pointers) to help with troubleshooting
- **Use the appropriate level**: Understand the purpose of each level and use it accordingly
- **Log state transitions**: Important changes in application state should be logged
- **Use structured data**: When possible, include structured information rather than unformatted text
### DON'T
- **Log sensitive information**: Never log passwords, tokens, or personal information
- **Overuse high-severity levels**: Reserve WARN and EXCEPTION for real issues
- **Log in tight loops**: Avoid excessive logging in performance-critical paths
- **Use inconsistent formats**: Follow a consistent message format throughout your code
- **Ignore log levels**: Don't use DEBUG for important operational events or EXCEPTION for minor issues
## Examples of Good Logging
### Error Handling Pattern
```c
void *allocate_resource(size_t size) {
raise_debug("Allocating %zu bytes", size);
void *ptr = malloc(size);
if (!ptr) {
raise_exception("Memory allocation failed for %zu bytes", size);
return NULL;
}
raise_debug("Successfully allocated %zu bytes at %p", size, ptr);
return ptr;
}
```
### State Transition Pattern
```c
void change_connection_state(Connection *conn, ConnState new_state) {
raise_debug("Connection %p state change requested: %s -> %s",
conn, conn_state_to_string(conn->state), conn_state_to_string(new_state));
if (!is_valid_transition(conn->state, new_state)) {
raise_warn("Invalid state transition from %s to %s",
conn_state_to_string(conn->state), conn_state_to_string(new_state));
return;
}
ConnState old_state = conn->state;
conn->state = new_state;
raise_info("Connection %s state changed: %s -> %s",
conn->id, conn_state_to_string(old_state), conn_state_to_string(new_state));
}
```
### Operation Pattern
```c
int process_file(const char *filename) {
raise_log("Processing file: %s", filename);
FILE *f = fopen(filename, "r");
if (!f) {
raise_warn("Could not open file %s: %s", filename, strerror(errno));
return -1;
}
// Process file...
raise_info("Successfully processed file %s: %d records", filename, record_count);
return 0;
}
```

205
package/c/hectic/docs/logging_audit.md Executable file
View File

@@ -0,0 +1,205 @@
# Logging Audit Guide for Hectic
This guide provides a systematic approach to auditing and improving logging in existing functions of the Hectic library.
## Checklist for Function Audit
### 1. Basic Logging Check
- [ ] Function has entry logging (DEBUG or TRACE level)
- [ ] Function has result/exit logging
- [ ] Failures and errors are logged with appropriate levels (WARN or EXCEPTION)
- [ ] Intermediate steps are logged at TRACE or DEBUG level
- [ ] Successful operation completions are logged at LOG level
### 2. Level Consistency Check
- [ ] `LOG_LEVEL_TRACE` is used for detailed execution tracking
- [ ] `LOG_LEVEL_DEBUG` is used for significant internal steps
- [ ] `LOG_LEVEL_LOG` is used for important operational events and successful operation completions
- [ ] `LOG_LEVEL_INFO` is used *rarely*, only for user-critical events
- [ ] `LOG_LEVEL_NOTICE` is used *very rarely*, almost not needed for a low-level library
- [ ] `LOG_LEVEL_WARN` is used for recoverable problems
- [ ] `LOG_LEVEL_EXCEPTION` is used only for critical errors
### 3. Message Formatting Check
- [ ] Messages start with a domain prefix (PARSE:, ALLOC:, FORMAT:, etc.)
- [ ] Message structure follows the pattern "Action: object (details)"
- [ ] Messages contain sufficient context for understanding (pointers, sizes, values)
- [ ] Messages don't contain redundant information
- [ ] Pointers use %p format
- [ ] Sizes use %zu format
- [ ] Strings use length limitation when necessary (%.20s)
- [ ] NULL pointer checks are added before using pointers in logs
## Logging Level Usage Rules
### TRACE
- Function calls and exits
- Detailed loop iteration information
- Variable values during execution
- Any detailed debugging information
### DEBUG
- Entries to public API functions
- Resource allocation and deallocation
- Key algorithm steps
- Data processing details
### LOG
- Successful component initialization
- Completion of significant operations
- State changes important for operation
- Key business logic points
### INFO (use rarely!)
- Library startup and shutdown
- Version and configuration information
- Extremely important events visible to users
- Large operations requested by users
### NOTICE (almost never use)
- Events that users should pay attention to
- Significant planned actions
### WARN
- Unexpected but handled errors
- Edge cases
- Warnings about potential problems
- Use of deprecated APIs
### EXCEPTION
- Serious errors affecting system operation
- Data integrity violations
- Resource exhaustion
- Critical security failures
## Audit and Update Process
### Step 1: Function Analysis
1. Determine the function type:
- Initialization/resource management function
- Data processing function
- Utility function
- Other
2. Identify key logging points:
- Function entry
- Parameter checks
- Main processing steps
- Error conditions
- Function exit
### Step 2: Update Planning
1. Create a list of necessary logs at each level
2. Determine the right prefixes for each message type
3. Prepare detailed messages with necessary context
4. Ensure parameter checks are logged before use
### Step 3: Implementing Changes
1. Add/update function entry logging
2. Add/update input parameter checks
3. Update intermediate step logging
4. Add/update error condition logging
5. Add/update result logging
### Step 4: Testing
1. Check message output correctness
2. Verify proper level usage
3. Check that all necessary information is included in logs
4. Compare with other already updated functions for consistency
## Examples for Typical Functions
### Memory Allocation Function:
```c
void* memory_function__(const char *file, const char *func, int line, size_t size) {
// Function entry
raise_message(LOG_LEVEL_DEBUG, file, func, line,
"ALLOC: Requesting memory allocation (size: %zu bytes)", size);
// Parameter check
if (size == 0) {
raise_message(LOG_LEVEL_WARN, file, func, line,
"ALLOC: Zero-sized memory allocation requested");
return NULL;
}
// Memory allocation
void *ptr = malloc(size);
if (!ptr) {
raise_message(LOG_LEVEL_EXCEPTION, file, func, line,
"ALLOC: Memory allocation failed (requested: %zu bytes)", size);
return NULL;
}
// Result
raise_message(LOG_LEVEL_LOG, file, func, line,
"ALLOC: Memory allocated successfully (address: %p, size: %zu bytes)",
ptr, size);
return ptr;
}
```
### Data Conversion Function:
```c
char* convert_function__(const char *file, const char *func, int line,
const void *input, size_t input_size) {
// Function entry
raise_message(LOG_LEVEL_DEBUG, file, func, line,
"CONVERT: Starting data conversion (input: %p, size: %zu)",
input, input_size);
// Parameter check
if (!input) {
raise_message(LOG_LEVEL_WARN, file, func, line,
"CONVERT: NULL input provided");
return NULL;
}
if (input_size == 0) {
raise_message(LOG_LEVEL_WARN, file, func, line,
"CONVERT: Zero input size provided");
return NULL;
}
// Processing start
raise_message(LOG_LEVEL_TRACE, file, func, line,
"CONVERT: Processing input data...");
// Processing...
// Result
char *result = NULL; // conversion result
if (!result) {
raise_message(LOG_LEVEL_WARN, file, func, line,
"CONVERT: Conversion failed");
return NULL;
}
raise_message(LOG_LEVEL_LOG, file, func, line,
"CONVERT: Data conversion completed successfully (result: %p)", result);
return result;
}
```
## Update Priorities
Recommended order for updating functions:
1. Memory management functions (`arena_*`)
2. Parsing functions (`json_parse_*`)
3. Formatting functions (`json_to_string_*`)
4. Data processing functions (`slice_*`)
5. Utility functions
## Conclusion
Consistent application of these recommendations to functions in the library will significantly improve logging quality and facilitate debugging and code maintenance in the future.

285
package/c/hectic/docs/logging_improvement_plan.md Executable file
View File

@@ -0,0 +1,285 @@
# Logging System Improvement Plan for Hectic Library
## Current Issues
After analyzing the logging in the hectic library, the following issues have been identified:
1. **Inconsistent message formatting** - messages are formatted differently in various parts of the code
2. **Inefficient use of logging levels** - levels don't always correspond to the nature of the message
3. **Incomplete logging** - some important operations aren't logged at all
4. **Lack of context** - messages don't always contain necessary context for debugging
5. **Mixed formats** - no unified style for logging different types of data
## Standardizing Logging by Function Types
### 1. Initialization and Resource Management Functions
**Logging pattern:**
1. `LOG_LEVEL_DEBUG` when entering a function with parameters
2. `LOG_LEVEL_DEBUG` when performing significant steps within the function
3. `LOG_LEVEL_LOG` on successful resource allocation/initialization
4. `LOG_LEVEL_WARN` for warning conditions
5. `LOG_LEVEL_EXCEPTION` for critical errors
**Example (arena_init):**
```c
Arena arena_init__(const char *file, const char *func, int line, size_t size) {
raise_message(LOG_LEVEL_DEBUG, file, func, line,
"Initializing arena with size %zu bytes", size);
Arena arena;
arena.begin = malloc(size);
if (!arena.begin) {
raise_message(LOG_LEVEL_EXCEPTION, file, func, line,
"Failed to allocate memory for arena (requested %zu bytes)", size);
exit(1);
}
memset(arena.begin, 0, size);
arena.current = arena.begin;
arena.capacity = size;
raise_message(LOG_LEVEL_LOG, file, func, line,
"Arena initialized: address=%p, capacity=%zu bytes", arena.begin, size);
return arena;
}
```
### 2. Data Processing Functions (parsers, serializers)
**Logging pattern:**
1. `LOG_LEVEL_DEBUG` when entering a function with main parameters
2. `LOG_LEVEL_TRACE` for detailed tracking of parsing/serialization steps
3. `LOG_LEVEL_DEBUG` when discovering intermediate results
4. `LOG_LEVEL_WARN` for recoverable format issues
5. `LOG_LEVEL_EXCEPTION` for unrecoverable format errors
6. `LOG_LEVEL_LOG` on successful completion of a significant operation
**Example (for json_parse):**
```c
Json *json_parse__(const char* file, const char* func, int line, Arena *arena, const char **s) {
raise_message(LOG_LEVEL_DEBUG, file, func, line,
"Starting JSON parsing from position %p", *s);
// Start parsing
if (!s || !*s) {
raise_message(LOG_LEVEL_EXCEPTION, file, func, line,
"Invalid input: NULL pointer provided for JSON parsing");
return NULL;
}
// Show first 20 characters for debugging
raise_message(LOG_LEVEL_TRACE, file, func, line,
"JSON input preview: '%.20s%s'", *s, strlen(*s) > 20 ? "..." : "");
Json *result = json_parse_value__(file, func, line, s, arena);
if (!result) {
raise_message(LOG_LEVEL_WARN, file, func, line,
"JSON parsing failed at position: %p", *s);
} else {
raise_message(LOG_LEVEL_LOG, file, func, line,
"JSON parsed successfully, type: %d", result->type);
}
return result;
}
```
### 3. Utility Functions
**Logging pattern:**
1. `LOG_LEVEL_TRACE` when entering a function with full parameters
2. `LOG_LEVEL_DEBUG` for logging important intermediate steps
3. `LOG_LEVEL_LOG` for successful operation completion
4. `LOG_LEVEL_WARN` for unusual but handled situations
5. `LOG_LEVEL_TRACE` when exiting with a result
**Example (substr_clone):**
```c
void substr_clone__(const char *file, const char *func, int line,
const char * const src, char *dest, size_t from, size_t len) {
raise_message(LOG_LEVEL_TRACE, file, func, line,
"Entering substring clone: src=%p (\"%s\"), dest=%p, from=%zu, len=%zu",
src, src ? (strlen(src) < 20 ? src : "<long string>") : "<null>",
dest, from, len);
if (!src || !dest) {
raise_message(LOG_LEVEL_EXCEPTION, file, func, line,
"Invalid NULL pointer: %s%s",
(!src ? "src " : ""), (!dest ? "dest" : ""));
if (dest) dest[0] = '\0';
return;
}
size_t srclen = strlen(src);
if (from >= srclen) {
raise_message(LOG_LEVEL_WARN, file, func, line,
"Out of range: 'from' index (%zu) exceeds source length (%zu)",
from, srclen);
dest[0] = '\0';
return;
}
if (from + len > srclen) {
size_t old_len = len;
len = srclen - from;
raise_message(LOG_LEVEL_DEBUG, file, func, line,
"Adjusted length from %zu to %zu to fit source bounds",
old_len, len);
}
strncpy(dest, src + from, len);
dest[len] = '\0';
raise_message(LOG_LEVEL_TRACE, file, func, line,
"Substring cloned: result=\"%s\", copied_length=%zu",
dest, len);
}
```
## Log Naming Standards
### 1. Function Prefixes
To make logs easier to search, use prefixes in messages:
- **INIT:** - for initialization logs
- **ALLOC:** - for memory allocation logs
- **PARSE:** - for parsing logs
- **PROCESS:** - for data processing logs
- **FREE:** - for resource freeing logs
### 2. Message Structure
All messages should have a consistent structure:
- **Action**: What is being done (verb in present continuous)
- **Object**: What is being acted upon (noun phrase)
- **Details**: Additional information (in parentheses or after a colon)
**Examples:**
- "Initializing arena (size: %zu bytes)"
- "Processing JSON object with %d members"
- "Allocating memory block: address=%p, size=%zu"
## Logging Levels
Recommendations for using logging levels in a low-level library:
1. **TRACE (Very detailed)** - For detailed tracking of function operation:
- Function entry/exit
- Data contents
- Intermediate variable values
- Processing loop details
2. **DEBUG (Detailed)** - For programmers working with the library:
- Main algorithm steps
- Resource allocation/freeing
- Intermediate object states
- Debugging information
3. **LOG (Operational)** - For important library operations:
- Successful resource initialization
- Successful operation completion
- System state changes
- Main execution points of working algorithms
4. **INFO (Informational)** - For informing the application user:
- *This level should be used rarely in the library*
- Only truly important events for the user
- Version and configuration information
- High-level public API calls
5. **NOTICE (Notable)** - Important state changes:
- *Almost never used in a low-level library*
- Events requiring user attention
- Important business events (if applicable)
6. **WARN (Warning)** - Potentially problematic situations:
- Recoverable errors
- Edge cases in data
- Requests with potentially bad results
- Deprecated APIs
7. **EXCEPTION (Exceptional situation)** - Critical errors:
- Unrecoverable errors
- Data integrity violations
- Resource exhaustion
- Errors requiring termination
## Action Plan for Logging Improvement
1. **Automation**: Create a script to find inconsistencies in logging
2. **Prioritization**: First update the most critical components (memory management, parsers)
3. **Documentation**: Expand documentation with examples for developers
4. **Testing**: Add tests that check logging under various scenarios
5. **Review**: Conduct code reviews of all logging changes
## Examples for Different Modules
### Memory Management (arena)
```c
// Initialization
raise_message(LOG_LEVEL_DEBUG, file, func, line, "INIT: Creating new arena (size: %zu bytes)", size);
// Allocation
raise_message(LOG_LEVEL_DEBUG, file, func, line, "ALLOC: Requesting memory from arena (size: %zu bytes, available: %zu bytes)", size, available);
// Error
raise_message(LOG_LEVEL_EXCEPTION, file, func, line, "ERROR: Arena memory exhausted (requested: %zu bytes, available: %zu bytes)", size, available);
// Successful operation completion
raise_message(LOG_LEVEL_LOG, file, func, line, "ALLOC: Memory allocated successfully (address: %p, size: %zu bytes)", ptr, size);
// Freeing
raise_message(LOG_LEVEL_DEBUG, file, func, line, "FREE: Releasing arena resources (total size: %zu bytes, used: %zu bytes)", arena->capacity, used);
```
### JSON Parser
```c
// Start parsing
raise_message(LOG_LEVEL_DEBUG, file, func, line, "PARSE: Starting JSON parsing (input: %.20s%s)", *s, strlen(*s) > 20 ? "..." : "");
// Intermediate result
raise_message(LOG_LEVEL_TRACE, file, func, line, "PARSE: Found JSON %s at position %p", type_str, position);
// Parsing error
raise_message(LOG_LEVEL_WARN, file, func, line, "PARSE: Invalid JSON syntax at position %p (context: '%.10s')", *s, *s);
// Completion
raise_message(LOG_LEVEL_LOG, file, func, line, "PARSE: JSON parsing completed successfully (type: %s, size: %zu bytes)", type_str, size);
```
### Slice Operations
```c
// Creating a slice
raise_message(LOG_LEVEL_TRACE, file, func, line, "SLICE: Creating slice from array (source size: %zu, slice: %zu elements from index %zu)", array_len, len, start);
// Subslice
raise_message(LOG_LEVEL_TRACE, file, func, line, "SLICE: Extracting sub-slice (from: %zu, length: %zu)", start, len);
// Error
raise_message(LOG_LEVEL_WARN, file, func, line, "SLICE: Out of bounds slice request (start: %zu, length: %zu, available: %zu)", start, len, available);
// Successful creation
raise_message(LOG_LEVEL_LOG, file, func, line, "SLICE: Successfully created slice (length: %zu, element size: %zu)", slice.len, slice.isize);
```
## Conclusion
Implementing these standards will:
1. Simplify library debugging
2. Speed up code understanding for new developers
3. Make it easier to find problems in production
4. Make the library more professional and maintainable