49
50
#define ovs_assert use_assert_instead_of_ovs_assert_in_this_module
51
52
/* Name for each logging level. */
52
static const char *level_names[VLL_N_LEVELS] = {
53
static const char *const level_names[VLL_N_LEVELS] = {
53
54
#define VLOG_LEVEL(NAME, SYSLOG_LEVEL) #NAME,
58
59
/* Syslog value for each logging level. */
59
static int syslog_levels[VLL_N_LEVELS] = {
60
static const int syslog_levels[VLL_N_LEVELS] = {
60
61
#define VLOG_LEVEL(NAME, SYSLOG_LEVEL) SYSLOG_LEVEL,
81
82
#define n_vlog_modules ARRAY_SIZE(vlog_modules)
85
/* Protects the 'pattern' in all "struct facility"s, so that a race between
86
* changing and reading the pattern does not cause an access to freed
88
static struct ovs_rwlock pattern_rwlock = OVS_RWLOCK_INITIALIZER;
84
90
/* Information about each facility. */
86
92
const char *name; /* Name. */
87
char *pattern; /* Current pattern. */
93
char *pattern OVS_GUARDED_BY(pattern_rwlock); /* Current pattern. */
88
94
bool default_pattern; /* Whether current pattern is the default. */
90
96
static struct facility facilities[VLF_N_FACILITIES] = {
93
99
#undef VLOG_FACILITY
96
/* VLF_FILE configuration. */
97
static char *log_file_name;
98
static int log_fd = -1;
102
/* Sequence number for the message currently being composed. */
103
DEFINE_PER_THREAD_DATA(unsigned int, msg_num, 0);
100
/* vlog initialized? */
101
static bool vlog_inited;
105
/* VLF_FILE configuration.
107
* All of the following is protected by 'log_file_mutex', which nests inside
109
static struct ovs_mutex log_file_mutex = OVS_ADAPTIVE_MUTEX_INITIALIZER;
110
static char *log_file_name OVS_GUARDED_BY(log_file_mutex);
111
static int log_fd OVS_GUARDED_BY(log_file_mutex) = -1;
112
static struct async_append *log_writer OVS_GUARDED_BY(log_file_mutex);
103
114
static void format_log_message(const struct vlog_module *, enum vlog_level,
104
enum vlog_facility, unsigned int msg_num,
105
116
const char *message, va_list, struct ds *)
107
static void vlog_write_file(struct ds *);
108
static void vlog_update_async_log_fd(void);
117
PRINTF_FORMAT(4, 0) OVS_REQ_RDLOCK(&pattern_rwlock);
110
119
/* Searches the 'n_names' in 'names'. Returns the index of a match for
111
120
* 'target', or 'n_names' if no name matches. */
113
search_name_array(const char *target, const char **names, size_t n_names)
122
search_name_array(const char *target, const char *const *names, size_t n_names)
274
/* Returns the name of the log file used by VLF_FILE, or a null pointer if no
275
* log file has been set. (A non-null return value does not assert that the
276
* named log file is in use: if vlog_set_log_file() or vlog_reopen_log_file()
277
* fails, it still sets the log file name.) */
279
vlog_get_log_file(void)
281
return log_file_name;
284
288
/* Sets the name of the log file used by VLF_FILE to 'file_name', or to the
285
289
* default file name if 'file_name' is null. Returns 0 if successful,
286
290
* otherwise a positive errno value. */
288
292
vlog_set_log_file(const char *file_name)
290
char *old_log_file_name;
294
char *new_log_file_name;
291
295
struct vlog_module **mp;
294
/* Close old log file. */
296
struct stat old_stat;
297
struct stat new_stat;
302
/* Open new log file. */
303
new_log_file_name = (file_name
305
: xasprintf("%s/%s.log", ovs_logdir(), program_name));
306
new_log_fd = open(new_log_file_name, O_WRONLY | O_CREAT | O_APPEND, 0666);
307
if (new_log_fd < 0) {
308
VLOG_WARN("failed to open %s for logging: %s",
309
new_log_file_name, ovs_strerror(errno));
310
free(new_log_file_name);
314
/* If the new log file is the same one we already have open, bail out. */
315
ovs_mutex_lock(&log_file_mutex);
316
same_file = (log_fd >= 0
318
&& !fstat(log_fd, &old_stat)
319
&& !fstat(new_log_fd, &new_stat)
320
&& old_stat.st_dev == new_stat.st_dev
321
&& old_stat.st_ino == new_stat.st_ino);
322
ovs_mutex_unlock(&log_file_mutex);
325
free(new_log_file_name);
329
/* Log closing old log file (we can't log while holding log_file_mutex). */
330
ovs_mutex_lock(&log_file_mutex);
331
log_close = log_fd >= 0;
332
ovs_mutex_unlock(&log_file_mutex);
296
334
VLOG_INFO("closing log file");
337
/* Close old log file, if any, and install new one. */
338
ovs_mutex_lock(&log_file_mutex);
301
/* Update log file name and free old name. The ordering is important
302
* because 'file_name' might be 'log_file_name' or some suffix of it. */
303
old_log_file_name = log_file_name;
304
log_file_name = (file_name
306
: xasprintf("%s/%s.log", ovs_logdir(), program_name));
307
free(old_log_file_name);
308
file_name = NULL; /* Might have been freed. */
310
/* Open new log file and update min_levels[] to reflect whether we actually
311
* have a log_file. */
312
log_fd = open(log_file_name, O_WRONLY | O_CREAT | O_APPEND, 0666);
314
vlog_update_async_log_fd();
342
async_append_destroy(log_writer);
345
log_file_name = xstrdup(new_log_file_name);
347
log_writer = async_append_create(new_log_fd);
316
349
for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
317
350
update_min_level(*mp);
320
/* Log success or failure. */
322
VLOG_WARN("failed to open %s for logging: %s",
323
log_file_name, strerror(errno));
326
VLOG_INFO("opened log file %s", log_file_name);
352
ovs_mutex_unlock(&log_file_mutex);
354
/* Log opening new log file (we can't log while holding log_file_mutex). */
355
VLOG_INFO("opened log file %s", new_log_file_name);
356
free(new_log_file_name);
333
361
/* Closes and then attempts to re-open the current log file. (This is useful
337
365
vlog_reopen_log_file(void)
339
struct stat old, new;
341
/* Skip re-opening if there's nothing to reopen. */
342
if (!log_file_name) {
346
/* Skip re-opening if it would be a no-op because the old and new files are
347
* the same. (This avoids writing "closing log file" followed immediately
348
* by "opened log file".) */
350
&& !fstat(log_fd, &old)
351
&& !stat(log_file_name, &new)
352
&& old.st_dev == new.st_dev
353
&& old.st_ino == new.st_ino) {
357
return vlog_set_log_file(log_file_name);
369
ovs_mutex_lock(&log_file_mutex);
370
fn = log_file_name ? xstrdup(log_file_name) : NULL;
371
ovs_mutex_unlock(&log_file_mutex);
374
int error = vlog_set_log_file(fn);
360
382
/* Set debugging levels. Returns null if successful, otherwise an error
486
508
vlog_unixctl_reopen(struct unixctl_conn *conn, int argc OVS_UNUSED,
487
509
const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED)
513
ovs_mutex_lock(&log_file_mutex);
514
has_log_file = log_file_name != NULL;
515
ovs_mutex_unlock(&log_file_mutex);
490
518
int error = vlog_reopen_log_file();
492
unixctl_command_reply_error(conn, strerror(errno));
520
unixctl_command_reply_error(conn, ovs_strerror(errno));
494
522
unixctl_command_reply(conn, NULL);
547
575
set_rate_limits(conn, argc, argv, false);
550
/* Initializes the logging subsystem and registers its unixctl server
555
581
static char *program_name_copy;
563
584
/* openlog() is allowed to keep the pointer passed in, without making a
564
585
* copy. The daemonize code sometimes frees and replaces 'program_name',
565
586
* so make a private copy just for openlog(). (We keep a pointer to the
711
729
p = fetch_braces(p, "%Y-%m-%d %H:%M:%S", tmp, sizeof tmp);
712
ds_put_strftime(s, tmp, false);
730
ds_put_strftime(s, tmp, time_wall(), false);
715
733
p = fetch_braces(p, "%Y-%m-%d %H:%M:%S", tmp, sizeof tmp);
716
ds_put_strftime(s, tmp, true);
734
ds_put_strftime(s, tmp, time_wall(), true);
719
737
/* Format user-supplied log message and trim trailing new-lines. */
777
797
bool log_to_console = module->levels[VLF_CONSOLE] >= level;
778
798
bool log_to_syslog = module->levels[VLF_SYSLOG] >= level;
779
bool log_to_file = module->levels[VLF_FILE] >= level && log_fd >= 0;
801
ovs_mutex_lock(&log_file_mutex);
802
log_to_file = module->levels[VLF_FILE] >= level && log_fd >= 0;
803
ovs_mutex_unlock(&log_file_mutex);
780
804
if (log_to_console || log_to_syslog || log_to_file) {
781
805
int save_errno = errno;
782
static unsigned int msg_num;
788
811
ds_reserve(&s, 1024);
814
ovs_rwlock_rdlock(&pattern_rwlock);
791
815
if (log_to_console) {
792
format_log_message(module, level, VLF_CONSOLE, msg_num,
816
format_log_message(module, level, VLF_CONSOLE, message, args, &s);
794
817
ds_put_char(&s, '\n');
795
818
fputs(ds_cstr(&s), stderr);
800
823
char *save_ptr = NULL;
803
format_log_message(module, level, VLF_SYSLOG, msg_num,
826
format_log_message(module, level, VLF_SYSLOG, message, args, &s);
805
827
for (line = strtok_r(s.string, "\n", &save_ptr); line;
806
828
line = strtok_r(NULL, "\n", &save_ptr)) {
807
829
syslog(syslog_level, "%s", line);
811
833
if (log_to_file) {
812
format_log_message(module, level, VLF_FILE, msg_num,
834
format_log_message(module, level, VLF_FILE, message, args, &s);
814
835
ds_put_char(&s, '\n');
837
ovs_mutex_lock(&log_file_mutex);
839
async_append_write(log_writer, s.string, s.length);
840
if (level == VLL_EMER) {
841
async_append_flush(log_writer);
844
ovs_mutex_unlock(&log_file_mutex);
846
ovs_rwlock_unlock(&pattern_rwlock);
819
849
errno = save_errno;
921
952
rl->last_dropped = now;
954
ovs_mutex_unlock(&rl->mutex);
958
if (!rl->n_dropped) {
959
ovs_mutex_unlock(&rl->mutex);
927
961
time_t now = time_now();
962
unsigned int n_dropped = rl->n_dropped;
928
963
unsigned int first_dropped_elapsed = now - rl->first_dropped;
929
964
unsigned int last_dropped_elapsed = now - rl->last_dropped;
966
ovs_mutex_unlock(&rl->mutex);
931
968
vlog(module, level,
932
969
"Dropped %u log messages in last %u seconds (most recently, "
933
970
"%u seconds ago) due to excessive rate",
934
rl->n_dropped, first_dropped_elapsed, last_dropped_elapsed);
971
n_dropped, first_dropped_elapsed, last_dropped_elapsed);
961
997
" (default: %s/%s.log)\n",
962
998
ovs_logdir(), program_name);
965
static bool vlog_async_inited = false;
967
static worker_request_func vlog_async_write_request_cb;
970
vlog_write_file(struct ds *s)
972
if (worker_is_running()) {
973
static bool in_worker_request = false;
974
if (!in_worker_request) {
975
in_worker_request = true;
977
worker_request(s->string, s->length,
978
&log_fd, vlog_async_inited ? 0 : 1,
979
vlog_async_write_request_cb, NULL, NULL);
980
vlog_async_inited = true;
982
in_worker_request = false;
985
/* We've been entered recursively. This can happen if
986
* worker_request(), or a function that it calls, tries to log
987
* something. We can't call worker_request() recursively, so fall
988
* back to writing the log file directly. */
989
COVERAGE_INC(vlog_recursive);
992
ignore(write(log_fd, s->string, s->length));
996
vlog_update_async_log_fd(void)
998
if (worker_is_running()) {
999
worker_request(NULL, 0, &log_fd, 1, vlog_async_write_request_cb,
1001
vlog_async_inited = true;
1006
vlog_async_write_request_cb(struct ofpbuf *request,
1007
const int *fd, size_t n_fds)
1016
if (request->size > 0) {
1017
ignore(write(log_fd, request->data, request->size));
added
removed
lib/vlog.c
