Line data Source code
1 : /*
2 : * PT_Log - POSIX Implementation
3 : *
4 : * Thread-safe logging for Linux, macOS, BSD with pthread_mutex.
5 : */
6 :
7 : #include "../../include/pt_log.h"
8 :
9 : #ifndef PT_LOG_STRIP
10 :
11 : #include <stdio.h>
12 : #include <stdlib.h>
13 : #include <string.h>
14 : #include <stdarg.h>
15 : #include <unistd.h>
16 : #include <sys/time.h>
17 : #include <pthread.h>
18 : #include <time.h>
19 :
20 : /* Compile-time assertion for PT_LogPerfEntry size */
21 : typedef char PT_LogPerfEntry_must_be_16_bytes[
22 : (sizeof(PT_LogPerfEntry) == 16) ? 1 : -1
23 : ];
24 :
25 : /*============================================================================
26 : * Constants
27 : *
28 : * BUFFER SIZE RATIONALE (POSIX):
29 : * 512 bytes chosen for POSIX systems to balance throughput vs memory:
30 : * - Larger than Classic Mac's 256 bytes (no 68030 cache constraint)
31 : * - Not so large as to waste memory in multi-context scenarios
32 : * - 8x a typical 64-byte cache line (good prefetch behavior)
33 : * - Matches common filesystem block sizes (512 bytes)
34 : *
35 : * For very high-throughput logging, applications can increase this by
36 : * modifying the source. For memory-constrained POSIX systems, reduce to 256.
37 : *============================================================================*/
38 :
39 : #define PT_LOG_BUFFER_SIZE 512
40 : #define PT_LOG_LINE_MAX 256
41 :
42 : /*============================================================================
43 : * Log Context Structure
44 : *
45 : * Field ordering is optimized for cache efficiency AND minimal padding:
46 : * - Fields ordered largest-to-smallest to eliminate implicit padding
47 : * - 8-byte pointers first, then 4-byte, then 2-byte, then 1-byte
48 : * - Hot path fields grouped together in first cache line
49 : * - Large buffer at end (cold on non-write paths)
50 : *
51 : * On 64-bit: First 64 bytes contain all hot/warm fields (one cache line)
52 : *============================================================================*/
53 :
54 : struct pt_log {
55 : /* === 8-BYTE FIELDS (pointers, timeval) === */
56 : FILE *file; /* 8 bytes - file handle */
57 : PT_LogCallback msg_callback; /* 8 bytes - callback pointer */
58 : void *msg_user_data; /* 8 bytes - callback context */
59 : PT_LogPerfCallback perf_callback; /* 8 bytes */
60 : void *perf_user_data; /* 8 bytes */
61 : struct timeval start_time; /* 16 bytes - timestamp base */
62 :
63 : /* === 4-BYTE FIELDS === */
64 : int buffer_pos; /* 4 bytes - buffer write position */
65 : uint32_t next_seq; /* 4 bytes - sequence counter */
66 :
67 : /* === 2-BYTE FIELDS === */
68 : uint16_t categories; /* 2 bytes - filter check */
69 :
70 : /* === 1-BYTE FIELDS (grouped to avoid padding) === */
71 : uint8_t level; /* 1 byte - stores PT_LogLevel enum value */
72 : uint8_t outputs; /* 1 byte - output routing */
73 : uint8_t auto_flush; /* 1 byte - flush decision */
74 : uint8_t _pad[1]; /* 1 byte - explicit padding for alignment */
75 :
76 : /* === MUTEX (platform-dependent size, typically 40 bytes) === */
77 : pthread_mutex_t mutex;
78 :
79 : /* === BUFFER: Large, at end to avoid polluting cache === */
80 : char buffer[PT_LOG_BUFFER_SIZE]; /* 512 bytes */
81 : };
82 :
83 : /*============================================================================
84 : * Static Data
85 : *============================================================================*/
86 :
87 : static const char *g_level_names[] = {
88 : "---", /* NONE */
89 : "ERR",
90 : "WRN",
91 : "INF",
92 : "DBG"
93 : };
94 :
95 : static const char *g_version = "1.0.0";
96 :
97 : /*============================================================================
98 : * Lifecycle
99 : *============================================================================*/
100 :
101 248 : PT_Log *PT_LogCreate(void) {
102 248 : PT_Log *log = (PT_Log *)calloc(1, sizeof(PT_Log));
103 248 : if (!log) return NULL;
104 :
105 : /* Defaults */
106 248 : log->level = PT_LOG_INFO;
107 248 : log->categories = PT_LOG_CAT_ALL;
108 248 : log->outputs = PT_LOG_OUT_CONSOLE;
109 248 : log->auto_flush = 0;
110 248 : log->next_seq = 1;
111 :
112 : /* Record start time */
113 248 : gettimeofday(&log->start_time, NULL);
114 :
115 : /* Initialize mutex */
116 248 : pthread_mutex_init(&log->mutex, NULL);
117 :
118 248 : return log;
119 : }
120 :
121 249 : void PT_LogDestroy(PT_Log *log) {
122 249 : if (!log) return;
123 :
124 248 : PT_LogFlush(log);
125 :
126 248 : if (log->file) {
127 5 : fclose(log->file);
128 : }
129 :
130 248 : pthread_mutex_destroy(&log->mutex);
131 248 : free(log);
132 : }
133 :
134 : /*============================================================================
135 : * Configuration
136 : *============================================================================*/
137 :
138 11 : void PT_LogSetLevel(PT_Log *log, PT_LogLevel level) {
139 11 : if (log) log->level = (uint8_t)level;
140 11 : }
141 :
142 2 : PT_LogLevel PT_LogGetLevel(PT_Log *log) {
143 2 : return log ? (PT_LogLevel)log->level : PT_LOG_NONE;
144 : }
145 :
146 240 : void PT_LogSetCategories(PT_Log *log, uint16_t categories) {
147 240 : if (log) log->categories = categories;
148 240 : }
149 :
150 2 : uint16_t PT_LogGetCategories(PT_Log *log) {
151 2 : return log ? log->categories : 0;
152 : }
153 :
154 241 : void PT_LogSetOutput(PT_Log *log, uint8_t outputs) {
155 241 : if (log) log->outputs = outputs;
156 241 : }
157 :
158 1 : uint8_t PT_LogGetOutput(PT_Log *log) {
159 1 : return log ? log->outputs : 0;
160 : }
161 :
162 5 : int PT_LogSetFile(PT_Log *log, const char *filename) {
163 5 : if (!log) return -1;
164 :
165 5 : pthread_mutex_lock(&log->mutex);
166 :
167 : /* Close existing file */
168 5 : if (log->file) {
169 0 : fclose(log->file);
170 0 : log->file = NULL;
171 : }
172 :
173 5 : if (filename) {
174 5 : log->file = fopen(filename, "a");
175 5 : if (!log->file) {
176 0 : pthread_mutex_unlock(&log->mutex);
177 0 : return -1;
178 : }
179 5 : log->outputs |= PT_LOG_OUT_FILE;
180 : }
181 :
182 5 : pthread_mutex_unlock(&log->mutex);
183 5 : return 0;
184 : }
185 :
186 0 : int PT_LogClearFile(PT_Log *log) {
187 0 : int result = -1;
188 :
189 0 : if (!log) return -1;
190 :
191 0 : pthread_mutex_lock(&log->mutex);
192 :
193 0 : if (log->file) {
194 : /* Flush any buffered content first */
195 0 : if (log->buffer_pos > 0) {
196 0 : fwrite(log->buffer, 1, log->buffer_pos, log->file);
197 0 : log->buffer_pos = 0;
198 : }
199 :
200 : /* Truncate file to 0 bytes */
201 0 : if (ftruncate(fileno(log->file), 0) == 0) {
202 : /* Seek back to beginning */
203 0 : fseek(log->file, 0, SEEK_SET);
204 0 : result = 0;
205 : }
206 : }
207 :
208 0 : pthread_mutex_unlock(&log->mutex);
209 0 : return result;
210 : }
211 :
212 7 : void PT_LogSetCallback(PT_Log *log, PT_LogCallback callback, void *user_data) {
213 7 : if (log) {
214 7 : log->msg_callback = callback;
215 7 : log->msg_user_data = user_data;
216 : }
217 7 : }
218 :
219 3 : void PT_LogSetPerfCallback(PT_Log *log, PT_LogPerfCallback callback, void *user_data) {
220 3 : if (log) {
221 3 : log->perf_callback = callback;
222 3 : log->perf_user_data = user_data;
223 : }
224 3 : }
225 :
226 2 : void PT_LogSetAutoFlush(PT_Log *log, int enabled) {
227 2 : if (log) log->auto_flush = enabled ? 1 : 0;
228 2 : }
229 :
230 : /*============================================================================
231 : * Internal Helpers
232 : *============================================================================*/
233 :
234 1098 : static void flush_to_file(PT_Log *log) {
235 1098 : if (log->file && log->buffer_pos > 0) {
236 620 : fwrite(log->buffer, 1, log->buffer_pos, log->file);
237 620 : log->buffer_pos = 0;
238 : }
239 1098 : if (log->file && log->auto_flush) {
240 0 : fflush(log->file);
241 : }
242 1098 : }
243 :
244 18866 : static void write_line(PT_Log *log, const char *line, int len) {
245 : /* Buffer full? Flush it */
246 18866 : if (log->buffer_pos + len > PT_LOG_BUFFER_SIZE) {
247 615 : flush_to_file(log);
248 : }
249 :
250 : /* Still doesn't fit? Write directly */
251 18866 : if (len > PT_LOG_BUFFER_SIZE) {
252 0 : if (log->file) {
253 0 : fwrite(line, 1, len, log->file);
254 0 : if (log->auto_flush) {
255 0 : fflush(log->file);
256 : }
257 : }
258 0 : if (log->outputs & PT_LOG_OUT_CONSOLE) {
259 0 : fwrite(line, 1, len, stderr);
260 : }
261 0 : return;
262 : }
263 :
264 : /* Append to buffer */
265 18866 : if (log->outputs & PT_LOG_OUT_FILE) {
266 8007 : memcpy(log->buffer + log->buffer_pos, line, len);
267 8007 : log->buffer_pos += len;
268 : }
269 :
270 : /* Console output (unbuffered) */
271 18866 : if (log->outputs & PT_LOG_OUT_CONSOLE) {
272 2841 : fwrite(line, 1, len, stderr);
273 : }
274 : }
275 :
276 : /*============================================================================
277 : * Logging
278 : *============================================================================*/
279 :
280 19137 : void PT_LogWrite(
281 : PT_Log *log,
282 : PT_LogLevel level,
283 : PT_LogCategory category,
284 : const char *fmt,
285 : ...
286 : ) {
287 : va_list args;
288 19137 : va_start(args, fmt);
289 19137 : PT_LogWriteV(log, level, category, fmt, args);
290 19187 : va_end(args);
291 19187 : }
292 :
293 19120 : void PT_LogWriteV(
294 : PT_Log *log,
295 : PT_LogLevel level,
296 : PT_LogCategory category,
297 : const char *fmt,
298 : va_list args
299 : ) {
300 19448 : if (!log) return;
301 :
302 : /* Filter by level (early exit before allocation) */
303 19057 : if (level > log->level) return;
304 :
305 : /* Filter by category (early exit before allocation) */
306 18733 : if (!(category & log->categories)) return;
307 :
308 : /* Now allocate stack buffer (only if passing filters) */
309 : char line[PT_LOG_LINE_MAX];
310 : uint32_t timestamp_ms;
311 : const char *level_name;
312 : int prefix_len, total_len;
313 :
314 18729 : pthread_mutex_lock(&log->mutex);
315 :
316 : /* Get timestamp */
317 : struct timeval now;
318 18851 : gettimeofday(&now, NULL);
319 18851 : timestamp_ms = (uint32_t)(
320 18851 : (now.tv_sec - log->start_time.tv_sec) * 1000 +
321 18851 : (now.tv_usec - log->start_time.tv_usec) / 1000
322 : );
323 :
324 : /* Format: [timestamp][LEVEL] message\n */
325 18851 : level_name = PT_LogLevelName(level);
326 : /* cppcheck-suppress invalidPrintfArgType_uint ; uint32_t is unsigned int on unix64 */
327 18851 : prefix_len = snprintf(line, PT_LOG_LINE_MAX, "[%08u][%s] ",
328 : timestamp_ms, level_name);
329 :
330 : /* Format user message */
331 18851 : vsnprintf(line + prefix_len, PT_LOG_LINE_MAX - prefix_len - 1, fmt, args);
332 18851 : total_len = strlen(line);
333 :
334 : /* Ensure newline */
335 18851 : if (total_len < PT_LOG_LINE_MAX - 1 && line[total_len - 1] != '\n') {
336 18851 : line[total_len++] = '\n';
337 18851 : line[total_len] = '\0';
338 : }
339 :
340 : /* Write to outputs */
341 18851 : write_line(log, line, total_len);
342 :
343 : /* Callback dispatch (WARNING: callback holds mutex - don't call PT_Log!) */
344 18851 : if ((log->outputs & PT_LOG_OUT_CALLBACK) && log->msg_callback) {
345 8021 : log->msg_callback(level, category, timestamp_ms, line, log->msg_user_data);
346 : }
347 :
348 18851 : pthread_mutex_unlock(&log->mutex);
349 : }
350 :
351 16 : void PT_LogPerf(PT_Log *log, const PT_LogPerfEntry *entry, const char *label) {
352 16 : if (!log || !entry) return;
353 :
354 : /* Filter by category */
355 16 : if (!(entry->category & log->categories)) return;
356 :
357 15 : pthread_mutex_lock(&log->mutex);
358 :
359 : /* Callback dispatch */
360 15 : if (log->perf_callback) {
361 14 : log->perf_callback(entry, label, log->perf_user_data);
362 : }
363 :
364 : /* Text output (optional) */
365 15 : if (log->outputs & (PT_LOG_OUT_FILE | PT_LOG_OUT_CONSOLE)) {
366 : char line[PT_LOG_LINE_MAX];
367 : int len;
368 :
369 15 : if (label && *label) {
370 : /* cppcheck-suppress invalidPrintfArgType_uint ; uint32_t/uint16_t are unsigned int compatible */
371 3 : len = snprintf(line, PT_LOG_LINE_MAX,
372 : "[%08u][INF] PERF %s: seq=%u type=%u v1=%u v2=%u flags=0x%02X cat=0x%04X\n",
373 3 : entry->timestamp_ms,
374 : label,
375 3 : entry->seq_num,
376 3 : entry->event_type,
377 3 : entry->value1,
378 3 : entry->value2,
379 3 : entry->flags,
380 3 : entry->category);
381 : } else {
382 : /* cppcheck-suppress invalidPrintfArgType_uint ; uint32_t/uint16_t are unsigned int compatible */
383 12 : len = snprintf(line, PT_LOG_LINE_MAX,
384 : "[%08u][INF] PERF seq=%u type=%u v1=%u v2=%u flags=0x%02X cat=0x%04X\n",
385 12 : entry->timestamp_ms,
386 12 : entry->seq_num,
387 12 : entry->event_type,
388 12 : entry->value1,
389 12 : entry->value2,
390 12 : entry->flags,
391 12 : entry->category);
392 : }
393 :
394 15 : write_line(log, line, len);
395 : }
396 :
397 15 : pthread_mutex_unlock(&log->mutex);
398 : }
399 :
400 483 : void PT_LogFlush(PT_Log *log) {
401 483 : if (!log) return;
402 :
403 483 : pthread_mutex_lock(&log->mutex);
404 483 : flush_to_file(log);
405 483 : if (log->file) {
406 10 : fflush(log->file);
407 : }
408 483 : pthread_mutex_unlock(&log->mutex);
409 : }
410 :
411 : /*============================================================================
412 : * Utilities
413 : *============================================================================*/
414 :
415 14 : uint32_t PT_LogElapsedMs(PT_Log *log) {
416 14 : if (!log) return 0;
417 :
418 : struct timeval now;
419 14 : gettimeofday(&now, NULL);
420 :
421 14 : return (uint32_t)(
422 14 : (now.tv_sec - log->start_time.tv_sec) * 1000 +
423 14 : (now.tv_usec - log->start_time.tv_usec) / 1000
424 : );
425 : }
426 :
427 8015 : uint32_t PT_LogNextSeq(PT_Log *log) {
428 8015 : if (!log) return 0;
429 :
430 : uint32_t seq;
431 8015 : pthread_mutex_lock(&log->mutex);
432 8015 : seq = log->next_seq++;
433 8015 : pthread_mutex_unlock(&log->mutex);
434 :
435 8015 : return seq;
436 : }
437 :
438 18856 : const char *PT_LogLevelName(PT_LogLevel level) {
439 18856 : if (level < 0 || level > PT_LOG_DEBUG) {
440 0 : return "???";
441 : }
442 18856 : return g_level_names[level];
443 : }
444 :
445 1 : const char *PT_LogVersion(void) {
446 1 : return g_version;
447 : }
448 :
449 : #endif /* PT_LOG_STRIP */
|
