Branch data Line data Source code
1 : : /*
2 : : * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013, 2015, 2016 Nicira, Inc.
3 : : *
4 : : * Licensed under the Apache License, Version 2.0 (the "License");
5 : : * you may not use this file except in compliance with the License.
6 : : * You may obtain a copy of the License at:
7 : : *
8 : : * http://www.apache.org/licenses/LICENSE-2.0
9 : : *
10 : : * Unless required by applicable law or agreed to in writing, software
11 : : * distributed under the License is distributed on an "AS IS" BASIS,
12 : : * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 : : * See the License for the specific language governing permissions and
14 : : * limitations under the License.
15 : : */
16 : :
17 : : #include <config.h>
18 : : #include "openvswitch/vlog.h"
19 : : #include <assert.h>
20 : : #include <ctype.h>
21 : : #include <errno.h>
22 : : #include <fcntl.h>
23 : : #include <stdarg.h>
24 : : #include <stdlib.h>
25 : : #include <string.h>
26 : : #include <sys/stat.h>
27 : : #include <sys/types.h>
28 : : #include <syslog.h>
29 : : #include <time.h>
30 : : #include <unistd.h>
31 : : #include "async-append.h"
32 : : #include "coverage.h"
33 : : #include "dirs.h"
34 : : #include "openvswitch/dynamic-string.h"
35 : : #include "openvswitch/ofpbuf.h"
36 : : #include "ovs-thread.h"
37 : : #include "sat-math.h"
38 : : #include "socket-util.h"
39 : : #include "svec.h"
40 : : #include "syslog-direct.h"
41 : : #include "syslog-libc.h"
42 : : #include "syslog-provider.h"
43 : : #include "timeval.h"
44 : : #include "unixctl.h"
45 : : #include "util.h"
46 : :
47 : 53956 : VLOG_DEFINE_THIS_MODULE(vlog);
48 : :
49 : : /* ovs_assert() logs the assertion message, so using ovs_assert() in this
50 : : * source file could cause recursion. */
51 : : #undef ovs_assert
52 : : #define ovs_assert use_assert_instead_of_ovs_assert_in_this_module
53 : :
54 : : /* Name for each logging level. */
55 : : static const char *const level_names[VLL_N_LEVELS] = {
56 : : #define VLOG_LEVEL(NAME, SYSLOG_LEVEL, RFC5424) #NAME,
57 : : VLOG_LEVELS
58 : : #undef VLOG_LEVEL
59 : : };
60 : :
61 : : /* Syslog value for each logging level. */
62 : : static const int syslog_levels[VLL_N_LEVELS] = {
63 : : #define VLOG_LEVEL(NAME, SYSLOG_LEVEL, RFC5424) SYSLOG_LEVEL,
64 : : VLOG_LEVELS
65 : : #undef VLOG_LEVEL
66 : : };
67 : :
68 : : /* RFC 5424 defines specific values for each syslog level. Normally LOG_* use
69 : : * the same values. Verify that in fact they're the same. If we get assertion
70 : : * failures here then we need to define a separate rfc5424_levels[] array. */
71 : : #define VLOG_LEVEL(NAME, SYSLOG_LEVEL, RFC5424) \
72 : : BUILD_ASSERT_DECL(SYSLOG_LEVEL == RFC5424);
73 : : VLOG_LEVELS
74 : : #undef VLOG_LEVELS
75 : :
76 : : /* Similarly, RFC 5424 defines the local0 facility with the value ordinarily
77 : : * used for LOG_LOCAL0. */
78 : : BUILD_ASSERT_DECL(LOG_LOCAL0 == (16 << 3));
79 : :
80 : : /* Protects the 'pattern' in all "struct destination"s, so that a race between
81 : : * changing and reading the pattern does not cause an access to freed
82 : : * memory. */
83 : : static struct ovs_rwlock pattern_rwlock = OVS_RWLOCK_INITIALIZER;
84 : :
85 : : /* Information about each destination. */
86 : : struct destination {
87 : : const char *name; /* Name. */
88 : : char *pattern OVS_GUARDED_BY(pattern_rwlock); /* Current pattern. */
89 : : bool default_pattern; /* Whether current pattern is the default. */
90 : : };
91 : : static struct destination destinations[VLF_N_DESTINATIONS] = {
92 : : #define VLOG_DESTINATION(NAME, PATTERN) {#NAME, PATTERN, true},
93 : : VLOG_DESTINATIONS
94 : : #undef VLOG_DESTINATION
95 : : };
96 : :
97 : : /* Sequence number for the message currently being composed. */
98 : 774934 : DEFINE_STATIC_PER_THREAD_DATA(unsigned int, msg_num, 0);
99 : :
100 : : /* VLF_FILE configuration.
101 : : *
102 : : * All of the following is protected by 'log_file_mutex', which nests inside
103 : : * pattern_rwlock. */
104 : : static struct ovs_mutex log_file_mutex OVS_ACQ_AFTER(pattern_rwlock)
105 : : = OVS_MUTEX_INITIALIZER;
106 : : static char *log_file_name OVS_GUARDED_BY(log_file_mutex) = NULL;
107 : : static int log_fd OVS_GUARDED_BY(log_file_mutex) = -1;
108 : : static struct async_append *log_writer OVS_GUARDED_BY(log_file_mutex);
109 : : static bool log_async OVS_GUARDED_BY(log_file_mutex);
110 : : static struct syslogger *syslogger = NULL;
111 : :
112 : : /* The log modules. */
113 : : static struct ovs_list vlog_modules OVS_GUARDED_BY(log_file_mutex)
114 : : = OVS_LIST_INITIALIZER(&vlog_modules);
115 : :
116 : : /* Syslog export configuration. */
117 : : static int syslog_fd OVS_GUARDED_BY(pattern_rwlock) = -1;
118 : :
119 : : /* Log facility configuration. */
120 : : static atomic_int log_facility = ATOMIC_VAR_INIT(0);
121 : :
122 : : /* Facility name and its value. */
123 : : struct vlog_facility {
124 : : char *name; /* Name. */
125 : : unsigned int value; /* Facility associated with 'name'. */
126 : : };
127 : : static struct vlog_facility vlog_facilities[] = {
128 : : {"kern", LOG_KERN},
129 : : {"user", LOG_USER},
130 : : {"mail", LOG_MAIL},
131 : : {"daemon", LOG_DAEMON},
132 : : {"auth", LOG_AUTH},
133 : : {"syslog", LOG_SYSLOG},
134 : : {"lpr", LOG_LPR},
135 : : {"news", LOG_NEWS},
136 : : {"uucp", LOG_UUCP},
137 : : {"clock", LOG_CRON},
138 : : {"ftp", LOG_FTP},
139 : : {"ntp", 12<<3},
140 : : {"audit", 13<<3},
141 : : {"alert", 14<<3},
142 : : {"clock2", 15<<3},
143 : : {"local0", LOG_LOCAL0},
144 : : {"local1", LOG_LOCAL1},
145 : : {"local2", LOG_LOCAL2},
146 : : {"local3", LOG_LOCAL3},
147 : : {"local4", LOG_LOCAL4},
148 : : {"local5", LOG_LOCAL5},
149 : : {"local6", LOG_LOCAL6},
150 : : {"local7", LOG_LOCAL7}
151 : : };
152 : : static bool vlog_facility_exists(const char* facility, int *value);
153 : :
154 : : static void format_log_message(const struct vlog_module *, enum vlog_level,
155 : : const char *pattern,
156 : : const char *message, va_list, struct ds *)
157 : : OVS_PRINTF_FORMAT(4, 0);
158 : :
159 : : /* Searches the 'n_names' in 'names'. Returns the index of a match for
160 : : * 'target', or 'n_names' if no name matches. */
161 : : static size_t
162 : 27601 : search_name_array(const char *target, const char *const *names, size_t n_names)
163 : : {
164 : : size_t i;
165 : :
166 [ + + ]: 129487 : for (i = 0; i < n_names; i++) {
167 [ - + ]: 119834 : assert(names[i]);
168 [ + + ]: 119834 : if (!strcasecmp(names[i], target)) {
169 : 17948 : break;
170 : : }
171 : : }
172 : 27601 : return i;
173 : : }
174 : :
175 : : /* Returns the name for logging level 'level'. */
176 : : const char *
177 : 195497 : vlog_get_level_name(enum vlog_level level)
178 : : {
179 [ - + ]: 195497 : assert(level < VLL_N_LEVELS);
180 : 195497 : return level_names[level];
181 : : }
182 : :
183 : : /* Returns the logging level with the given 'name', or VLL_N_LEVELS if 'name'
184 : : * is not the name of a logging level. */
185 : : enum vlog_level
186 : 27601 : vlog_get_level_val(const char *name)
187 : : {
188 : 27601 : return search_name_array(name, level_names, ARRAY_SIZE(level_names));
189 : : }
190 : :
191 : : /* Returns the name for logging destination 'destination'. */
192 : : const char *
193 : 0 : vlog_get_destination_name(enum vlog_destination destination)
194 : : {
195 [ # # ]: 0 : assert(destination < VLF_N_DESTINATIONS);
196 : 0 : return destinations[destination].name;
197 : : }
198 : :
199 : : /* Returns the logging destination named 'name', or VLF_N_DESTINATIONS if
200 : : * 'name' is not the name of a logging destination. */
201 : : enum vlog_destination
202 : 20943 : vlog_get_destination_val(const char *name)
203 : : {
204 : : size_t i;
205 : :
206 [ + + ]: 79147 : for (i = 0; i < VLF_N_DESTINATIONS; i++) {
207 [ + + ]: 60519 : if (!strcasecmp(destinations[i].name, name)) {
208 : 2315 : break;
209 : : }
210 : : }
211 : 20943 : return i;
212 : : }
213 : :
214 : : void
215 : 1052166 : vlog_insert_module(struct ovs_list *vlog)
216 : : {
217 : 1052166 : ovs_mutex_lock(&log_file_mutex);
218 : 1052166 : ovs_list_insert(&vlog_modules, vlog);
219 : 1052166 : ovs_mutex_unlock(&log_file_mutex);
220 : 1052166 : }
221 : :
222 : : /* Returns the name for logging module 'module'. */
223 : : const char *
224 : 195647 : vlog_get_module_name(const struct vlog_module *module)
225 : : {
226 : 195647 : return module->name;
227 : : }
228 : :
229 : : /* Returns the logging module named 'name', or NULL if 'name' is not the name
230 : : * of a logging module. */
231 : : struct vlog_module *
232 : 19305 : vlog_module_from_name(const char *name)
233 : : {
234 : : struct vlog_module *mp;
235 : :
236 : 19305 : ovs_mutex_lock(&log_file_mutex);
237 [ + + ]: 628918 : LIST_FOR_EACH (mp, list, &vlog_modules) {
238 [ + + ]: 628917 : if (!strcasecmp(name, mp->name)) {
239 : 19304 : ovs_mutex_unlock(&log_file_mutex);
240 : 19304 : return mp;
241 : : }
242 : : }
243 : 1 : ovs_mutex_unlock(&log_file_mutex);
244 : :
245 : 1 : return NULL;
246 : : }
247 : :
248 : : /* Returns the current logging level for the given 'module' and
249 : : * 'destination'. */
250 : : enum vlog_level
251 : 378 : vlog_get_level(const struct vlog_module *module,
252 : : enum vlog_destination destination)
253 : : {
254 [ - + ]: 378 : assert(destination < VLF_N_DESTINATIONS);
255 : 378 : return module->levels[destination];
256 : : }
257 : :
258 : : static void
259 : 655101 : update_min_level(struct vlog_module *module) OVS_REQUIRES(&log_file_mutex)
260 : : {
261 : : enum vlog_destination destination;
262 : :
263 : 655101 : module->min_level = VLL_OFF;
264 [ + + ]: 2620404 : for (destination = 0; destination < VLF_N_DESTINATIONS; destination++) {
265 [ + + ][ + + ]: 1965303 : if (log_fd >= 0 || destination != VLF_FILE) {
266 : 1507625 : enum vlog_level level = module->levels[destination];
267 [ + + ]: 1507625 : if (level > module->min_level) {
268 : 672335 : module->min_level = level;
269 : : }
270 : : }
271 : : }
272 : 655101 : }
273 : :
274 : : static void
275 : 39662 : set_destination_level(enum vlog_destination destination,
276 : : struct vlog_module *module, enum vlog_level level)
277 : : {
278 [ + - ][ - + ]: 39662 : assert(destination >= 0 && destination < VLF_N_DESTINATIONS);
279 [ - + ]: 39662 : assert(level < VLL_N_LEVELS);
280 : :
281 : 39662 : ovs_mutex_lock(&log_file_mutex);
282 [ + + ]: 39662 : if (!module) {
283 : : struct vlog_module *mp;
284 [ + + ]: 538468 : LIST_FOR_EACH (mp, list, &vlog_modules) {
285 : 527888 : mp->levels[destination] = level;
286 : 527888 : update_min_level(mp);
287 : : }
288 : : } else {
289 : 29082 : module->levels[destination] = level;
290 : 29082 : update_min_level(module);
291 : : }
292 : 39662 : ovs_mutex_unlock(&log_file_mutex);
293 : 39662 : }
294 : :
295 : : /* Sets the logging level for the given 'module' and 'destination' to 'level'.
296 : : * A null 'module' or a 'destination' of VLF_ANY_DESTINATION is treated as a
297 : : * wildcard across all modules or destinations, respectively. */
298 : : void
299 : 19734 : vlog_set_levels(struct vlog_module *module, enum vlog_destination destination,
300 : : enum vlog_level level)
301 : : {
302 [ - + ][ # # ]: 19734 : assert(destination < VLF_N_DESTINATIONS ||
303 : : destination == VLF_ANY_DESTINATION);
304 [ + + ]: 19734 : if (destination == VLF_ANY_DESTINATION) {
305 [ + + ]: 39856 : for (destination = 0; destination < VLF_N_DESTINATIONS;
306 : 29892 : destination++) {
307 : 29892 : set_destination_level(destination, module, level);
308 : : }
309 : : } else {
310 : 9770 : set_destination_level(destination, module, level);
311 : : }
312 : 19734 : }
313 : :
314 : : static void
315 : 287 : do_set_pattern(enum vlog_destination destination, const char *pattern)
316 : : {
317 : 287 : struct destination *f = &destinations[destination];
318 : :
319 : 287 : ovs_rwlock_wrlock(&pattern_rwlock);
320 [ - + ]: 287 : if (!f->default_pattern) {
321 : 0 : free(f->pattern);
322 : : } else {
323 : 287 : f->default_pattern = false;
324 : : }
325 : 287 : f->pattern = xstrdup(pattern);
326 : 287 : ovs_rwlock_unlock(&pattern_rwlock);
327 : 287 : }
328 : :
329 : : /* Sets the pattern for the given 'destination' to 'pattern'. */
330 : : void
331 : 281 : vlog_set_pattern(enum vlog_destination destination, const char *pattern)
332 : : {
333 [ - + ][ # # ]: 281 : assert(destination < VLF_N_DESTINATIONS ||
334 : : destination == VLF_ANY_DESTINATION);
335 [ + + ]: 281 : if (destination == VLF_ANY_DESTINATION) {
336 [ + + ]: 12 : for (destination = 0; destination < VLF_N_DESTINATIONS;
337 : 9 : destination++) {
338 : 9 : do_set_pattern(destination, pattern);
339 : : }
340 : : } else {
341 : 278 : do_set_pattern(destination, pattern);
342 : : }
343 : 281 : }
344 : :
345 : : /* Sets the name of the log file used by VLF_FILE to 'file_name', or to the
346 : : * default file name if 'file_name' is null. Returns 0 if successful,
347 : : * otherwise a positive errno value. */
348 : : int
349 : 1735 : vlog_set_log_file(const char *file_name)
350 : : {
351 : : char *new_log_file_name;
352 : : struct vlog_module *mp;
353 : : struct stat old_stat;
354 : : struct stat new_stat;
355 : : int new_log_fd;
356 : : bool same_file;
357 : : bool log_close;
358 : :
359 : : /* Open new log file. */
360 : 1735 : new_log_file_name = (file_name
361 : : ? xstrdup(file_name)
362 [ + + ]: 1735 : : xasprintf("%s/%s.log", ovs_logdir(), program_name));
363 : 1735 : new_log_fd = open(new_log_file_name, O_WRONLY | O_CREAT | O_APPEND, 0666);
364 [ - + ]: 1735 : if (new_log_fd < 0) {
365 [ # # ]: 0 : VLOG_WARN("failed to open %s for logging: %s",
366 : : new_log_file_name, ovs_strerror(errno));
367 : 0 : free(new_log_file_name);
368 : 0 : return errno;
369 : : }
370 : :
371 : : /* If the new log file is the same one we already have open, bail out. */
372 : 1735 : ovs_mutex_lock(&log_file_mutex);
373 : 3470 : same_file = (log_fd >= 0
374 [ + - ]: 3 : && new_log_fd >= 0
375 [ + - ]: 3 : && !fstat(log_fd, &old_stat)
376 [ + - ]: 3 : && !fstat(new_log_fd, &new_stat)
377 [ + + ]: 3 : && old_stat.st_dev == new_stat.st_dev
378 [ + + ][ - + ]: 1738 : && old_stat.st_ino == new_stat.st_ino);
379 : 1735 : ovs_mutex_unlock(&log_file_mutex);
380 [ - + ]: 1735 : if (same_file) {
381 : 0 : close(new_log_fd);
382 : 0 : free(new_log_file_name);
383 : 0 : return 0;
384 : : }
385 : :
386 : : /* Log closing old log file (we can't log while holding log_file_mutex). */
387 : 1735 : ovs_mutex_lock(&log_file_mutex);
388 : 1735 : log_close = log_fd >= 0;
389 : 1735 : ovs_mutex_unlock(&log_file_mutex);
390 [ + + ]: 1735 : if (log_close) {
391 [ + - ]: 3 : VLOG_INFO("closing log file");
392 : : }
393 : :
394 : : /* Close old log file, if any, and install new one. */
395 : 1735 : ovs_mutex_lock(&log_file_mutex);
396 [ + + ]: 1735 : if (log_fd >= 0) {
397 : 3 : free(log_file_name);
398 : 3 : close(log_fd);
399 : 3 : async_append_destroy(log_writer);
400 : : }
401 : :
402 : 1735 : log_file_name = xstrdup(new_log_file_name);
403 : 1735 : log_fd = new_log_fd;
404 [ + + ]: 1735 : if (log_async) {
405 : 2 : log_writer = async_append_create(new_log_fd);
406 : : }
407 : :
408 [ + + ]: 99623 : LIST_FOR_EACH (mp, list, &vlog_modules) {
409 : 97888 : update_min_level(mp);
410 : : }
411 : 1735 : ovs_mutex_unlock(&log_file_mutex);
412 : :
413 : : /* Log opening new log file (we can't log while holding log_file_mutex). */
414 [ + + ]: 1735 : VLOG_INFO("opened log file %s", new_log_file_name);
415 : 1735 : free(new_log_file_name);
416 : :
417 : 1735 : return 0;
418 : : }
419 : :
420 : : /* Closes and then attempts to re-open the current log file. (This is useful
421 : : * just after log rotation, to ensure that the new log file starts being used.)
422 : : * Returns 0 if successful, otherwise a positive errno value. */
423 : : int
424 : 6 : vlog_reopen_log_file(void)
425 : : {
426 : : char *fn;
427 : :
428 : 6 : ovs_mutex_lock(&log_file_mutex);
429 : 6 : fn = nullable_xstrdup(log_file_name);
430 : 6 : ovs_mutex_unlock(&log_file_mutex);
431 : :
432 [ + - ]: 6 : if (fn) {
433 : 6 : int error = vlog_set_log_file(fn);
434 : 6 : free(fn);
435 : 6 : return error;
436 : : } else {
437 : 0 : return 0;
438 : : }
439 : : }
440 : :
441 : : #ifndef _WIN32
442 : : /* In case a log file exists, change its owner to new 'user' and 'group'.
443 : : *
444 : : * This is useful for handling cases where the --log-file option is
445 : : * specified ahead of the --user option. */
446 : : void
447 : 0 : vlog_change_owner_unix(uid_t user, gid_t group)
448 : : {
449 : 0 : struct ds err = DS_EMPTY_INITIALIZER;
450 : : int error;
451 : :
452 : 0 : ovs_mutex_lock(&log_file_mutex);
453 [ # # ]: 0 : error = log_file_name ? chown(log_file_name, user, group) : 0;
454 [ # # ]: 0 : if (error) {
455 : : /* Build the error message. We can not call VLOG_FATAL directly
456 : : * here because VLOG_FATAL() will try again to to acquire
457 : : * 'log_file_mutex' lock, causing deadlock.
458 : : */
459 : 0 : ds_put_format(&err, "Failed to change %s ownership: %s.",
460 : 0 : log_file_name, ovs_strerror(errno));
461 : : }
462 : 0 : ovs_mutex_unlock(&log_file_mutex);
463 : :
464 [ # # ]: 0 : if (error) {
465 : 0 : VLOG_FATAL("%s", ds_steal_cstr(&err));
466 : : }
467 : 0 : }
468 : : #endif
469 : :
470 : : /* Set debugging levels. Returns null if successful, otherwise an error
471 : : * message that the caller must free(). */
472 : : char *
473 : 11175 : vlog_set_levels_from_string(const char *s_)
474 : : {
475 : 11175 : char *s = xstrdup(s_);
476 : 11175 : char *save_ptr = NULL;
477 : 11175 : char *msg = NULL;
478 : : char *word;
479 : :
480 : 11175 : word = strtok_r(s, " ,:\t", &save_ptr);
481 [ + - ][ + + ]: 11427 : if (word && !strcasecmp(word, "PATTERN")) {
482 : : enum vlog_destination destination;
483 : :
484 : 254 : word = strtok_r(NULL, " ,:\t", &save_ptr);
485 [ + + ]: 254 : if (!word) {
486 : 1 : msg = xstrdup("missing destination");
487 : 1 : goto exit;
488 : : }
489 : :
490 [ + + ]: 253 : destination = (!strcasecmp(word, "ANY")
491 : : ? VLF_ANY_DESTINATION
492 : : : vlog_get_destination_val(word));
493 [ + + ]: 253 : if (destination == VLF_N_DESTINATIONS) {
494 : 1 : msg = xasprintf("unknown destination \"%s\"", word);
495 : 1 : goto exit;
496 : : }
497 : 252 : vlog_set_pattern(destination, save_ptr);
498 [ + - ][ + + ]: 10923 : } else if (word && !strcasecmp(word, "FACILITY")) {
499 : : int value;
500 : :
501 [ + + ]: 3 : if (!vlog_facility_exists(save_ptr, &value)) {
502 : 1 : msg = xstrdup("invalid facility");
503 : 1 : goto exit;
504 : : }
505 : 2 : atomic_store_explicit(&log_facility, value, memory_order_relaxed);
506 : : } else {
507 : 10918 : struct vlog_module *module = NULL;
508 : 10918 : enum vlog_level level = VLL_N_LEVELS;
509 : 10918 : enum vlog_destination destination = VLF_N_DESTINATIONS;
510 : :
511 [ + + ]: 30578 : for (; word != NULL; word = strtok_r(NULL, " ,:\t", &save_ptr)) {
512 [ + + ]: 19661 : if (!strcasecmp(word, "ANY")) {
513 : 1 : continue;
514 [ + + ]: 19660 : } else if (vlog_get_destination_val(word) != VLF_N_DESTINATIONS) {
515 [ - + ]: 1033 : if (destination != VLF_N_DESTINATIONS) {
516 : 0 : msg = xstrdup("cannot specify multiple destinations");
517 : 0 : goto exit;
518 : : }
519 : 1033 : destination = vlog_get_destination_val(word);
520 [ + + ]: 18627 : } else if (vlog_get_level_val(word) != VLL_N_LEVELS) {
521 [ - + ]: 8974 : if (level != VLL_N_LEVELS) {
522 : 0 : msg = xstrdup("cannot specify multiple levels");
523 : 0 : goto exit;
524 : : }
525 : 8974 : level = vlog_get_level_val(word);
526 [ + + ]: 9653 : } else if (vlog_module_from_name(word)) {
527 [ - + ]: 9652 : if (module) {
528 : 0 : msg = xstrdup("cannot specify multiple modules");
529 : 0 : goto exit;
530 : : }
531 : 9652 : module = vlog_module_from_name(word);
532 : : } else {
533 : 1 : msg = xasprintf("no destination, level, or module \"%s\"",
534 : : word);
535 : 1 : goto exit;
536 : : }
537 : : }
538 : :
539 [ + + ]: 10917 : if (destination == VLF_N_DESTINATIONS) {
540 : 9884 : destination = VLF_ANY_DESTINATION;
541 : : }
542 [ + + ]: 10917 : if (level == VLL_N_LEVELS) {
543 : 1943 : level = VLL_DBG;
544 : : }
545 : 10917 : vlog_set_levels(module, destination, level);
546 : : }
547 : :
548 : : exit:
549 : 11175 : free(s);
550 : 11175 : return msg;
551 : : }
552 : :
553 : : /* Set debugging levels. Abort with an error message if 's' is invalid. */
554 : : void
555 : 6484 : vlog_set_levels_from_string_assert(const char *s)
556 : : {
557 : 6484 : char *error = vlog_set_levels_from_string(s);
558 [ - + ]: 6484 : if (error) {
559 : 0 : ovs_fatal(0, "%s", error);
560 : : }
561 : 6484 : }
562 : :
563 : : /* If 'arg' is null, configure maximum verbosity. Otherwise, sets
564 : : * configuration according to 'arg' (see vlog_set_levels_from_string()). */
565 : : void
566 : 4585 : vlog_set_verbosity(const char *arg)
567 : : {
568 [ + + ]: 4585 : if (arg) {
569 : 4529 : char *msg = vlog_set_levels_from_string(arg);
570 [ - + ]: 4529 : if (msg) {
571 : 4529 : ovs_fatal(0, "processing \"%s\": %s", arg, msg);
572 : : }
573 : : } else {
574 : 56 : vlog_set_levels(NULL, VLF_ANY_DESTINATION, VLL_DBG);
575 : : }
576 : 4585 : }
577 : :
578 : : void
579 : 0 : vlog_set_syslog_method(const char *method)
580 : : {
581 [ # # ]: 0 : if (syslogger) {
582 : : /* Set syslogger only, if one is not already set. This effectively
583 : : * means that only the first --syslog-method argument is honored. */
584 : 0 : return;
585 : : }
586 : :
587 [ # # ]: 0 : if (!strcmp(method, "libc")) {
588 : 0 : syslogger = syslog_libc_create();
589 [ # # ][ # # ]: 0 : } else if (!strncmp(method, "udp:", 4) || !strncmp(method, "unix:", 5)) {
590 : 0 : syslogger = syslog_direct_create(method);
591 : : } else {
592 : 0 : ovs_fatal(0, "unsupported syslog method '%s'", method);
593 : : }
594 : : }
595 : :
596 : : /* Set the vlog udp syslog target. */
597 : : void
598 : 0 : vlog_set_syslog_target(const char *target)
599 : : {
600 : : int new_fd;
601 : :
602 : 0 : inet_open_active(SOCK_DGRAM, target, 0, NULL, &new_fd, 0);
603 : :
604 : 0 : ovs_rwlock_wrlock(&pattern_rwlock);
605 [ # # ]: 0 : if (syslog_fd >= 0) {
606 : 0 : close(syslog_fd);
607 : : }
608 : 0 : syslog_fd = new_fd;
609 : 0 : ovs_rwlock_unlock(&pattern_rwlock);
610 : 0 : }
611 : :
612 : : /* Returns 'false' if 'facility' is not a valid string. If 'facility'
613 : : * is a valid string, sets 'value' with the integer value of 'facility'
614 : : * and returns 'true'. */
615 : : static bool
616 : 3 : vlog_facility_exists(const char* facility, int *value)
617 : : {
618 : : size_t i;
619 [ + + ]: 51 : for (i = 0; i < ARRAY_SIZE(vlog_facilities); i++) {
620 [ + + ]: 50 : if (!strcasecmp(vlog_facilities[i].name, facility)) {
621 : 2 : *value = vlog_facilities[i].value;
622 : 2 : return true;
623 : : }
624 : : }
625 : 1 : return false;
626 : : }
627 : :
628 : : static void
629 : 84 : vlog_unixctl_set(struct unixctl_conn *conn, int argc, const char *argv[],
630 : : void *aux OVS_UNUSED)
631 : : {
632 : : int i;
633 : :
634 [ + + ]: 242 : for (i = 1; i < argc; i++) {
635 : 162 : char *msg = vlog_set_levels_from_string(argv[i]);
636 [ + + ]: 162 : if (msg) {
637 : 4 : unixctl_command_reply_error(conn, msg);
638 : 4 : free(msg);
639 : 4 : return;
640 : : }
641 : : }
642 : 80 : unixctl_command_reply(conn, NULL);
643 : : }
644 : :
645 : : static void
646 : 2 : vlog_unixctl_list(struct unixctl_conn *conn, int argc OVS_UNUSED,
647 : : const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED)
648 : : {
649 : 2 : char *msg = vlog_get_levels();
650 : 2 : unixctl_command_reply(conn, msg);
651 : 2 : free(msg);
652 : 2 : }
653 : :
654 : : static void
655 : 0 : vlog_unixctl_list_pattern(struct unixctl_conn *conn, int argc OVS_UNUSED,
656 : : const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED)
657 : : {
658 : : char *msg;
659 : :
660 : 0 : msg = vlog_get_patterns();
661 : 0 : unixctl_command_reply(conn, msg);
662 : 0 : free(msg);
663 : 0 : }
664 : :
665 : : static void
666 : 7 : vlog_unixctl_reopen(struct unixctl_conn *conn, int argc OVS_UNUSED,
667 : : const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED)
668 : : {
669 : : bool has_log_file;
670 : :
671 : 7 : ovs_mutex_lock(&log_file_mutex);
672 : 7 : has_log_file = log_file_name != NULL;
673 : 7 : ovs_mutex_unlock(&log_file_mutex);
674 : :
675 [ + + ]: 7 : if (has_log_file) {
676 : 6 : int error = vlog_reopen_log_file();
677 [ - + ]: 6 : if (error) {
678 : 0 : unixctl_command_reply_error(conn, ovs_strerror(errno));
679 : : } else {
680 : 6 : unixctl_command_reply(conn, NULL);
681 : : }
682 : : } else {
683 : 1 : unixctl_command_reply_error(conn, "Logging to file not configured");
684 : : }
685 : 7 : }
686 : :
687 : : static void
688 : 4 : vlog_unixctl_close(struct unixctl_conn *conn, int argc OVS_UNUSED,
689 : : const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED)
690 : : {
691 : 4 : ovs_mutex_lock(&log_file_mutex);
692 [ + + ]: 4 : if (log_fd >= 0) {
693 : 3 : close(log_fd);
694 : 3 : log_fd = -1;
695 : :
696 : 3 : async_append_destroy(log_writer);
697 : 3 : log_writer = NULL;
698 : :
699 : : struct vlog_module *mp;
700 [ + + ]: 246 : LIST_FOR_EACH (mp, list, &vlog_modules) {
701 : 243 : update_min_level(mp);
702 : : }
703 : : }
704 : 4 : ovs_mutex_unlock(&log_file_mutex);
705 : :
706 : 4 : unixctl_command_reply(conn, NULL);
707 : 4 : }
708 : :
709 : : static void
710 : 0 : set_all_rate_limits(bool enable)
711 : : {
712 : : struct vlog_module *mp;
713 : :
714 : 0 : ovs_mutex_lock(&log_file_mutex);
715 [ # # ]: 0 : LIST_FOR_EACH (mp, list, &vlog_modules) {
716 : 0 : mp->honor_rate_limits = enable;
717 : : }
718 : 0 : ovs_mutex_unlock(&log_file_mutex);
719 : 0 : }
720 : :
721 : : static void
722 : 0 : set_rate_limits(struct unixctl_conn *conn, int argc,
723 : : const char *argv[], bool enable)
724 : : {
725 [ # # ]: 0 : if (argc > 1) {
726 : : int i;
727 : :
728 [ # # ]: 0 : for (i = 1; i < argc; i++) {
729 [ # # ]: 0 : if (!strcasecmp(argv[i], "ANY")) {
730 : 0 : set_all_rate_limits(enable);
731 : : } else {
732 : 0 : struct vlog_module *module = vlog_module_from_name(argv[i]);
733 [ # # ]: 0 : if (!module) {
734 : 0 : unixctl_command_reply_error(conn, "unknown module");
735 : 0 : return;
736 : : }
737 : 0 : module->honor_rate_limits = enable;
738 : : }
739 : : }
740 : : } else {
741 : 0 : set_all_rate_limits(enable);
742 : : }
743 : 0 : unixctl_command_reply(conn, NULL);
744 : : }
745 : :
746 : : static void
747 : 0 : vlog_enable_rate_limit(struct unixctl_conn *conn, int argc,
748 : : const char *argv[], void *aux OVS_UNUSED)
749 : : {
750 : 0 : set_rate_limits(conn, argc, argv, true);
751 : 0 : }
752 : :
753 : : static void
754 : 0 : vlog_disable_rate_limit(struct unixctl_conn *conn, int argc,
755 : : const char *argv[], void *aux OVS_UNUSED)
756 : : {
757 : 0 : set_rate_limits(conn, argc, argv, false);
758 : 0 : }
759 : :
760 : : /* Initializes the logging subsystem and registers its unixctl server
761 : : * commands. */
762 : : void
763 : 98678 : vlog_init(void)
764 : : {
765 : : static struct ovsthread_once once = OVSTHREAD_ONCE_INITIALIZER;
766 : :
767 [ + + ]: 98678 : if (ovsthread_once_start(&once)) {
768 : : long long int now;
769 : : int facility;
770 : : bool print_syslog_target_deprecation;
771 : :
772 : : /* Do initialization work that needs to be done before any logging
773 : : * occurs. We want to keep this really minimal because any attempt to
774 : : * log anything before calling ovsthread_once_done() will deadlock. */
775 : 6684 : atomic_read_explicit(&log_facility, &facility, memory_order_relaxed);
776 [ + - ]: 6684 : if (!syslogger) {
777 : 6684 : syslogger = syslog_libc_create();
778 : : }
779 [ + + ]: 6684 : syslogger->class->openlog(syslogger, facility ? facility : LOG_DAEMON);
780 : 6684 : ovsthread_once_done(&once);
781 : :
782 : : /* Now do anything that we want to happen only once but doesn't have to
783 : : * finish before we start logging. */
784 : :
785 : 6684 : now = time_wall_msec();
786 [ - + ]: 6684 : if (now < 0) {
787 : 0 : char *s = xastrftime_msec("%a, %d %b %Y %H:%M:%S", now, true);
788 [ # # ]: 0 : VLOG_ERR("current time is negative: %s (%lld)", s, now);
789 : 0 : free(s);
790 : : }
791 : :
792 : 6684 : unixctl_command_register(
793 : : "vlog/set", "{spec | PATTERN:destination:pattern}",
794 : : 1, INT_MAX, vlog_unixctl_set, NULL);
795 : 6684 : unixctl_command_register("vlog/list", "", 0, 0, vlog_unixctl_list,
796 : : NULL);
797 : 6684 : unixctl_command_register("vlog/list-pattern", "", 0, 0,
798 : : vlog_unixctl_list_pattern, NULL);
799 : 6684 : unixctl_command_register("vlog/enable-rate-limit", "[module]...",
800 : : 0, INT_MAX, vlog_enable_rate_limit, NULL);
801 : 6684 : unixctl_command_register("vlog/disable-rate-limit", "[module]...",
802 : : 0, INT_MAX, vlog_disable_rate_limit, NULL);
803 : 6684 : unixctl_command_register("vlog/reopen", "", 0, 0,
804 : : vlog_unixctl_reopen, NULL);
805 : 6684 : unixctl_command_register("vlog/close", "", 0, 0,
806 : : vlog_unixctl_close, NULL);
807 : :
808 : 6684 : ovs_rwlock_rdlock(&pattern_rwlock);
809 : 6684 : print_syslog_target_deprecation = syslog_fd >= 0;
810 : 6684 : ovs_rwlock_unlock(&pattern_rwlock);
811 : :
812 [ - + ]: 6684 : if (print_syslog_target_deprecation) {
813 [ # # ]: 6684 : VLOG_WARN("--syslog-target flag is deprecated, use "
814 : : "--syslog-method instead");
815 : : }
816 : : }
817 : 98678 : }
818 : :
819 : : /* Enables VLF_FILE log output to be written asynchronously to disk.
820 : : * Asynchronous file writes avoid blocking the process in the case of a busy
821 : : * disk, but on the other hand they are less robust: there is a chance that the
822 : : * write will not make it to the log file if the process crashes soon after the
823 : : * log call. */
824 : : void
825 : 615 : vlog_enable_async(void)
826 : : {
827 : 615 : ovs_mutex_lock(&log_file_mutex);
828 : 615 : log_async = true;
829 [ + - ][ + - ]: 615 : if (log_fd >= 0 && !log_writer) {
830 : 615 : log_writer = async_append_create(log_fd);
831 : : }
832 : 615 : ovs_mutex_unlock(&log_file_mutex);
833 : 615 : }
834 : :
835 : : /* Print the current logging level for each module. */
836 : : char *
837 : 2 : vlog_get_levels(void)
838 : : {
839 : 2 : struct ds s = DS_EMPTY_INITIALIZER;
840 : : struct vlog_module *mp;
841 : 2 : struct svec lines = SVEC_EMPTY_INITIALIZER;
842 : : char *line;
843 : : size_t i;
844 : :
845 : 2 : ds_put_format(&s, " console syslog file\n");
846 : 2 : ds_put_format(&s, " ------- ------ ------\n");
847 : :
848 : 2 : ovs_mutex_lock(&log_file_mutex);
849 [ + + ]: 128 : LIST_FOR_EACH (mp, list, &vlog_modules) {
850 : : struct ds line;
851 : :
852 : 126 : ds_init(&line);
853 : 126 : ds_put_format(&line, "%-16s %4s %4s %4s",
854 : : vlog_get_module_name(mp),
855 : : vlog_get_level_name(vlog_get_level(mp, VLF_CONSOLE)),
856 : : vlog_get_level_name(vlog_get_level(mp, VLF_SYSLOG)),
857 : : vlog_get_level_name(vlog_get_level(mp, VLF_FILE)));
858 [ - + ]: 126 : if (!mp->honor_rate_limits) {
859 : 0 : ds_put_cstr(&line, " (rate limiting disabled)");
860 : : }
861 : 126 : ds_put_char(&line, '\n');
862 : :
863 : 126 : svec_add_nocopy(&lines, ds_steal_cstr(&line));
864 : : }
865 : 2 : ovs_mutex_unlock(&log_file_mutex);
866 : :
867 : 2 : svec_sort(&lines);
868 [ + + ][ + + ]: 128 : SVEC_FOR_EACH (i, line, &lines) {
869 : 126 : ds_put_cstr(&s, line);
870 : : }
871 : 2 : svec_destroy(&lines);
872 : :
873 : 2 : return ds_cstr(&s);
874 : : }
875 : :
876 : : /* Returns as a string current logging patterns for each destination.
877 : : * This string must be released by caller. */
878 : : char *
879 : 0 : vlog_get_patterns(void)
880 : : {
881 : 0 : struct ds ds = DS_EMPTY_INITIALIZER;
882 : : enum vlog_destination destination;
883 : :
884 : 0 : ovs_rwlock_rdlock(&pattern_rwlock);
885 : 0 : ds_put_format(&ds, " prefix format\n");
886 : 0 : ds_put_format(&ds, " ------ ------\n");
887 : :
888 [ # # ]: 0 : for (destination = 0; destination < VLF_N_DESTINATIONS; destination++) {
889 : 0 : struct destination *f = &destinations[destination];
890 : 0 : const char *prefix = "none";
891 : :
892 [ # # ][ # # ]: 0 : if (destination == VLF_SYSLOG && syslogger) {
893 : 0 : prefix = syslog_get_prefix(syslogger);
894 : : }
895 : 0 : ds_put_format(&ds, "%-7s %-32s %s\n", f->name, prefix, f->pattern);
896 : : }
897 : 0 : ovs_rwlock_unlock(&pattern_rwlock);
898 : :
899 : 0 : return ds_cstr(&ds);
900 : : }
901 : :
902 : : /* Returns true if a log message emitted for the given 'module' and 'level'
903 : : * would cause some log output, false if that module and level are completely
904 : : * disabled. */
905 : : bool
906 : 988631 : vlog_is_enabled(const struct vlog_module *module, enum vlog_level level)
907 : : {
908 : 988631 : return module->min_level >= level;
909 : : }
910 : :
911 : : static const char *
912 : 294470 : fetch_braces(const char *p, const char *def, char *out, size_t out_size)
913 : : {
914 [ + + ]: 294470 : if (*p == '{') {
915 : 98949 : size_t n = strcspn(p + 1, "}");
916 : 98949 : size_t n_copy = MIN(n, out_size - 1);
917 : 98949 : memcpy(out, p + 1, n_copy);
918 : 98949 : out[n_copy] = '\0';
919 : 98949 : p += n + 2;
920 : : } else {
921 : 195521 : ovs_strlcpy(out, def, out_size);
922 : : }
923 : 294470 : return p;
924 : : }
925 : :
926 : : static void
927 : 195550 : format_log_message(const struct vlog_module *module, enum vlog_level level,
928 : : const char *pattern, const char *message,
929 : : va_list args_, struct ds *s)
930 : : {
931 : : char tmp[128];
932 : : va_list args;
933 : : const char *p;
934 : : int facility;
935 : :
936 : 195550 : ds_clear(s);
937 [ + + ]: 2340535 : for (p = pattern; *p != '\0'; ) {
938 : : const char *subprogram_name;
939 : 2144985 : enum { LEFT, RIGHT } justify = RIGHT;
940 : 2144985 : int pad = '0';
941 : : size_t length, field, used;
942 : :
943 [ + + ]: 2144985 : if (*p != '%') {
944 : 1070884 : ds_put_char(s, *p++);
945 : 1070883 : continue;
946 : : }
947 : :
948 : 1074101 : p++;
949 [ - + ]: 1074101 : if (*p == '-') {
950 : 0 : justify = LEFT;
951 : 0 : p++;
952 : : }
953 [ + + ]: 1074101 : if (*p == '0') {
954 : 194469 : pad = '0';
955 : 194469 : p++;
956 : : }
957 : 1074101 : field = 0;
958 [ + + ]: 1268570 : while (isdigit((unsigned char)*p)) {
959 : 194469 : field = (field * 10) + (*p - '0');
960 : 194469 : p++;
961 : : }
962 : :
963 : 1074103 : length = s->length;
964 [ + + + - : 1074103 : switch (*p++) {
+ - + + -
+ - - - +
- ]
965 : : case 'A':
966 : 13 : ds_put_cstr(s, program_name);
967 : 13 : break;
968 : : case 'B':
969 : 13 : atomic_read_explicit(&log_facility, &facility,
970 : : memory_order_relaxed);
971 [ + + ]: 13 : facility = facility ? facility : LOG_LOCAL0;
972 : 13 : ds_put_format(s, "%d", facility + syslog_levels[level]);
973 : 13 : break;
974 : : case 'c':
975 : 195521 : p = fetch_braces(p, "", tmp, sizeof tmp);
976 : 195521 : ds_put_cstr(s, vlog_get_module_name(module));
977 : 195521 : break;
978 : : case 'd':
979 : 0 : p = fetch_braces(p, "%Y-%m-%d %H:%M:%S.###", tmp, sizeof tmp);
980 : 0 : ds_put_strftime_msec(s, tmp, time_wall_msec(), false);
981 : 0 : break;
982 : : case 'D':
983 : 98949 : p = fetch_braces(p, "%Y-%m-%d %H:%M:%S.###", tmp, sizeof tmp);
984 : 98949 : ds_put_strftime_msec(s, tmp, time_wall_msec(), true);
985 : 98949 : break;
986 : : case 'E':
987 : 0 : gethostname(tmp, sizeof tmp);
988 : 0 : tmp[sizeof tmp - 1] = '\0';
989 : 0 : ds_put_cstr(s, tmp);
990 : 0 : break;
991 : : case 'm':
992 : : /* Format user-supplied log message and trim trailing new-lines. */
993 : 195550 : length = s->length;
994 : 195550 : va_copy(args, args_);
995 : 195550 : ds_put_format_valist(s, message, args);
996 : 195550 : va_end(args);
997 [ + - ][ + + ]: 285043 : while (s->length > length && s->string[s->length - 1] == '\n') {
998 : 89493 : s->length--;
999 : : }
1000 : 195550 : break;
1001 : : case 'N':
1002 : 194469 : ds_put_format(s, "%u", *msg_num_get_unsafe());
1003 : 194469 : break;
1004 : : case 'n':
1005 : 0 : ds_put_char(s, '\n');
1006 : 0 : break;
1007 : : case 'p':
1008 : 195119 : ds_put_cstr(s, vlog_get_level_name(level));
1009 : 195119 : break;
1010 : : case 'P':
1011 : 0 : ds_put_format(s, "%ld", (long int) getpid());
1012 : 0 : break;
1013 : : case 'r':
1014 : 0 : ds_put_format(s, "%lld", time_msec() - time_boot_msec());
1015 : 0 : break;
1016 : : case 't':
1017 : 0 : subprogram_name = get_subprogram_name();
1018 [ # # ]: 0 : ds_put_cstr(s, subprogram_name[0] ? subprogram_name : "main");
1019 : 0 : break;
1020 : : case 'T':
1021 : 194469 : subprogram_name = get_subprogram_name();
1022 [ + + ]: 194469 : if (subprogram_name[0]) {
1023 : 6844 : ds_put_format(s, "(%s)", subprogram_name);
1024 : : }
1025 : 194469 : break;
1026 : : default:
1027 : 0 : ds_put_char(s, p[-1]);
1028 : 0 : break;
1029 : : }
1030 : 1074103 : used = s->length - length;
1031 [ + + ]: 1074103 : if (used < field) {
1032 : 194469 : size_t n_pad = field - used;
1033 [ + - ]: 194469 : if (justify == RIGHT) {
1034 : 194469 : ds_put_uninit(s, n_pad);
1035 : 194469 : memmove(&s->string[length + n_pad], &s->string[length], used);
1036 : 194469 : memset(&s->string[length], pad, n_pad);
1037 : : } else {
1038 : 0 : ds_put_char_multiple(s, pad, n_pad);
1039 : : }
1040 : : }
1041 : : }
1042 : 195550 : }
1043 : :
1044 : : /* Exports the given 'syslog_message' to the configured udp syslog sink. */
1045 : : static void
1046 : 0 : send_to_syslog_fd(const char *s, size_t length)
1047 : : OVS_REQ_RDLOCK(pattern_rwlock)
1048 : : {
1049 : : static size_t max_length = SIZE_MAX;
1050 : 0 : size_t send_len = MIN(length, max_length);
1051 : :
1052 [ # # ][ # # ]: 0 : while (write(syslog_fd, s, send_len) < 0 && errno == EMSGSIZE) {
1053 : 0 : send_len -= send_len / 20;
1054 : 0 : max_length = send_len;
1055 : : }
1056 : 0 : }
1057 : :
1058 : : /* Writes 'message' to the log at the given 'level' and as coming from the
1059 : : * given 'module'.
1060 : : *
1061 : : * Guaranteed to preserve errno. */
1062 : : void
1063 : 96499 : vlog_valist(const struct vlog_module *module, enum vlog_level level,
1064 : : const char *message, va_list args)
1065 : : {
1066 : 96499 : bool log_to_console = module->levels[VLF_CONSOLE] >= level;
1067 : 96499 : bool log_to_syslog = module->levels[VLF_SYSLOG] >= level;
1068 : : bool log_to_file;
1069 : :
1070 : 96499 : ovs_mutex_lock(&log_file_mutex);
1071 [ + + ][ + + ]: 96499 : log_to_file = module->levels[VLF_FILE] >= level && log_fd >= 0;
1072 : 96499 : ovs_mutex_unlock(&log_file_mutex);
1073 [ + + ][ + + ]: 96499 : if (log_to_console || log_to_syslog || log_to_file) {
[ + - ]
1074 : 96499 : int save_errno = errno;
1075 : : struct ds s;
1076 : :
1077 : 96499 : vlog_init();
1078 : :
1079 : 96499 : ds_init(&s);
1080 : 96499 : ds_reserve(&s, 1024);
1081 : 96499 : ++*msg_num_get();
1082 : :
1083 : 96499 : ovs_rwlock_rdlock(&pattern_rwlock);
1084 [ + + ]: 96499 : if (log_to_console) {
1085 : 10081 : format_log_message(module, level,
1086 : 10081 : destinations[VLF_CONSOLE].pattern, message,
1087 : : args, &s);
1088 : 10081 : ds_put_char(&s, '\n');
1089 : 10081 : fputs(ds_cstr(&s), stderr);
1090 : : }
1091 : :
1092 [ + + ]: 96499 : if (log_to_syslog) {
1093 : 95729 : int syslog_level = syslog_levels[level];
1094 : 95729 : char *save_ptr = NULL;
1095 : : char *line;
1096 : : int facility;
1097 : :
1098 : 95729 : format_log_message(module, level, destinations[VLF_SYSLOG].pattern,
1099 : : message, args, &s);
1100 [ + + ]: 316844 : for (line = strtok_r(s.string, "\n", &save_ptr); line;
1101 : 221115 : line = strtok_r(NULL, "\n", &save_ptr)) {
1102 : 221115 : atomic_read_explicit(&log_facility, &facility,
1103 : : memory_order_relaxed);
1104 : 221115 : syslogger->class->syslog(syslogger, syslog_level|facility, line);
1105 : : }
1106 : :
1107 [ - + ]: 95729 : if (syslog_fd >= 0) {
1108 : 0 : format_log_message(module, level,
1109 : : "<%B>1 %D{%Y-%m-%dT%H:%M:%S.###Z} "
1110 : : "%E %A %P %c - \xef\xbb\xbf%m",
1111 : : message, args, &s);
1112 : 95729 : send_to_syslog_fd(ds_cstr(&s), s.length);
1113 : : }
1114 : : }
1115 : :
1116 [ + + ]: 96499 : if (log_to_file) {
1117 : 89740 : format_log_message(module, level, destinations[VLF_FILE].pattern,
1118 : : message, args, &s);
1119 : 89740 : ds_put_char(&s, '\n');
1120 : :
1121 : 89740 : ovs_mutex_lock(&log_file_mutex);
1122 [ + - ]: 89740 : if (log_fd >= 0) {
1123 [ + + ]: 89740 : if (log_writer) {
1124 : 82154 : async_append_write(log_writer, s.string, s.length);
1125 [ - + ]: 82154 : if (level == VLL_EMER) {
1126 : 82154 : async_append_flush(log_writer);
1127 : : }
1128 : : } else {
1129 : 7586 : ignore(write(log_fd, s.string, s.length));
1130 : : }
1131 : : }
1132 : 89740 : ovs_mutex_unlock(&log_file_mutex);
1133 : : }
1134 : 96499 : ovs_rwlock_unlock(&pattern_rwlock);
1135 : :
1136 : 96499 : ds_destroy(&s);
1137 : 96499 : errno = save_errno;
1138 : : }
1139 : 96499 : }
1140 : :
1141 : : void
1142 : 49404 : vlog(const struct vlog_module *module, enum vlog_level level,
1143 : : const char *message, ...)
1144 : : {
1145 : : va_list args;
1146 : :
1147 : 49404 : va_start(args, message);
1148 : 49404 : vlog_valist(module, level, message, args);
1149 : 49404 : va_end(args);
1150 : 49404 : }
1151 : :
1152 : : /* Logs 'message' to 'module' at maximum verbosity, then exits with a failure
1153 : : * exit code. Always writes the message to stderr, even if the console
1154 : : * destination is disabled.
1155 : : *
1156 : : * Choose this function instead of vlog_abort_valist() if the daemon monitoring
1157 : : * facility shouldn't automatically restart the current daemon. */
1158 : : void
1159 : 2 : vlog_fatal_valist(const struct vlog_module *module_,
1160 : : const char *message, va_list args)
1161 : : {
1162 : 2 : struct vlog_module *module = CONST_CAST(struct vlog_module *, module_);
1163 : :
1164 : : /* Don't log this message to the console to avoid redundancy with the
1165 : : * message written by the later ovs_fatal_valist(). */
1166 : 2 : module->levels[VLF_CONSOLE] = VLL_OFF;
1167 : :
1168 : 2 : vlog_valist(module, VLL_EMER, message, args);
1169 : 2 : ovs_fatal_valist(0, message, args);
1170 : : }
1171 : :
1172 : : /* Logs 'message' to 'module' at maximum verbosity, then exits with a failure
1173 : : * exit code. Always writes the message to stderr, even if the console
1174 : : * destination is disabled.
1175 : : *
1176 : : * Choose this function instead of vlog_abort() if the daemon monitoring
1177 : : * facility shouldn't automatically restart the current daemon. */
1178 : : void
1179 : 2 : vlog_fatal(const struct vlog_module *module, const char *message, ...)
1180 : : {
1181 : : va_list args;
1182 : :
1183 : 2 : va_start(args, message);
1184 : 2 : vlog_fatal_valist(module, message, args);
1185 : : va_end(args);
1186 : : }
1187 : :
1188 : : /* Logs 'message' to 'module' at maximum verbosity, then calls abort(). Always
1189 : : * writes the message to stderr, even if the console destination is disabled.
1190 : : *
1191 : : * Choose this function instead of vlog_fatal_valist() if the daemon monitoring
1192 : : * facility should automatically restart the current daemon. */
1193 : : void
1194 : 0 : vlog_abort_valist(const struct vlog_module *module_,
1195 : : const char *message, va_list args)
1196 : : {
1197 : 0 : struct vlog_module *module = (struct vlog_module *) module_;
1198 : :
1199 : : /* Don't log this message to the console to avoid redundancy with the
1200 : : * message written by the later ovs_abort_valist(). */
1201 : 0 : module->levels[VLF_CONSOLE] = VLL_OFF;
1202 : :
1203 : 0 : vlog_valist(module, VLL_EMER, message, args);
1204 : 0 : ovs_abort_valist(0, message, args);
1205 : : }
1206 : :
1207 : : /* Logs 'message' to 'module' at maximum verbosity, then calls abort(). Always
1208 : : * writes the message to stderr, even if the console destination is disabled.
1209 : : *
1210 : : * Choose this function instead of vlog_fatal() if the daemon monitoring
1211 : : * facility should automatically restart the current daemon. */
1212 : : void
1213 : 0 : vlog_abort(const struct vlog_module *module, const char *message, ...)
1214 : : {
1215 : : va_list args;
1216 : :
1217 : 0 : va_start(args, message);
1218 : 0 : vlog_abort_valist(module, message, args);
1219 : : va_end(args);
1220 : : }
1221 : :
1222 : : bool
1223 : 177405 : vlog_should_drop(const struct vlog_module *module, enum vlog_level level,
1224 : : struct vlog_rate_limit *rl)
1225 : : {
1226 [ - + ]: 177405 : if (!module->honor_rate_limits) {
1227 : 0 : return false;
1228 : : }
1229 : :
1230 [ + + ]: 177405 : if (!vlog_is_enabled(module, level)) {
1231 : 70517 : return true;
1232 : : }
1233 : :
1234 : 106888 : ovs_mutex_lock(&rl->mutex);
1235 [ + + ]: 106888 : if (!token_bucket_withdraw(&rl->token_bucket, VLOG_MSG_TOKENS)) {
1236 : 56926 : time_t now = time_now();
1237 [ + + ]: 56926 : if (!rl->n_dropped) {
1238 : 1080 : rl->first_dropped = now;
1239 : : }
1240 : 56926 : rl->last_dropped = now;
1241 : 56926 : rl->n_dropped++;
1242 : 56926 : ovs_mutex_unlock(&rl->mutex);
1243 : 56926 : return true;
1244 : : }
1245 : :
1246 [ + + ]: 49962 : if (!rl->n_dropped) {
1247 : 49032 : ovs_mutex_unlock(&rl->mutex);
1248 : : } else {
1249 : 930 : time_t now = time_now();
1250 : 930 : unsigned int n_dropped = rl->n_dropped;
1251 : 930 : unsigned int first_dropped_elapsed = now - rl->first_dropped;
1252 : 930 : unsigned int last_dropped_elapsed = now - rl->last_dropped;
1253 : 930 : rl->n_dropped = 0;
1254 : 930 : ovs_mutex_unlock(&rl->mutex);
1255 : :
1256 : 930 : vlog(module, level,
1257 : : "Dropped %u log messages in last %u seconds (most recently, "
1258 : : "%u seconds ago) due to excessive rate",
1259 : : n_dropped, first_dropped_elapsed, last_dropped_elapsed);
1260 : : }
1261 : :
1262 : 49962 : return false;
1263 : : }
1264 : :
1265 : : void
1266 : 84880 : vlog_rate_limit(const struct vlog_module *module, enum vlog_level level,
1267 : : struct vlog_rate_limit *rl, const char *message, ...)
1268 : : {
1269 [ + + ]: 84880 : if (!vlog_should_drop(module, level, rl)) {
1270 : : va_list args;
1271 : :
1272 : 47093 : va_start(args, message);
1273 : 47093 : vlog_valist(module, level, message, args);
1274 : 47093 : va_end(args);
1275 : : }
1276 : 84880 : }
1277 : :
1278 : : void
1279 : 0 : vlog_usage(void)
1280 : : {
1281 : 0 : printf("\n\
1282 : : Logging options:\n\
1283 : : -vSPEC, --verbose=SPEC set logging levels\n\
1284 : : -v, --verbose set maximum verbosity level\n\
1285 : : --log-file[=FILE] enable logging to specified FILE\n\
1286 : : (default: %s/%s.log)\n\
1287 : : --syslog-method=(libc|unix:file|udp:ip:port)\n\
1288 : : specify how to send messages to syslog daemon\n\
1289 : : --syslog-target=HOST:PORT also send syslog msgs to HOST:PORT via UDP\n",
1290 : : ovs_logdir(), program_name);
1291 : 0 : }
|
