Coverage Report

Created: 2025-11-24 06:35

next uncovered line (L), next uncovered region (R), next uncovered branch (B)
/src/libwebsockets/lib/core/logs.c
Line
Count
Source
1
/*
2
 * libwebsockets - small server side websockets and web server implementation
3
 *
4
 * Copyright (C) 2010 - 2021 Andy Green <andy@warmcat.com>
5
 *
6
 * Permission is hereby granted, free of charge, to any person obtaining a copy
7
 * of this software and associated documentation files (the "Software"), to
8
 * deal in the Software without restriction, including without limitation the
9
 * rights to use, copy, modify, merge, publish, distribute, sublicense, and/or
10
 * sell copies of the Software, and to permit persons to whom the Software is
11
 * furnished to do so, subject to the following conditions:
12
 *
13
 * The above copyright notice and this permission notice shall be included in
14
 * all copies or substantial portions of the Software.
15
 *
16
 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
17
 * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
18
 * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
19
 * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
20
 * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
21
 * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS
22
 * IN THE SOFTWARE.
23
 */
24
25
#include "private-lib-core.h"
26
27
#ifdef LWS_HAVE_SYS_TYPES_H
28
#include <sys/types.h>
29
#endif
30
31
#if defined(LWS_PLAT_OPTEE)
32
void lwsl_emit_optee(int level, const char *line);
33
#endif
34
35
lws_log_cx_t log_cx = {
36
#if !defined(LWS_PLAT_OPTEE)
37
  .u.emit       = lwsl_emit_stderr,
38
#else
39
  .u.emit       = lwsl_emit_optee,
40
#endif
41
  .lll_flags      = LLL_ERR | LLL_WARN | LLL_NOTICE,
42
};
43
44
#if !defined(LWS_PLAT_OPTEE) && !defined(LWS_WITH_NO_LOGS)
45
static const char * log_level_names ="EWNIDPHXCLUT??";
46
#endif
47
48
/*
49
 * Name an instance tag and attach to a group
50
 */
51
52
void
53
__lws_lc_tag(struct lws_context *context, lws_lifecycle_group_t *grp,
54
       lws_lifecycle_t *lc, const char *format, ...)
