[Oisf-devel] [PATCH] Custom logging feature for log-httplog

I. Sanchez sanchezmartin.ji at gmail.com
Wed Jul 4 16:33:34 UTC 2012


This patch adds support for custom http logging using a format syntax
inspired by Apache mod_log_config. The following commented out example is
added to the suricata.yaml configuration file.

#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"

I have left the previous code of log_httplog almost untouched and by
default suricata will behave as usual using the old format.

The new format will only be activated if the "custom: yes" is specified in
the configuration file.

In addition to %h, %H, %m, %u, %i, %C, %s, %o and %B - almost - as
described by mod_log_config (
http://httpd.apache.org/docs/2.0/mod/mod_log_config.html), I have added %z,
%a, %p, %A and %P for the precision time, IPs and ports.


---
 src/log-httplog.c |  323 ++++++++++++++++++++++++++++++
++++++++++++++++-------
 suricata.yaml.in  |    2 +
 2 files changed, 282 insertions(+), 43 deletions(-)

diff --git a/src/log-httplog.c b/src/log-httplog.c
index aeeea50..bf5056c 100644
--- a/src/log-httplog.c
+++ b/src/log-httplog.c
@@ -19,6 +19,7 @@
  * \file
  *
  * \author Victor Julien <victor at inliniac.net>
+ * \author Ignacio Sanchez <sanchezmartin.ji at gmail.com>
  *
  * 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]; /** Array of
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;
@@ -122,6 +154,149 @@ 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,50 +455,54 @@ 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, "<hostname unknown>");
-        }
-        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, "<hostname unknown>");
+            }
+            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, "<useragent unknown>");
-        }
-        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, "<useragent unknown>");
+            }
+            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 ++;

         SCMutexLock(&hlog->file_ctx->fp_mutex);
@@ -430,6 +609,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 +629,70 @@ 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 (*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-1;
+                    np=NULL; /* End */
+                }else{
+                    n=np-p;
+                }
+
 strncpy(httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data,p,n);
+                httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data[n]='\0';
+                p=np;
+            } else {
+                /* Non Literal found in format string */
+                p++;
+                if (*p=='{'){ /* Simple format char */
+                    np=strchr(p,'}');
+                     if (np!=NULL && np-p>1){
+                        p++;
+                        n=np-p;
+
 strncpy(httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data,p,n);
+
 httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data[n]='\0';
+                        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;
+
 strcpy(httplog_ctx->cf_nodes[httplog_ctx->cf_n]->data,"%");
+                }
+                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 +709,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 7cfe24f..4daaa99 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.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openinfosecfoundation.org/pipermail/oisf-devel/attachments/20120704/9d89f757/attachment-0002.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0001-Custom-logging-feature-for-log-httplog.patch
Type: application/octet-stream
Size: 18690 bytes
Desc: not available
URL: <http://lists.openinfosecfoundation.org/pipermail/oisf-devel/attachments/20120704/9d89f757/attachment-0002.obj>


More information about the Oisf-devel mailing list