log.c 33 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194
  1. /* Copyright (c) 2001, Matej Pfajfar.
  2. * Copyright (c) 2001-2004, Roger Dingledine.
  3. * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson.
  4. * Copyright (c) 2007-2013, The Tor Project, Inc. */
  5. /* See LICENSE for licensing information */
  6. /**
  7. * \file log.c
  8. * \brief Functions to send messages to log files or the console.
  9. **/
  10. #include "orconfig.h"
  11. #include <stdarg.h>
  12. #include <assert.h>
  13. // #include <stdio.h>
  14. #include <stdlib.h>
  15. #include <string.h>
  16. #ifdef HAVE_SYS_TIME_H
  17. #include <sys/time.h>
  18. #endif
  19. #ifdef HAVE_TIME_H
  20. #include <time.h>
  21. #endif
  22. #ifdef HAVE_UNISTD_H
  23. #include <unistd.h>
  24. #endif
  25. #ifdef HAVE_SYS_TYPES_H
  26. #include <sys/types.h>
  27. #endif
  28. #ifdef HAVE_FCNTL_H
  29. #include <fcntl.h>
  30. #endif
  31. #include "compat.h"
  32. #include "util.h"
  33. #define LOG_PRIVATE
  34. #include "torlog.h"
  35. #include "container.h"
  36. /** Given a severity, yields an index into log_severity_list_t.masks to use
  37. * for that severity. */
  38. #define SEVERITY_MASK_IDX(sev) ((sev) - LOG_ERR)
  39. /** @{ */
  40. /** The string we stick at the end of a log message when it is too long,
  41. * and its length. */
  42. #define TRUNCATED_STR "[...truncated]"
  43. #define TRUNCATED_STR_LEN 14
  44. /** @} */
  45. /** Information for a single logfile; only used in log.c */
  46. typedef struct logfile_t {
  47. struct logfile_t *next; /**< Next logfile_t in the linked list. */
  48. char *filename; /**< Filename to open. */
  49. int fd; /**< fd to receive log messages, or -1 for none. */
  50. int seems_dead; /**< Boolean: true if the stream seems to be kaput. */
  51. int needs_close; /**< Boolean: true if the stream gets closed on shutdown. */
  52. int is_temporary; /**< Boolean: close after initializing logging subsystem.*/
  53. int is_syslog; /**< Boolean: send messages to syslog. */
  54. log_callback callback; /**< If not NULL, send messages to this function. */
  55. log_severity_list_t *severities; /**< Which severity of messages should we
  56. * log for each log domain? */
  57. } logfile_t;
  58. static void log_free(logfile_t *victim);
  59. /** Helper: map a log severity to descriptive string. */
  60. static INLINE const char *
  61. sev_to_string(int severity)
  62. {
  63. switch (severity) {
  64. case LOG_DEBUG: return "debug";
  65. case LOG_INFO: return "info";
  66. case LOG_NOTICE: return "notice";
  67. case LOG_WARN: return "warn";
  68. case LOG_ERR: return "err";
  69. default: /* Call assert, not tor_assert, since tor_assert
  70. * calls log on failure. */
  71. assert(0); return "UNKNOWN";
  72. }
  73. }
  74. /** Helper: decide whether to include the function name in the log message. */
  75. static INLINE int
  76. should_log_function_name(log_domain_mask_t domain, int severity)
  77. {
  78. switch (severity) {
  79. case LOG_DEBUG:
  80. case LOG_INFO:
  81. /* All debugging messages occur in interesting places. */
  82. return 1;
  83. case LOG_NOTICE:
  84. case LOG_WARN:
  85. case LOG_ERR:
  86. /* We care about places where bugs occur. */
  87. return (domain == LD_BUG);
  88. default:
  89. /* Call assert, not tor_assert, since tor_assert calls log on failure. */
  90. assert(0); return 0;
  91. }
  92. }
  93. /** A mutex to guard changes to logfiles and logging. */
  94. static tor_mutex_t log_mutex;
  95. /** True iff we have initialized log_mutex */
  96. static int log_mutex_initialized = 0;
  97. /** Linked list of logfile_t. */
  98. static logfile_t *logfiles = NULL;
  99. /** Boolean: do we report logging domains? */
  100. static int log_domains_are_logged = 0;
  101. #ifdef HAVE_SYSLOG_H
  102. /** The number of open syslog log handlers that we have. When this reaches 0,
  103. * we can close our connection to the syslog facility. */
  104. static int syslog_count = 0;
  105. #endif
  106. /** Represents a log message that we are going to send to callback-driven
  107. * loggers once we can do so in a non-reentrant way. */
  108. typedef struct pending_cb_message_t {
  109. int severity; /**< The severity of the message */
  110. log_domain_mask_t domain; /**< The domain of the message */
  111. char *msg; /**< The content of the message */
  112. } pending_cb_message_t;
  113. /** Log messages waiting to be replayed onto callback-based logs */
  114. static smartlist_t *pending_cb_messages = NULL;
  115. /** Lock the log_mutex to prevent others from changing the logfile_t list */
  116. #define LOCK_LOGS() STMT_BEGIN \
  117. tor_mutex_acquire(&log_mutex); \
  118. STMT_END
  119. /** Unlock the log_mutex */
  120. #define UNLOCK_LOGS() STMT_BEGIN tor_mutex_release(&log_mutex); STMT_END
  121. /** What's the lowest log level anybody cares about? Checking this lets us
  122. * bail out early from log_debug if we aren't debugging. */
  123. int log_global_min_severity_ = LOG_NOTICE;
  124. static void delete_log(logfile_t *victim);
  125. static void close_log(logfile_t *victim);
  126. static char *domain_to_string(log_domain_mask_t domain,
  127. char *buf, size_t buflen);
  128. static INLINE char *format_msg(char *buf, size_t buf_len,
  129. log_domain_mask_t domain, int severity, const char *funcname,
  130. const char *suffix,
  131. const char *format, va_list ap, size_t *msg_len_out)
  132. CHECK_PRINTF(7,0);
  133. static void logv(int severity, log_domain_mask_t domain, const char *funcname,
  134. const char *suffix, const char *format, va_list ap)
  135. CHECK_PRINTF(5,0);
  136. /** Name of the application: used to generate the message we write at the
  137. * start of each new log. */
  138. static char *appname = NULL;
  139. /** Set the "application name" for the logs to <b>name</b>: we'll use this
  140. * name in the message we write when starting up, and at the start of each new
  141. * log.
  142. *
  143. * Tor uses this string to write the version number to the log file. */
  144. void
  145. log_set_application_name(const char *name)
  146. {
  147. tor_free(appname);
  148. appname = name ? tor_strdup(name) : NULL;
  149. }
  150. /** Log time granularity in milliseconds. */
  151. static int log_time_granularity = 1;
  152. /** Define log time granularity for all logs to be <b>granularity_msec</b>
  153. * milliseconds. */
  154. void
  155. set_log_time_granularity(int granularity_msec)
  156. {
  157. log_time_granularity = granularity_msec;
  158. }
  159. /** Helper: Write the standard prefix for log lines to a
  160. * <b>buf_len</b> character buffer in <b>buf</b>.
  161. */
  162. static INLINE size_t
  163. log_prefix_(char *buf, size_t buf_len, int severity)
  164. {
  165. time_t t;
  166. struct timeval now;
  167. struct tm tm;
  168. size_t n;
  169. int r, ms;
  170. tor_gettimeofday(&now);
  171. t = (time_t)now.tv_sec;
  172. ms = (int)now.tv_usec / 1000;
  173. if (log_time_granularity >= 1000) {
  174. t -= t % (log_time_granularity / 1000);
  175. ms = 0;
  176. } else {
  177. ms -= ((int)now.tv_usec / 1000) % log_time_granularity;
  178. }
  179. n = strftime(buf, buf_len, "%b %d %H:%M:%S", tor_localtime_r(&t, &tm));
  180. r = tor_snprintf(buf+n, buf_len-n, ".%.3i [%s] ", ms,
  181. sev_to_string(severity));
  182. if (r<0)
  183. return buf_len-1;
  184. else
  185. return n+r;
  186. }
  187. /** If lf refers to an actual file that we have just opened, and the file
  188. * contains no data, log an "opening new logfile" message at the top.
  189. *
  190. * Return -1 if the log is broken and needs to be deleted, else return 0.
  191. */
  192. static int
  193. log_tor_version(logfile_t *lf, int reset)
  194. {
  195. char buf[256];
  196. size_t n;
  197. int is_new;
  198. if (!lf->needs_close)
  199. /* If it doesn't get closed, it isn't really a file. */
  200. return 0;
  201. if (lf->is_temporary)
  202. /* If it's temporary, it isn't really a file. */
  203. return 0;
  204. is_new = lf->fd >= 0 && tor_fd_getpos(lf->fd) == 0;
  205. if (reset && !is_new)
  206. /* We are resetting, but we aren't at the start of the file; no
  207. * need to log again. */
  208. return 0;
  209. n = log_prefix_(buf, sizeof(buf), LOG_NOTICE);
  210. if (appname) {
  211. tor_snprintf(buf+n, sizeof(buf)-n,
  212. "%s opening %slog file.\n", appname, is_new?"new ":"");
  213. } else {
  214. tor_snprintf(buf+n, sizeof(buf)-n,
  215. "Tor %s opening %slog file.\n", VERSION, is_new?"new ":"");
  216. }
  217. if (write_all(lf->fd, buf, strlen(buf), 0) < 0) /* error */
  218. return -1; /* failed */
  219. return 0;
  220. }
  221. /** Helper: Format a log message into a fixed-sized buffer. (This is
  222. * factored out of <b>logv</b> so that we never format a message more
  223. * than once.) Return a pointer to the first character of the message
  224. * portion of the formatted string.
  225. */
  226. static INLINE char *
  227. format_msg(char *buf, size_t buf_len,
  228. log_domain_mask_t domain, int severity, const char *funcname,
  229. const char *suffix,
  230. const char *format, va_list ap, size_t *msg_len_out)
  231. {
  232. size_t n;
  233. int r;
  234. char *end_of_prefix;
  235. char *buf_end;
  236. assert(buf_len >= 16); /* prevent integer underflow and general stupidity */
  237. buf_len -= 2; /* subtract 2 characters so we have room for \n\0 */
  238. buf_end = buf+buf_len; /* point *after* the last char we can write to */
  239. n = log_prefix_(buf, buf_len, severity);
  240. end_of_prefix = buf+n;
  241. if (log_domains_are_logged) {
  242. char *cp = buf+n;
  243. if (cp == buf_end) goto format_msg_no_room_for_domains;
  244. *cp++ = '{';
  245. if (cp == buf_end) goto format_msg_no_room_for_domains;
  246. cp = domain_to_string(domain, cp, (buf+buf_len-cp));
  247. if (cp == buf_end) goto format_msg_no_room_for_domains;
  248. *cp++ = '}';
  249. if (cp == buf_end) goto format_msg_no_room_for_domains;
  250. *cp++ = ' ';
  251. if (cp == buf_end) goto format_msg_no_room_for_domains;
  252. end_of_prefix = cp;
  253. n = cp-buf;
  254. format_msg_no_room_for_domains:
  255. /* This will leave end_of_prefix and n unchanged, and thus cause
  256. * whatever log domain string we had written to be clobbered. */
  257. ;
  258. }
  259. if (funcname && should_log_function_name(domain, severity)) {
  260. r = tor_snprintf(buf+n, buf_len-n, "%s(): ", funcname);
  261. if (r<0)
  262. n = strlen(buf);
  263. else
  264. n += r;
  265. }
  266. if (domain == LD_BUG && buf_len-n > 6) {
  267. memcpy(buf+n, "Bug: ", 6);
  268. n += 5;
  269. }
  270. r = tor_vsnprintf(buf+n,buf_len-n,format,ap);
  271. if (r < 0) {
  272. /* The message was too long; overwrite the end of the buffer with
  273. * "[...truncated]" */
  274. if (buf_len >= TRUNCATED_STR_LEN) {
  275. size_t offset = buf_len-TRUNCATED_STR_LEN;
  276. /* We have an extra 2 characters after buf_len to hold the \n\0,
  277. * so it's safe to add 1 to the size here. */
  278. strlcpy(buf+offset, TRUNCATED_STR, buf_len-offset+1);
  279. }
  280. /* Set 'n' to the end of the buffer, where we'll be writing \n\0.
  281. * Since we already subtracted 2 from buf_len, this is safe.*/
  282. n = buf_len;
  283. } else {
  284. n += r;
  285. if (suffix) {
  286. size_t suffix_len = strlen(suffix);
  287. if (buf_len-n >= suffix_len) {
  288. memcpy(buf+n, suffix, suffix_len);
  289. n += suffix_len;
  290. }
  291. }
  292. }
  293. buf[n]='\n';
  294. buf[n+1]='\0';
  295. *msg_len_out = n+1;
  296. return end_of_prefix;
  297. }
  298. /** Helper: sends a message to the appropriate logfiles, at loglevel
  299. * <b>severity</b>. If provided, <b>funcname</b> is prepended to the
  300. * message. The actual message is derived as from tor_snprintf(format,ap).
  301. */
  302. static void
  303. logv(int severity, log_domain_mask_t domain, const char *funcname,
  304. const char *suffix, const char *format, va_list ap)
  305. {
  306. char buf[10024];
  307. size_t msg_len = 0;
  308. int formatted = 0;
  309. logfile_t *lf;
  310. char *end_of_prefix=NULL;
  311. int callbacks_deferred = 0;
  312. /* Call assert, not tor_assert, since tor_assert calls log on failure. */
  313. assert(format);
  314. /* check that severity is sane. Overrunning the masks array leads to
  315. * interesting and hard to diagnose effects */
  316. assert(severity >= LOG_ERR && severity <= LOG_DEBUG);
  317. LOCK_LOGS();
  318. if ((! (domain & LD_NOCB)) && smartlist_len(pending_cb_messages))
  319. flush_pending_log_callbacks();
  320. lf = logfiles;
  321. while (lf) {
  322. if (! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) {
  323. lf = lf->next;
  324. continue;
  325. }
  326. if (! (lf->fd >= 0 || lf->is_syslog || lf->callback)) {
  327. lf = lf->next;
  328. continue;
  329. }
  330. if (lf->seems_dead) {
  331. lf = lf->next;
  332. continue;
  333. }
  334. if (!formatted) {
  335. end_of_prefix =
  336. format_msg(buf, sizeof(buf), domain, severity, funcname, suffix,
  337. format, ap, &msg_len);
  338. formatted = 1;
  339. }
  340. if (lf->is_syslog) {
  341. #ifdef HAVE_SYSLOG_H
  342. char *m = end_of_prefix;
  343. #ifdef MAXLINE
  344. /* Some syslog implementations have limits on the length of what you can
  345. * pass them, and some very old ones do not detect overflow so well.
  346. * Regrettably, they call their maximum line length MAXLINE. */
  347. #if MAXLINE < 64
  348. #warn "MAXLINE is a very low number; it might not be from syslog.h after all"
  349. #endif
  350. if (msg_len >= MAXLINE)
  351. m = tor_strndup(end_of_prefix, MAXLINE-1);
  352. #endif
  353. syslog(severity, "%s", m);
  354. #ifdef MAXLINE
  355. if (m != end_of_prefix) {
  356. tor_free(m);
  357. }
  358. #endif
  359. #endif
  360. lf = lf->next;
  361. continue;
  362. } else if (lf->callback) {
  363. if (domain & LD_NOCB) {
  364. if (!callbacks_deferred && pending_cb_messages) {
  365. pending_cb_message_t *msg = tor_malloc(sizeof(pending_cb_message_t));
  366. msg->severity = severity;
  367. msg->domain = domain;
  368. msg->msg = tor_strdup(end_of_prefix);
  369. smartlist_add(pending_cb_messages, msg);
  370. callbacks_deferred = 1;
  371. }
  372. } else {
  373. lf->callback(severity, domain, end_of_prefix);
  374. }
  375. lf = lf->next;
  376. continue;
  377. }
  378. if (write_all(lf->fd, buf, msg_len, 0) < 0) { /* error */
  379. /* don't log the error! mark this log entry to be blown away, and
  380. * continue. */
  381. lf->seems_dead = 1;
  382. }
  383. lf = lf->next;
  384. }
  385. UNLOCK_LOGS();
  386. }
  387. /** Output a message to the log. It gets logged to all logfiles that
  388. * care about messages with <b>severity</b> in <b>domain</b>. The content
  389. * is formatted printf-style based on <b>format</b> and extra arguments.
  390. * */
  391. void
  392. tor_log(int severity, log_domain_mask_t domain, const char *format, ...)
  393. {
  394. va_list ap;
  395. if (severity > log_global_min_severity_)
  396. return;
  397. va_start(ap,format);
  398. logv(severity, domain, NULL, NULL, format, ap);
  399. va_end(ap);
  400. }
  401. /** Output a message to the log, prefixed with a function name <b>fn</b>. */
  402. #ifdef __GNUC__
  403. /** GCC-based implementation of the log_fn backend, used when we have
  404. * variadic macros. All arguments are as for log_fn, except for
  405. * <b>fn</b>, which is the name of the calling functions. */
  406. void
  407. log_fn_(int severity, log_domain_mask_t domain, const char *fn,
  408. const char *format, ...)
  409. {
  410. va_list ap;
  411. if (severity > log_global_min_severity_)
  412. return;
  413. va_start(ap,format);
  414. logv(severity, domain, fn, NULL, format, ap);
  415. va_end(ap);
  416. }
  417. void
  418. log_fn_ratelim_(ratelim_t *ratelim, int severity, log_domain_mask_t domain,
  419. const char *fn, const char *format, ...)
  420. {
  421. va_list ap;
  422. char *m;
  423. if (severity > log_global_min_severity_)
  424. return;
  425. m = rate_limit_log(ratelim, approx_time());
  426. if (m == NULL)
  427. return;
  428. va_start(ap, format);
  429. logv(severity, domain, fn, m, format, ap);
  430. va_end(ap);
  431. tor_free(m);
  432. }
  433. #else
  434. /** @{ */
  435. /** Variant implementation of log_fn, log_debug, log_info,... for C compilers
  436. * without variadic macros. In this case, the calling function sets
  437. * log_fn_function_name_ to the name of the function, then invokes the
  438. * appropriate log_fn_, log_debug_, etc. */
  439. const char *log_fn_function_name_=NULL;
  440. void
  441. log_fn_(int severity, log_domain_mask_t domain, const char *format, ...)
  442. {
  443. va_list ap;
  444. if (severity > log_global_min_severity_)
  445. return;
  446. va_start(ap,format);
  447. logv(severity, domain, log_fn_function_name_, NULL, format, ap);
  448. va_end(ap);
  449. log_fn_function_name_ = NULL;
  450. }
  451. void
  452. log_fn_ratelim_(ratelim_t *ratelim, int severity, log_domain_mask_t domain,
  453. const char *format, ...)
  454. {
  455. va_list ap;
  456. char *m;
  457. if (severity > log_global_min_severity_)
  458. return;
  459. m = rate_limit_log(ratelim, approx_time());
  460. if (m == NULL)
  461. return;
  462. va_start(ap, format);
  463. logv(severity, domain, log_fn_function_name_, m, format, ap);
  464. va_end(ap);
  465. tor_free(m);
  466. }
  467. void
  468. log_debug_(log_domain_mask_t domain, const char *format, ...)
  469. {
  470. va_list ap;
  471. /* For GCC we do this check in the macro. */
  472. if (PREDICT_LIKELY(LOG_DEBUG > log_global_min_severity_))
  473. return;
  474. va_start(ap,format);
  475. logv(LOG_DEBUG, domain, log_fn_function_name_, NULL, format, ap);
  476. va_end(ap);
  477. log_fn_function_name_ = NULL;
  478. }
  479. void
  480. log_info_(log_domain_mask_t domain, const char *format, ...)
  481. {
  482. va_list ap;
  483. if (LOG_INFO > log_global_min_severity_)
  484. return;
  485. va_start(ap,format);
  486. logv(LOG_INFO, domain, log_fn_function_name_, NULL, format, ap);
  487. va_end(ap);
  488. log_fn_function_name_ = NULL;
  489. }
  490. void
  491. log_notice_(log_domain_mask_t domain, const char *format, ...)
  492. {
  493. va_list ap;
  494. if (LOG_NOTICE > log_global_min_severity_)
  495. return;
  496. va_start(ap,format);
  497. logv(LOG_NOTICE, domain, log_fn_function_name_, NULL, format, ap);
  498. va_end(ap);
  499. log_fn_function_name_ = NULL;
  500. }
  501. void
  502. log_warn_(log_domain_mask_t domain, const char *format, ...)
  503. {
  504. va_list ap;
  505. if (LOG_WARN > log_global_min_severity_)
  506. return;
  507. va_start(ap,format);
  508. logv(LOG_WARN, domain, log_fn_function_name_, NULL, format, ap);
  509. va_end(ap);
  510. log_fn_function_name_ = NULL;
  511. }
  512. void
  513. log_err_(log_domain_mask_t domain, const char *format, ...)
  514. {
  515. va_list ap;
  516. if (LOG_ERR > log_global_min_severity_)
  517. return;
  518. va_start(ap,format);
  519. logv(LOG_ERR, domain, log_fn_function_name_, NULL, format, ap);
  520. va_end(ap);
  521. log_fn_function_name_ = NULL;
  522. }
  523. /** @} */
  524. #endif
  525. /** Free all storage held by <b>victim</b>. */
  526. static void
  527. log_free(logfile_t *victim)
  528. {
  529. if (!victim)
  530. return;
  531. tor_free(victim->severities);
  532. tor_free(victim->filename);
  533. tor_free(victim);
  534. }
  535. /** Close all open log files, and free other static memory. */
  536. void
  537. logs_free_all(void)
  538. {
  539. logfile_t *victim, *next;
  540. smartlist_t *messages;
  541. LOCK_LOGS();
  542. next = logfiles;
  543. logfiles = NULL;
  544. messages = pending_cb_messages;
  545. pending_cb_messages = NULL;
  546. UNLOCK_LOGS();
  547. while (next) {
  548. victim = next;
  549. next = next->next;
  550. close_log(victim);
  551. log_free(victim);
  552. }
  553. tor_free(appname);
  554. SMARTLIST_FOREACH(messages, pending_cb_message_t *, msg, {
  555. tor_free(msg->msg);
  556. tor_free(msg);
  557. });
  558. smartlist_free(messages);
  559. /* We _could_ destroy the log mutex here, but that would screw up any logs
  560. * that happened between here and the end of execution. */
  561. }
  562. /** Remove and free the log entry <b>victim</b> from the linked-list
  563. * logfiles (it is probably present, but it might not be due to thread
  564. * racing issues). After this function is called, the caller shouldn't
  565. * refer to <b>victim</b> anymore.
  566. *
  567. * Long-term, we need to do something about races in the log subsystem
  568. * in general. See bug 222 for more details.
  569. */
  570. static void
  571. delete_log(logfile_t *victim)
  572. {
  573. logfile_t *tmpl;
  574. if (victim == logfiles)
  575. logfiles = victim->next;
  576. else {
  577. for (tmpl = logfiles; tmpl && tmpl->next != victim; tmpl=tmpl->next) ;
  578. // tor_assert(tmpl);
  579. // tor_assert(tmpl->next == victim);
  580. if (!tmpl)
  581. return;
  582. tmpl->next = victim->next;
  583. }
  584. log_free(victim);
  585. }
  586. /** Helper: release system resources (but not memory) held by a single
  587. * logfile_t. */
  588. static void
  589. close_log(logfile_t *victim)
  590. {
  591. if (victim->needs_close && victim->fd >= 0) {
  592. close(victim->fd);
  593. victim->fd = -1;
  594. } else if (victim->is_syslog) {
  595. #ifdef HAVE_SYSLOG_H
  596. if (--syslog_count == 0) {
  597. /* There are no other syslogs; close the logging facility. */
  598. closelog();
  599. }
  600. #endif
  601. }
  602. }
  603. /** Adjust a log severity configuration in <b>severity_out</b> to contain
  604. * every domain between <b>loglevelMin</b> and <b>loglevelMax</b>, inclusive.
  605. */
  606. void
  607. set_log_severity_config(int loglevelMin, int loglevelMax,
  608. log_severity_list_t *severity_out)
  609. {
  610. int i;
  611. tor_assert(loglevelMin >= loglevelMax);
  612. tor_assert(loglevelMin >= LOG_ERR && loglevelMin <= LOG_DEBUG);
  613. tor_assert(loglevelMax >= LOG_ERR && loglevelMax <= LOG_DEBUG);
  614. memset(severity_out, 0, sizeof(log_severity_list_t));
  615. for (i = loglevelMin; i >= loglevelMax; --i) {
  616. severity_out->masks[SEVERITY_MASK_IDX(i)] = ~0u;
  617. }
  618. }
  619. /** Add a log handler named <b>name</b> to send all messages in <b>severity</b>
  620. * to <b>fd</b>. Copies <b>severity</b>. Helper: does no locking. */
  621. static void
  622. add_stream_log_impl(const log_severity_list_t *severity,
  623. const char *name, int fd)
  624. {
  625. logfile_t *lf;
  626. lf = tor_malloc_zero(sizeof(logfile_t));
  627. lf->fd = fd;
  628. lf->filename = tor_strdup(name);
  629. lf->severities = tor_memdup(severity, sizeof(log_severity_list_t));
  630. lf->next = logfiles;
  631. logfiles = lf;
  632. log_global_min_severity_ = get_min_log_level();
  633. }
  634. /** Add a log handler named <b>name</b> to send all messages in <b>severity</b>
  635. * to <b>fd</b>. Steals a reference to <b>severity</b>; the caller must
  636. * not use it after calling this function. */
  637. void
  638. add_stream_log(const log_severity_list_t *severity, const char *name, int fd)
  639. {
  640. LOCK_LOGS();
  641. add_stream_log_impl(severity, name, fd);
  642. UNLOCK_LOGS();
  643. }
  644. /** Initialize the global logging facility */
  645. void
  646. init_logging(void)
  647. {
  648. if (!log_mutex_initialized) {
  649. tor_mutex_init(&log_mutex);
  650. log_mutex_initialized = 1;
  651. }
  652. if (pending_cb_messages == NULL)
  653. pending_cb_messages = smartlist_new();
  654. }
  655. /** Set whether we report logging domains as a part of our log messages.
  656. */
  657. void
  658. logs_set_domain_logging(int enabled)
  659. {
  660. LOCK_LOGS();
  661. log_domains_are_logged = enabled;
  662. UNLOCK_LOGS();
  663. }
  664. /** Add a log handler to receive messages during startup (before the real
  665. * logs are initialized).
  666. */
  667. void
  668. add_temp_log(int min_severity)
  669. {
  670. log_severity_list_t *s = tor_malloc_zero(sizeof(log_severity_list_t));
  671. set_log_severity_config(min_severity, LOG_ERR, s);
  672. LOCK_LOGS();
  673. add_stream_log_impl(s, "<temp>", fileno(stdout));
  674. tor_free(s);
  675. logfiles->is_temporary = 1;
  676. UNLOCK_LOGS();
  677. }
  678. /**
  679. * Add a log handler to send messages in <b>severity</b>
  680. * to the function <b>cb</b>.
  681. */
  682. int
  683. add_callback_log(const log_severity_list_t *severity, log_callback cb)
  684. {
  685. logfile_t *lf;
  686. lf = tor_malloc_zero(sizeof(logfile_t));
  687. lf->fd = -1;
  688. lf->severities = tor_memdup(severity, sizeof(log_severity_list_t));
  689. lf->filename = tor_strdup("<callback>");
  690. lf->callback = cb;
  691. lf->next = logfiles;
  692. LOCK_LOGS();
  693. logfiles = lf;
  694. log_global_min_severity_ = get_min_log_level();
  695. UNLOCK_LOGS();
  696. return 0;
  697. }
  698. /** Adjust the configured severity of any logs whose callback function is
  699. * <b>cb</b>. */
  700. void
  701. change_callback_log_severity(int loglevelMin, int loglevelMax,
  702. log_callback cb)
  703. {
  704. logfile_t *lf;
  705. log_severity_list_t severities;
  706. set_log_severity_config(loglevelMin, loglevelMax, &severities);
  707. LOCK_LOGS();
  708. for (lf = logfiles; lf; lf = lf->next) {
  709. if (lf->callback == cb) {
  710. memcpy(lf->severities, &severities, sizeof(severities));
  711. }
  712. }
  713. log_global_min_severity_ = get_min_log_level();
  714. UNLOCK_LOGS();
  715. }
  716. /** If there are any log messages that were generated with LD_NOCB waiting to
  717. * be sent to callback-based loggers, send them now. */
  718. void
  719. flush_pending_log_callbacks(void)
  720. {
  721. logfile_t *lf;
  722. smartlist_t *messages, *messages_tmp;
  723. LOCK_LOGS();
  724. if (0 == smartlist_len(pending_cb_messages)) {
  725. UNLOCK_LOGS();
  726. return;
  727. }
  728. messages = pending_cb_messages;
  729. pending_cb_messages = smartlist_new();
  730. do {
  731. SMARTLIST_FOREACH_BEGIN(messages, pending_cb_message_t *, msg) {
  732. const int severity = msg->severity;
  733. const int domain = msg->domain;
  734. for (lf = logfiles; lf; lf = lf->next) {
  735. if (! lf->callback || lf->seems_dead ||
  736. ! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) {
  737. continue;
  738. }
  739. lf->callback(severity, domain, msg->msg);
  740. }
  741. tor_free(msg->msg);
  742. tor_free(msg);
  743. } SMARTLIST_FOREACH_END(msg);
  744. smartlist_clear(messages);
  745. messages_tmp = pending_cb_messages;
  746. pending_cb_messages = messages;
  747. messages = messages_tmp;
  748. } while (smartlist_len(messages));
  749. smartlist_free(messages);
  750. UNLOCK_LOGS();
  751. }
  752. /** Close any log handlers added by add_temp_log() or marked by
  753. * mark_logs_temp(). */
  754. void
  755. close_temp_logs(void)
  756. {
  757. logfile_t *lf, **p;
  758. LOCK_LOGS();
  759. for (p = &logfiles; *p; ) {
  760. if ((*p)->is_temporary) {
  761. lf = *p;
  762. /* we use *p here to handle the edge case of the head of the list */
  763. *p = (*p)->next;
  764. close_log(lf);
  765. log_free(lf);
  766. } else {
  767. p = &((*p)->next);
  768. }
  769. }
  770. log_global_min_severity_ = get_min_log_level();
  771. UNLOCK_LOGS();
  772. }
  773. /** Make all currently temporary logs (set to be closed by close_temp_logs)
  774. * live again, and close all non-temporary logs. */
  775. void
  776. rollback_log_changes(void)
  777. {
  778. logfile_t *lf;
  779. LOCK_LOGS();
  780. for (lf = logfiles; lf; lf = lf->next)
  781. lf->is_temporary = ! lf->is_temporary;
  782. UNLOCK_LOGS();
  783. close_temp_logs();
  784. }
  785. /** Configure all log handles to be closed by close_temp_logs(). */
  786. void
  787. mark_logs_temp(void)
  788. {
  789. logfile_t *lf;
  790. LOCK_LOGS();
  791. for (lf = logfiles; lf; lf = lf->next)
  792. lf->is_temporary = 1;
  793. UNLOCK_LOGS();
  794. }
  795. /**
  796. * Add a log handler to send messages to <b>filename</b>. If opening the
  797. * logfile fails, -1 is returned and errno is set appropriately (by open(2)).
  798. */
  799. int
  800. add_file_log(const log_severity_list_t *severity, const char *filename)
  801. {
  802. int fd;
  803. logfile_t *lf;
  804. fd = tor_open_cloexec(filename, O_WRONLY|O_CREAT|O_APPEND, 0644);
  805. if (fd<0)
  806. return -1;
  807. if (tor_fd_seekend(fd)<0) {
  808. close(fd);
  809. return -1;
  810. }
  811. LOCK_LOGS();
  812. add_stream_log_impl(severity, filename, fd);
  813. logfiles->needs_close = 1;
  814. lf = logfiles;
  815. log_global_min_severity_ = get_min_log_level();
  816. if (log_tor_version(lf, 0) < 0) {
  817. delete_log(lf);
  818. }
  819. UNLOCK_LOGS();
  820. return 0;
  821. }
  822. #ifdef HAVE_SYSLOG_H
  823. /**
  824. * Add a log handler to send messages to they system log facility.
  825. */
  826. int
  827. add_syslog_log(const log_severity_list_t *severity)
  828. {
  829. logfile_t *lf;
  830. if (syslog_count++ == 0)
  831. /* This is the first syslog. */
  832. openlog("Tor", LOG_PID | LOG_NDELAY, LOGFACILITY);
  833. lf = tor_malloc_zero(sizeof(logfile_t));
  834. lf->fd = -1;
  835. lf->severities = tor_memdup(severity, sizeof(log_severity_list_t));
  836. lf->filename = tor_strdup("<syslog>");
  837. lf->is_syslog = 1;
  838. LOCK_LOGS();
  839. lf->next = logfiles;
  840. logfiles = lf;
  841. log_global_min_severity_ = get_min_log_level();
  842. UNLOCK_LOGS();
  843. return 0;
  844. }
  845. #endif
  846. /** If <b>level</b> is a valid log severity, return the corresponding
  847. * numeric value. Otherwise, return -1. */
  848. int
  849. parse_log_level(const char *level)
  850. {
  851. if (!strcasecmp(level, "err"))
  852. return LOG_ERR;
  853. if (!strcasecmp(level, "warn"))
  854. return LOG_WARN;
  855. if (!strcasecmp(level, "notice"))
  856. return LOG_NOTICE;
  857. if (!strcasecmp(level, "info"))
  858. return LOG_INFO;
  859. if (!strcasecmp(level, "debug"))
  860. return LOG_DEBUG;
  861. return -1;
  862. }
  863. /** Return the string equivalent of a given log level. */
  864. const char *
  865. log_level_to_string(int level)
  866. {
  867. return sev_to_string(level);
  868. }
  869. /** NULL-terminated array of names for log domains such that domain_list[dom]
  870. * is a description of <b>dom</b>. */
  871. static const char *domain_list[] = {
  872. "GENERAL", "CRYPTO", "NET", "CONFIG", "FS", "PROTOCOL", "MM",
  873. "HTTP", "APP", "CONTROL", "CIRC", "REND", "BUG", "DIR", "DIRSERV",
  874. "OR", "EDGE", "ACCT", "HIST", "HANDSHAKE", "HEARTBEAT", "CHANNEL", NULL
  875. };
  876. /** Return a bitmask for the log domain for which <b>domain</b> is the name,
  877. * or 0 if there is no such name. */
  878. static log_domain_mask_t
  879. parse_log_domain(const char *domain)
  880. {
  881. int i;
  882. for (i=0; domain_list[i]; ++i) {
  883. if (!strcasecmp(domain, domain_list[i]))
  884. return (1u<<i);
  885. }
  886. return 0;
  887. }
  888. /** Translate a bitmask of log domains to a string. */
  889. static char *
  890. domain_to_string(log_domain_mask_t domain, char *buf, size_t buflen)
  891. {
  892. char *cp = buf;
  893. char *eos = buf+buflen;
  894. buf[0] = '\0';
  895. if (! domain)
  896. return buf;
  897. while (1) {
  898. const char *d;
  899. int bit = tor_log2(domain);
  900. size_t n;
  901. if (bit >= N_LOGGING_DOMAINS) {
  902. tor_snprintf(buf, buflen, "<BUG:Unknown domain %lx>", (long)domain);
  903. return buf+strlen(buf);
  904. }
  905. d = domain_list[bit];
  906. n = strlcpy(cp, d, eos-cp);
  907. if (n >= buflen) {
  908. tor_snprintf(buf, buflen, "<BUG:Truncating domain %lx>", (long)domain);
  909. return buf+strlen(buf);
  910. }
  911. cp += n;
  912. domain &= ~(1<<bit);
  913. if (domain == 0 || (eos-cp) < 2)
  914. return cp;
  915. memcpy(cp, ",", 2); /*Nul-terminated ,"*/
  916. cp++;
  917. }
  918. }
  919. /** Parse a log severity pattern in *<b>cfg_ptr</b>. Advance cfg_ptr after
  920. * the end of the severityPattern. Set the value of <b>severity_out</b> to
  921. * the parsed pattern. Return 0 on success, -1 on failure.
  922. *
  923. * The syntax for a SeverityPattern is:
  924. * <pre>
  925. * SeverityPattern = *(DomainSeverity SP)* DomainSeverity
  926. * DomainSeverity = (DomainList SP)? SeverityRange
  927. * SeverityRange = MinSeverity ("-" MaxSeverity )?
  928. * DomainList = "[" (SP? DomainSpec SP? ",") SP? DomainSpec "]"
  929. * DomainSpec = "*" | Domain | "~" Domain
  930. * </pre>
  931. * A missing MaxSeverity defaults to ERR. Severities and domains are
  932. * case-insensitive. "~" indicates negation for a domain; negation happens
  933. * last inside a DomainList. Only one SeverityRange without a DomainList is
  934. * allowed per line.
  935. */
  936. int
  937. parse_log_severity_config(const char **cfg_ptr,
  938. log_severity_list_t *severity_out)
  939. {
  940. const char *cfg = *cfg_ptr;
  941. int got_anything = 0;
  942. int got_an_unqualified_range = 0;
  943. memset(severity_out, 0, sizeof(*severity_out));
  944. cfg = eat_whitespace(cfg);
  945. while (*cfg) {
  946. const char *dash, *space;
  947. char *sev_lo, *sev_hi;
  948. int low, high, i;
  949. log_domain_mask_t domains = ~0u;
  950. if (*cfg == '[') {
  951. int err = 0;
  952. char *domains_str;
  953. smartlist_t *domains_list;
  954. log_domain_mask_t neg_domains = 0;
  955. const char *closebracket = strchr(cfg, ']');
  956. if (!closebracket)
  957. return -1;
  958. domains = 0;
  959. domains_str = tor_strndup(cfg+1, closebracket-cfg-1);
  960. domains_list = smartlist_new();
  961. smartlist_split_string(domains_list, domains_str, ",", SPLIT_SKIP_SPACE,
  962. -1);
  963. tor_free(domains_str);
  964. SMARTLIST_FOREACH_BEGIN(domains_list, const char *, domain) {
  965. if (!strcmp(domain, "*")) {
  966. domains = ~0u;
  967. } else {
  968. int d;
  969. int negate=0;
  970. if (*domain == '~') {
  971. negate = 1;
  972. ++domain;
  973. }
  974. d = parse_log_domain(domain);
  975. if (!d) {
  976. log_warn(LD_CONFIG, "No such logging domain as %s", domain);
  977. err = 1;
  978. } else {
  979. if (negate)
  980. neg_domains |= d;
  981. else
  982. domains |= d;
  983. }
  984. }
  985. } SMARTLIST_FOREACH_END(domain);
  986. SMARTLIST_FOREACH(domains_list, char *, d, tor_free(d));
  987. smartlist_free(domains_list);
  988. if (err)
  989. return -1;
  990. if (domains == 0 && neg_domains)
  991. domains = ~neg_domains;
  992. else
  993. domains &= ~neg_domains;
  994. cfg = eat_whitespace(closebracket+1);
  995. } else {
  996. ++got_an_unqualified_range;
  997. }
  998. if (!strcasecmpstart(cfg, "file") ||
  999. !strcasecmpstart(cfg, "stderr") ||
  1000. !strcasecmpstart(cfg, "stdout") ||
  1001. !strcasecmpstart(cfg, "syslog")) {
  1002. goto done;
  1003. }
  1004. if (got_an_unqualified_range > 1)
  1005. return -1;
  1006. space = strchr(cfg, ' ');
  1007. dash = strchr(cfg, '-');
  1008. if (!space)
  1009. space = strchr(cfg, '\0');
  1010. if (dash && dash < space) {
  1011. sev_lo = tor_strndup(cfg, dash-cfg);
  1012. sev_hi = tor_strndup(dash+1, space-(dash+1));
  1013. } else {
  1014. sev_lo = tor_strndup(cfg, space-cfg);
  1015. sev_hi = tor_strdup("ERR");
  1016. }
  1017. low = parse_log_level(sev_lo);
  1018. high = parse_log_level(sev_hi);
  1019. tor_free(sev_lo);
  1020. tor_free(sev_hi);
  1021. if (low == -1)
  1022. return -1;
  1023. if (high == -1)
  1024. return -1;
  1025. got_anything = 1;
  1026. for (i=low; i >= high; --i)
  1027. severity_out->masks[SEVERITY_MASK_IDX(i)] |= domains;
  1028. cfg = eat_whitespace(space);
  1029. }
  1030. done:
  1031. *cfg_ptr = cfg;
  1032. return got_anything ? 0 : -1;
  1033. }
  1034. /** Return the least severe log level that any current log is interested in. */
  1035. int
  1036. get_min_log_level(void)
  1037. {
  1038. logfile_t *lf;
  1039. int i;
  1040. int min = LOG_ERR;
  1041. for (lf = logfiles; lf; lf = lf->next) {
  1042. for (i = LOG_DEBUG; i > min; --i)
  1043. if (lf->severities->masks[SEVERITY_MASK_IDX(i)])
  1044. min = i;
  1045. }
  1046. return min;
  1047. }
  1048. /** Switch all logs to output at most verbose level. */
  1049. void
  1050. switch_logs_debug(void)
  1051. {
  1052. logfile_t *lf;
  1053. int i;
  1054. LOCK_LOGS();
  1055. for (lf = logfiles; lf; lf=lf->next) {
  1056. for (i = LOG_DEBUG; i >= LOG_ERR; --i)
  1057. lf->severities->masks[SEVERITY_MASK_IDX(i)] = ~0u;
  1058. }
  1059. log_global_min_severity_ = get_min_log_level();
  1060. UNLOCK_LOGS();
  1061. }
  1062. #if 0
  1063. static void
  1064. dump_log_info(logfile_t *lf)
  1065. {
  1066. const char *tp;
  1067. if (lf->filename) {
  1068. printf("=== log into \"%s\" (%s-%s) (%stemporary)\n", lf->filename,
  1069. sev_to_string(lf->min_loglevel),
  1070. sev_to_string(lf->max_loglevel),
  1071. lf->is_temporary?"":"not ");
  1072. } else if (lf->is_syslog) {
  1073. printf("=== syslog (%s-%s) (%stemporary)\n",
  1074. sev_to_string(lf->min_loglevel),
  1075. sev_to_string(lf->max_loglevel),
  1076. lf->is_temporary?"":"not ");
  1077. } else {
  1078. printf("=== log (%s-%s) (%stemporary)\n",
  1079. sev_to_string(lf->min_loglevel),
  1080. sev_to_string(lf->max_loglevel),
  1081. lf->is_temporary?"":"not ");
  1082. }
  1083. }
  1084. void
  1085. describe_logs(void)
  1086. {
  1087. logfile_t *lf;
  1088. printf("==== BEGIN LOGS ====\n");
  1089. for (lf = logfiles; lf; lf = lf->next)
  1090. dump_log_info(lf);
  1091. printf("==== END LOGS ====\n");
  1092. }
  1093. #endif