55
0
{
56
0
  va_list ap;
57
0
  int n = 1;
58
59
0
  if (*lc->gutag == '[') {
60
    /* appending inside [] */
61
62
0
    char *cp = strchr(lc->gutag, ']');
63
0
    char rend[96];
64
0
    size_t ll, k;
65
0
    int n;
66
67
0
    if (!cp)
68
0
      return;
69
70
    /* length of closing brace and anything else after it */
71
0
    k = strlen(cp);
72
73
    /* compute the remaining gutag unused */
74
0
    ll = sizeof(lc->gutag) - lws_ptr_diff_size_t(cp, lc->gutag) - k - 1;
75
0
    if (ll > sizeof(rend) - 1)
76
0
      ll = sizeof(rend) - 1;
77
0
    va_start(ap, format);
78
0
    n = vsnprintf(rend, ll, format, ap);
79
0
    va_end(ap);
80
81
0
    if ((unsigned int)n > ll)
82
0
      n = (int)ll;
83
84
    /* shove the trailer up by what we added */
85
0
    memmove(cp + n, cp, k);
86
0
    assert(k + (unsigned int)n < sizeof(lc->gutag));
87
0
    cp[k + (unsigned int)n] = '\0';
88
    /* copy what we added into place */
89
0
    memcpy(cp, rend, (unsigned int)n);
90
91
0
    return;
92
0
  }
93
94
0
  assert(grp);
95
0
  assert(grp->tag_prefix); /* lc group must have a tag prefix string */
96
97
0
  lc->gutag[0] = '[';
98
99
#if defined(LWS_WITH_SECURE_STREAMS_PROXY_API) /* ie, will have getpid if set */
100
  n += lws_snprintf(&lc->gutag[n], sizeof(lc->gutag) -
101
           (unsigned int)n - 1u, "%u|", getpid());
102
#endif
103
0
  n += lws_snprintf(&lc->gutag[n], sizeof(lc->gutag) -
104
0
           (unsigned int)n - 1u, "%s|%lx|",
105
0
           grp->tag_prefix,
106
0
           (unsigned long)grp->ordinal++);
107
108
0
  va_start(ap, format);
109
0
  n += vsnprintf(&lc->gutag[n], sizeof(lc->gutag) - (unsigned int)n -
110
0
      1u, format, ap);
111
0
  va_end(ap);
112
113
0
  if (n < (int)sizeof(lc->gutag) - 2) {
114
0
    lc->gutag[n++] = ']';
115
0
    lc->gutag[n++] = '\0';
116
0
  } else {
117
0
    lc->gutag[sizeof(lc->gutag) - 2] = ']';
118
0
    lc->gutag[sizeof(lc->gutag) - 1] = '\0';
119
0
  }
120
121
0
  lc->us_creation = (uint64_t)lws_now_usecs();
122
0
  lws_dll2_add_tail(&lc->list, &grp->owner);
123
124
0
  lwsl_refcount_cx(lc->log_cx, 1);
125
126
0
#if defined(LWS_LOG_TAG_LIFECYCLE)
127
0
  lwsl_cx_info(context, " ++ %s (%d)", lc->gutag, (int)grp->owner.count);
128
0
#endif
129
0
}
130
131
/*
132
 * Normally we want to set the tag one time at creation.  But sometimes we
133
 * don't have enough information at that point to give it a meaningful tag, eg,
134
 * it's an accepted, served connection but we haven't read data from it yet
135
 * to find out what it wants to be.
136
 *
137
 * This allows you to append some extra info to the tag in those cases, the
138
 * initial tag remains the same on the lhs so it can be tracked correctly.
139
 */
140
141
void
142
__lws_lc_tag_append(lws_lifecycle_t *lc, const char *app)
143
0
{
144
0
  int n = (int)strlen(lc->gutag);
145
146
0
  if (n && lc->gutag[n - 1] == ']')
147
0
    n--;
148
149
0
  if (!lc->recycle_len)
150
0
    lc->recycle_len = (uint8_t)n;
151
0
  else
152
0
    n = lc->recycle_len;
153
154
0
  n += lws_snprintf(&lc->gutag[n], sizeof(lc->gutag) - 2u -
155
0
           (unsigned int)n, "|%s]", app);
156
157
0
  if ((unsigned int)n >= sizeof(lc->gutag) - 2u) {
158
0
    lc->gutag[sizeof(lc->gutag) - 2] = ']';
159
0
    lc->gutag[sizeof(lc->gutag) - 1] = '\0';
160
0
  }
161
0
}
162
163
/*
164
 * Remove instance from group
165
 */
