lsquic_logger.c revision 461e84d8 
1/* Copyright (c) 2017 LiteSpeed Technologies Inc.  See LICENSE. */
2/*
3 * LSQUIC Logger implementation.
4 */
5
6#include <errno.h>
7#include <inttypes.h>
8#include <stdarg.h>
9#include <stdio.h>
10#include <stdlib.h>
11#include <string.h>
12#ifndef WIN32
13#include <sys/time.h>
14#endif
15#include <time.h>
16
17#define LSQUIC_LOGGER_MODULE LSQLM_LOGGER /* Quis custodiet ipsos custodes? */
18#include "lsquic_logger.h"
19#include "lsquic.h"
20
21static enum lsquic_logger_timestamp_style g_llts = LLTS_NONE;
22
23static int
24null_vprintf (void *ctx, const char *fmt, va_list ap)
25{
26    return 0;
27}
28
29
30static int
31file_vprintf (void *ctx, const char *fmt, va_list ap)
32{
33    return vfprintf((FILE *) ctx, fmt, ap);
34}
35
36
37static const struct lsquic_logger_if file_logger_if = {
38    .vprintf    = file_vprintf,
39};
40
41static const struct lsquic_logger_if null_logger_if = {
42    .vprintf    = null_vprintf,
43};
44
45static void *logger_ctx = NULL;
46static const struct lsquic_logger_if *logger_if = &null_logger_if;
47
48enum lsq_log_level lsq_log_levels[N_LSQUIC_LOGGER_MODULES] = {
49    [LSQLM_NOMODULE]    = LSQ_LOG_WARN,
50    [LSQLM_LOGGER]      = LSQ_LOG_WARN,
51    [LSQLM_EVENT]       = LSQ_LOG_WARN,
52    [LSQLM_ENGINE]      = LSQ_LOG_WARN,
53    [LSQLM_CONN]        = LSQ_LOG_WARN,
54    [LSQLM_RECHIST]     = LSQ_LOG_WARN,
55    [LSQLM_STREAM]      = LSQ_LOG_WARN,
56    [LSQLM_PARSE]       = LSQ_LOG_WARN,
57    [LSQLM_CFCW]        = LSQ_LOG_WARN,
58    [LSQLM_SFCW]        = LSQ_LOG_WARN,
59    [LSQLM_SENDCTL]     = LSQ_LOG_WARN,
60    [LSQLM_ALARMSET]    = LSQ_LOG_WARN,
61    [LSQLM_CRYPTO]      = LSQ_LOG_WARN,
62    [LSQLM_HANDSHAKE]   = LSQ_LOG_WARN,
63    [LSQLM_HSK_ADAPTER] = LSQ_LOG_WARN,
64    [LSQLM_CUBIC]       = LSQ_LOG_WARN,
65    [LSQLM_HEADERS]     = LSQ_LOG_WARN,
66    [LSQLM_FRAME_READER]= LSQ_LOG_WARN,
67    [LSQLM_FRAME_WRITER]= LSQ_LOG_WARN,
68    [LSQLM_CONN_HASH]   = LSQ_LOG_WARN,
69    [LSQLM_ENG_HIST]    = LSQ_LOG_WARN,
70    [LSQLM_SPI]         = LSQ_LOG_WARN,
71    [LSQLM_DI]          = LSQ_LOG_WARN,
72    [LSQLM_PACER]       = LSQ_LOG_WARN,
73};
74
75const char *const lsqlm_to_str[N_LSQUIC_LOGGER_MODULES] = {
76    [LSQLM_NOMODULE]    = "",
77    [LSQLM_LOGGER]      = "logger",
78    [LSQLM_EVENT]       = "event",
79    [LSQLM_ENGINE]      = "engine",
80    [LSQLM_CONN]        = "conn",
81    [LSQLM_RECHIST]     = "rechist",
82    [LSQLM_STREAM]      = "stream",
83    [LSQLM_PARSE]       = "parse",
84    [LSQLM_CFCW]        = "cfcw",
85    [LSQLM_SFCW]        = "sfcw",
86    [LSQLM_SENDCTL]     = "sendctl",
87    [LSQLM_ALARMSET]    = "alarmset",
88    [LSQLM_CRYPTO]      = "crypto",
89    [LSQLM_HANDSHAKE]   = "handshake",
90    [LSQLM_HSK_ADAPTER] = "hsk-adapter",
91    [LSQLM_CUBIC]       = "cubic",
92    [LSQLM_HEADERS]     = "headers",
93    [LSQLM_FRAME_READER]= "frame-reader",
94    [LSQLM_FRAME_WRITER]= "frame-writer",
95    [LSQLM_CONN_HASH]   = "conn-hash",
96    [LSQLM_ENG_HIST]    = "eng-hist",
97    [LSQLM_SPI]         = "spi",
98    [LSQLM_DI]          = "di",
99    [LSQLM_PACER]       = "pacer",
100};
101
102const char *const lsq_loglevel2str[N_LSQUIC_LOG_LEVELS] = {
103    [LSQ_LOG_ALERT]   =  "ALERT",
104    [LSQ_LOG_CRIT]    =  "CRIT",
105    [LSQ_LOG_DEBUG]   =  "DEBUG",
106    [LSQ_LOG_EMERG]   =  "EMERG",
107    [LSQ_LOG_ERROR]   =  "ERROR",
108    [LSQ_LOG_INFO]    =  "INFO",
109    [LSQ_LOG_NOTICE]  =  "NOTICE",
110    [LSQ_LOG_WARN]    =  "WARN",
111};
112
113
114static void
115lsquic_printf (const char *fmt, ...)
116{
117    va_list ap;
118    va_start(ap, fmt);
119    logger_if->vprintf(logger_ctx, fmt, ap);
120    va_end(ap);
121}
122
123
124static void
125print_timestamp (void)
126{
127#ifndef WIN32
128    struct tm tm;
129    struct timeval tv;
130    gettimeofday(&tv, NULL);
131    localtime_r(&tv.tv_sec, &tm);
132    if (g_llts == LLTS_YYYYMMDD_HHMMSSUS)
133        lsquic_printf("%04d-%02d-%02d %02d:%02d:%02d.%06d ",
134            tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
135            tm.tm_hour, tm.tm_min, tm.tm_sec, (int) (tv.tv_usec));
136    else if (g_llts == LLTS_YYYYMMDD_HHMMSSMS)
137        lsquic_printf("%04d-%02d-%02d %02d:%02d:%02d.%03d ",
138            tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
139            tm.tm_hour, tm.tm_min, tm.tm_sec, (int) (tv.tv_usec / 1000));
140    else if (g_llts == LLTS_HHMMSSMS)
141        lsquic_printf("%02d:%02d:%02d.%03d ", tm.tm_hour, tm.tm_min,
142                                    tm.tm_sec, (int) (tv.tv_usec / 1000));
143    else if (g_llts == LLTS_HHMMSSUS)
144        lsquic_printf("%02d:%02d:%02d.%06d ", tm.tm_hour, tm.tm_min,
145                                    tm.tm_sec, (int) tv.tv_usec);
146    else if (g_llts == LLTS_CHROMELIKE)
147        lsquic_printf("%02d%02d/%02d%02d%02d.%06d ", tm.tm_mon + 1,
148            tm.tm_mday,tm.tm_hour, tm.tm_min, tm.tm_sec, (int) tv.tv_usec);
149#else
150    SYSTEMTIME tm = { 0 };
151    GetSystemTime(&tm);
152    if (g_llts == LLTS_YYYYMMDD_HHMMSSUS)
153        lsquic_printf("%04d-%02d-%02d %02d:%02d:%02d.%06d ",
154            tm.wYear + 1900, tm.wMonth + 1, tm.wDay,
155            tm.wHour, tm.wMinute, tm.wSecond, tm.wMilliseconds*1000 );
156    else if (g_llts == LLTS_YYYYMMDD_HHMMSSMS)
157        lsquic_printf("%04d-%02d-%02d %02d:%02d:%02d.%03d ",
158            tm.wYear + 1900, tm.wMonth + 1, tm.wDay,
159            tm.wHour, tm.wMinute, tm.wSecond, tm.wMilliseconds*1000 );
160    else if (g_llts == LLTS_HHMMSSMS)
161        lsquic_printf("%02d:%02d:%02d.%03d ", tm.wHour, tm.wMinute,
162                                    tm.wSecond, tm.wMilliseconds );
163    else if (g_llts == LLTS_HHMMSSUS)
164        lsquic_printf("%02d:%02d:%02d.%03d ", tm.wHour, tm.wMinute,
165                                    tm.wSecond, tm.wMilliseconds*1000 );
166    else if (g_llts == LLTS_CHROMELIKE)
167        lsquic_printf("%02d%02d/%02d%02d%02d.%06d ", tm.wMonth + 1,
168            tm.wDay,tm.wHour, tm.wMinute, tm.wSecond, (int) tm.wMilliseconds*1000);
169#endif
170}
171
172
173void
174lsquic_logger_log3 (enum lsq_log_level log_level,
175                    enum lsquic_logger_module module,
176                    uint64_t conn_id, uint32_t stream_id, const char *fmt, ...)
177{
178    const int saved_errno = errno;
179
180    if (g_llts != LLTS_NONE)
181        print_timestamp();
182
183    lsquic_printf("[%s] [QUIC:%"PRIu64"-%"PRIu32"] %s: ",
184        lsq_loglevel2str[log_level], conn_id, stream_id, lsqlm_to_str[module]);
185    va_list ap;
186    va_start(ap, fmt);
187    logger_if->vprintf(logger_ctx, fmt, ap);
188    va_end(ap);
189    lsquic_printf("\n");
190    errno = saved_errno;
191}
192
193
194void
195lsquic_logger_log2 (enum lsq_log_level log_level,
196                    enum lsquic_logger_module module,
197                    uint64_t conn_id, const char *fmt, ...)
198{
199    const int saved_errno = errno;
200
201    if (g_llts != LLTS_NONE)
202        print_timestamp();
203
204    lsquic_printf("[%s] [QUIC:%"PRIu64"] %s: ",
205        lsq_loglevel2str[log_level], conn_id, lsqlm_to_str[module]);
206    va_list ap;
207    va_start(ap, fmt);
208    logger_if->vprintf(logger_ctx, fmt, ap);
209    va_end(ap);
210    lsquic_printf("\n");
211    errno = saved_errno;
212}
213
214
215void
216lsquic_logger_log1 (enum lsq_log_level log_level,
217                    enum lsquic_logger_module module,
218                    const char *fmt, ...)
219{
220    const int saved_errno = errno;
221
222    if (g_llts != LLTS_NONE)
223        print_timestamp();
224
225    lsquic_printf("[%s] %s: ", lsq_loglevel2str[log_level],
226                                                lsqlm_to_str[module]);
227    va_list ap;
228    va_start(ap, fmt);
229    logger_if->vprintf(logger_ctx, fmt, ap);
230    va_end(ap);
231    lsquic_printf("\n");
232    errno = saved_errno;
233}
234
235
236void
237lsquic_logger_log0 (enum lsq_log_level log_level, const char *fmt, ...)
238{
239    const int saved_errno = errno;
240
241    if (g_llts != LLTS_NONE)
242        print_timestamp();
243
244    lsquic_printf("[%s] ", lsq_loglevel2str[log_level]);
245    va_list ap;
246    va_start(ap, fmt);
247    logger_if->vprintf(logger_ctx, fmt, ap);
248    va_end(ap);
249    lsquic_printf("\n");
250    errno = saved_errno;
251}
252
253
254void
255lsquic_logger_init (const struct lsquic_logger_if *lif, void *lctx,
256                    unsigned llts)
257{
258    logger_if  = lif;
259    logger_ctx = lctx;
260    if (llts < N_LLTS)
261        g_llts = llts;
262    LSQ_DEBUG("%s called", __func__);
263}
264
265
266enum lsquic_logger_module
267lsquic_str_to_logger_module (const char *str)
268{
269    enum lsquic_logger_module i;
270    for (i = 0; i < sizeof(lsqlm_to_str) / sizeof(lsqlm_to_str[0]); ++i)
271        if (0 == strcasecmp(lsqlm_to_str[i], str))
272            return i;
273    return -1;
274}
275
276
277enum lsq_log_level
278lsquic_str_to_log_level (const char *str)
279{
280    if (0 == strcasecmp(str, "emerg"))
281        return LSQ_LOG_EMERG;
282    if (0 == strcasecmp(str, "alert"))
283        return LSQ_LOG_ALERT;
284    if (0 == strcasecmp(str, "crit"))
285        return LSQ_LOG_CRIT;
286    if (0 == strcasecmp(str, "error"))
287        return LSQ_LOG_ERROR;
288    if (0 == strcasecmp(str, "warn"))
289        return LSQ_LOG_WARN;
290    if (0 == strcasecmp(str, "notice"))
291        return LSQ_LOG_NOTICE;
292    if (0 == strcasecmp(str, "info"))
293        return LSQ_LOG_INFO;
294    if (0 == strcasecmp(str, "debug"))
295        return LSQ_LOG_DEBUG;
296    return -1;
297}
298
299
300void
301lsquic_log_to_fstream (FILE *file, unsigned llts)
302{
303    lsquic_logger_init(&file_logger_if, file, llts);
304}
305
306
307int
308lsquic_logger_lopt (const char *optarg_orig)
309{
310    char *const optarg = strdup(optarg_orig);
311    char *mod_str;
312    int i;
313    for (i = 0; (mod_str = strtok(i ? NULL : optarg, ",")); ++i) {
314        char *level_str = strchr(mod_str, '=');
315        if (!level_str) {
316            fprintf(stderr, "Invalid module specification `%s'\n", mod_str);
317            break;
318        }
319        *level_str = '\0';
320        ++level_str;
321        enum lsquic_logger_module mod = lsquic_str_to_logger_module(mod_str);
322        if (-1 == (int) mod) {
323            fprintf(stderr, "`%s' is not a valid module name\n", mod_str);
324            break;
325        }
326        enum lsq_log_level level = lsquic_str_to_log_level(level_str);
327        if (-1 == (int) level) {
328            fprintf(stderr, "`%s' is not a valid level\n", level_str);
329            break;
330        }
331        lsq_log_levels[mod] = level;
332        LSQ_INFO("set %s to %s", mod_str, level_str);
333    }
334    free(optarg);
335    return mod_str == NULL ? 0 : -1;
336}
337
338
339int
340lsquic_set_log_level (const char *level_str)
341{
342    enum lsq_log_level level;
343    unsigned i;
344
345    level = lsquic_str_to_log_level(level_str);
346    if ((int) level >= 0)
347    {
348        for (i = 0; i < sizeof(lsq_log_levels) / sizeof(lsq_log_levels[0]); ++i)
349            lsq_log_levels[i] = level;
350        return 0;
351    }
352    else
353        return -1;
354}
355
356
357