From: Ken Steele Date: Tue, 7 Jan 2014 15:31:40 +0000 (-0500) Subject: Reduce time the file lock is held to write an alert to Fast.log X-Git-Tag: suricata-2.0rc1~31 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=2200dd61a1c358486ac96427ca50096abcc978e5;p=thirdparty%2Fsuricata.git Reduce time the file lock is held to write an alert to Fast.log Generate the alert string into a temporary buffer before aquiring the file lock. Only hold the file lock while writing the alert string to the file. In the case of multiple alerts, it would be better to generate all the alerts, then aquire the lock once and write them all and then flush. Changed PrintRawLineHexFp, which printed to a file, to PrintBufferRawLineHex, that puts the same output into a string buffer. It was only used by fast.log. --- diff --git a/src/alert-fastlog.c b/src/alert-fastlog.c index 550c023946..6657aed495 100644 --- a/src/alert-fastlog.c +++ b/src/alert-fastlog.c @@ -62,6 +62,8 @@ #define MODULE_NAME "AlertFastLog" +#define MAX_FASTLOG_ALERT_SIZE 2048 + TmEcode AlertFastLogThreadInit(ThreadVars *, void *, void **); TmEcode AlertFastLogThreadDeinit(ThreadVars *, void *); void AlertFastLogExitPrintStats(ThreadVars *, void *); @@ -93,6 +95,26 @@ int AlertFastLogCondition(ThreadVars *tv, const Packet *p) { return (p->alerts.cnt ? TRUE : FALSE); } +static inline void AlertFastLogOutputAlert(AlertFastLogThread *aft, char *buffer, + int alert_size) +{ + FILE *fp = aft->file_ctx->fp; + /* fp should never be NULL, but checking here makes sure the value + * is available before the lock is aquired, rather than possibly + * stalling while holding the lock. + */ + if (unlikely(fp == NULL)) + return; + + /* Output the alert string. Only need to lock here. */ + SCMutex *file_lock = &aft->file_ctx->fp_mutex; + SCMutexLock(file_lock); + aft->file_ctx->alerts++; + fwrite(buffer, alert_size, 1, fp); + fflush(fp); + SCMutexUnlock(file_lock); +} + int AlertFastLogger(ThreadVars *tv, void *data, const Packet *p) { AlertFastLogThread *aft = (AlertFastLogThread *)data; @@ -115,6 +137,11 @@ int AlertFastLogger(ThreadVars *tv, void *data, const Packet *p) decoder_event = 1; } + /* Buffer to store the generated alert string. The buffer is + * reused for each alert. + */ + char alert_buffer[MAX_FASTLOG_ALERT_SIZE]; + for (i = 0; i < p->alerts.cnt; i++) { const PacketAlert *pa = &p->alerts.alerts[i]; if (unlikely(pa->s == NULL)) { @@ -136,34 +163,37 @@ int AlertFastLogger(ThreadVars *tv, void *data, const Packet *p) } } - SCMutexLock(&aft->file_ctx->fp_mutex); + /* Create the alert string without locking. */ + int size = 0; if (likely(decoder_event == 0)) { - fprintf(aft->file_ctx->fp, "%s %s[**] [%" PRIu32 ":%" PRIu32 ":%" - PRIu32 "] %s [**] [Classification: %s] [Priority: %"PRIu32"]" - " {%s} %s:%" PRIu32 " -> %s:%" PRIu32 "\n", timebuf, action, - pa->s->gid, pa->s->id, pa->s->rev, pa->s->msg, pa->s->class_msg, pa->s->prio, - proto, srcip, p->sp, dstip, p->dp); + PrintBufferData(alert_buffer, &size, MAX_FASTLOG_ALERT_SIZE, + "%s %s[**] [%" PRIu32 ":%" PRIu32 ":%" + PRIu32 "] %s [**] [Classification: %s] [Priority: %"PRIu32"]" + " {%s} %s:%" PRIu32 " -> %s:%" PRIu32 "\n", timebuf, action, + pa->s->gid, pa->s->id, pa->s->rev, pa->s->msg, pa->s->class_msg, pa->s->prio, + proto, srcip, p->sp, dstip, p->dp); } else { - fprintf(aft->file_ctx->fp, "%s %s[**] [%" PRIu32 ":%" PRIu32 - ":%" PRIu32 "] %s [**] [Classification: %s] [Priority: " - "%" PRIu32 "] [**] [Raw pkt: ", timebuf, action, pa->s->gid, - pa->s->id, pa->s->rev, pa->s->msg, pa->s->class_msg, pa->s->prio); - PrintRawLineHexFp(aft->file_ctx->fp, GET_PKT_DATA(p), GET_PKT_LEN(p) < 32 ? GET_PKT_LEN(p) : 32); + PrintBufferData(alert_buffer, &size, MAX_FASTLOG_ALERT_SIZE, + "%s %s[**] [%" PRIu32 ":%" PRIu32 + ":%" PRIu32 "] %s [**] [Classification: %s] [Priority: " + "%" PRIu32 "] [**] [Raw pkt: ", timebuf, action, pa->s->gid, + pa->s->id, pa->s->rev, pa->s->msg, pa->s->class_msg, pa->s->prio); + PrintBufferRawLineHex(alert_buffer, &size, GET_PKT_DATA(p), GET_PKT_LEN(p) < 32 ? GET_PKT_LEN(p) : 32); if (p->pcap_cnt != 0) { - fprintf(aft->file_ctx->fp, "] [pcap file packet: %"PRIu64"]\n", p->pcap_cnt); + PrintBufferData(alert_buffer, &size, MAX_FASTLOG_ALERT_SIZE, + "] [pcap file packet: %"PRIu64"]\n", p->pcap_cnt); } else { - fprintf(aft->file_ctx->fp, "]\n"); + PrintBufferData(alert_buffer, &size, MAX_FASTLOG_ALERT_SIZE, "]\n"); } } - fflush(aft->file_ctx->fp); - aft->file_ctx->alerts++; - SCMutexUnlock(&aft->file_ctx->fp_mutex); + + /* Write the alert to output file */ + AlertFastLogOutputAlert(aft, alert_buffer, size); } return TM_ECODE_OK; } - TmEcode AlertFastLogThreadInit(ThreadVars *t, void *initdata, void **data) { AlertFastLogThread *aft = SCMalloc(sizeof(AlertFastLogThread)); diff --git a/src/util-print.c b/src/util-print.c index 71163852b8..b02c5f009c 100644 --- a/src/util-print.c +++ b/src/util-print.c @@ -33,21 +33,19 @@ * * Prints in the format "00 AA BB" * - * \param fp FILE pointer to print to + * \param nbuf buffer into which the output is written + * \param offset of where to start writting into the buffer + * \param max_size the size of the output buffer * \param buf buffer to print from * \param buflen length of the input buffer */ -void PrintRawLineHexFp(FILE *fp, uint8_t *buf, uint32_t buflen) +void PrintBufferRawLineHex(char *nbuf, int *offset, int max_size, uint8_t *buf, uint32_t buflen) { -#define BUFFER_LENGTH 2048 - char nbuf[BUFFER_LENGTH] = ""; - uint32_t offset = 0; uint32_t u = 0; for (u = 0; u < buflen; u++) { - PrintBufferData(nbuf, &offset, BUFFER_LENGTH, "%02X ", buf[u]); + PrintBufferData(nbuf, offset, max_size, "%02X ", buf[u]); } - fprintf(fp, "%s", nbuf); } /** diff --git a/src/util-print.h b/src/util-print.h index 111cfdac0f..64a275215b 100644 --- a/src/util-print.h +++ b/src/util-print.h @@ -41,7 +41,7 @@ } \ } while (0) -void PrintRawLineHexFp(FILE *, uint8_t *, uint32_t); +void PrintBufferRawLineHex(char *, int *,int, uint8_t *, uint32_t); void PrintRawUriFp(FILE *, uint8_t *, uint32_t); void PrintRawUriBuf(char *, uint32_t *, uint32_t, uint8_t *, uint32_t);