166
167
void
168
__lws_lc_untag(struct lws_context *context, lws_lifecycle_t *lc)
169
0
{
170
  //lws_lifecycle_group_t *grp;
171
0
  char buf[24];
172
173
0
  if (!lc->gutag[0]) { /* we never tagged this object... */
174
0
    lwsl_cx_err(context, "%s never tagged", lc->gutag);
175
0
    assert(0);
176
0
    return;
177
0
  }
178
179
0
  if (!lc->list.owner) { /* we already untagged this object... */
180
0
    lwsl_cx_err(context, "%s untagged twice", lc->gutag);
181
0
    assert(0);
182
0
    return;
183
0
  }
184
185
  //grp = lws_container_of(lc->list.owner, lws_lifecycle_group_t, owner);
186
187
0
#if defined(LWS_LOG_TAG_LIFECYCLE)
188
0
  if (lws_humanize(buf, sizeof(buf),
189
0
         (uint64_t)lws_now_usecs() - lc->us_creation,
190
0
         humanize_schema_us) > 0)
191
192
0
  lwsl_cx_info(context, " -- %s (%d) %s", lc->gutag,
193
0
        (int)lc->list.owner->count - 1, buf);
194
0
#endif
195
196
0
  lws_dll2_remove(&lc->list);
197
198
0
  lwsl_refcount_cx(lc->log_cx, -1);
199
0
}
200
201
const char *
202
lws_lc_tag(lws_lifecycle_t *lc)
203
0
{
204
0
  return lc->gutag;
205
0
}
206
207
208
int
209
lwsl_timestamp(int level, char *p, size_t len)
210
37
{
211
37
#if !defined(LWS_PLAT_OPTEE) && !defined(LWS_WITH_NO_LOGS)
212
37
  time_t o_now;
213
37
  unsigned long long now;
214
37
  struct timeval tv;
215
37
  struct tm *ptm = NULL;
216
37
#if defined(LWS_HAVE_LOCALTIME_R)
217
37
  struct tm tm;
218
37
#endif
219
37
  int n;
220
221
37
  gettimeofday(&tv, NULL);
222
37
  o_now = tv.tv_sec;
223
37
  now = ((unsigned long long)tv.tv_sec * 10000) +
224
37
        (unsigned int)(tv.tv_usec / 100);
225
226
37
#if defined(LWS_HAVE_LOCALTIME_R)
227
37
  ptm = localtime_r(&o_now, &tm);
228
#else
229
  ptm = localtime(&o_now);
230
#endif
231
37
  p[0] = '\0';
232
37
  for (n = 0; n < LLL_COUNT; n++) {
233
37
    if (level != (1 << n))
234
0
      continue;
235
236
37
    if (ptm)
237
37
      n = lws_snprintf(p, len,
238
37
        "[%04d/%02d/%02d %02d:%02d:%02d:%04d] %c: ",
239
37
        ptm->tm_year + 1900,
240
37
        ptm->tm_mon + 1,
241
37
        ptm->tm_mday,
242
37
        ptm->tm_hour,
243
37
        ptm->tm_min,
244
37
        ptm->tm_sec,
245
37
        (int)(now % 10000), log_level_names[n]);
246
0
    else
247
0
      n = lws_snprintf(p, len, "[%llu:%04d] %c: ",
248
0
          (unsigned long long) now / 10000,
249
0
          (int)(now % 10000), log_level_names[n]);
250
251
#if defined(LWS_PLAT_FREERTOS)
252
    n += lws_snprintf(p + n, len - n, "%6u: ",
253
#if defined(LWS_AMAZON_RTOS)
254
          (unsigned int)xPortGetFreeHeapSize());
255
#else
256
          (unsigned int)esp_get_free_heap_size());
257
#endif
258
#endif
259
260
37
    return n;
261
37
  }
262
#else
263
  p[0] = '\0';
264
#endif
265
266
0
  return 0;
267
37
}
268
269
#ifndef LWS_PLAT_OPTEE
270
static const char * const colours[] = {
271
  "[31;1m", /* LLL_ERR */
272
  "[36;1m", /* LLL_WARN */
273
  "[35;1m", /* LLL_NOTICE */
274
  "[32;1m", /* LLL_INFO */
275
  "[34;1m", /* LLL_DEBUG */
276
  "[33;1m", /* LLL_PARSER */
277
  "[33m", /* LLL_HEADER */
278
  "[33m", /* LLL_EXT */
279
  "[33m", /* LLL_CLIENT */
280
  "[33;1m", /* LLL_LATENCY */
281
        "[0;1m", /* LLL_USER */
282
  "[31m", /* LLL_THREAD */
283
};
284
285
static char tty;
286
287
static void
288
_lwsl_emit_stderr(int level, const char *line)
289
37
{
290
37
  int n, m = LWS_ARRAY_SIZE(colours) - 1;
291
292
37
  if (!tty)
293
1
    tty = (char)(isatty(2) | 2);
294
295
37
  if (tty == 3) {
296
0
    n = 1 << (LWS_ARRAY_SIZE(colours) - 1);
297
0
    while (n) {
298
0
      if (level & n)
299
0
        break;
300
0
      m--;
301
0
      n >>= 1;
302
0
    }
303
0
    fprintf(stderr, "%c%s%s%c[0m", 27, colours[m], line, 27);
304
0
  } else
305
37
    fprintf(stderr, "%s", line);
306
37
}
307
308
void
309
lwsl_emit_stderr(int level, const char *line)
310
37
{
311
37
  _lwsl_emit_stderr(level, line);
312
37
}
313
314
void
315
lwsl_emit_stderr_notimestamp(int level, const char *line)
316
0
{
317
0
  _lwsl_emit_stderr(level, line);
318
0
}
319
320
#if !defined(LWS_PLAT_FREERTOS) && !defined(LWS_PLAT_OPTEE) && !defined(LWS_PLAT_BAREMETAL)
321
322
/*
323
 * Helper to emit to a file
324
 */
