From b057a20f10367a2fd0b688841950de07b490bed5 Mon Sep 17 00:00:00 2001 From: Ignacio Sanchez Date: Wed, 22 Aug 2012 16:38:32 +0100 Subject: [PATCH] Custom logging feature for log-httplog --- src/log-httplog.c | 346 ++++++++++++++++++++++++++++++++++++++++------ suricata.yaml.in | 2 + 2 files changed, 304 insertions(+), 44 deletions(-) diff --git a/src/log-httplog.c b/src/log-httplog.c index aeeea50fc1..a8bd96c436 100644 --- a/src/log-httplog.c +++ b/src/log-httplog.c @@ -19,6 +19,7 @@ * \file * * \author Victor Julien + * \author Ignacio Sanchez * * Implements http logging portion of the engine. */ @@ -96,13 +97,44 @@ void TmModuleLogHttpLogIPv6Register (void) { tmm_modules[TMM_LOGHTTPLOG6].RegisterTests = NULL; } +#define LOG_HTTP_MAXN_NODES 64 +#define LOG_HTTP_NODE_STRLEN 256 + +#define TIMESTAMP_DEFAULT_FORMAT "%b %d, %Y; %H:%M:%S" +#define LOG_HTTP_CF_NONE "-" +#define LOG_HTTP_CF_LITERAL '%' +#define LOG_HTTP_CF_REQUEST_HOST 'h' +#define LOG_HTTP_CF_REQUEST_PROTOCOL 'H' +#define LOG_HTTP_CF_REQUEST_METHOD 'm' +#define LOG_HTTP_CF_REQUEST_URI 'u' +#define LOG_HTTP_CF_REQUEST_TIME 't' +#define LOG_HTTP_CF_REQUEST_HEADER 'i' +#define LOG_HTTP_CF_REQUEST_COOKIE 'C' +#define LOG_HTTP_CF_RESPONSE_STATUS 's' +#define LOG_HTTP_CF_RESPONSE_HEADER 'o' +#define LOG_HTTP_CF_RESPONSE_LEN 'B' +#define LOG_HTTP_CF_TIMESTAMP 't' +#define LOG_HTTP_CF_TIMESTAMP_U 'z' +#define LOG_HTTP_CF_CLIENT_IP 'a' +#define LOG_HTTP_CF_SERVER_IP 'A' +#define LOG_HTTP_CF_CLIENT_PORT 'p' +#define LOG_HTTP_CF_SERVER_PORT 'P' + +typedef struct LogHttpCustomFormatNode_ { + uint32_t type; /** Node format type. ie: LOG_HTTP_CF_LITERAL, LOG_HTTP_CF_REQUEST_HEADER */ + char data[LOG_HTTP_NODE_STRLEN]; /** optional data. ie: http header name */ +} LogHttpCustomFormatNode; + typedef struct LogHttpFileCtx_ { LogFileCtx *file_ctx; uint32_t flags; /** Store mode */ + uint32_t cf_n; /** Total number of custom string format nodes */ + LogHttpCustomFormatNode *cf_nodes[LOG_HTTP_MAXN_NODES]; /** Custom format string nodes */ } LogHttpFileCtx; #define LOG_HTTP_DEFAULT 0 #define LOG_HTTP_EXTENDED 1 +#define LOG_HTTP_CUSTOM 2 typedef struct LogHttpLogThread_ { LogHttpFileCtx *httplog_ctx; @@ -112,7 +144,8 @@ typedef struct LogHttpLogThread_ { MemBuffer *buffer; } LogHttpLogThread; -static void CreateTimeString (const struct timeval *ts, char *str, size_t size) { +static void CreateTimeString (const struct timeval *ts, char *str, size_t size) +{ time_t time = ts->tv_sec; struct tm local_tm; struct tm *t = (struct tm *)SCLocalTime(time, &local_tm); @@ -122,6 +155,162 @@ static void CreateTimeString (const struct timeval *ts, char *str, size_t size) t->tm_min, t->tm_sec, (uint32_t) ts->tv_usec); } +/* Custom format logging */ +static void LogHttpLogCustom(LogHttpLogThread *aft, htp_tx_t *tx, const struct timeval *ts, + char *srcip, Port sp, char *dstip, Port dp) +{ + LogHttpFileCtx *httplog_ctx = aft->httplog_ctx; + uint32_t i; + char buf[128]; + + htp_header_t *h_request_hdr = NULL; + htp_header_t *h_response_hdr = NULL; + + time_t time = ts->tv_sec; + struct tm local_tm; + struct tm *timestamp = (struct tm *)SCLocalTime(time, &local_tm); + + for (i = 0; i < httplog_ctx->cf_n; i++) { + switch (httplog_ctx->cf_nodes[i]->type){ + case LOG_HTTP_CF_LITERAL: + /* LITERAL */ + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)httplog_ctx->cf_nodes[i]->data, + strlen(httplog_ctx->cf_nodes[i]->data)); + break; + case LOG_HTTP_CF_TIMESTAMP: + /* TIMESTAMP */ + if (httplog_ctx->cf_nodes[i]->data == '\0') { + strftime(buf, 62, TIMESTAMP_DEFAULT_FORMAT, timestamp); + } else { + strftime(buf, 62, httplog_ctx->cf_nodes[i]->data, timestamp); + } + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)buf,strlen(buf)); + break; + case LOG_HTTP_CF_TIMESTAMP_U: + /* TIMESTAMP USECONDS */ + snprintf(buf, 62, "%06u", (unsigned int) ts->tv_usec); + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)buf,strlen(buf)); + break; + case LOG_HTTP_CF_CLIENT_IP: + /* CLIENT IP ADDRESS */ + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)srcip,strlen(srcip)); + break; + case LOG_HTTP_CF_SERVER_IP: + /* SERVER IP ADDRESS */ + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)dstip,strlen(dstip)); + break; + case LOG_HTTP_CF_CLIENT_PORT: + /* CLIENT PORT */ + MemBufferWriteString(aft->buffer, "%" PRIu16 "", sp); + break; + case LOG_HTTP_CF_SERVER_PORT: + /* SERVER PORT */ + MemBufferWriteString(aft->buffer, "%" PRIu16 "", dp); + break; + case LOG_HTTP_CF_REQUEST_METHOD: + /* METHOD */ + if (tx->request_method != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(tx->request_method), + bstr_len(tx->request_method)); + } else { + MemBufferWriteString(aft->buffer, LOG_HTTP_CF_NONE); + } + break; + case LOG_HTTP_CF_REQUEST_URI: + /* URI */ + if (tx->request_uri != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(tx->request_uri), + bstr_len(tx->request_uri)); + } else { + MemBufferWriteString(aft->buffer, LOG_HTTP_CF_NONE); + } + break; + case LOG_HTTP_CF_REQUEST_HOST: + /* HOSTNAME */ + if (tx->parsed_uri != NULL && tx->parsed_uri->hostname != NULL) + { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(tx->parsed_uri->hostname), + bstr_len(tx->parsed_uri->hostname)); + } else { + MemBufferWriteString(aft->buffer, LOG_HTTP_CF_NONE); + } + break; + case LOG_HTTP_CF_REQUEST_PROTOCOL: + /* PROTOCOL */ + if (tx->request_protocol != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(tx->request_protocol), + bstr_len(tx->request_protocol)); + } else { + MemBufferWriteString(aft->buffer, LOG_HTTP_CF_NONE); + } + break; + case LOG_HTTP_CF_REQUEST_HEADER: + /* REQUEST HEADER */ + if (tx->request_headers != NULL) { + h_request_hdr = table_getc(tx->request_headers, httplog_ctx->cf_nodes[i]->data); + } + if (h_request_hdr != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(h_request_hdr->value), + bstr_len(h_request_hdr->value)); + } else { + MemBufferWriteString(aft->buffer, LOG_HTTP_CF_NONE); + } + break; + case LOG_HTTP_CF_RESPONSE_STATUS: + /* RESPONSE STATUS */ + if (tx->response_status != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(tx->response_status), + bstr_len(tx->response_status)); + /* Redirect? */ + if ((tx->response_status_number > 300) && ((tx->response_status_number) < 303)){ + htp_header_t *h_location = table_getc(tx->response_headers, "location"); + if (h_location != NULL) { + MemBufferWriteString(aft->buffer, "("); + + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(h_location->value), + bstr_len(h_location->value)); + MemBufferWriteString(aft->buffer, ")"); + } + } + } else { + MemBufferWriteString(aft->buffer, LOG_HTTP_CF_NONE); + } + break; + case LOG_HTTP_CF_RESPONSE_HEADER: + /* RESPONSE HEADER */ + if (tx->response_headers != NULL) { + h_response_hdr = table_getc(tx->response_headers, + httplog_ctx->cf_nodes[i]->data); + } + if (h_response_hdr != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, + aft->buffer->size, (uint8_t *)bstr_ptr(h_response_hdr->value), + bstr_len(h_response_hdr->value)); + } else { + MemBufferWriteString(aft->buffer, LOG_HTTP_CF_NONE); + } + break; + case LOG_HTTP_CF_RESPONSE_LEN: + /* RESPONSE LEN */ + MemBufferWriteString(aft->buffer, "%"PRIuMAX"", (uintmax_t)tx->response_message_len); + break; + } + } + MemBufferWriteString(aft->buffer, "\n"); +} + static void LogHttpLogExtended(LogHttpLogThread *aft, htp_tx_t *tx) { MemBufferWriteString(aft->buffer, " [**] "); @@ -280,49 +469,53 @@ static TmEcode LogHttpLogIPWrapper(ThreadVars *tv, Packet *p, void *data, Packet /* reset */ MemBufferReset(aft->buffer); - /* time */ - MemBufferWriteString(aft->buffer, "%s ", timebuf); - - /* hostname */ - if (tx->parsed_uri != NULL && - tx->parsed_uri->hostname != NULL) - { - PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, aft->buffer->size, - (uint8_t *)bstr_ptr(tx->parsed_uri->hostname), - bstr_len(tx->parsed_uri->hostname)); + if (hlog->flags & LOG_HTTP_CUSTOM) { + LogHttpLogCustom(aft, tx, &p->ts, srcip, sp, dstip, dp); } else { - MemBufferWriteString(aft->buffer, ""); - } - MemBufferWriteString(aft->buffer, " [**] "); + /* time */ + MemBufferWriteString(aft->buffer, "%s ", timebuf); - /* uri */ - if (tx->request_uri != NULL) { - PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, aft->buffer->size, - (uint8_t *)bstr_ptr(tx->request_uri), - bstr_len(tx->request_uri)); - } - MemBufferWriteString(aft->buffer, " [**] "); + /* hostname */ + if (tx->parsed_uri != NULL && + tx->parsed_uri->hostname != NULL) + { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, aft->buffer->size, + (uint8_t *)bstr_ptr(tx->parsed_uri->hostname), + bstr_len(tx->parsed_uri->hostname)); + } else { + MemBufferWriteString(aft->buffer, ""); + } + MemBufferWriteString(aft->buffer, " [**] "); - /* user agent */ - htp_header_t *h_user_agent = NULL; - if (tx->request_headers != NULL) { - h_user_agent = table_getc(tx->request_headers, "user-agent"); - } - if (h_user_agent != NULL) { - PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, aft->buffer->size, - (uint8_t *)bstr_ptr(h_user_agent->value), - bstr_len(h_user_agent->value)); - } else { - MemBufferWriteString(aft->buffer, ""); - } - if (hlog->flags & LOG_HTTP_EXTENDED) { - LogHttpLogExtended(aft, tx); - } + /* uri */ + if (tx->request_uri != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, aft->buffer->size, + (uint8_t *)bstr_ptr(tx->request_uri), + bstr_len(tx->request_uri)); + } + MemBufferWriteString(aft->buffer, " [**] "); - /* ip/tcp header info */ - MemBufferWriteString(aft->buffer, - " [**] %s:%" PRIu16 " -> %s:%" PRIu16 "\n", - srcip, sp, dstip, dp); + /* user agent */ + htp_header_t *h_user_agent = NULL; + if (tx->request_headers != NULL) { + h_user_agent = table_getc(tx->request_headers, "user-agent"); + } + if (h_user_agent != NULL) { + PrintRawUriBuf((char *)aft->buffer->buffer, &aft->buffer->offset, aft->buffer->size, + (uint8_t *)bstr_ptr(h_user_agent->value), + bstr_len(h_user_agent->value)); + } else { + MemBufferWriteString(aft->buffer, ""); + } + if (hlog->flags & LOG_HTTP_EXTENDED) { + LogHttpLogExtended(aft, tx); + } + + /* ip/tcp header info */ + MemBufferWriteString(aft->buffer, + " [**] %s:%" PRIu16 " -> %s:%" PRIu16 "\n", + srcip, sp, dstip, dp); + } aft->uri_cnt ++; @@ -430,6 +623,8 @@ void LogHttpLogExitPrintStats(ThreadVars *tv, void *data) { OutputCtx *LogHttpLogInitCtx(ConfNode *conf) { LogFileCtx* file_ctx = LogFileNewCtx(); + const char *p, *np; + uint32_t n; if(file_ctx == NULL) { SCLogError(SC_ERR_HTTP_LOG_GENERIC, "couldn't create new file_ctx"); return NULL; @@ -448,18 +643,77 @@ OutputCtx *LogHttpLogInitCtx(ConfNode *conf) memset(httplog_ctx, 0x00, sizeof(LogHttpFileCtx)); httplog_ctx->file_ctx = file_ctx; + httplog_ctx->cf_n=0; const char *extended = ConfNodeLookupChildValue(conf, "extended"); - if (extended == NULL) { - httplog_ctx->flags |= LOG_HTTP_DEFAULT; + const char *custom = ConfNodeLookupChildValue(conf, "custom"); + const char *customformat = ConfNodeLookupChildValue(conf, "customformat"); + + /* If custom logging format is selected, lets parse it */ + if (custom != NULL && customformat != NULL && ConfValIsTrue(custom)) { + p=customformat; + httplog_ctx->flags |= LOG_HTTP_CUSTOM; + for (httplog_ctx->cf_n = 0; httplog_ctx->cf_n < LOG_HTTP_MAXN_NODES-1 && p && *p != '\0'; + httplog_ctx->cf_n++){ + httplog_ctx->cf_nodes[httplog_ctx->cf_n] = SCMalloc(sizeof(LogHttpCustomFormatNode)); + if (httplog_ctx->cf_nodes[httplog_ctx->cf_n] == NULL) { + for (n = 0; n < httplog_ctx->cf_n; n++) { + SCFree(httplog_ctx->cf_nodes[n]); + } + LogFileFreeCtx(file_ctx); + SCFree(httplog_ctx); + return NULL; + } + if (*p != '%'){ + /* Literal found in format string */ + httplog_ctx->cf_nodes[httplog_ctx->cf_n]->type = LOG_HTTP_CF_LITERAL; + np = strchr(p, '%'); + if (np == NULL){ + n = LOG_HTTP_NODE_STRLEN-2; + np = NULL; /* End */ + }else{ + n = np-p; + } + strlcpy(httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data,p,n+1); + p = np; + } else { + /* Non Literal found in format string */ + p++; + if (*p == '{') { /* Simple format char */ + np = strchr(p, '}'); + if (np != NULL && np-p > 1 && np-p < LOG_HTTP_NODE_STRLEN-2) { + p++; + n = np-p; + strlcpy(httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data, p, n+1); + p = np; + } + p++; + } else { + httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data[0] = '\0'; + } + httplog_ctx->cf_nodes[httplog_ctx->cf_n]->type = *p; + if (*p == '%'){ + httplog_ctx->cf_nodes[httplog_ctx->cf_n]->type = LOG_HTTP_CF_LITERAL; + strlcpy(httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data, "%", 2); + } + p++; + } + } } else { - if (ConfValIsTrue(extended)) { - httplog_ctx->flags |= LOG_HTTP_EXTENDED; + if (extended == NULL) { + httplog_ctx->flags |= LOG_HTTP_DEFAULT; + } else { + if (ConfValIsTrue(extended)) { + httplog_ctx->flags |= LOG_HTTP_EXTENDED; + } } } OutputCtx *output_ctx = SCCalloc(1, sizeof(OutputCtx)); if (output_ctx == NULL) { + for (n = 0; n < httplog_ctx->cf_n; n++) { + SCFree(httplog_ctx->cf_nodes[n]); + } LogFileFreeCtx(file_ctx); SCFree(httplog_ctx); return NULL; @@ -476,6 +730,10 @@ OutputCtx *LogHttpLogInitCtx(ConfNode *conf) static void LogHttpLogDeInitCtx(OutputCtx *output_ctx) { LogHttpFileCtx *httplog_ctx = (LogHttpFileCtx *)output_ctx->data; + uint32_t i; + for (i = 0; i < httplog_ctx->cf_n; i++) { + SCFree(httplog_ctx->cf_nodes[i]); + } LogFileFreeCtx(httplog_ctx->file_ctx); SCFree(httplog_ctx); SCFree(output_ctx); diff --git a/suricata.yaml.in b/suricata.yaml.in index 73d1086ed5..99c6be8c25 100644 --- a/suricata.yaml.in +++ b/suricata.yaml.in @@ -71,6 +71,8 @@ outputs: filename: http.log append: yes #extended: yes # enable this for extended logging information + #custom: yes # enabled the custom logging format (defined by customformat) + #customformat: "%{%D-%H:%M:%S}t.%z %{X-Forwarded-For}i %H %m %h %u %s %B %a:%p -> %A:%P" #filetype: regular # 'regular', 'unix_stream' or 'unix_dgram' # a line based log to used with pcap file study.