PageRenderTime 39ms CodeModel.GetById 22ms RepoModel.GetById 0ms app.codeStats 0ms

/lib/modsecurity-apache_2.6.1/mlogc/mlogc.c

http://vulture.googlecode.com/
C | 2306 lines | 1670 code | 347 blank | 289 comment | 341 complexity | b33f83eee008110c94c57af1a57cd690 MD5 | raw file
Possible License(s): Apache-2.0

Large files files are truncated, but you can click here to view the full file

  1. /*
  2. * ModSecurity for Apache 2.x, http://www.modsecurity.org/
  3. * Copyright (c) 2004-2011 Trustwave Holdings, Inc. (http://www.trustwave.com/)
  4. *
  5. * You may not use this file except in compliance with
  6. * the License.  You may obtain a copy of the License at
  7. *
  8. *     http://www.apache.org/licenses/LICENSE-2.0
  9. *
  10. * If any of the files related to licensing are missing or if you have any
  11. * other questions related to licensing please contact Trustwave Holdings, Inc.
  12. * directly using the email address security@modsecurity.org.
  13. */
  14. #include <apr.h>
  15. #include <apr_errno.h>
  16. #include <apr_general.h>
  17. #include <apr_file_io.h>
  18. #include <apr_file_info.h>
  19. #include <apr_hash.h>
  20. #include <apr_lib.h>
  21. #include <apr_strings.h>
  22. #include <apr_signal.h>
  23. #include <apr_thread_proc.h>
  24. #include <apr_global_mutex.h>
  25. #include <apr_getopt.h>
  26. #include <apr_version.h>
  27. #if APR_HAVE_UNISTD_H
  28. #include <unistd.h> /* for getpid() */
  29. #endif
  30. #include <pcre.h>
  31. #include <curl/curl.h>
  32. #include <fcntl.h>
  33. #include <sys/stat.h>
  34. #include <sys/types.h>
  35. #include "msc_release.h"
  36. static void logc_shutdown(int rc);
  37. static void create_new_worker(int lock);
  38. static void error_log(int level, void *thread,
  39. const char *text, ...) PRINTF_ATTRIBUTE(3,4);
  40. /* -- Constants -- */
  41. /* Error log levels. */
  42. #define LOG_ERROR 1
  43. #define LOG_WARNING 2
  44. #define LOG_NOTICE 3
  45. #define LOG_DEBUG 4
  46. #define LOG_DEBUG2 5
  47. /* The management thread will wake up every five seconds. */
  48. #define MANAGER_SLEEP 5000000
  49. #define MANAGER_SUBSLEEP 10000
  50. /* Hack to allow multiple mlogc with single delete */
  51. #define KEEP_ENTRIES_REMOVE_HACK 2600
  52. #define KEEP_ENTRIES_REMOVE_TIME 0l
  53. #ifdef TEST_HACK
  54. #define TEST_WITH_RAND_SLEEP(n) \
  55. do { \
  56. int sec = rand()/(RAND_MAX/n); \
  57. error_log(LOG_DEBUG2, NULL, "TEST_HACK: Sleeping for %ds", sec); \
  58. apr_sleep(apr_time_from_sec(sec)); \
  59. } while(0)
  60. #else
  61. #define TEST_WITH_RAND_SLEEP(n)
  62. #endif
  63. #define CAPTUREVECTORSIZE 60
  64. #define PIPE_BUF_SIZE 65536
  65. #define MEMALLOC_ERROR_MSG "Memory allocation failed!"
  66. #define VERSION MODSEC_VERSION
  67. #define CMDLINE_OPTS "fvh"
  68. #define TXIN 0
  69. #define TXOUT 1
  70. #define STATUSBUF_SIZE 256
  71. #define ISHEXCHAR(X) ( ((X >= '0')&&(X <= '9')) \
  72. || ((X >= 'a')&&(X <= 'f')) \
  73. || ((X >= 'A')&&(X <= 'F')) )
  74. /* -- Regex Patterns -- */
  75. /**
  76. * This regular expression is used to parse the entire
  77. * log line we receive from Apache. The REQUEST_LINE is
  78. * treated as a single parameter to allow for invalid
  79. * requests.
  80. */
  81. static const char logline_pattern[] =
  82. "^(\\S+)"
  83. "\\ (\\S+)\\ (\\S+)\\ (\\S+)"
  84. "\\ \\[([^:]+):(\\d+:\\d+:\\d+)\\ ([^\\]]+)\\]"
  85. "\\ \"(.*)\""
  86. "\\ (\\d+)\\ (\\S+)"
  87. "\\ \"(.*)\"\\ \"(.*)\""
  88. "\\ (\\S+)\\ \"(.*)\""
  89. "\\ /?(\\S+)\\ (\\d+)\\ (\\d+)"
  90. "\\ (\\S+)"
  91. "(.*)$";
  92. /**
  93. * This regular expression can be used to parse
  94. * a REQUEST_LINE field into method, URI, and
  95. * protocol.
  96. */
  97. static const char requestline_pattern[] =
  98. "(\\S+)\\ (.*?)\\ (\\S+)";
  99. /* -- Structures -- */
  100. typedef struct {
  101. unsigned long int id;
  102. const char *line;
  103. apr_size_t line_size;
  104. } entry_t;
  105. /* -- Global variables -- */
  106. static pid_t logc_pid = 0;
  107. static const char *conffile = NULL;
  108. static const char *lockfile = NULL;
  109. static int have_read_data = 0;
  110. static int checkpoint_interval = 60;
  111. static apr_time_t checkpoint_time_last = 0;
  112. static const char *collector_root = NULL;
  113. static apr_table_t *conf = NULL;
  114. static const char *console_uri = NULL;
  115. static apr_array_header_t *curl_handles = NULL;
  116. static int current_workers = 0;
  117. static int management_thread_active = 0;
  118. static unsigned long int entry_counter = 1;
  119. static const char *error_log_path = NULL;
  120. static apr_file_t *error_log_fd = NULL;
  121. static int error_log_level = 2;
  122. static apr_hash_t *in_progress = NULL;
  123. static int keep_alive = 150; /* Not used yet. */
  124. static int keep_alive_timeout = 300; /* Not used yet. */
  125. static int keep_entries = 0;
  126. static const char *log_repository = NULL;
  127. static void *logline_regex = NULL;
  128. static int max_connections = 10;
  129. static int max_worker_requests = 1000;
  130. static apr_global_mutex_t *gmutex = NULL;
  131. static apr_thread_mutex_t *mutex = NULL;
  132. static apr_pool_t *pool = NULL;
  133. static apr_pool_t *thread_pool = NULL;
  134. static apr_pool_t *recv_pool = NULL;
  135. static apr_array_header_t *queue = NULL;
  136. static const char *queue_path = NULL;
  137. /* static apr_time_t queue_time = 0; */
  138. static void *requestline_regex = NULL;
  139. static int running = 0;
  140. static const char *sensor_password = NULL;
  141. static const char *sensor_username = NULL;
  142. static int server_error = 0;
  143. static apr_time_t server_error_last_check_time = 0;
  144. static int server_error_timeout = 60;
  145. static int startup_delay = 100;
  146. static int transaction_delay = 100;
  147. static const char *transaction_log_path = NULL;
  148. static apr_file_t *transaction_log_fd = NULL;
  149. /* -- Commandline opts -- */
  150. static int opt_force = 0;
  151. /* -- Code -- */
  152. static char *_log_escape(apr_pool_t *mp, const char *input,
  153. apr_size_t input_len)
  154. {
  155. static const char c2x_table[] = "0123456789abcdef";
  156. unsigned char *d = NULL;
  157. char *ret = NULL;
  158. unsigned long int i;
  159. if (input == NULL) return NULL;
  160. ret = apr_palloc(mp, input_len * 4 + 1);
  161. if (ret == NULL) return NULL;
  162. d = (unsigned char *)ret;
  163. i = 0;
  164. while(i < input_len) {
  165. switch(input[i]) {
  166. case '"' :
  167. *d++ = '\\';
  168. *d++ = '"';
  169. break;
  170. case '\b' :
  171. *d++ = '\\';
  172. *d++ = 'b';
  173. break;
  174. case '\n' :
  175. *d++ = '\\';
  176. *d++ = 'n';
  177. break;
  178. case '\r' :
  179. *d++ = '\\';
  180. *d++ = 'r';
  181. break;
  182. case '\t' :
  183. *d++ = '\\';
  184. *d++ = 't';
  185. break;
  186. case '\v' :
  187. *d++ = '\\';
  188. *d++ = 'v';
  189. break;
  190. case '\\' :
  191. *d++ = '\\';
  192. *d++ = '\\';
  193. break;
  194. default :
  195. if ((input[i] <= 0x1f)||(input[i] >= 0x7f)) {
  196. *d++ = '\\';
  197. *d++ = 'x';
  198. *d++ = c2x_table[input[i] >> 4];
  199. *d++ = c2x_table[input[i] & 0x0f];
  200. } else {
  201. *d++ = input[i];
  202. }
  203. break;
  204. }
  205. i++;
  206. }
  207. *d = 0;
  208. return ret;
  209. }
  210. /**
  211. * Converts a byte given as its hexadecimal representation
  212. * into a proper byte. Handles uppercase and lowercase letters
  213. * but does not check for overflows.
  214. */
  215. static unsigned char x2c(unsigned char *what) {
  216. register unsigned char digit;
  217. digit = (what[0] >= 'A' ? ((what[0] & 0xdf) - 'A') + 10 : (what[0] - '0'));
  218. digit *= 16;
  219. digit += (what[1] >= 'A' ? ((what[1] & 0xdf) - 'A') + 10 : (what[1] - '0'));
  220. return digit;
  221. }
  222. /**
  223. * URL Decodes a string in-place
  224. */
  225. static int urldecode_inplace(unsigned char *input, apr_size_t input_len) {
  226. unsigned char *d = (unsigned char *)input;
  227. apr_size_t i;
  228. if (input == NULL) return 0;
  229. i = 0;
  230. while (i < input_len) {
  231. if (input[i] == '%') {
  232. /* Character is a percent sign. */
  233. /* Are there enough bytes available? */
  234. if (i + 2 < input_len) {
  235. char c1 = input[i + 1];
  236. char c2 = input[i + 2];
  237. if (ISHEXCHAR(c1) && ISHEXCHAR(c2)) {
  238. /* Valid encoding - decode it. */
  239. *d++ = x2c(&input[i + 1]);
  240. i += 3;
  241. } else {
  242. /* Not a valid encoding, skip this % */
  243. *d++ = input[i++];
  244. }
  245. } else {
  246. /* Not enough bytes available, copy the raw bytes. */
  247. *d++ = input[i++];
  248. }
  249. } else {
  250. /* Character is not a percent sign. */
  251. if (input[i] == '+') {
  252. *d++ = ' ';
  253. } else {
  254. *d++ = input[i];
  255. }
  256. i++;
  257. }
  258. }
  259. *d = '\0';
  260. return 1;
  261. }
  262. /**
  263. * Detect a relative path and merge it with the collector root
  264. * path. Leave absolute paths as they are.
  265. */
  266. static const char *file_path(const char *path)
  267. {
  268. char *newpath = NULL;
  269. apr_status_t rc;
  270. if (path == NULL) return NULL;
  271. rc = apr_filepath_merge(&newpath, collector_root,
  272. path, APR_FILEPATH_TRUENAME, pool);
  273. if ((newpath != NULL) && (rc == APR_SUCCESS || APR_STATUS_IS_EPATHWILD(rc)
  274. || APR_STATUS_IS_ENOENT(rc) || APR_STATUS_IS_ENOTDIR(rc)))
  275. {
  276. return newpath;
  277. }
  278. else {
  279. return NULL;
  280. }
  281. }
  282. /**
  283. * Returns the current datetime as a string.
  284. */
  285. static char *current_logtime(char *dest, int dlen)
  286. {
  287. apr_time_exp_t t;
  288. apr_size_t len;
  289. apr_time_exp_lt(&t, apr_time_now());
  290. apr_strftime(dest, &len, dlen, "%a %b %d %H:%M:%S %Y", &t);
  291. return dest;
  292. }
  293. /**
  294. * Logs error to the error log (if available) or
  295. * to the stderr.
  296. */
  297. static void error_log(int level, void *thread, const char *text, ...)
  298. {
  299. char msg1[4096] = "";
  300. char msg2[4096] = "";
  301. char datetime[100];
  302. va_list ap;
  303. if (level > error_log_level) return;
  304. va_start(ap, text);
  305. apr_vsnprintf(msg1, sizeof(msg1), text, ap);
  306. apr_snprintf(msg2, sizeof(msg2), "[%s] [%d] [%" APR_PID_T_FMT "/%pp] %s\n",
  307. current_logtime(datetime, sizeof(datetime)),
  308. level, logc_pid, (thread ? thread : 0), msg1);
  309. if (error_log_fd != NULL) {
  310. apr_size_t nbytes_written;
  311. apr_size_t nbytes = strlen(msg2);
  312. apr_file_write_full(error_log_fd, msg2, nbytes, &nbytes_written);
  313. }
  314. else {
  315. fprintf(stderr, "%s", msg2);
  316. }
  317. va_end(ap);
  318. }
  319. /**
  320. * Adds one entry to the internal queue. It will (optionally) start
  321. * a new thread to handle it.
  322. */
  323. static void add_entry(const char *data, int start_worker)
  324. {
  325. entry_t *entry = NULL;
  326. entry = (entry_t *)malloc(sizeof(entry_t));
  327. entry->id = 0;
  328. entry->line = strdup(data);
  329. entry->line_size = strlen(entry->line);
  330. error_log(LOG_DEBUG, NULL, "Queue locking thread mutex.");
  331. if (APR_STATUS_IS_EBUSY(apr_thread_mutex_trylock(mutex))) {
  332. error_log(LOG_DEBUG, NULL, "Queue waiting on thread mutex.");
  333. apr_thread_mutex_lock(mutex);
  334. }
  335. /* Assign unique ID to this log entry. */
  336. entry->id = entry_counter++;
  337. /* Add the new audit log entry to the queue. */
  338. *(entry_t **)apr_array_push(queue) = entry;
  339. /* Create a new worker if we can, but not if there is a
  340. * known problem with the server.
  341. */
  342. if ( (start_worker != 0)
  343. && (current_workers < max_connections)&&(server_error == 0))
  344. {
  345. create_new_worker(0);
  346. }
  347. error_log(LOG_DEBUG, NULL, "Queue unlocking thread mutex.");
  348. apr_thread_mutex_unlock(mutex);
  349. }
  350. /**
  351. * Read the queue entries.
  352. */
  353. static int read_queue_entries(apr_file_t *fd, apr_time_t *queue_time)
  354. {
  355. char linebuf[4100];
  356. int line_count = -1;
  357. for(;;) {
  358. apr_status_t rc = apr_file_gets(linebuf, 4096, fd);
  359. char *p;
  360. if (rc == APR_EOF) break;
  361. if (rc != APR_SUCCESS) {
  362. error_log(LOG_ERROR, NULL, "Error reading from the queue file.");
  363. logc_shutdown(1);
  364. }
  365. if (line_count < 0) {
  366. /* First line contains the queue time. */
  367. *queue_time = (apr_time_t)apr_atoi64(linebuf);
  368. line_count = 0;
  369. continue;
  370. }
  371. p = &linebuf[0];
  372. /* Remove the \n from the end of the line. */
  373. while(*p != '\0') {
  374. if (*p == '\n') {
  375. *p = '\0';
  376. break;
  377. }
  378. p++;
  379. }
  380. if (linebuf[0] == '#') { /* Ignore comments. */
  381. continue;
  382. }
  383. add_entry((const char *)&linebuf, 0);
  384. line_count++;
  385. }
  386. apr_file_close(fd);
  387. return line_count;
  388. }
  389. /**
  390. * Initialise the transaction log. This code should be
  391. * executed only once at startup.
  392. */
  393. static void transaction_log_init(void)
  394. {
  395. /* ENH: These big enough? */
  396. char new_queue_path[256];
  397. char old_queue_path[256];
  398. apr_file_t *queue_fd = NULL;
  399. apr_time_t queue_time;
  400. apr_snprintf(new_queue_path, sizeof(new_queue_path), "%s.new", queue_path);
  401. apr_snprintf(old_queue_path, sizeof(old_queue_path), "%s.old", queue_path);
  402. /* Put a lock in place to ensure exclusivity. */
  403. error_log(LOG_DEBUG, NULL,
  404. "Transaction initialization locking global mutex.");
  405. if (APR_STATUS_IS_EBUSY(apr_global_mutex_trylock(gmutex))) {
  406. error_log(LOG_DEBUG, NULL,
  407. "Transaction initialization waiting on global mutex.");
  408. apr_global_mutex_lock(gmutex);
  409. }
  410. error_log(LOG_DEBUG, NULL, "Transaction initialization started.");
  411. /* Delete .new file if there is one. */
  412. apr_file_remove(new_queue_path, pool);
  413. /* Read in the data from the queue. */
  414. if (apr_file_open(&queue_fd, queue_path, APR_READ | APR_FILE_NOCLEANUP,
  415. 0, pool) == APR_SUCCESS)
  416. {
  417. int line_count = read_queue_entries(queue_fd, &queue_time);
  418. apr_file_close(queue_fd);
  419. if (line_count > 0) {
  420. error_log(LOG_NOTICE, NULL,
  421. "Loaded %d entries from the queue file.", line_count);
  422. }
  423. }
  424. /* Try the old queue file. */
  425. else if (apr_file_open(&queue_fd, old_queue_path,
  426. APR_READ | APR_FILE_NOCLEANUP,
  427. 0, pool) == APR_SUCCESS)
  428. {
  429. int line_count = read_queue_entries(queue_fd, &queue_time);
  430. apr_file_close(queue_fd);
  431. error_log(LOG_NOTICE, NULL,
  432. "Loaded %d entries from the OLD queue file.", line_count);
  433. apr_file_rename(old_queue_path, queue_path, pool);
  434. }
  435. else {
  436. error_log(LOG_NOTICE, NULL,
  437. "Queue file not found. New one will be created.");
  438. }
  439. /* Delete the old queue file. */
  440. apr_file_remove(old_queue_path, pool);
  441. checkpoint_time_last = apr_time_now();
  442. /* Start fresh with the transaction log. Do note that
  443. * we do not truncate the transaction log on purpose. Apache
  444. * will start copies of piped logging binaries during configuration
  445. * testing. Truncating would erase the log of a currently running
  446. * instance.
  447. */
  448. if (apr_file_open(&transaction_log_fd, transaction_log_path,
  449. APR_WRITE | APR_CREATE | APR_APPEND | APR_XTHREAD,
  450. APR_OS_DEFAULT, pool) != APR_SUCCESS)
  451. {
  452. error_log(LOG_ERROR, NULL,
  453. "Failed to open the transaction log: %s\n",
  454. transaction_log_path);
  455. error_log(LOG_DEBUG, NULL,
  456. "Transaction initialization unlocking global mutex.");
  457. apr_global_mutex_unlock(gmutex);
  458. logc_shutdown(1);
  459. }
  460. error_log(LOG_DEBUG, NULL, "Transaction initialization completed.");
  461. /* Unlock */
  462. error_log(LOG_DEBUG, NULL,
  463. "Transaction initialization unlocking global mutex.");
  464. apr_global_mutex_unlock(gmutex);
  465. }
  466. /**
  467. * Log entry event (incoming or outgoing) to the transaction log.
  468. */
  469. static void transaction_log(int direction, const char *entry)
  470. {
  471. apr_size_t nbytes, nbytes_written;
  472. char msg[8196] = "";
  473. apr_snprintf(msg, sizeof(msg), "%u %s: %s\n",
  474. (unsigned int)apr_time_sec(apr_time_now()),
  475. (direction == TXIN ? "IN" : "OUT"), entry);
  476. nbytes = strlen(msg);
  477. apr_file_write_full(transaction_log_fd, msg, nbytes, &nbytes_written);
  478. }
  479. /**
  480. * Executes a checkpoint, which causes the current queue to be
  481. * written to a file and the transaction log to be truncated.
  482. */
  483. static void transaction_checkpoint(void)
  484. {
  485. /* ENH: These big enough? */
  486. char new_queue_path[256];
  487. char old_queue_path[256];
  488. apr_file_t *queue_fd = NULL;
  489. apr_hash_index_t *hi = NULL;
  490. char msg[256];
  491. int i;
  492. apr_pool_t *cpool;
  493. apr_snprintf(new_queue_path, sizeof(new_queue_path), "%s.new", queue_path);
  494. apr_snprintf(old_queue_path, sizeof(old_queue_path), "%s.old", queue_path);
  495. apr_snprintf(msg, sizeof(msg), "%u\n",
  496. (unsigned int)apr_time_sec(apr_time_now()));
  497. if (! have_read_data) {
  498. error_log(LOG_DEBUG, NULL, "Checkpoint not required.");
  499. return;
  500. }
  501. /* Put a lock in place to ensure exclusivity. */
  502. error_log(LOG_DEBUG, NULL, "Checkpoint locking global mutex.");
  503. if (APR_STATUS_IS_EBUSY(apr_global_mutex_trylock(gmutex))) {
  504. error_log(LOG_DEBUG, NULL, "Checkpoint waiting on global mutex.");
  505. apr_global_mutex_lock(gmutex);
  506. }
  507. error_log(LOG_DEBUG, NULL, "Checkpoint started.");
  508. apr_pool_create(&cpool, NULL);
  509. /* Dump active entries into a new queue file. */
  510. if (apr_file_open(&queue_fd, new_queue_path,
  511. APR_WRITE | APR_CREATE | APR_EXCL |
  512. APR_TRUNCATE | APR_FILE_NOCLEANUP,
  513. APR_OS_DEFAULT, cpool) != APR_SUCCESS)
  514. {
  515. error_log(LOG_ERROR, NULL, "Failed to create file: %s", new_queue_path);
  516. error_log(LOG_DEBUG, NULL, "Checkpoint unlocking global mutex.");
  517. apr_pool_destroy(cpool);
  518. apr_global_mutex_unlock(gmutex);
  519. return;
  520. }
  521. /* Write the time first. */
  522. apr_file_write_full(queue_fd, msg, strlen(msg), NULL);
  523. /* Dump the entries sitting in the queue first. */
  524. for (i = 0; i < queue->nelts; i++) {
  525. entry_t *entry = ((entry_t **)queue->elts)[i];
  526. apr_file_write_full(queue_fd, entry->line, entry->line_size, NULL);
  527. apr_file_write_full(queue_fd, &"\n", 1, NULL);
  528. }
  529. error_log(LOG_DEBUG2, NULL,
  530. "Checkpoint wrote %d queued entries to new queue.", i);
  531. /* Then dump the ones that are currently being processed. */
  532. i = 0;
  533. for (hi = apr_hash_first(NULL, in_progress);
  534. hi != NULL; hi = apr_hash_next(hi))\
  535. {
  536. void *e;
  537. entry_t *entry = NULL;
  538. i++;
  539. apr_hash_this(hi, NULL, NULL, &e);
  540. entry = e; /* quiet type-punned warning */
  541. apr_file_write_full(queue_fd, entry->line, entry->line_size, NULL);
  542. apr_file_write_full(queue_fd, &"\n", 1, NULL);
  543. }
  544. error_log(LOG_DEBUG2, NULL,
  545. "Checkpoint wrote %d additional entries to new queue.", i);
  546. apr_file_close(queue_fd);
  547. /* Switch the files and truncate the transaction log file. */
  548. apr_file_remove(old_queue_path, cpool);
  549. apr_file_rename(queue_path, old_queue_path, cpool);
  550. apr_file_rename(new_queue_path, queue_path, cpool);
  551. apr_file_remove(old_queue_path, cpool);
  552. apr_file_trunc(transaction_log_fd, 0);
  553. error_log(LOG_DEBUG, NULL, "Checkpoint completed.");
  554. apr_pool_destroy(cpool);
  555. /* Unlock and exit. */
  556. error_log(LOG_DEBUG, NULL, "Checkpoint unlocking global mutex.");
  557. apr_global_mutex_unlock(gmutex);
  558. }
  559. /**
  560. * Parse one confguration line and add it to the
  561. * configuration table.
  562. */
  563. static void parse_configuration_line(const char *line, int line_count)
  564. {
  565. char *start = NULL, *command = NULL;
  566. char *p = NULL;
  567. /* Remove the trailing newline character. */
  568. p = (char *)line;
  569. while(*p != '\0') p++;
  570. if ((p > start)&&(*(p - 1) == '\n')) *(p - 1) = '\0';
  571. p = (char *)line;
  572. /* Ignore whitespace at the beginning of the line. */
  573. while(apr_isspace(*p)) p++;
  574. /* Ignore empty lines and comments. */
  575. if ((*p == '\0')||(*p == '#')) return;
  576. start = p;
  577. while(!apr_isspace(*p)&&(*p != '\0')) p++;
  578. command = apr_pstrmemdup(pool, start, p - start);
  579. while(apr_isspace(*p)) p++;
  580. /* Remove whitespace at the end. */
  581. start = p;
  582. while(*p != '\0') p++;
  583. if (p > start) {
  584. p--;
  585. while(apr_isspace(*p)) {
  586. *p-- = '\0';
  587. }
  588. }
  589. /* Remove quotes, but only if we have matching */
  590. if ((*start == '"') && (p > start) && (*p == '"')) {
  591. start++;
  592. *p-- = '\0';
  593. }
  594. /* Take the last directive */
  595. /* ENH: Error on dup directives? */
  596. apr_table_set(conf, command, start);
  597. }
  598. /**
  599. * Reads configuration from a file.
  600. */
  601. static void read_configuration(void)
  602. {
  603. char linebuf[4096];
  604. apr_status_t rc;
  605. apr_file_t *fd;
  606. int line_count;
  607. conf = apr_table_make(pool, 32);
  608. if (conf == NULL) {
  609. error_log(LOG_ERROR, NULL, MEMALLOC_ERROR_MSG);
  610. logc_shutdown(1);
  611. }
  612. rc = apr_file_open(&fd, conffile, APR_READ | APR_FILE_NOCLEANUP, 0, pool);
  613. if (rc != APR_SUCCESS) {
  614. error_log(LOG_ERROR, NULL,
  615. "Unable to open configuration file: %s", conffile);
  616. logc_shutdown(1);
  617. }
  618. line_count = 0;
  619. for(;;) {
  620. rc = apr_file_gets(linebuf, 4096, fd);
  621. if (rc == APR_EOF) return;
  622. if (rc != APR_SUCCESS) {
  623. error_log(LOG_ERROR, NULL,
  624. "Error reading from the configuration file.");
  625. logc_shutdown(1);
  626. }
  627. line_count++;
  628. parse_configuration_line(linebuf, line_count);
  629. }
  630. apr_file_close(fd);
  631. }
  632. /**
  633. * Initialize the configuration.
  634. */
  635. static void init_configuration(void)
  636. {
  637. char errstr[1024];
  638. apr_status_t rc = 0;
  639. const char *s = NULL;
  640. /* Other values may be based off the collector root. */
  641. s = apr_table_get(conf, "CollectorRoot");
  642. if (s != NULL) {
  643. collector_root = s;
  644. }
  645. /* Error Log */
  646. s = apr_table_get(conf, "ErrorLog");
  647. if (s != NULL) {
  648. error_log_path = file_path(s);
  649. }
  650. s = apr_table_get(conf, "ErrorLogLevel");
  651. if (s != NULL) {
  652. error_log_level = atoi(s);
  653. }
  654. if ((rc = apr_file_open(&error_log_fd, error_log_path,
  655. APR_WRITE | APR_CREATE | APR_APPEND,
  656. APR_OS_DEFAULT, pool)) != APR_SUCCESS)
  657. {
  658. error_log(LOG_ERROR, NULL, "Failed to open the error log %s: %s\n",
  659. error_log_path, apr_strerror(rc, errstr, 1024));
  660. logc_shutdown(1);
  661. }
  662. error_log(LOG_NOTICE, NULL,
  663. "Configuring ModSecurity Audit Log Collector %s.", VERSION);
  664. /* Startup Delay */
  665. s = apr_table_get(conf, "StartupDelay");
  666. if (s != NULL) {
  667. startup_delay = atoi(s);
  668. }
  669. if ( startup_delay > 0 ) {
  670. error_log(LOG_NOTICE, NULL,
  671. "Delaying execution for %dms.", startup_delay);
  672. apr_sleep(startup_delay * 1000);
  673. error_log(LOG_DEBUG, NULL,
  674. "Continuing execution after %dms delay.", startup_delay);
  675. }
  676. /* Remaining Configuration */
  677. error_log(LOG_DEBUG2, NULL, "CollectorRoot=%s", collector_root);
  678. error_log(LOG_DEBUG2, NULL, "ErrorLog=%s", error_log_path);
  679. error_log(LOG_DEBUG2, NULL, "ErrorLogLevel=%d", error_log_level);
  680. error_log(LOG_DEBUG2, NULL, "StartupDelay=%d", startup_delay);
  681. s = apr_table_get(conf, "CheckpointInterval");
  682. if (s != NULL) {
  683. checkpoint_interval = atoi(s);
  684. error_log(LOG_DEBUG2, NULL,
  685. "CheckpointInterval=%d", checkpoint_interval);
  686. }
  687. s = apr_table_get(conf, "QueuePath");
  688. if (s != NULL) {
  689. queue_path = file_path(s);
  690. error_log(LOG_DEBUG2, NULL, "QueuePath=%s", queue_path);
  691. }
  692. else {
  693. error_log(LOG_ERROR, NULL,
  694. "QueuePath not defined in the configuration file.");
  695. logc_shutdown(1);
  696. }
  697. s = apr_table_get(conf, "LockFile");
  698. if (s != NULL) {
  699. lockfile = file_path(s);
  700. error_log(LOG_DEBUG2, NULL, "LockFile=%s", lockfile);
  701. }
  702. s = apr_table_get(conf, "ServerErrorTimeout");
  703. if (s != NULL) {
  704. server_error_timeout = atoi(s);
  705. error_log(LOG_DEBUG2, NULL,
  706. "ServerErrorTimeout=%d", server_error_timeout);
  707. }
  708. s = apr_table_get(conf, "TransactionDelay");
  709. if (s != NULL) {
  710. transaction_delay = atoi(s);
  711. error_log(LOG_DEBUG2, NULL, "TransactionDelay=%d", transaction_delay);
  712. }
  713. s = apr_table_get(conf, "TransactionLog");
  714. if (s != NULL) {
  715. transaction_log_path = file_path(s);
  716. error_log(LOG_DEBUG2, NULL, "TransactionLog=%s", transaction_log_path);
  717. }
  718. s = apr_table_get(conf, "MaxConnections");
  719. if (s != NULL) {
  720. int v = atoi(s);
  721. if (v >= 0) max_connections = v;
  722. error_log(LOG_DEBUG2, NULL, "MaxConnections=%d", max_connections);
  723. }
  724. s = apr_table_get(conf, "MaxWorkerRequests");
  725. if (s != NULL) {
  726. int v = atoi(s);
  727. if (v >= 0) max_worker_requests = v;
  728. error_log(LOG_DEBUG2, NULL,
  729. "MaxWorkerRequests=%d", max_worker_requests);
  730. }
  731. s = apr_table_get(conf, "KeepAlive");
  732. if (s != NULL) {
  733. int v = atoi(s);
  734. if (v >= 0) keep_alive = v;
  735. error_log(LOG_DEBUG2, NULL, "KeepAlive=%d", keep_alive);
  736. }
  737. s = apr_table_get(conf, "KeepAliveTimeout");
  738. if (s != NULL) {
  739. int v = atoi(s);
  740. if (v >= 0) keep_alive_timeout = v;
  741. error_log(LOG_DEBUG2, NULL, "KeepAliveTimeout=%d", keep_alive_timeout);
  742. }
  743. s = apr_table_get(conf, "LogStorageDir");
  744. if (s != NULL) {
  745. log_repository = file_path(s);
  746. error_log(LOG_DEBUG2, NULL, "LogStorageDir=%s", log_repository);
  747. }
  748. else {
  749. error_log(LOG_ERROR, NULL,
  750. "Missing mandatory parameter LogStorageDir.\n");
  751. logc_shutdown(1);
  752. }
  753. s = apr_table_get(conf, "ConsoleURI");
  754. if (s != NULL) {
  755. console_uri = s;
  756. error_log(LOG_DEBUG2, NULL, "ConsoleURI=%s", console_uri);
  757. }
  758. else {
  759. error_log(LOG_ERROR, NULL, "Missing mandatory parameter ConsoleURI.\n");
  760. logc_shutdown(1);
  761. }
  762. s = apr_table_get(conf, "SensorUsername");
  763. if (s != NULL) {
  764. sensor_username = s;
  765. error_log(LOG_DEBUG2, NULL, "SensorUsername=%s", sensor_username);
  766. }
  767. else {
  768. error_log(LOG_ERROR, NULL,
  769. "Missing mandatory parameter SensorUsername.\n");
  770. logc_shutdown(1);
  771. }
  772. s = apr_table_get(conf, "SensorPassword");
  773. if (s != NULL) {
  774. sensor_password = s;
  775. error_log(LOG_DEBUG2, NULL, "SensorPassword=%s", sensor_password);
  776. }
  777. else {
  778. error_log(LOG_ERROR, NULL,
  779. "Missing mandatory parameter SensorPassword.\n");
  780. logc_shutdown(1);
  781. }
  782. s = apr_table_get(conf, "KeepEntries");
  783. if (s != NULL) {
  784. keep_entries = atoi(s);
  785. }
  786. else {
  787. keep_entries = 0;
  788. }
  789. error_log(LOG_DEBUG2, NULL, "KeepEntries=%d", keep_entries);
  790. }
  791. /**
  792. * Clean-up resources before process shutdown.
  793. */
  794. static void logc_cleanup(void)
  795. {
  796. curl_global_cleanup();
  797. }
  798. /**
  799. * Shutdown the logger.
  800. */
  801. static void logc_shutdown(int rc)
  802. {
  803. /* Tell the threads to shut down. */
  804. running = 0;
  805. error_log(LOG_DEBUG, NULL, "Shutting down");
  806. /* Wait for the management thread to stop */
  807. /* ENH: Need a fixed timeout if this never happens */
  808. while(management_thread_active != 0) {
  809. apr_sleep(10 * 1000);
  810. }
  811. if (rc == 0) {
  812. error_log(LOG_NOTICE, NULL,
  813. "ModSecurity Audit Log Collector %s terminating normally.",
  814. VERSION);
  815. }
  816. else {
  817. error_log(LOG_NOTICE, NULL,
  818. "ModSecurity Audit Log Collector %s "
  819. "terminating with error %d", VERSION, rc);
  820. }
  821. if (error_log_fd != NULL) {
  822. apr_file_flush(error_log_fd);
  823. }
  824. exit(rc);
  825. }
  826. /**
  827. * Handle signals.
  828. */
  829. static int handle_signals(int signum)
  830. {
  831. switch (signum) {
  832. case SIGINT:
  833. error_log(LOG_NOTICE, NULL, "Caught SIGINT, shutting down.");
  834. logc_shutdown(0);
  835. case SIGTERM:
  836. error_log(LOG_NOTICE, NULL, "Caught SIGTERM, shutting down.");
  837. logc_shutdown(0);
  838. #ifndef WIN32
  839. case SIGHUP:
  840. error_log(LOG_NOTICE, NULL, "Caught SIGHUP, ignored.");
  841. /* ENH: reload config? */
  842. return 0;
  843. case SIGALRM:
  844. error_log(LOG_DEBUG, NULL, "Caught SIGALRM, ignored.");
  845. return 0;
  846. case SIGTSTP:
  847. error_log(LOG_DEBUG, NULL, "Caught SIGTSTP, ignored.");
  848. return 0;
  849. #endif /* WIN32 */
  850. }
  851. #ifndef WIN32
  852. error_log(LOG_NOTICE, NULL,
  853. "Caught unexpected signal %d: %s",
  854. signum, apr_signal_description_get(signum));
  855. #else
  856. error_log(LOG_NOTICE, NULL, "Caught unexpected signal %d", signum);
  857. #endif /* WIN32 */
  858. logc_shutdown(1);
  859. return 0; /* should never reach */
  860. }
  861. #ifdef WIN32
  862. /**
  863. * This function is invoked by Curl to read the source file on Windows
  864. */
  865. static size_t curl_readfunction(void *ptr, size_t size,
  866. size_t nmemb, void *stream)
  867. {
  868. return fread(ptr, size, nmemb, (FILE *)stream);
  869. }
  870. #endif
  871. /**
  872. * This function is invoked by Curl to read the response
  873. * body. Since we don't care about the response body the function
  874. * pretends it is retrieving data where it isn't.
  875. */
  876. static size_t curl_writefunction(void *ptr, size_t size,
  877. size_t nmemb, void *stream)
  878. {
  879. unsigned char *data = (unsigned char *)ptr;
  880. unsigned char *status = (unsigned char *)stream;
  881. /* Grab the status line text from the first line of output */
  882. if ((status[0] == 0) && (status[1] == 1)) {
  883. apr_size_t i, j;
  884. int ismsg = 0;
  885. status[1] = 0; /* reset hidden init flag */
  886. for (i = 0, j = 0; i < STATUSBUF_SIZE; i++) {
  887. /* We found a line ending so we are done */
  888. if ( data[i] == '\r' ) {
  889. break;
  890. }
  891. /* Skip to after the first space (where msg is) */
  892. if (ismsg < 3) {
  893. if ((ismsg == 1) && !isspace(data[i])) {
  894. ismsg++;
  895. }
  896. else if (isspace(data[i])) {
  897. ismsg++;
  898. }
  899. continue;
  900. }
  901. /* Copy data (msg) from data to status */
  902. status[j++] = data[i];
  903. }
  904. status[j] = '\0';
  905. urldecode_inplace(status, j);
  906. }
  907. /* do nothing */
  908. return (size * nmemb);
  909. }
  910. /**
  911. * This function is invoked by Curl whenever it has something
  912. * to say. We forward its messages to the error log at level
  913. * DEBUG or DEBUG2 depending on the verbosity.
  914. */
  915. static int curl_debugfunction(CURL *curl, curl_infotype infotype,
  916. char *data, size_t datalen, void *ourdata)
  917. {
  918. apr_size_t i, effectivelen;
  919. apr_thread_t *thread = (apr_thread_t *)ourdata;
  920. if (error_log_level < LOG_DEBUG) return 0;
  921. effectivelen = datalen;
  922. for(i = 0; i < datalen; i++) {
  923. if ((data[i] == 0x0a)||(data[i] == 0x0d)) {
  924. effectivelen = i;
  925. break;
  926. }
  927. }
  928. switch (infotype) {
  929. case CURLINFO_TEXT:
  930. /* More verbose data starts with an indent */
  931. if (apr_isspace(data[0])) {
  932. char *dataptr = data + 1;
  933. /* Skip initial whitespace (indent) */
  934. while ( ((size_t)(dataptr - data) > datalen)
  935. && apr_isspace(*dataptr)) dataptr++;
  936. dataptr++;
  937. error_log(LOG_DEBUG2, thread, "CURL: %s",
  938. _log_escape(apr_thread_pool_get(thread), dataptr,
  939. effectivelen - (dataptr - data)));
  940. }
  941. else {
  942. error_log(LOG_DEBUG, thread, "CURL: %s",
  943. _log_escape(apr_thread_pool_get(thread), data,
  944. effectivelen));
  945. }
  946. break;
  947. case CURLINFO_HEADER_IN:
  948. error_log(LOG_DEBUG, thread, "CURL: HEADER_IN %s",
  949. _log_escape(apr_thread_pool_get(thread), data,
  950. effectivelen));
  951. break;
  952. case CURLINFO_HEADER_OUT:
  953. error_log(LOG_DEBUG, thread, "CURL: HEADER_OUT %s",
  954. _log_escape(apr_thread_pool_get(thread), data,
  955. effectivelen));
  956. break;
  957. case CURLINFO_DATA_IN:
  958. error_log(LOG_DEBUG2, thread, "CURL: DATA_IN %s",
  959. _log_escape(apr_thread_pool_get(thread), data,
  960. effectivelen));
  961. break;
  962. case CURLINFO_DATA_OUT:
  963. error_log(LOG_DEBUG2, thread, "CURL: DATA_OUT %s",
  964. _log_escape(apr_thread_pool_get(thread), data,
  965. effectivelen));
  966. break;
  967. default:
  968. /* Ignore anything else */
  969. break;
  970. }
  971. return 0;
  972. }
  973. /**
  974. * Initialise the necessary resources and structures.
  975. */
  976. static void logc_init(void)
  977. {
  978. char errstr[1024];
  979. apr_status_t rc = 0;
  980. const char *errptr = NULL;
  981. int i, erroffset;
  982. queue = apr_array_make(pool, 64, sizeof(entry_t *));
  983. if (queue == NULL) {
  984. error_log(LOG_ERROR, NULL, MEMALLOC_ERROR_MSG);
  985. logc_shutdown(1);
  986. }
  987. in_progress = apr_hash_make(pool);
  988. if (in_progress == NULL) {
  989. error_log(LOG_ERROR, NULL, MEMALLOC_ERROR_MSG);
  990. logc_shutdown(1);
  991. }
  992. if ((rc = apr_global_mutex_create(&gmutex, lockfile,
  993. APR_LOCK_DEFAULT, pool)) != APR_SUCCESS)
  994. {
  995. error_log(LOG_ERROR, NULL, "Failed to create global mutex: %s",
  996. apr_strerror(rc, errstr, 1024));
  997. logc_shutdown(1);
  998. }
  999. if ((rc = apr_thread_mutex_create(&mutex, APR_THREAD_MUTEX_UNNESTED,
  1000. pool)) != APR_SUCCESS)
  1001. {
  1002. error_log(LOG_ERROR, NULL, "Failed to create thread mutex: %s",
  1003. apr_strerror(rc, errstr, 1024));
  1004. logc_shutdown(1);
  1005. }
  1006. entry_counter = 1;
  1007. curl_handles = apr_array_make(pool, max_connections, sizeof(CURL *));
  1008. if (curl_handles == NULL) {
  1009. error_log(LOG_ERROR, NULL, MEMALLOC_ERROR_MSG);
  1010. logc_shutdown(1);
  1011. }
  1012. /* Initialise a number of Curl handles. */
  1013. for(i = 0; i < max_connections; i++) {
  1014. CURL *curl = NULL;
  1015. /* Create cURL handle. */
  1016. curl = curl_easy_init();
  1017. /* Pre-configure the handle. */
  1018. curl_easy_setopt(curl, CURLOPT_UPLOAD, TRUE);
  1019. curl_easy_setopt(curl, CURLOPT_ERRORBUFFER, (char *)NULL);
  1020. curl_easy_setopt(curl, CURLOPT_URL, console_uri);
  1021. curl_easy_setopt(curl, CURLOPT_HTTPAUTH, CURLAUTH_BASIC);
  1022. curl_easy_setopt(curl, CURLOPT_SSL_VERIFYPEER, FALSE);
  1023. curl_easy_setopt(curl, CURLOPT_SSL_VERIFYHOST, 0);
  1024. /* SSLv3 works better overall as some servers have issues with TLS */
  1025. curl_easy_setopt(curl, CURLOPT_SSLVERSION, CURL_SSLVERSION_SSLv3);
  1026. curl_easy_setopt(curl, CURLOPT_CONNECTTIMEOUT, 15);
  1027. curl_easy_setopt(curl, CURLOPT_NOSIGNAL, TRUE);
  1028. curl_easy_setopt(curl, CURLOPT_HEADER, TRUE);
  1029. curl_easy_setopt(curl, CURLOPT_WRITEFUNCTION, curl_writefunction);
  1030. *(CURL **)apr_array_push(curl_handles) = curl;
  1031. }
  1032. logline_regex = pcre_compile(logline_pattern, PCRE_CASELESS,
  1033. &errptr, &erroffset, NULL);
  1034. if (logline_regex == NULL) {
  1035. error_log(LOG_ERROR, NULL,
  1036. "Failed to compile pattern: %s\n", logline_pattern);
  1037. logc_shutdown(1);
  1038. }
  1039. requestline_regex = pcre_compile(requestline_pattern,
  1040. PCRE_CASELESS, &errptr, &erroffset, NULL);
  1041. if (requestline_regex == NULL) {
  1042. error_log(LOG_ERROR, NULL,
  1043. "Failed to compile pattern: %s\n", requestline_pattern);
  1044. logc_shutdown(1);
  1045. }
  1046. }
  1047. /**
  1048. * HACK: To allow two mlogcs running against a single dataset we use the
  1049. * mtime as a flag for deletion.
  1050. *
  1051. * 1) Check file date.
  1052. * 2) If it is KEEP_ENTRIES_REMOVE_TIME, then remove the file.
  1053. * 3) Otherwise set the date and let the other mlogc remove it.
  1054. */
  1055. static void keep_entries_hack(apr_pool_t *mp,
  1056. apr_thread_t *thread, const char *fn)
  1057. {
  1058. apr_file_t *f = NULL;
  1059. apr_finfo_t finfo;
  1060. char errstr[1024];
  1061. apr_status_t rc;
  1062. /* Opening for write as required for exclusive lock */
  1063. if ((rc = apr_file_open(&f, fn,
  1064. APR_READ|APR_WRITE|APR_APPEND,
  1065. APR_OS_DEFAULT, mp)) != APR_SUCCESS)
  1066. {
  1067. error_log(LOG_ERROR, thread,
  1068. "Could not open \"%s\": %s",
  1069. fn, apr_strerror(rc, errstr, 1024));
  1070. return;
  1071. }
  1072. if ((rc = apr_file_lock(f,
  1073. APR_FLOCK_EXCLUSIVE|APR_FLOCK_NONBLOCK)) != APR_SUCCESS)
  1074. {
  1075. error_log(LOG_DEBUG2, thread,
  1076. "Waiting for lock on \"%s\": %s",
  1077. fn, apr_strerror(rc, errstr, 1024));
  1078. if ((rc = apr_file_lock(f, APR_FLOCK_EXCLUSIVE)) != APR_SUCCESS) {
  1079. error_log(LOG_ERROR, thread,
  1080. "Could not lock \"%s\": %s",
  1081. fn, apr_strerror(rc, errstr, 1024));
  1082. apr_file_close(f);
  1083. return;
  1084. }
  1085. }
  1086. error_log(LOG_DEBUG2, thread, "Locked: %s", fn);
  1087. /* For testing only */
  1088. TEST_WITH_RAND_SLEEP(2);
  1089. if ((rc = apr_stat(&finfo, fn, APR_FINFO_MIN, mp)) != APR_SUCCESS) {
  1090. error_log(LOG_ERROR, thread,
  1091. "Could not stat \"%s\": %s",
  1092. fn, apr_strerror(rc, errstr, 1024));
  1093. error_log(LOG_DEBUG2, thread, "Unlocked: %s", fn);
  1094. apr_file_close(f);
  1095. return;
  1096. }
  1097. if (error_log_level >= LOG_DEBUG) {
  1098. error_log(LOG_DEBUG, thread,
  1099. "STAT \"%s\" {"
  1100. "uid=%d; gid=%d; size=%" APR_OFF_T_FMT "; "
  1101. "csize=%" APR_OFF_T_FMT "; atime=%" APR_TIME_T_FMT "; "
  1102. "ctime=%" APR_TIME_T_FMT "; mtime=%" APR_TIME_T_FMT
  1103. "}",
  1104. fn, finfo.user, finfo.group, finfo.size,
  1105. finfo.csize, finfo.atime, finfo.ctime, finfo.mtime);
  1106. }
  1107. if (finfo.mtime != KEEP_ENTRIES_REMOVE_TIME) {
  1108. error_log(LOG_DEBUG2, thread, "Set mtime: %s", fn);
  1109. if ((rc = apr_file_mtime_set(fn,
  1110. (apr_time_t)KEEP_ENTRIES_REMOVE_TIME, mp))
  1111. != APR_SUCCESS)
  1112. {
  1113. error_log(LOG_ERROR, thread,
  1114. "Could not set mtime on \"%s\": %s",
  1115. fn, apr_strerror(rc, errstr, 1024));
  1116. }
  1117. error_log(LOG_DEBUG2, thread, "Unlocked: %s", fn);
  1118. apr_file_close(f);
  1119. return;
  1120. }
  1121. error_log(LOG_DEBUG, thread, "Removing: %s", fn);
  1122. error_log(LOG_DEBUG2, thread, "Unlocked: %s", fn);
  1123. apr_file_close(f);
  1124. apr_file_remove(fn, mp);
  1125. }
  1126. /**
  1127. * Worker thread. Works in a loop, fetching jobs from the queue,
  1128. * until the queue is empty or it is otherwise told to quit.
  1129. */
  1130. static void * APR_THREAD_FUNC thread_worker(apr_thread_t *thread, void *data)
  1131. {
  1132. unsigned int loop_count = 0;
  1133. CURL *curl = (CURL *)data;
  1134. entry_t **entryptr = NULL;
  1135. entry_t *entry = NULL;
  1136. apr_status_t rc;
  1137. apr_finfo_t finfo;
  1138. int capturevector[CAPTUREVECTORSIZE];
  1139. int take_new = 1;
  1140. apr_pool_t *tpool;
  1141. struct curl_slist *headerlist = NULL;
  1142. char curl_error_buffer[CURL_ERROR_SIZE] = "";
  1143. int num_requests = 0;
  1144. /* There is no need to do the sleep if this was an invalid entry
  1145. * as the sleep is just to protect flooding the console server
  1146. * with rapid requests. With an invalid entry we never hit the
  1147. * server, so we should not delay processing the next event.
  1148. */
  1149. int nodelay = 0;
  1150. error_log(LOG_DEBUG, thread, "Worker thread starting.");
  1151. /* Each worker uses its own pool to manage memory. To avoid
  1152. * memory leaks the pool is cleared after each processed
  1153. * entry.
  1154. */
  1155. apr_pool_create(&tpool, thread_pool);
  1156. /* Process jobs in a queue until there are no more jobs to process. */
  1157. for(;;) {
  1158. nodelay = 0;
  1159. /* Do we need to shut down? */
  1160. if (running == 0) {
  1161. error_log(LOG_DEBUG, thread, "We were told to shut down.");
  1162. goto THREAD_SHUTDOWN;
  1163. }
  1164. /* Is there a problem with the server? We need
  1165. * to shut down if there is. Except that we don't
  1166. * want to shut down if we were launched to investigate
  1167. * if the server came back online (loop_count will be
  1168. * zero in that case).
  1169. */
  1170. if ((server_error == 1)&&(loop_count != 0)) {
  1171. error_log(LOG_DEBUG, thread, "Shutting down due to server error.");
  1172. goto THREAD_SHUTDOWN;
  1173. }
  1174. loop_count++;
  1175. /* Get a new entry, but only if we need one. */
  1176. if (take_new) {
  1177. error_log(LOG_DEBUG, thread, "Worker fetch locking thread mutex.");
  1178. if (APR_STATUS_IS_EBUSY(apr_thread_mutex_trylock(mutex))) {
  1179. error_log(LOG_DEBUG, thread,
  1180. "Worker fetch waiting on thread mutex.");
  1181. apr_thread_mutex_lock(mutex);
  1182. }
  1183. error_log(LOG_DEBUG, thread, "Worker fetch started.");
  1184. /* Deal with the previous entry. */
  1185. if (entry != NULL) {
  1186. error_log(LOG_DEBUG, thread,
  1187. "Removing previous entry from storage.");
  1188. transaction_log(TXOUT, entry->line);
  1189. /* Remove previous entry from storage. */
  1190. apr_hash_set(in_progress, &entry->id, sizeof(entry->id), NULL);
  1191. /* Release the memory it used to occupy. */
  1192. free((void *)entry->line);
  1193. free(entry);
  1194. entry = NULL;
  1195. }
  1196. error_log(LOG_DEBUG, thread, "Getting one entry from the queue.");
  1197. /* Get one entry. */
  1198. entryptr = (entry_t **)apr_array_pop(queue);
  1199. if (entryptr == NULL) {
  1200. error_log(LOG_DEBUG, thread,
  1201. "Worker fetch unlocking thread mutex.");
  1202. apr_thread_mutex_unlock(mutex);
  1203. error_log(LOG_DEBUG, thread,
  1204. "No more work for this thread, exiting.");
  1205. goto THREAD_SHUTDOWN;
  1206. }
  1207. entry = *entryptr;
  1208. apr_hash_set(in_progress, &entry->id, sizeof(entry->id), entry);
  1209. error_log(LOG_DEBUG, thread, "Worker fetch completed.");
  1210. error_log(LOG_DEBUG, thread,
  1211. "Worker fetch unlocking thread mutex.");
  1212. apr_thread_mutex_unlock(mutex);
  1213. }
  1214. /* Send one entry. */
  1215. error_log(LOG_DEBUG, thread, "Processing entry.");
  1216. take_new = 0;
  1217. /* Keep track of requests processed if we need to */
  1218. if (max_worker_requests > 0) {
  1219. num_requests++;
  1220. }
  1221. rc = pcre_exec(logline_regex, NULL, entry->line, entry->line_size, 0, 0,
  1222. capturevector, CAPTUREVECTORSIZE);
  1223. if (rc == PCRE_ERROR_NOMATCH) { /* No match. */
  1224. error_log(LOG_WARNING, thread,
  1225. "Invalid entry (failed to match regex): %s",
  1226. _log_escape(tpool, entry->line, entry->line_size));
  1227. take_new = 1;
  1228. nodelay = 1;
  1229. }
  1230. else if (rc < 0) { /* Error condition. */
  1231. error_log(LOG_WARNING, thread,
  1232. "Invalid entry (PCRE error %d): %s",
  1233. rc, _log_escape(tpool, entry->line, entry->line_size));
  1234. take_new = 1;
  1235. nodelay = 1;
  1236. }
  1237. else { /* We have a match. */
  1238. char *uniqueid = NULL;
  1239. char *auditlogentry = NULL;
  1240. char *hash = NULL;
  1241. char *summary = NULL;
  1242. char *credentials = NULL;
  1243. error_log(LOG_DEBUG, thread, "Regular expression matched.");
  1244. /* For testing only */
  1245. TEST_WITH_RAND_SLEEP(2);
  1246. uniqueid = apr_psprintf(tpool, "%.*s",
  1247. (capturevector[2*13+1] - capturevector[2*13]),
  1248. (entry->line + capturevector[2*13]));
  1249. auditlogentry = apr_psprintf(tpool, "%s/%.*s", log_repository,
  1250. (capturevector[2*15+1] - capturevector[2*15]),
  1251. (entry->line + capturevector[2*15]));
  1252. hash = apr_psprintf(tpool, "X-Content-Hash: %.*s",
  1253. (capturevector[2*18+1] - capturevector[2*15]),
  1254. (entry->line + capturevector[2*18]));
  1255. summary = apr_psprintf(tpool, "X-ForensicLog-Summary: %s",
  1256. entry->line);
  1257. credentials = apr_psprintf(tpool, "%s:%s",
  1258. sensor_username, sensor_password);
  1259. rc = apr_stat(&finfo, auditlogentry, APR_FINFO_SIZE, tpool);
  1260. if (rc == APR_SUCCESS) {
  1261. FILE *hd_src;
  1262. char response_buf[STATUSBUF_SIZE];
  1263. CURLcode res;
  1264. if (error_log_level >= LOG_DEBUG) {
  1265. error_log(LOG_DEBUG, thread,
  1266. "STAT \"%s\" {"
  1267. "uid=%d; gid=%d; size=%" APR_OFF_T_FMT "; "
  1268. "csize=%" APR_OFF_T_FMT "; "
  1269. "atime=%" APR_TIME_T_FMT "; "
  1270. "ctime=%" APR_TIME_T_FMT "; "
  1271. "mtime=%" APR_TIME_T_FMT
  1272. "}",
  1273. auditlogentry, finfo.user, finfo.group,
  1274. finfo.size, finfo.csize, finfo.atime,
  1275. finfo.ctime, finfo.mtime);
  1276. }
  1277. /* Initialize the respone buffer with a hidden value */
  1278. response_buf[0] = 0;
  1279. response_buf[1] = 1;
  1280. if (finfo.size == 0) {
  1281. error_log(LOG_WARNING, thread,
  1282. "File found (%" APR_OFF_T_FMT
  1283. " bytes), skipping.", finfo.size);
  1284. take_new = 1;
  1285. nodelay = 1;
  1286. goto THREAD_CLEANUP;
  1287. }
  1288. else {
  1289. error_log(LOG_DEBUG, thread,
  1290. "File found (%" APR_OFF_T_FMT
  1291. " bytes), activating cURL.", finfo.size);
  1292. }
  1293. curl_easy_setopt(curl, CURLOPT_VERBOSE, 1);
  1294. curl_easy_setopt(curl, CURLOPT_DEBUGFUNCTION,
  1295. curl_debugfunction);
  1296. curl_easy_setopt(curl, CURLOPT_DEBUGDATA, thread);
  1297. curl_easy_setopt(curl, CURLOPT_ERRORBUFFER, curl_error_buffer);
  1298. curl_easy_setopt(curl, CURLOPT_USERPWD, credentials);
  1299. curl_easy_setopt(curl, CURLOPT_WRITEDATA, (char *)response_buf);
  1300. headerlist = curl_slist_append(headerlist, "Expect:");
  1301. headerlist = curl_slist_append(headerlist, hash);
  1302. headerlist = curl_slist_append(headerlist, summary);
  1303. curl_easy_setopt(curl, CURLOPT_HTTPHEADER, headerlist);
  1304. hd_src = fopen(auditlogentry, "rb");
  1305. if (hd_src == NULL) {
  1306. error_log(LOG_WARNING, thread,
  1307. "Invalid entry (failed to open file for "
  1308. "reading): %s", auditlogentry);
  1309. take_new = 1;
  1310. nodelay = 1;
  1311. goto THREAD_CLEANUP;
  1312. }
  1313. curl_easy_setopt(curl, CURLOPT_READDATA, hd_src);
  1314. curl_easy_setopt(curl, CURLOPT_INFILESIZE_LARGE, finfo.size);
  1315. #ifdef WIN32
  1316. /* Mandatory on win32 */
  1317. curl_easy_setopt(curl, CURLOPT_READFUNCTION, curl_readfunction);
  1318. #endif
  1319. res = curl_easy_perform(curl);
  1320. fclose(hd_src);
  1321. if (res == 0) {
  1322. long response_code = 0;
  1323. res = curl_easy_getinfo(curl, CURLINFO_RESPONSE_CODE,
  1324. &response_code);
  1325. error_log(LOG_DEBUG, thread,
  1326. "Request returned with status \"%ld %s\": %s",
  1327. response_code, response_buf, uniqueid);
  1328. if (response_code == 0) {
  1329. /* Assume problem with connection */
  1330. error_log(LOG_WARNING, thread,
  1331. "Flagging server as errored after failure "
  1332. "to retrieve response code for entry %s "
  1333. "(cURL code %d): Possible SSL negotiation "
  1334. "error",
  1335. uniqueid, res);
  1336. apr_sleep(1000 * 1000);
  1337. take_new = 0;
  1338. server_error = 1;
  1339. server_error_last_check_time = apr_time_now();
  1340. }
  1341. else if (res != 0) {
  1342. error_log(LOG_WARNING, thread,
  1343. "Flagging server as er…

Large files files are truncated, but you can click here to view the full file