325
326
void
327
lws_log_emit_cx_file(struct lws_log_cx *cx, int level, const char *line,
328
      size_t len)
329
0
{
330
0
  int fd = (int)(intptr_t)cx->stg;
331
332
0
  if (fd >= 0)
333
0
    if (write(fd, line, (unsigned int)len) != (ssize_t)len)
334
0
      fprintf(stderr, "Unable to write log to file\n");
335
0
}
336
337
/*
338
 * Helper to use a .refcount_cb to store logs in a file
339
 */
340
341
void
342
lws_log_use_cx_file(struct lws_log_cx *cx, int _new)
343
0
{
344
0
  int fd;
345
346
0
  if (_new > 0 && cx->refcount == 1) {
347
0
    fd = open((const char *)cx->opaque,
348
0
        LWS_O_CREAT | LWS_O_TRUNC | LWS_O_WRONLY, 0600);
349
0
    if (fd < 0)
350
0
      fprintf(stderr, "Unable to open log %s: errno %d\n",
351
0
        (const char *)cx->opaque, errno);
352
0
    cx->stg = (void *)(intptr_t)fd;
353
354
0
    return;
355
0
  }
356
357
0
  fd = (int)(intptr_t)cx->stg;
358
359
0
  if (_new <= 0 && cx->refcount == 0 && fd >= 0) {
360
0
    close(fd);
361
0
    cx->stg = (void *)(intptr_t)-1;
362
0
  }
363
0
}
364
365
#endif
366
367
#endif
368
369
#if !(defined(LWS_PLAT_OPTEE) && !defined(LWS_WITH_NETWORK))
370
void
371
__lws_logv(lws_log_cx_t *cx, lws_log_prepend_cx_t prep, void *obj,
372
     int filter, const char *_fun, const char *format, va_list vl)
