1 /*
2 * libwebsockets - small server side websockets and web server implementation
3 *
4 * Copyright (C) 2010 - 2019 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 int log_level = LLL_ERR | LLL_WARN | LLL_NOTICE;
36 static void (*lwsl_emit)(int level, const char *line)
37 #ifndef LWS_PLAT_OPTEE
38 = lwsl_emit_stderr
39 #else
40 = lwsl_emit_optee;
41 #endif
42 ;
43 #if !defined(LWS_PLAT_OPTEE) && !defined(LWS_WITH_NO_LOGS)
44 static const char * log_level_names ="EWNIDPHXCLUT??";
45 #endif
46
47 /*
48 * Name an instance tag and attach to a group
49 */
50
51 void
__lws_lc_tag(lws_lifecycle_group_t * grp,lws_lifecycle_t * lc,const char * format,...)52 __lws_lc_tag(lws_lifecycle_group_t *grp, lws_lifecycle_t *lc,
53 const char *format, ...)
54 {
55 va_list ap;
56 int n = 1;
57
58 if (*lc->gutag == '[') {
59 /* appending inside [] */
60
61 char *cp = strchr(lc->gutag, ']');
62 char rend[96];
63 size_t ll, k;
64 int n;
65
66 if (!cp)
67 return;
68
69 /* length of closing brace and anything else after it */
70 k = strlen(cp);
71
72 /* compute the remaining gutag unused */
73 ll = sizeof(lc->gutag) - lws_ptr_diff_size_t(cp, lc->gutag) - k - 1;
74 if (ll > sizeof(rend) - 1)
75 ll = sizeof(rend) - 1;
76 va_start(ap, format);
77 n = vsnprintf(rend, ll, format, ap);
78 va_end(ap);
79
80 if ((unsigned int)n > ll)
81 n = (int)ll;
82
83 /* shove the trailer up by what we added */
84 memmove(cp + n, cp, k);
85 assert(k + (unsigned int)n < sizeof(lc->gutag));
86 cp[k + (unsigned int)n] = '\0';
87 /* copy what we added into place */
88 memcpy(cp, rend, (unsigned int)n);
89
90 return;
91 }
92
93 assert(grp);
94 assert(grp->tag_prefix); /* lc group must have a tag prefix string */
95
96 lc->gutag[0] = '[';
97
98 #if defined(LWS_WITH_SECURE_STREAMS_PROXY_API) /* ie, will have getpid if set */
99 n += lws_snprintf(&lc->gutag[n], sizeof(lc->gutag) - (unsigned int)n - 1u,
100 "%u|", getpid());
101 #endif
102 n += lws_snprintf(&lc->gutag[n], sizeof(lc->gutag) - (unsigned int)n - 1u,
103 "%s|%lx|", grp->tag_prefix, (unsigned long)grp->ordinal++);
104
105 va_start(ap, format);
106 n += vsnprintf(&lc->gutag[n], sizeof(lc->gutag) - (unsigned int)n -
107 1u, format, ap);
108 va_end(ap);
109
110 if (n < (int)sizeof(lc->gutag) - 2) {
111 lc->gutag[n++] = ']';
112 lc->gutag[n++] = '\0';
113 } else {
114 lc->gutag[sizeof(lc->gutag) - 2] = ']';
115 lc->gutag[sizeof(lc->gutag) - 1] = '\0';
116 }
117
118 lc->us_creation = (uint64_t)lws_now_usecs();
119 lws_dll2_add_tail(&lc->list, &grp->owner);
120
121 #if defined(LWS_LOG_TAG_LIFECYCLE)
122 lwsl_notice(" ++ %s (%d)\n", lc->gutag, (int)grp->owner.count);
123 #endif
124 }
125
126 /*
127 * Normally we want to set the tag one time at creation. But sometimes we
128 * don't have enough information at that point to give it a meaningful tag, eg,
129 * it's an accepted, served connection but we haven't read data from it yet
130 * to find out what it wants to be.
131 *
132 * This allows you to append some extra info to the tag in those cases, the
133 * initial tag remains the same on the lhs so it can be tracked correctly.
134 */
135
136 void
__lws_lc_tag_append(lws_lifecycle_t * lc,const char * app)137 __lws_lc_tag_append(lws_lifecycle_t *lc, const char *app)
138 {
139 int n = (int)strlen(lc->gutag);
140
141 if (n && lc->gutag[n - 1] == ']')
142 n--;
143
144 n += lws_snprintf(&lc->gutag[n], sizeof(lc->gutag) - 2u - (unsigned int)n,
145 "|%s]", app);
146
147 if ((unsigned int)n >= sizeof(lc->gutag) - 2u) {
148 lc->gutag[sizeof(lc->gutag) - 2] = ']';
149 lc->gutag[sizeof(lc->gutag) - 1] = '\0';
150 }
151 }
152
153 /*
154 * Remove instance from group
155 */
156
157 void
__lws_lc_untag(lws_lifecycle_t * lc)158 __lws_lc_untag(lws_lifecycle_t *lc)
159 {
160 //lws_lifecycle_group_t *grp;
161 char buf[24];
162
163 if (!lc->gutag[0]) { /* we never tagged this object... */
164 lwsl_err("%s: %s never tagged\n", __func__, lc->gutag);
165 assert(0);
166 return;
167 }
168
169 if (!lc->list.owner) { /* we already untagged this object... */
170 lwsl_err("%s: %s untagged twice\n", __func__, lc->gutag);
171 assert(0);
172 return;
173 }
174
175 //grp = lws_container_of(lc->list.owner, lws_lifecycle_group_t, owner);
176
177 lws_humanize(buf, sizeof(buf), (uint64_t)lws_now_usecs() - lc->us_creation,
178 humanize_schema_us);
179
180 #if defined(LWS_LOG_TAG_LIFECYCLE)
181 lwsl_notice(" -- %s (%d) %s\n", lc->gutag, (int)lc->list.owner->count - 1, buf);
182 #endif
183
184 lws_dll2_remove(&lc->list);
185 }
186
187 const char *
lws_lc_tag(lws_lifecycle_t * lc)188 lws_lc_tag(lws_lifecycle_t *lc)
189 {
190 return lc->gutag;
191 }
192
193
194 #if defined(LWS_LOGS_TIMESTAMP)
195 int
lwsl_timestamp(int level,char * p,size_t len)196 lwsl_timestamp(int level, char *p, size_t len)
197 {
198 #if !defined(LWS_PLAT_OPTEE) && !defined(LWS_WITH_NO_LOGS)
199 time_t o_now;
200 unsigned long long now;
201 struct timeval tv;
202 struct tm *ptm = NULL;
203 #if defined(LWS_HAVE_LOCALTIME_R)
204 struct tm tm;
205 #endif
206 int n;
207
208 gettimeofday(&tv, NULL);
209 o_now = tv.tv_sec;
210 now = ((unsigned long long)tv.tv_sec * 10000) + (unsigned int)(tv.tv_usec / 100);
211
212 #if defined(LWS_HAVE_LOCALTIME_R)
213 ptm = localtime_r(&o_now, &tm);
214 #else
215 ptm = localtime(&o_now);
216 #endif
217 p[0] = '\0';
218 for (n = 0; n < LLL_COUNT; n++) {
219 if (level != (1 << n))
220 continue;
221
222 if (ptm)
223 n = lws_snprintf(p, len,
224 "[%04d/%02d/%02d %02d:%02d:%02d:%04d] %c: ",
225 ptm->tm_year + 1900,
226 ptm->tm_mon + 1,
227 ptm->tm_mday,
228 ptm->tm_hour,
229 ptm->tm_min,
230 ptm->tm_sec,
231 (int)(now % 10000), log_level_names[n]);
232 else
233 n = lws_snprintf(p, len, "[%llu:%04d] %c: ",
234 (unsigned long long) now / 10000,
235 (int)(now % 10000), log_level_names[n]);
236 return n;
237 }
238 #else
239 p[0] = '\0';
240 #endif
241
242 return 0;
243 }
244 #endif
245
246 #ifndef LWS_PLAT_OPTEE
247 static const char * const colours[] = {
248 "[31;1m", /* LLL_ERR */
249 "[36;1m", /* LLL_WARN */
250 "[35;1m", /* LLL_NOTICE */
251 "[32;1m", /* LLL_INFO */
252 "[34;1m", /* LLL_DEBUG */
253 "[33;1m", /* LLL_PARSER */
254 "[33m", /* LLL_HEADER */
255 "[33m", /* LLL_EXT */
256 "[33m", /* LLL_CLIENT */
257 "[33;1m", /* LLL_LATENCY */
258 "[0;1m", /* LLL_USER */
259 "[31m", /* LLL_THREAD */
260 };
261
262 static char tty;
263
264 static void
_lwsl_emit_stderr(int level,const char * line,int ts)265 _lwsl_emit_stderr(int level, const char *line, int ts)
266 {
267 char buf[50];
268 int n, m = LWS_ARRAY_SIZE(colours) - 1;
269
270 if (!tty)
271 tty = (char)(isatty(2) | 2);
272
273 buf[0] = '\0';
274 #if defined(LWS_LOGS_TIMESTAMP)
275 if (ts)
276 lwsl_timestamp(level, buf, sizeof(buf));
277 #endif
278
279 if (tty == 3) {
280 n = 1 << (LWS_ARRAY_SIZE(colours) - 1);
281 while (n) {
282 if (level & n)
283 break;
284 m--;
285 n >>= 1;
286 }
287 fprintf(stderr, "%c%s%s%s%c[0m", 27, colours[m], buf, line, 27);
288 } else
289 fprintf(stderr, "%s%s", buf, line);
290 }
291
292 void
lwsl_emit_stderr(int level,const char * line)293 lwsl_emit_stderr(int level, const char *line)
294 {
295 _lwsl_emit_stderr(level, line, 1);
296 }
297
298 void
lwsl_emit_stderr_notimestamp(int level,const char * line)299 lwsl_emit_stderr_notimestamp(int level, const char *line)
300 {
301 _lwsl_emit_stderr(level, line, 0);
302 }
303
304 #endif
305
306 #if !(defined(LWS_PLAT_OPTEE) && !defined(LWS_WITH_NETWORK))
_lws_logv(int filter,const char * format,va_list vl)307 void _lws_logv(int filter, const char *format, va_list vl)
308 {
309 #if LWS_MAX_SMP == 1 && !defined(LWS_WITH_THREADPOOL)
310 /* this is incompatible with multithreaded logging */
311 static char buf[256];
312 #else
313 char buf[1024];
314 #endif
315 int n;
316
317 if (!(log_level & filter))
318 return;
319
320 n = vsnprintf(buf, sizeof(buf) - 1, format, vl);
321 (void)n;
322 /* vnsprintf returns what it would have written, even if truncated */
323 if (n > (int)sizeof(buf) - 1) {
324 n = sizeof(buf) - 5;
325 buf[n++] = '.';
326 buf[n++] = '.';
327 buf[n++] = '.';
328 buf[n++] = '\n';
329 buf[n] = '\0';
330 }
331 if (n > 0)
332 buf[n] = '\0';
333 lwsl_emit(filter, buf);
334 }
335
_lws_log(int filter,const char * format,...)336 void _lws_log(int filter, const char *format, ...)
337 {
338 va_list ap;
339
340 va_start(ap, format);
341 _lws_logv(filter, format, ap);
342 va_end(ap);
343 }
344 #endif
lws_set_log_level(int level,void (* func)(int level,const char * line))345 void lws_set_log_level(int level, void (*func)(int level, const char *line))
346 {
347 log_level = level;
348 if (func)
349 lwsl_emit = func;
350 }
351
lwsl_visible(int level)352 int lwsl_visible(int level)
353 {
354 return log_level & level;
355 }
356
357 void
lwsl_hexdump_level(int hexdump_level,const void * vbuf,size_t len)358 lwsl_hexdump_level(int hexdump_level, const void *vbuf, size_t len)
359 {
360 unsigned char *buf = (unsigned char *)vbuf;
361 unsigned int n;
362
363 if (!lwsl_visible(hexdump_level))
364 return;
365
366 if (!len) {
367 _lws_log(hexdump_level, "(hexdump: zero length)\n");
368 return;
369 }
370
371 if (!vbuf) {
372 _lws_log(hexdump_level, "(hexdump: NULL ptr)\n");
373 return;
374 }
375
376 _lws_log(hexdump_level, "\n");
377
378 for (n = 0; n < len;) {
379 unsigned int start = n, m;
380 char line[80], *p = line;
381
382 p += lws_snprintf(p, 10, "%04X: ", start);
383
384 for (m = 0; m < 16 && n < len; m++)
385 p += lws_snprintf(p, 5, "%02X ", buf[n++]);
386 while (m++ < 16)
387 p += lws_snprintf(p, 5, " ");
388
389 p += lws_snprintf(p, 6, " ");
390
391 for (m = 0; m < 16 && (start + m) < len; m++) {
392 if (buf[start + m] >= ' ' && buf[start + m] < 127)
393 *p++ = (char)buf[start + m];
394 else
395 *p++ = '.';
396 }
397 while (m++ < 16)
398 *p++ = ' ';
399
400 *p++ = '\n';
401 *p = '\0';
402 _lws_log(hexdump_level, "%s", line);
403 (void)line;
404 }
405
406 _lws_log(hexdump_level, "\n");
407 }
408
409 void
lwsl_hexdump(const void * vbuf,size_t len)410 lwsl_hexdump(const void *vbuf, size_t len)
411 {
412 #if defined(_DEBUG)
413 lwsl_hexdump_level(LLL_DEBUG, vbuf, len);
414 #endif
415 }
416