@cryptotaxi247 / netdata
Code Commits Issues Pulls Sessions CI/CD
master
master
c 557 lines 18.6 KB
Raw
1 // SPDX-License-Identifier: GPL-3.0-or-later
2
3 // do not REMOVE this, it is used by systemd-journal includes to prevent saving the file, function, line of the
4 // source code that makes the calls, allowing our loggers to log the lines of source code that actually log
5 #define SD_JOURNAL_SUPPRESS_LOCATION
6
7 #include "../libnetdata.h"
8 #include "nd_log-internals.h"
9 #include "../stacktrace/stacktrace.h"
10
11 const char *program_name = "";
12 uint64_t debug_flags = 0;
13 int aclklog_enabled = 0;
14
15 // --------------------------------------------------------------------------------------------------------------------
16
17 ALWAYS_INLINE void errno_clear(void) {
18 errno = 0;
19
20 #if defined(OS_WINDOWS)
21 SetLastError(ERROR_SUCCESS);
22 #endif
23 }
24
25 // --------------------------------------------------------------------------------------------------------------------
26 // logger router
27
28 static ND_LOG_METHOD nd_logger_select_output(ND_LOG_SOURCES source, FILE **fpp, int *fdp, netdata_mutex_t **mutexp) {
29 bool mutexes_initialized = __atomic_load_n(&nd_log.mutexes_initialized, __ATOMIC_ACQUIRE);
30
31 *fdp = -1;
32 *mutexp = NULL;
33
34 if(source >= _NDLS_MAX)
35 source = NDLS_DAEMON;
36
37 ND_LOG_METHOD output = nd_log.sources[source].method;
38
39 switch(output) {
40 case NDLM_JOURNAL:
41 if(unlikely(!nd_log.journal_direct.initialized && !nd_log.journal.initialized)) {
42 output = NDLM_FILE;
43 *fpp = stderr;
44 *fdp = STDERR_FILENO;
45 *mutexp = &nd_log.std_error.mutex;
46 }
47 else {
48 *fpp = NULL;
49 }
50 break;
51
52 #if defined(OS_WINDOWS) && (defined(HAVE_ETW) || defined(HAVE_WEL))
53 #if defined(HAVE_ETW)
54 case NDLM_ETW:
55 #endif
56 #if defined(HAVE_WEL)
57 case NDLM_WEL:
58 #endif
59 if(unlikely(!nd_log.eventlog.initialized)) {
60 output = NDLM_FILE;
61 *fpp = stderr;
62 *fdp = STDERR_FILENO;
63 *mutexp = &nd_log.std_error.mutex;
64 }
65 else {
66 *fpp = NULL;
67 }
68 break;
69 #endif
70
71 case NDLM_SYSLOG:
72 if(unlikely(!nd_log.syslog.initialized)) {
73 output = NDLM_FILE;
74 *fpp = stderr;
75 *fdp = STDERR_FILENO;
76 *mutexp = &nd_log.std_error.mutex;
77 }
78 else {
79 *fpp = NULL;
80 }
81 break;
82
83 case NDLM_FILE:
84 if(!nd_log.sources[source].fp) {
85 *fpp = stderr;
86 *fdp = STDERR_FILENO;
87 *mutexp = &nd_log.std_error.mutex;
88 }
89 else {
90 *fpp = nd_log.sources[source].fp;
91 *fdp = nd_log.sources[source].fd;
92 *mutexp = &nd_log.sources[source].mutex;
93 }
94 break;
95
96 case NDLM_STDOUT:
97 output = NDLM_FILE;
98 *fpp = stdout;
99 *fdp = STDOUT_FILENO;
100 *mutexp = &nd_log.std_output.mutex;
101 break;
102
103 default:
104 case NDLM_DEFAULT:
105 case NDLM_STDERR:
106 output = NDLM_FILE;
107 *fpp = stderr;
108 *fdp = STDERR_FILENO;
109 *mutexp = &nd_log.std_error.mutex;
110 break;
111
112 case NDLM_DISABLED:
113 case NDLM_DEVNULL:
114 output = NDLM_DISABLED;
115 *fpp = NULL;
116 break;
117 }
118
119 if(output == NDLM_FILE && *fpp && *fdp < 0) {
120 *fpp = stderr;
121 *fdp = STDERR_FILENO;
122 *mutexp = &nd_log.std_error.mutex;
123 }
124
125 // Constructor-time logging can happen before the explicit startup init
126 // path runs. Until then, bypass write serialization and log unlocked.
127 if(nd_log.single_threaded_child || !mutexes_initialized)
128 *mutexp = NULL;
129
130 return output;
131 }
132
133 static inline netdata_mutex_t *nd_logger_stderr_mutex(void) {
134 if(nd_log.single_threaded_child)
135 return NULL;
136
137 if(!__atomic_load_n(&nd_log.mutexes_initialized, __ATOMIC_ACQUIRE))
138 return NULL;
139
140 return &nd_log.std_error.mutex;
141 }
142
143 // --------------------------------------------------------------------------------------------------------------------
144
145 static __thread bool nd_log_fatal_event = false;
146
147 static void nd_log_fatal_hook(struct log_field *fields, size_t fields_max __maybe_unused) {
148 if(!nd_log_fatal_event)
149 return;
150
151 nd_log_fatal_event = false;
152
153 if(!nd_log.fatal_hook_cb)
154 return;
155
156 const char *filename = log_field_strdupz(&fields[NDF_FILE]);
157 const char *message = log_field_strdupz(&fields[NDF_MESSAGE]);
158 const char *function = log_field_strdupz(&fields[NDF_FUNC]);
159 const char *stack_trace = log_field_strdupz(&fields[NDF_STACK_TRACE]);
160 const char *errno_str = log_field_strdupz(&fields[NDF_ERRNO]);
161 long line = log_field_to_int64(&fields[NDF_LINE]);
162
163 nd_log.fatal_hook_cb(filename, function, message, errno_str, stack_trace, line);
164 }
165
166 void nd_log_register_fatal_hook_cb(log_event_t cb) {
167 nd_log.fatal_hook_cb = cb;
168 }
169
170 // --------------------------------------------------------------------------------------------------------------------
171
172 void nd_log_register_fatal_final_cb(fatal_event_t cb) {
173 nd_log.fatal_final_cb = cb;
174 }
175
176 // --------------------------------------------------------------------------------------------------------------------
177 // high level logger
178
179 // Write serialization uses a netdata_mutex_t (sleeping mutex) per output
180 // destination, passed through from nd_logger_select_output(). Post-fork nofork
181 // spawn-server children stay single-threaded in-tree, so they bypass logger
182 // locking instead of trying to reuse inherited lock state.
183 static void nd_logger_log_fields(FILE *fp, int fd, netdata_mutex_t *mutex, bool limit,
184 ND_LOG_FIELD_PRIORITY priority,
185 ND_LOG_METHOD output, struct nd_log_source *source,
186 struct log_field *fields, size_t fields_max) {
187 nd_log_fatal_hook(fields, fields_max);
188
189 // check the limits (uses its own source->limits.spinlock internally)
190 if(limit && nd_log_limit_reached(source))
191 return;
192
193 if(output == NDLM_JOURNAL) {
194 if(!nd_logger_journal_direct(fields, fields_max) && !nd_logger_journal_libsystemd(fields, fields_max)) {
195 // we can't log to journal, let's log to stderr
196 output = NDLM_FILE;
197 fp = stderr;
198 fd = STDERR_FILENO;
199 mutex = nd_logger_stderr_mutex();
200 }
201 }
202
203 #if defined(OS_WINDOWS)
204 #if defined(HAVE_ETW)
205 if(output == NDLM_ETW) {
206 if(!nd_logger_etw(source, fields, fields_max)) {
207 // we can't log to windows events, let's log to stderr
208 output = NDLM_FILE;
209 fp = stderr;
210 fd = STDERR_FILENO;
211 mutex = nd_logger_stderr_mutex();
212 }
213 }
214 #endif
215 #if defined(HAVE_WEL)
216 if(output == NDLM_WEL) {
217 if(!nd_logger_wel(source, fields, fields_max)) {
218 // we can't log to windows events, let's log to stderr
219 output = NDLM_FILE;
220 fp = stderr;
221 fd = STDERR_FILENO;
222 mutex = nd_logger_stderr_mutex();
223 }
224 }
225 #endif
226 #endif
227
228 if(output == NDLM_SYSLOG)
229 nd_logger_syslog(priority, source->format, fields, fields_max);
230
231 if(output == NDLM_FILE)
232 nd_logger_file(fd, fp, mutex, source->format, fields, fields_max);
233 }
234
235 static void nd_logger_unset_all_thread_fields(void) {
236 size_t fields_max = THREAD_FIELDS_MAX;
237 for(size_t i = 0; i < fields_max ; i++)
238 thread_log_fields[i].entry.set = false;
239 }
240
241 static void nd_logger_merge_log_stack_to_thread_fields(void) {
242 for(size_t c = 0; c < thread_log_stack_next ;c++) {
243 struct log_stack_entry *lgs = thread_log_stack_base[c];
244
245 for(size_t i = 0; lgs[i].id != NDF_STOP ; i++) {
246 if(lgs[i].id >= _NDF_MAX || !lgs[i].set)
247 continue;
248
249 struct log_stack_entry *e = &lgs[i];
250 ND_LOG_STACK_FIELD_TYPE type = lgs[i].type;
251
252 // do not add empty / unset fields
253 if((type == NDFT_TXT && (!e->txt || !*e->txt)) ||
254 (type == NDFT_BFR && (!e->bfr || !buffer_strlen(e->bfr))) ||
255 (type == NDFT_STR && !e->str) ||
256 (type == NDFT_UUID && (!e->uuid || uuid_is_null(*e->uuid))) ||
257 (type == NDFT_CALLBACK && !e->cb.formatter) ||
258 type == NDFT_UNSET)
259 continue;
260
261 thread_log_fields[lgs[i].id].entry = *e;
262 }
263 }
264 }
265
266 static void nd_logger(const char *file, const char *function, const unsigned long line,
267 ND_LOG_SOURCES source, ND_LOG_FIELD_PRIORITY priority, bool limit,
268 int saved_errno, size_t saved_winerror __maybe_unused, const char *fmt, va_list ap) {
269
270 FILE *fp;
271 int fd;
272 netdata_mutex_t *mutex;
273 ND_LOG_METHOD output = nd_logger_select_output(source, &fp, &fd, &mutex);
274 if(!IS_FINAL_LOG_METHOD(output))
275 return;
276
277 // mark all fields as unset
278 nd_logger_unset_all_thread_fields();
279
280 // flatten the log stack into the fields
281 nd_logger_merge_log_stack_to_thread_fields();
282
283 // set the common fields that are automatically set by the logging subsystem
284
285 #if 0
286 // getting stack traces is crashing on some architectures, so we get them only for daemon status file
287 if(likely(!thread_log_fields[NDF_STACK_TRACE].entry.set) && priority <= NDLP_ALERT) // only on fatal errors
288 thread_log_fields[NDF_STACK_TRACE].entry = ND_LOG_FIELD_CB(NDF_STACK_TRACE, stack_trace_formatter, NULL);
289 #endif
290
291 if(likely(!thread_log_fields[NDF_INVOCATION_ID].entry.set))
292 thread_log_fields[NDF_INVOCATION_ID].entry = ND_LOG_FIELD_UUID(NDF_INVOCATION_ID, &nd_log.invocation_id);
293
294 if(likely(!thread_log_fields[NDF_LOG_SOURCE].entry.set))
295 thread_log_fields[NDF_LOG_SOURCE].entry = ND_LOG_FIELD_TXT(NDF_LOG_SOURCE, nd_log_id2source(source));
296 else {
297 ND_LOG_SOURCES src = source;
298
299 if(thread_log_fields[NDF_LOG_SOURCE].entry.type == NDFT_TXT)
300 src = nd_log_source2id(thread_log_fields[NDF_LOG_SOURCE].entry.txt, source);
301 else if(thread_log_fields[NDF_LOG_SOURCE].entry.type == NDFT_U64)
302 src = thread_log_fields[NDF_LOG_SOURCE].entry.u64;
303
304 if(src != source && src < _NDLS_MAX) {
305 source = src;
306 output = nd_logger_select_output(source, &fp, &fd, &mutex);
307 if(output != NDLM_FILE && output != NDLM_JOURNAL && output != NDLM_SYSLOG)
308 return;
309 }
310 }
311
312 if(likely(!thread_log_fields[NDF_SYSLOG_IDENTIFIER].entry.set))
313 thread_log_fields[NDF_SYSLOG_IDENTIFIER].entry = ND_LOG_FIELD_TXT(NDF_SYSLOG_IDENTIFIER, program_name);
314
315 if(likely(!thread_log_fields[NDF_LINE].entry.set)) {
316 thread_log_fields[NDF_LINE].entry = ND_LOG_FIELD_U64(NDF_LINE, line);
317 thread_log_fields[NDF_FILE].entry = ND_LOG_FIELD_TXT(NDF_FILE, file);
318 thread_log_fields[NDF_FUNC].entry = ND_LOG_FIELD_TXT(NDF_FUNC, function);
319 }
320
321 if(likely(!thread_log_fields[NDF_PRIORITY].entry.set)) {
322 thread_log_fields[NDF_PRIORITY].entry = ND_LOG_FIELD_U64(NDF_PRIORITY, priority);
323 }
324
325 if(likely(!thread_log_fields[NDF_TID].entry.set))
326 thread_log_fields[NDF_TID].entry = ND_LOG_FIELD_U64(NDF_TID, gettid_cached());
327
328 if(likely(!thread_log_fields[NDF_THREAD_TAG].entry.set)) {
329 const char *thread_tag = nd_thread_tag();
330 thread_log_fields[NDF_THREAD_TAG].entry = ND_LOG_FIELD_TXT(NDF_THREAD_TAG, thread_tag);
331
332 // TODO: fix the ND_MODULE in logging by setting proper module name in threads
333 // if(!thread_log_fields[NDF_MODULE].entry.set)
334 // thread_log_fields[NDF_MODULE].entry = ND_LOG_FIELD_CB(NDF_MODULE, thread_tag_to_module, (void *)thread_tag);
335 }
336
337 if(likely(!thread_log_fields[NDF_TIMESTAMP_REALTIME_USEC].entry.set))
338 thread_log_fields[NDF_TIMESTAMP_REALTIME_USEC].entry = ND_LOG_FIELD_U64(NDF_TIMESTAMP_REALTIME_USEC, now_realtime_usec());
339
340 if(saved_errno != 0 && !thread_log_fields[NDF_ERRNO].entry.set)
341 thread_log_fields[NDF_ERRNO].entry = ND_LOG_FIELD_I64(NDF_ERRNO, saved_errno);
342
343 if(saved_winerror != 0 && !thread_log_fields[NDF_WINERROR].entry.set)
344 thread_log_fields[NDF_WINERROR].entry = ND_LOG_FIELD_U64(NDF_WINERROR, saved_winerror);
345
346 CLEAN_BUFFER *wb = NULL;
347 if(fmt && !thread_log_fields[NDF_MESSAGE].entry.set) {
348 wb = buffer_create(1024, NULL);
349 buffer_vsprintf(wb, fmt, ap);
350 thread_log_fields[NDF_MESSAGE].entry = ND_LOG_FIELD_TXT(NDF_MESSAGE, buffer_tostring(wb));
351 }
352
353 nd_logger_log_fields(fp, fd, mutex, limit, priority, output, &nd_log.sources[source],
354 thread_log_fields, THREAD_FIELDS_MAX);
355
356 if(nd_log.sources[source].pending_msg && spinlock_trylock(&nd_log.sources[source].limits.spinlock)) {
357 // we have to check again if the pending message is still there
358
359 const char *pending_msg = nd_log.sources[source].pending_msg;
360
361 if(pending_msg) {
362 nd_logger_unset_all_thread_fields();
363
364 thread_log_fields[NDF_TIMESTAMP_REALTIME_USEC].entry = (struct log_stack_entry){
365 .set = true,
366 .type = NDFT_U64,
367 .u64 = now_realtime_usec(),
368 };
369
370 thread_log_fields[NDF_LOG_SOURCE].entry = (struct log_stack_entry){
371 .set = true,
372 .type = NDFT_TXT,
373 .txt = nd_log_id2source(source),
374 };
375
376 thread_log_fields[NDF_SYSLOG_IDENTIFIER].entry = (struct log_stack_entry){
377 .set = true,
378 .type = NDFT_TXT,
379 .txt = program_name,
380 };
381
382 thread_log_fields[NDF_MESSAGE].entry = (struct log_stack_entry){
383 .set = true,
384 .type = NDFT_TXT,
385 .txt = pending_msg,
386 };
387
388 thread_log_fields[NDF_MESSAGE_ID].entry = (struct log_stack_entry){
389 .set = nd_log.sources[source].pending_msgid != NULL,
390 .type = NDFT_UUID,
391 .uuid = nd_log.sources[source].pending_msgid,
392 };
393
394 nd_log.sources[source].pending_msg = NULL;
395 nd_log.sources[source].pending_msgid = NULL;
396 }
397
398 spinlock_unlock(&nd_log.sources[source].limits.spinlock);
399
400 if(pending_msg)
401 nd_logger_log_fields(fp, fd, mutex, false, priority, output, &nd_log.sources[source],
402 thread_log_fields, THREAD_FIELDS_MAX);
403
404 freez((void *)pending_msg);
405 }
406
407 errno_clear();
408 }
409
410 static ND_LOG_SOURCES nd_log_validate_source(ND_LOG_SOURCES source) {
411 if(source >= _NDLS_MAX)
412 source = NDLS_DAEMON;
413
414 if(nd_log.overwrite_process_source)
415 source = nd_log.overwrite_process_source;
416
417 return source;
418 }
419
420 // --------------------------------------------------------------------------------------------------------------------
421 // public API for loggers
422
423 NEVER_INLINE
424 void netdata_logger(ND_LOG_SOURCES source, ND_LOG_FIELD_PRIORITY priority, const char *file, const char *function, unsigned long line, const char *fmt, ... )
425 {
426 int saved_errno = errno;
427
428 size_t saved_winerror = 0;
429 #if defined(OS_WINDOWS)
430 saved_winerror = GetLastError();
431 #endif
432
433 source = nd_log_validate_source(source);
434
435 if (source != NDLS_DEBUG && priority > nd_log.sources[source].min_priority)
436 return;
437
438 va_list args;
439 va_start(args, fmt);
440 nd_logger(file, function, line, source, priority,
441 source == NDLS_DAEMON || source == NDLS_COLLECTORS,
442 saved_errno, saved_winerror, fmt, args);
443 va_end(args);
444 }
445
446 NEVER_INLINE
447 void netdata_logger_with_limit(ERROR_LIMIT *erl, ND_LOG_SOURCES source, ND_LOG_FIELD_PRIORITY priority, const char *file __maybe_unused, const char *function __maybe_unused, const unsigned long line __maybe_unused, const char *fmt, ... ) {
448 int saved_errno = errno;
449
450 size_t saved_winerror = 0;
451 #if defined(OS_WINDOWS)
452 saved_winerror = GetLastError();
453 #endif
454
455 source = nd_log_validate_source(source);
456
457 if (source != NDLS_DEBUG && priority > nd_log.sources[source].min_priority)
458 return;
459
460 if(erl->sleep_ut)
461 sleep_usec(erl->sleep_ut);
462
463 if(!nd_log.single_threaded_child)
464 spinlock_lock(&erl->spinlock);
465
466 erl->count++;
467 time_t now = now_boottime_sec();
468 if(now - erl->last_logged < erl->log_every) {
469 if(!nd_log.single_threaded_child)
470 spinlock_unlock(&erl->spinlock);
471 return;
472 }
473
474 if(!nd_log.single_threaded_child)
475 spinlock_unlock(&erl->spinlock);
476
477 va_list args;
478 va_start(args, fmt);
479 nd_logger(file, function, line, source, priority,
480 source == NDLS_DAEMON || source == NDLS_COLLECTORS,
481 saved_errno, saved_winerror, fmt, args);
482 va_end(args);
483 erl->last_logged = now;
484 erl->count = 0;
485 }
486
487 NEVER_INLINE NORETURN
488 static void recursive_fatal_abort(void) {
489 // keep this as a separate function, to have it logged like this in sentry
490 #ifdef ENABLE_SENTRY
491 abort();
492 #endif
493 _exit(1);
494 }
495
496 #ifdef NETDATA_INTERNAL_CHECKS
497 NEVER_INLINE NORETURN
498 static void fatal_abort_internal_checks(void) {
499 // keep this as a separate function, to have it logged like this in sentry
500 abort();
501 _exit(1);
502 }
503 #endif
504
505 NEVER_INLINE
506 void netdata_logger_fatal(const char *file, const char *function, const unsigned long line, const char *fmt, ... ) {
507 static size_t already_in_fatal = 0;
508
509 size_t recursion = __atomic_add_fetch(&already_in_fatal, 1, __ATOMIC_SEQ_CST);
510 if(recursion > 1) {
511 // exit immediately, nothing more to be done
512 sleep(2); // give the first fatal the chance to be written
513 fprintf(stderr, "\nRECURSIVE FATAL STATEMENTS, latest from %s() of %lu@%s, EXITING NOW! 23e93dfccbf64e11aac858b9410d8a82\n",
514 function, line, file);
515 fflush(stderr);
516 recursive_fatal_abort();
517 }
518
519 // send this event to deamon_status_file
520 nd_log_fatal_event = true;
521
522 int saved_errno = errno;
523 size_t saved_winerror = 0;
524 #if defined(OS_WINDOWS)
525 saved_winerror = GetLastError();
526 #endif
527
528 // make sure the msg id does not leak
529 {
530 ND_LOG_STACK lgs[] = {
531 ND_LOG_FIELD_UUID(NDF_MESSAGE_ID, &netdata_fatal_msgid),
532 ND_LOG_FIELD_END(),
533 };
534 ND_LOG_STACK_PUSH(lgs);
535
536 ND_LOG_SOURCES source = NDLS_DAEMON;
537 source = nd_log_validate_source(source);
538
539 va_list args;
540 va_start(args, fmt);
541 nd_logger(file, function, line, source, NDLP_ALERT, true, saved_errno, saved_winerror, fmt, args);
542 va_end(args);
543 }
544
545 #if defined(FSANITIZE_ADDRESS)
546 fprintf(stderr, "FATAL: %04lu@%s:%s, errno = %d\n", line, file, function, saved_errno);
547 #endif
548
549 #ifdef NETDATA_INTERNAL_CHECKS
550 fatal_abort_internal_checks();
551 #endif
552
553 if(nd_log.fatal_final_cb)
554 nd_log.fatal_final_cb();
555
556 exit(1);
557 }