373
11.5k
{
374
11.5k
#if LWS_MAX_SMP == 1 && !defined(LWS_WITH_THREADPOOL)
375
  /* this is incompatible with multithreaded logging */
376
11.5k
  static char buf[256];
377
#else
378
  char buf[1024];
379
#endif
380
11.5k
  char *p = buf, *end = p + sizeof(buf) - 1;
381
11.5k
  lws_log_cx_t *cxp;
382
11.5k
  int n, back = 0;
383
384
  /*
385
   * We need to handle NULL wsi etc at the wrappers as gracefully as
386
   * possible
387
   */
388
389
11.5k
  if (!cx) {
390
0
    lws_strncpy(p, "NULL log cx: ", sizeof(buf) - 1);
391
0
    p += 13;
392
    /* use the processwide one for lack of anything better */
393
0
    cx = &log_cx;
394
0
  }
395
396
11.5k
  cxp = cx;
397
398
11.5k
  if (!(cx->lll_flags & (uint32_t)filter))
399
    /*
400
     * logs may be produced and built in to the code but disabled
401
     * at runtime
402
     */
403
11.4k
    return;
404
405
#if !defined(LWS_LOGS_TIMESTAMP)
406
  if (cx->lll_flags & LLLF_LOG_TIMESTAMP)
407
#endif
408
37
  {
409
37
    buf[0] = '\0';
410
37
    lwsl_timestamp(filter, buf, sizeof(buf));
411
37
    p += strlen(buf);
412
37
  }
413
414
  /*
415
   * prepend parent log ctx content first
416
   * top level cx also gets an opportunity to prepend
417
   */
418
419
37
  while (cxp->parent) {
420
0
    cxp = cxp->parent;
421
0
    back++;
422
0
  }
423
424
37
  do {
425
37
    int b = back;
426
427
37
    cxp = cx;
428
37
    while (b--)
429
0
      cxp = cxp->parent;
430
37
    if (cxp->prepend)
431
0
      cxp->prepend(cxp, NULL, &p, end);
432
433
37
    back--;
434
37
  } while (back > 0);
435
436
37
  if (prep)
437
0
    prep(cxp, obj, &p, end);
438
439
37
  if (_fun)
440
0
    p += lws_snprintf(p, lws_ptr_diff_size_t(end, p), "%s: ", _fun);
441
442
  /*
443
   * The actual log content
444
   */
445
446
37
  n = vsnprintf(p, lws_ptr_diff_size_t(end, p), format, vl);
447
448
  /* vnsprintf returns what it would have written, even if truncated */
449
37
  if (p + n > end - 2) {
450
0
    p = end - 5;
451
0
    *p++ = '.';
452
0
    *p++ = '.';
453
0
    *p++ = '.';
454
0
    *p++ = '\n';
455
0
    *p++ = '\0';
456
0
  } else
457
37
    if (n > 0) {
458
37
      p += n;
459
37
      if (p[-1] != '\n')
460
0
        *p++ = '\n';
461
37
      *p = '\0';
462
37
    }
463
464
  /*
465
   * The actual emit
466
   */
467
468
37
  if (cx->lll_flags & LLLF_LOG_CONTEXT_AWARE)
469
0
    cx->u.emit_cx(cx, filter, buf, lws_ptr_diff_size_t(p, buf));
470
37
  else
471
37
    cx->u.emit(filter, buf);
472
37
}
473
474
void _lws_logv(int filter, const char *format, va_list vl)
475
0
{
476
0
  __lws_logv(&log_cx, NULL, NULL, filter, NULL, format, vl);
477
0
}
478
479
void _lws_log(int filter, const char *format, ...)
480
11.5k
{
481
11.5k
  va_list ap;
482
483
11.5k
  va_start(ap, format);
484
11.5k
  __lws_logv(&log_cx, NULL, NULL, filter, NULL, format, ap);
485
11.5k
  va_end(ap);
486
11.5k
}
487
488
void _lws_log_cx(lws_log_cx_t *cx, lws_log_prepend_cx_t prep, void *obj,
489
     int filter, const char *_fun, const char *format, ...)
