CernVM-FS  2.13.0
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Pages
logging.cc
Go to the documentation of this file.
1 
14 #include <errno.h>
15 #include <fcntl.h>
16 #include <pthread.h>
17 #include <syslog.h>
18 #include <time.h>
19 #include <unistd.h>
20 
21 #include <cassert>
22 #include <cstdio>
23 #include <cstdlib>
24 #include <cstring>
25 #include <ctime>
26 #include <vector>
27 
28 #include "util/export.h"
29 #include "util/logging_internal.h" // NOLINT(build/include)
30 #include "util/mutex.h"
31 #include "util/platform.h"
32 #include "util/posix.h"
33 #include "util/single_copy.h"
34 #include "util/smalloc.h"
35 
36 using namespace std; // NOLINT
37 
38 #ifdef CVMFS_NAMESPACE_GUARD
39 namespace CVMFS_NAMESPACE_GUARD {
40 #endif
41 
42 static void LogCustom(unsigned id, const std::string &message);
43 
46 
48  DefaultLogging::info = info;
49  DefaultLogging::error = error;
50 }
51 
52 namespace {
53 
54 unsigned gMicroSyslogMax = 500 * 1024; // default: rotate after 500kB
55 
56 pthread_mutex_t lock_stdout = PTHREAD_MUTEX_INITIALIZER;
57 pthread_mutex_t lock_stderr = PTHREAD_MUTEX_INITIALIZER;
58 #ifdef DEBUGMSG
59 pthread_mutex_t lock_debug = PTHREAD_MUTEX_INITIALIZER;
60 FILE *file_debug = NULL;
61 string *path_debug = NULL;
62 #endif
63 const char *module_names[] = {
64  "unknown", "cache", "catalog", "sql",
65  "cvmfs", "hash", "download", "compress",
66  "quota", "talk", "monitor", "lru",
67  "fuse stub", "signature", "fs traversal", "catalog traversal",
68  "nfs maps", "publish", "spooler", "concurrency",
69  "utility", "glue buffer", "history", "unionfs",
70  "pathspec", "receiver", "upload s3", "upload http",
71  "s3fanout", "gc", "dns", "authz",
72  "reflog", "kvstore", "telemetry", "curl"};
73 int syslog_facility = LOG_USER;
74 int syslog_level = LOG_NOTICE;
75 char *syslog_prefix = NULL;
76 
77 string *usyslog_dest = NULL;
78 int usyslog_fd = -1;
79 int usyslog_fd1 = -1;
80 unsigned usyslog_size = 0;
81 pthread_mutex_t lock_usyslock = PTHREAD_MUTEX_INITIALIZER;
82 
83 const unsigned kMaxCustomlog = 3;
84 string *customlog_dests[] = {NULL, NULL, NULL};
85 int customlog_fds[] = {-1, -1, -1};
86 pthread_mutex_t customlog_locks[] = {PTHREAD_MUTEX_INITIALIZER,
87  PTHREAD_MUTEX_INITIALIZER,
88  PTHREAD_MUTEX_INITIALIZER};
89 
91 static void (*alt_log_func)(const LogSource source, const int mask,
92  const char *msg) = NULL;
93 
98  public:
99  LogBuffer() : next_id_(0) {
100  const int retval = pthread_mutex_init(&lock_, NULL);
101  assert(retval == 0);
102  }
103 
104  ~LogBuffer() { pthread_mutex_destroy(&lock_); }
105 
106  void Append(const LogBufferEntry &entry) {
107  const MutexLockGuard lock_guard(lock_);
108  const size_t idx = next_id_++ % kBufferSize;
109  if (idx >= buffer_.size()) {
110  buffer_.push_back(entry);
111  } else {
112  buffer_[idx] = entry;
113  }
114  }
115 
116  std::vector<LogBufferEntry> GetBuffer() {
117  // Return a buffer sorted from newest to oldest buffer
118  std::vector<LogBufferEntry> sorted_buffer;
119  const MutexLockGuard lock_guard(lock_);
120  for (unsigned i = 1; i <= buffer_.size(); ++i) {
121  const unsigned idx = (next_id_ - i) % kBufferSize;
122  sorted_buffer.push_back(buffer_[idx]);
123  }
124  return sorted_buffer;
125  }
126 
127  void Clear() {
128  const MutexLockGuard lock_guard(lock_);
129  next_id_ = 0;
130  buffer_.clear();
131  }
132 
133  private:
134  static const unsigned kBufferSize = 10;
135  pthread_mutex_t lock_;
136  int next_id_;
137  std::vector<LogBufferEntry> buffer_;
138 };
139 
141 
142 } // namespace
143 
147 void SetLogSyslogLevel(const int level) {
148  switch (level) {
149  case 1:
150  syslog_level = LOG_DEBUG;
151  break;
152  case 2:
153  syslog_level = LOG_INFO;
154  break;
155  case 3:
156  syslog_level = LOG_NOTICE;
157  break;
158  default:
159  syslog_level = LOG_NOTICE;
160  break;
161  }
162 }
163 
165  switch (syslog_level) {
166  case LOG_DEBUG:
167  return 1;
168  case LOG_INFO:
169  return 2;
170  default:
171  return 3;
172  }
173 }
174 
179 void SetLogSyslogFacility(const int local_facility) {
180  switch (local_facility) {
181  case 0:
182  syslog_facility = LOG_LOCAL0;
183  break;
184  case 1:
185  syslog_facility = LOG_LOCAL1;
186  break;
187  case 2:
188  syslog_facility = LOG_LOCAL2;
189  break;
190  case 3:
191  syslog_facility = LOG_LOCAL3;
192  break;
193  case 4:
194  syslog_facility = LOG_LOCAL4;
195  break;
196  case 5:
197  syslog_facility = LOG_LOCAL5;
198  break;
199  case 6:
200  syslog_facility = LOG_LOCAL6;
201  break;
202  case 7:
203  syslog_facility = LOG_LOCAL7;
204  break;
205  default:
206  syslog_facility = LOG_USER;
207  }
208 }
209 
211  switch (syslog_facility) {
212  case LOG_LOCAL0:
213  return 0;
214  case LOG_LOCAL1:
215  return 1;
216  case LOG_LOCAL2:
217  return 2;
218  case LOG_LOCAL3:
219  return 3;
220  case LOG_LOCAL4:
221  return 4;
222  case LOG_LOCAL5:
223  return 5;
224  case LOG_LOCAL6:
225  return 6;
226  case LOG_LOCAL7:
227  return 7;
228  default:
229  return -1;
230  }
231 }
232 
237 void SetLogSyslogPrefix(const std::string &prefix) {
238  if (syslog_prefix)
239  free(syslog_prefix);
240 
241  if (prefix == "") {
242  syslog_prefix = NULL;
243  } else {
244  const unsigned len = prefix.length() + 1;
245  syslog_prefix = static_cast<char *>(smalloc(len));
246  syslog_prefix[len - 1] = '\0';
247  memcpy(syslog_prefix, &prefix[0], prefix.length());
248  }
249 }
250 
251 void SetLogSyslogShowPID(bool flag) {
252  openlog(NULL, flag ? LOG_PID : 0, GetLogSyslogFacility());
253 }
254 
258 void SetLogVerbosity(const LogLevels max_level) { max_log_level = max_level; }
259 
260 
261 void SetLogMicroSyslogMaxSize(unsigned bytes) { gMicroSyslogMax = bytes; }
262 
267 void SetLogMicroSyslog(const std::string &filename) {
268  pthread_mutex_lock(&lock_usyslock);
269  if (usyslog_fd >= 0) {
270  close(usyslog_fd);
271  close(usyslog_fd1);
272  usyslog_fd = -1;
273  usyslog_fd1 = -1;
274  }
275 
276  if (filename == "") {
277  delete usyslog_dest;
278  usyslog_dest = NULL;
279  pthread_mutex_unlock(&lock_usyslock);
280  return;
281  }
282 
283  usyslog_fd = open(filename.c_str(), O_RDWR | O_APPEND | O_CREAT, 0600);
284  if (usyslog_fd < 0) {
285  fprintf(stderr, "could not open usyslog file %s (%d), aborting\n",
286  filename.c_str(), errno);
287  abort();
288  }
289  usyslog_fd1 = open((filename + ".1").c_str(), O_WRONLY | O_CREAT, 0600);
290  if (usyslog_fd1 < 0) {
291  fprintf(stderr, "could not open usyslog.1 file %s.1 (%d), aborting\n",
292  filename.c_str(), errno);
293  abort();
294  }
295  platform_stat64 info;
296  const int retval = platform_fstat(usyslog_fd, &info);
297  assert(retval == 0);
298  usyslog_size = info.st_size;
299  usyslog_dest = new string(filename);
300  pthread_mutex_unlock(&lock_usyslock);
301 }
302 
303 std::string GetLogMicroSyslog() {
304  pthread_mutex_lock(&lock_usyslock);
305  string result;
306  if (usyslog_dest)
307  result = *usyslog_dest;
308  pthread_mutex_unlock(&lock_usyslock);
309  return result;
310 }
311 
312 static void LogMicroSyslog(const std::string &message) {
313  if (message.size() == 0)
314  return;
315 
316  pthread_mutex_lock(&lock_usyslock);
317  if (usyslog_fd < 0) {
318  pthread_mutex_unlock(&lock_usyslock);
319  return;
320  }
321 
322  const int written = write(usyslog_fd, message.data(), message.size());
323  if ((written < 0) || (static_cast<unsigned>(written) != message.size())) {
324  close(usyslog_fd);
325  usyslog_fd = -1;
326  abort();
327  }
328  int retval = fsync(usyslog_fd);
329  assert(retval == 0);
330  usyslog_size += written;
331 
332  if (usyslog_size >= gMicroSyslogMax) {
333  // Wipe out usyslog.1 file
334  retval = ftruncate(usyslog_fd1, 0);
335  assert(retval == 0);
336 
337  // Copy from usyslog to usyslog.1
338  retval = lseek(usyslog_fd, 0, SEEK_SET);
339  assert(retval == 0);
340  unsigned char buf[4096];
341  int num_bytes;
342  do {
343  num_bytes = read(usyslog_fd, buf, 4096);
344  assert(num_bytes >= 0);
345  if (num_bytes == 0)
346  break;
347  const int written = write(usyslog_fd1, buf, num_bytes);
348  assert(written == num_bytes);
349  } while (num_bytes == 4096);
350  retval = lseek(usyslog_fd1, 0, SEEK_SET);
351  assert(retval == 0);
352 
353  // Reset usyslog
354  retval = lseek(usyslog_fd, 0, SEEK_SET);
355  assert(retval == 0);
356  retval = ftruncate(usyslog_fd, 0);
357  assert(retval == 0);
358  usyslog_size = 0;
359  }
360  pthread_mutex_unlock(&lock_usyslock);
361 }
362 
366 #ifdef DEBUGMSG
367 void SetLogDebugFile(const string &filename) {
368  if (filename == "") {
369  if ((file_debug != NULL) && (file_debug != stderr)) {
370  fclose(file_debug);
371  file_debug = NULL;
372  }
373  delete path_debug;
374  path_debug = NULL;
375  return;
376  }
377 
378  if ((file_debug != NULL) && (file_debug != stderr)) {
379  if ((fclose(file_debug) < 0)) {
380  fprintf(stderr, "could not close current log file (%d), aborting\n",
381  errno);
382 
383  abort();
384  }
385  }
386  const int fd = open(filename.c_str(), O_WRONLY | O_APPEND | O_CREAT, 0600);
387  if ((fd < 0) || ((file_debug = fdopen(fd, "a")) == NULL)) {
388  fprintf(stderr, "could not open debug log file %s (%d), aborting\n",
389  filename.c_str(), errno);
390  syslog(syslog_facility | LOG_ERR,
391  "could not open debug log file %s (%d), "
392  "aborting\n",
393  filename.c_str(), errno);
394  abort();
395  }
396  delete path_debug;
397  path_debug = new string(filename);
398 }
399 
400 string GetLogDebugFile() {
401  if (path_debug)
402  return *path_debug;
403  return "";
404 }
405 #endif
406 
407 void SetAltLogFunc(void (*fn)(const LogSource source, const int mask,
408  const char *msg)) {
409  alt_log_func = fn;
410 }
411 
412 
422 void vLogCvmfs(const LogSource source, const int mask, const char *format,
423  va_list variadic_list) {
424  char *msg = NULL;
425 
426 // Log level check, no flag set in mask means kLogNormal
427 #ifndef DEBUGMSG
428  int log_level = mask & ((2 * kLogNone - 1) ^ (kLogLevel0 - 1));
429  if (!log_level)
430  log_level = kLogNormal;
431  if (log_level == kLogNone)
432  return;
433  if (log_level > max_log_level)
434  return;
435 #endif
436 
437  // Format the message string
438  const int retval = vasprintf(&msg, format, variadic_list);
439  assert(retval != -1); // else: out of memory
440 
441  if (alt_log_func) {
442  (*alt_log_func)(source, mask, msg);
443  return;
444  }
445 
446 #ifdef DEBUGMSG
447  if (mask & kLogDebug) {
448  pthread_mutex_lock(&lock_debug);
449 
450  // Set the file pointer for debugging to stderr, if necessary
451  if (file_debug == NULL)
452  file_debug = stderr;
453 
454  // Get timestamp
455  time_t rawtime;
456  time(&rawtime);
457  struct tm now;
458  localtime_r(&rawtime, &now);
459 
460  if (file_debug == stderr)
461  pthread_mutex_lock(&lock_stderr);
462  fprintf(file_debug, "(%s) %s [%02d-%02d-%04d %02d:%02d:%02d %s]\n",
463  module_names[source], msg, (now.tm_mon) + 1, now.tm_mday,
464  (now.tm_year) + 1900, now.tm_hour, now.tm_min, now.tm_sec,
465  now.tm_zone);
466  fflush(file_debug);
467  if (file_debug == stderr)
468  pthread_mutex_unlock(&lock_stderr);
469 
470  pthread_mutex_unlock(&lock_debug);
471  }
472 #endif
473 
474  if (mask & kLogStdout) {
475  pthread_mutex_lock(&lock_stdout);
476  if (mask & kLogShowSource)
477  printf("(%s) ", module_names[source]);
478  printf("%s", msg);
479  if (!(mask & kLogNoLinebreak))
480  printf("\n");
481  fflush(stdout);
482  pthread_mutex_unlock(&lock_stdout);
483  }
484 
485  if (mask & kLogStderr) {
486  pthread_mutex_lock(&lock_stderr);
487  if (mask & kLogShowSource)
488  fprintf(stderr, "(%s) ", module_names[source]);
489  fprintf(stderr, "%s", msg);
490  if (!(mask & kLogNoLinebreak))
491  fprintf(stderr, "\n");
492  fflush(stderr);
493  pthread_mutex_unlock(&lock_stderr);
494  }
495 
496  if (mask & (kLogSyslog | kLogSyslogWarn | kLogSyslogErr)) {
497  if (usyslog_dest) {
498  string fmt_msg(msg);
499  if (syslog_prefix)
500  fmt_msg = "(" + string(syslog_prefix) + ") " + fmt_msg;
501  time_t rawtime;
502  time(&rawtime);
503  char fmt_time[26];
504  ctime_r(&rawtime, fmt_time);
505  fmt_msg = string(fmt_time, 24) + " " + fmt_msg;
506  fmt_msg.push_back('\n');
507  LogMicroSyslog(fmt_msg);
508  } else {
509  int level = syslog_level;
510  if (mask & kLogSyslogWarn)
511  level = LOG_WARNING;
512  if (mask & kLogSyslogErr)
513  level = LOG_ERR;
514  if (syslog_prefix) {
515  syslog(syslog_facility | level, "(%s) %s", syslog_prefix, msg);
516  } else {
517  syslog(syslog_facility | level, "%s", msg);
518  }
519  }
520  }
521 
522  if (mask & (kLogCustom0 | kLogCustom1 | kLogCustom2)) {
523  string fmt_msg(msg);
524  if (syslog_prefix)
525  fmt_msg = "(" + string(syslog_prefix) + ") " + fmt_msg;
526  if (!(mask & kLogNoLinebreak))
527  fmt_msg += "\n";
528  if (mask & kLogCustom0)
529  LogCustom(0, fmt_msg);
530  if (mask & kLogCustom1)
531  LogCustom(1, fmt_msg);
532  if (mask & kLogCustom2)
533  LogCustom(2, fmt_msg);
534  }
535 
536  // The log buffer can be read via extended attributes from cvmfs, therefore
537  // we provide an option to hide entries from the buffer if they contain
538  // sensitive information
539  if (!(mask & kLogSensitive))
540  g_log_buffer.Append(LogBufferEntry(source, mask, msg));
541 
542  free(msg);
543 }
545 void LogCvmfs(const LogSource source, const int mask, const char *format, ...) {
546  va_list variadic_list;
547  va_start(variadic_list, format);
548  vLogCvmfs(source, mask, format, variadic_list);
549  va_end(variadic_list);
550 }
551 
552 std::vector<LogBufferEntry> GetLogBuffer() { return g_log_buffer.GetBuffer(); }
553 
555 
556 void PrintError(const string &message) {
557  LogCvmfs(kLogCvmfs, kLogStderr, "[ERROR] %s", message.c_str());
558 }
559 
560 void PrintWarning(const string &message) {
561  LogCvmfs(kLogCvmfs, kLogStderr, "[WARNING] %s", message.c_str());
562 }
563 
564 
568 void SetLogCustomFile(unsigned id, const std::string &filename) {
569  assert(id < kMaxCustomlog);
570  pthread_mutex_lock(&customlog_locks[id]);
571 
572  if (customlog_fds[id] >= 0) {
573  close(customlog_fds[id]);
574  customlog_fds[id] = -1;
575  }
576 
577  if (filename.empty()) {
578  delete customlog_dests[id];
579  customlog_dests[id] = NULL;
580  pthread_mutex_unlock(&customlog_locks[id]);
581  return;
582  }
583 
584  customlog_fds[id] = open(filename.c_str(), O_RDWR | O_APPEND | O_CREAT, 0600);
585  if (customlog_fds[id] < 0) {
587  "could not open log file %s (%d), aborting", filename.c_str(),
588  errno);
589  abort();
590  }
591  delete customlog_dests[id];
592  customlog_dests[id] = new string(filename);
593 
594  pthread_mutex_unlock(&customlog_locks[id]);
595 }
596 
597 
598 static void LogCustom(unsigned id, const std::string &message) {
599  assert(id < kMaxCustomlog);
600  if (message.size() == 0)
601  return;
602 
603  pthread_mutex_lock(&customlog_locks[id]);
604  assert(customlog_fds[id] >= 0);
605 
606  const bool retval_b =
607  SafeWrite(customlog_fds[id], message.data(), message.size());
608  if (!retval_b) {
610  "could not write into log file %s (%d), aborting - lost: %s",
611  customlog_dests[id]->c_str(), errno, message.c_str());
612  abort();
613  }
614  const int retval_i = fsync(customlog_fds[id]);
615  assert(retval_i == 0);
616 
617  pthread_mutex_unlock(&customlog_locks[id]);
618 }
619 
620 
621 void LogShutdown() {
622  SetLogMicroSyslog("");
623  for (unsigned i = 0; i < kMaxCustomlog; ++i)
624  SetLogCustomFile(i, "");
625 }
626 
627 
628 #ifdef CVMFS_NAMESPACE_GUARD
629 } // namespace CVMFS_NAMESPACE_GUARD
630 #endif
std::vector< LogBufferEntry > GetLogBuffer()
Definition: logging.cc:552
void SetLogSyslogFacility(const int local_facility)
Definition: logging.cc:179
void SetLogVerbosity(const LogLevels max_level)
Definition: logging.cc:258
const char * module_names[]
Definition: logging.cc:63
pthread_mutex_t customlog_locks[]
Definition: logging.cc:86
void SetLogSyslogLevel(const int level)
Definition: logging.cc:147
struct stat64 platform_stat64
static void LogCustom(unsigned id, const std::string &message)
Definition: logging.cc:598
CVMFS_EXPORT const LogSource const int mask
Definition: exception.h:33
const unsigned kBufferSize
Definition: compression.cc:148
void SetLogSyslogShowPID(bool flag)
Definition: logging.cc:251
CVMFS_EXPORT const LogSource source
Definition: exception.h:33
std::vector< LogBufferEntry > GetBuffer()
Definition: logging.cc:116
CVMFS_EXPORT void vLogCvmfs(const LogSource source, const int mask, const char *format, va_list variadic_list)
Definition: logging.cc:422
#define CVMFS_EXPORT
Definition: export.h:11
static void Set(LogFacilities info, LogFacilities error)
Definition: logging.cc:47
static void LogMicroSyslog(const std::string &message)
Definition: logging.cc:312
bool SafeWrite(int fd, const void *buf, size_t nbyte)
Definition: posix.cc:2036
void SetLogMicroSyslogMaxSize(unsigned bytes)
Definition: logging.cc:261
assert((mem||(size==0))&&"Out Of Memory")
void Append(const LogBufferEntry &entry)
Definition: logging.cc:106
void SetAltLogFunc(void(*fn)(const LogSource source, const int mask, const char *msg))
Definition: logging.cc:407
void SetLogMicroSyslog(const std::string &filename)
Definition: logging.cc:267
#define SetLogDebugFile(filename)
pthread_mutex_t lock_stdout
Definition: logging.cc:56
static void(* alt_log_func)(const LogSource source, const int mask, const char *msg)
Definition: logging.cc:91
int GetLogSyslogLevel()
Definition: logging.cc:164
#define GetLogDebugFile()
Don&#39;t add the line to the memory log buffer.
pthread_mutex_t lock_usyslock
Definition: logging.cc:81
LogSource
void SetLogCustomFile(unsigned id, const std::string &filename)
Definition: logging.cc:568
std::string GetLogMicroSyslog()
Definition: logging.cc:303
void PrintWarning(const string &message)
Definition: logging.cc:560
LogLevels
void LogShutdown()
Definition: logging.cc:621
Definition: mutex.h:42
void ClearLogBuffer()
Definition: logging.cc:554
CVMFS_EXPORT const LogSource const int const char * format
Definition: exception.h:33
LogFacilities
void SetLogSyslogPrefix(const std::string &prefix)
Definition: logging.cc:237
void PrintError(const string &message)
Definition: logging.cc:556
int platform_fstat(int filedes, platform_stat64 *buf)
static LogFacilities info
static LogFacilities error
pthread_mutex_t lock_stderr
Definition: logging.cc:57
const unsigned kMaxCustomlog
Definition: logging.cc:83
std::vector< LogBufferEntry > buffer_
Definition: logging.cc:137
CVMFS_EXPORT void LogCvmfs(const LogSource source, const int mask, const char *format,...)
Definition: logging.cc:545
int GetLogSyslogFacility()
Definition: logging.cc:210