490
0
{
491
0
  va_list ap;
492
493
0
  if (!cx)
494
0
    cx = &log_cx;
495
496
0
  va_start(ap, format);
497
0
  __lws_logv(cx, prep, obj, filter, _fun, format, ap);
498
0
  va_end(ap);
499
0
}
500
#endif
501
502
void
503
lws_set_log_level(int flags, lws_log_emit_t func)
504
0
{
505
0
  log_cx.lll_flags = (uint32_t)(flags & (~LLLF_LOG_CONTEXT_AWARE));
506
507
0
  if (func)
508
0
    log_cx.u.emit = func;
509
0
}
510
511
int lwsl_visible(int level)
512
0
{
513
0
  return !!(log_cx.lll_flags & (uint32_t)level);
514
0
}
515
516
int lwsl_visible_cx(lws_log_cx_t *cx, int level)
517
0
{
518
0
  return !!(cx->lll_flags & (uint32_t)level);
519
0
}
520
521
void
522
lwsl_refcount_cx(lws_log_cx_t *cx, int _new)
523
0
{
524
#if LWS_MAX_SMP > 1
525
  volatile lws_log_cx_t *vcx = (volatile lws_log_cx_t *)cx;
526
#endif
527
528
0
  if (!cx)
529
0
    return;
530
531
#if LWS_MAX_SMP > 1
532
  if (!vcx->inited) {
533
    vcx->inited = 1;
534
    lws_pthread_mutex_init(&cx->refcount_lock);
535
    vcx->inited = 2;
536
  }
537
  while (vcx->inited != 2)
538
    ;
539
  lws_pthread_mutex_lock(&cx->refcount_lock);
540
#endif
541
542
0
  if (_new > 0)
543
0
    cx->refcount++;
544
0
  else {
545
0
    assert(cx->refcount);
546
0
    cx->refcount--;
547
0
  }
548
549
0
  if (cx->refcount_cb)
550
0
    cx->refcount_cb(cx, _new);
551
552
#if LWS_MAX_SMP > 1
553
  lws_pthread_mutex_unlock(&cx->refcount_lock);
554
#endif
555
0
}
556
557
void
558
lwsl_hexdump_level_cx(lws_log_cx_t *cx, lws_log_prepend_cx_t prep, void *obj,
559
          int hexdump_level, const void *vbuf, size_t len)
560
0
{
561
0
  unsigned char *buf = (unsigned char *)vbuf;
562
0
  unsigned int n;
563
564
0
  if (!lwsl_visible_cx(cx, hexdump_level))
565
0
    return;
566
567
0
  if (!len) {
568
0
    _lws_log_cx(cx, prep, obj, hexdump_level, NULL,
569
0
          "(hexdump: zero length)\n");
570
0
    return;
571
0
  }
572
573
0
  if (!vbuf) {
574
0
    _lws_log_cx(cx, prep, obj, hexdump_level, NULL,
575
0
          "(hexdump: NULL ptr)\n");
576
0
    return;
577
0
  }
578
579
0
  _lws_log_cx(cx, prep, obj, hexdump_level, NULL, "\n");
580
581
0
  for (n = 0; n < len;) {
582
0
    unsigned int start = n, m;
583
0
    char line[80], *p = line;
584
585
0
    p += lws_snprintf(p, 10, "%04X: ", start);
586
587
0
    for (m = 0; m < 16 && n < len; m++)
588
0
      p += lws_snprintf(p, 5, "%02X ", buf[n++]);
589
0
    while (m++ < 16)
590
0
      p += lws_snprintf(p, 5, "   ");
591
592
0
    p += lws_snprintf(p, 6, "   ");
593
594
0
    for (m = 0; m < 16 && (start + m) < len; m++) {
595
0
      if (buf[start + m] >= ' ' && buf[start + m] < 127)
596
0
        *p++ = (char)buf[start + m];
597
0
      else
598
0
        *p++ = '.';
599
0
    }
600
0
    while (m++ < 16)
601
0
      *p++ = ' ';
602
603
0
    *p++ = '\n';
604
0
    *p = '\0';
605
0
    _lws_log_cx(cx, prep, obj, hexdump_level, NULL, "%s", line);
606
0
    (void)line;
607
0
  }
608
609
0
  _lws_log_cx(cx, prep, obj, hexdump_level, NULL, "\n");
610
0
}
611
612
void
613
lwsl_hexdump_level(int hexdump_level, const void *vbuf, size_t len)
614
0
{
615
0
  lwsl_hexdump_level_cx(&log_cx, NULL, NULL, hexdump_level, vbuf, len);
616
0
}
617
618
void
619
lwsl_hexdump(const void *vbuf, size_t len)
620
0
{
621
0
#if defined(_DEBUG)
622
0
  lwsl_hexdump_level(LLL_DEBUG, vbuf, len);
623
0
#endif
624
0
}