log: tls custom format log

diff --git a/doc/userguide/output/custom-tls-logging.rst b/doc/userguide/output/custom-tls-logging.rst
new file mode 100644 (file)
index 0000000..b7031e9
--- /dev/null
+++ b/doc/userguide/output/custom-tls-logging.rst
@@ -0,0 +1,43 @@
+Custom tls logging
+===================
+
+In your Suricata.yaml, find the tls-log section and edit as follows:
+
+::
+
+
+  - tls-log:
+      enabled: yes      # Log TLS connections.
+      filename: tls.log # File to store TLS logs.
+      append: yes
+      custom: yes       # enabled the custom logging format (defined by customformat)
+      customformat: "%{%D-%H:%M:%S}t.%z %a:%p -> %A:%P %n %n %d %D"
+
+And in your tls.log file you would get the following, for example:
+
+::
+
+ 12/03/16-19:20:14.85859 10.10.10.4:58274 -> 192.0.78.24:443 VERSION='TLS 1.2' suricata-ids.org NOTBEFORE='2016-10-27T20:36:00' NOTAFTER='2017-01-25T20:36:00'
+
+::
+ 12/03/16-19:20:20.36849 10.10.10.4:39472 -> 192.30.253.113:443 VERSION='TLS 1.2' github.com NOTBEFORE='2016-03-10T00:00:00' NOTAFTER='2018-05-17T12:00:00'
+
+
+The list of supported format strings is the following:
+
+* %n - client SNI
+* %v - TLS/SSL version
+* %d - certificate date not before
+* %D - certificate date not after
+* %f - certificate fingerprint SHA1
+* %s - certificate subject
+* %i - certificate issuer dn
+* %E - extended format
+* %{strftime_format}t - timestamp of the TLS transaction in the selected strftime format. ie: 08/28/12-22:14:30
+* %z - precision time in useconds. ie: 693856
+* %a - client IP address
+* %p - client port number
+* %A - server IP address
+* %P - server port number
+
+Any non printable character will be represented by its byte value in hexadecimal format (\|XX\|, where XX is the hex code)

diff --git a/doc/userguide/output/index.rst b/doc/userguide/output/index.rst
index e0738e01f3f0c71c5f5229896c9634fd6f215168..3c1666c100c1daed6d1bd7b971cdbb383212d587 100644 (file)
--- a/doc/userguide/output/index.rst
+++ b/doc/userguide/output/index.rst
@@ -7,3 +7,4 @@ Output
    lua-output
    syslog-alerting-comp
    custom-http-logging
+   custom-tls-logging

diff --git a/src/log-cf-common.c b/src/log-cf-common.c
index c85703f8afa400863c2b213c060a6c17fb05d288..9a4efb3219c4c79cd7315a87e1440ac6d13ad686 100644 (file)
--- a/src/log-cf-common.c
+++ b/src/log-cf-common.c
@@ -36,14 +36,11 @@
  */
 LogCustomFormatNode * LogCustomFormatNodeAlloc()
 {
-    LogCustomFormatNode * node = SCMalloc(sizeof(LogCustomFormatNode));
+    LogCustomFormatNode * node = SCCalloc(1, sizeof(LogCustomFormatNode));
     if (unlikely(node == NULL)) {
         SCLogError(SC_ERR_MEM_ALLOC, "Failed to alloc custom format node");
         return NULL;
     }
-    memset(node, '\0', sizeof(LogCustomFormatNode));
-    memset(node->data, '\0', LOG_NODE_STRLEN);
-
     return node;
 }
 
@@ -54,13 +51,11 @@ LogCustomFormatNode * LogCustomFormatNodeAlloc()
  */
 LogCustomFormat * LogCustomFormatAlloc()
 {
-    LogCustomFormat * cf = SCMalloc(sizeof(LogCustomFormat));
+    LogCustomFormat * cf = SCCalloc(1, sizeof(LogCustomFormat));
     if (unlikely(cf == NULL)) {
         SCLogError(SC_ERR_MEM_ALLOC, "Failed to alloc custom format");
         return NULL;
     }
-    memset(cf, '\0', sizeof(LogCustomFormat));
-
     return cf;
 }
 
@@ -172,14 +167,12 @@ int LogCustomFormatParse(LogCustomFormat *cf, const char *format)
             p++;
         }
         LogCustomFormatAddNode(cf, node);
-
     }
     return 1;
 
 parsererror:
     LogCustomFormatNodeFree(node);
     return 0;
-
 }
 
 /**
@@ -230,7 +223,6 @@ void LogCustomFormatWriteTimestamp(MemBuffer *buffer, const char *fmt, const str
                    buffer->size, (uint8_t *)buf,strlen(buf));
 }
 
-
 #ifdef UNITTESTS
 /**
  * \internal
@@ -238,7 +230,6 @@ void LogCustomFormatWriteTimestamp(MemBuffer *buffer, const char *fmt, const str
  */
 static int LogCustomFormatTest01(void)
 {
-
     struct tm tm;
     tm.tm_sec = 0;
     tm.tm_min = 30;

diff --git a/src/log-cf-common.h b/src/log-cf-common.h
index ad66754830e83b4326a9a7691dad70d543cdb279..f871a3de35d2a2d1f39d4622931e79cd6412b800 100644 (file)
--- a/src/log-cf-common.h
+++ b/src/log-cf-common.h
@@ -47,9 +47,18 @@
 
 /* Line log common separators **/
 #define LOG_CF_STAR_SEPARATOR "[**]"
+#define LOG_CF_SPACE_SEPARATOR " "
+#define LOG_CF_UNKNOWN_VALUE "-"
+
 #define LOG_CF_WRITE_STAR_SEPATATOR(buffer) \
     MemBufferWriteString(buffer, LOG_CF_STAR_SEPARATOR);
 
+#define LOG_CF_WRITE_SPACE_SEPARATOR(buffer) \
+    MemBufferWriteString(buffer, LOG_CF_SPACE_SEPARATOR);
+
+#define LOG_CF_WRITE_UNKNOWN_VALUE(buffer) \
+    MemBufferWriteString(buffer, LOG_CF_UNKNOWN_VALUE);
+
 /* Include */
 #include "suricata-common.h"
 #include "util-buffer.h"

diff --git a/src/log-tlslog.c b/src/log-tlslog.c
index 9e70149f03f876aea3e208b3175691b1a0886aa8..97158b9daf12cf360699164f07b0b8d7052d979a 100644 (file)
--- a/src/log-tlslog.c
+++ b/src/log-tlslog.c
@@ -21,6 +21,7 @@
  * \author Roliers Jean-Paul <popof.fpn@gmail.co>
  * \author Eric Leblond <eric@regit.org>
  * \author Victor Julien <victor@inliniac.net>
+ * \author Paulo Pacheco <fooinha@gmail.com>
  *
  * Implements TLS logging portion of the engine. The TLS logger is
  * implemented as a packet logger, as the TLS parser is not transaction
@@ -53,6 +54,7 @@
 #include "util-logopenfile.h"
 #include "util-crypt.h"
 #include "util-time.h"
+#include "log-cf-common.h"
 
 #define DEFAULT_LOG_FILENAME "tls.log"
 
@@ -63,10 +65,21 @@
 
 #define LOG_TLS_DEFAULT     0
 #define LOG_TLS_EXTENDED    1
+#define LOG_TLS_CUSTOM      2
+
+#define LOG_TLS_CF_VERSION 'v'
+#define LOG_TLS_CF_DATE_NOT_BEFORE 'd'
+#define LOG_TLS_CF_DATE_NOT_AFTER 'D'
+#define LOG_TLS_CF_SHA1 'f'
+#define LOG_TLS_CF_SNI 'n'
+#define LOG_TLS_CF_SUBJECT 's'
+#define LOG_TLS_CF_ISSUER 'i'
+#define LOG_TLS_CF_EXTENDED 'E'
 
 typedef struct LogTlsFileCtx_ {
     LogFileCtx *file_ctx;
     uint32_t flags; /** Store mode */
+    LogCustomFormat *cf;
 } LogTlsFileCtx;
 
 typedef struct LogTlsLogThread_ {
@@ -78,58 +91,74 @@ typedef struct LogTlsLogThread_ {
     MemBuffer *buffer;
 } LogTlsLogThread;
 
-static void LogTlsLogExtended(LogTlsLogThread *aft, SSLState * state)
+static void LogTlsLogVersion(MemBuffer *buffer, uint16_t version)
 {
-    if (state->server_connp.cert0_fingerprint != NULL) {
-        MemBufferWriteString(aft->buffer, " SHA1='%s'", state->server_connp.cert0_fingerprint);
-    }
-    if (state->client_connp.sni != NULL) {
-        MemBufferWriteString(aft->buffer, " SNI='%s'", state->client_connp.sni);
-    }
-    if (state->server_connp.cert0_serial != NULL) {
-        MemBufferWriteString(aft->buffer, " SERIAL='%s'", state->server_connp.cert0_serial);
-    }
-    switch (state->server_connp.version) {
+    switch (version) {
         case TLS_VERSION_UNKNOWN:
-            MemBufferWriteString(aft->buffer, " VERSION='UNDETERMINED'");
+            MemBufferWriteString(buffer, "VERSION='UNDETERMINED'");
             break;
         case SSL_VERSION_2:
-            MemBufferWriteString(aft->buffer, " VERSION='SSLv2'");
+            MemBufferWriteString(buffer, "VERSION='SSLv2'");
             break;
         case SSL_VERSION_3:
-            MemBufferWriteString(aft->buffer, " VERSION='SSLv3'");
+            MemBufferWriteString(buffer, "VERSION='SSLv3'");
             break;
         case TLS_VERSION_10:
-            MemBufferWriteString(aft->buffer, " VERSION='TLSv1'");
+            MemBufferWriteString(buffer, "VERSION='TLSv1'");
             break;
         case TLS_VERSION_11:
-            MemBufferWriteString(aft->buffer, " VERSION='TLS 1.1'");
+            MemBufferWriteString(buffer, "VERSION='TLS 1.1'");
             break;
         case TLS_VERSION_12:
-            MemBufferWriteString(aft->buffer, " VERSION='TLS 1.2'");
+            MemBufferWriteString(buffer, "VERSION='TLS 1.2'");
             break;
         default:
-            MemBufferWriteString(aft->buffer, " VERSION='0x%04x'",
-                                 state->server_connp.version);
+            MemBufferWriteString(buffer, "VERSION='0x%04x'", version);
             break;
     }
+}
+
+static void LogTlsLogDate(MemBuffer *buffer, const char *title, time_t *date)
+{
+    char timebuf[64] = {0};
+    struct timeval tv;
+    tv.tv_sec = *date;
+    tv.tv_usec = 0;
+    CreateUtcIsoTimeString(&tv, timebuf, sizeof(timebuf));
+    MemBufferWriteString(buffer, "%s='%s'", title, timebuf);
+}
+
+static void LogTlsLogString(MemBuffer *buffer, const char *title, const char *value)
+{
+    MemBufferWriteString(buffer, "%s='%s'", title, value);
+}
+
+static void LogTlsLogExtended(LogTlsLogThread *aft, SSLState * state)
+{
+    if (state->server_connp.cert0_fingerprint != NULL) {
+        LOG_CF_WRITE_SPACE_SEPARATOR(aft->buffer);
+        LogTlsLogString(aft->buffer, "SHA1", state->server_connp.cert0_fingerprint);
+    }
+    if (state->client_connp.sni != NULL) {
+        LOG_CF_WRITE_SPACE_SEPARATOR(aft->buffer);
+        LogTlsLogString(aft->buffer, "SNI", state->client_connp.sni);
+    }
+    if (state->server_connp.cert0_serial != NULL) {
+        LOG_CF_WRITE_SPACE_SEPARATOR(aft->buffer);
+        LogTlsLogString(aft->buffer, "SERIAL", state->server_connp.cert0_serial);
+    }
+
+    LOG_CF_WRITE_SPACE_SEPARATOR(aft->buffer);
+    LogTlsLogVersion(aft->buffer, state->server_connp.version);
+
     if (state->server_connp.cert0_not_before != 0) {
-        char timebuf[64];
-        struct timeval tv;
-        tv.tv_sec = state->server_connp.cert0_not_before;
-        tv.tv_usec = 0;
-        CreateUtcIsoTimeString(&tv, timebuf, sizeof(timebuf));
-        MemBufferWriteString(aft->buffer, " NOTBEFORE='%s'", timebuf);
+        LOG_CF_WRITE_SPACE_SEPARATOR(aft->buffer);
+        LogTlsLogDate(aft->buffer, "NOTBEFORE", &state->server_connp.cert0_not_before);
     }
     if (state->server_connp.cert0_not_after != 0) {
-        char timebuf[64];
-        struct timeval tv;
-        tv.tv_sec = state->server_connp.cert0_not_after;
-        tv.tv_usec = 0;
-        CreateUtcIsoTimeString(&tv, timebuf, sizeof(timebuf));
-        MemBufferWriteString(aft->buffer, " NOTAFTER='%s'", timebuf);
+        LOG_CF_WRITE_SPACE_SEPARATOR(aft->buffer);
+        LogTlsLogDate(aft->buffer, "NOTAFTER", &state->server_connp.cert0_not_after);
     }
-    MemBufferWriteString(aft->buffer, "\n");
 }
 
 int TLSGetIPInformations(const Packet *p, char* srcip, size_t srcip_len,
@@ -215,6 +244,7 @@ static void LogTlsLogDeInitCtx(OutputCtx *output_ctx)
 {
     LogTlsFileCtx *tlslog_ctx = (LogTlsFileCtx *) output_ctx->data;
     LogFileFreeCtx(tlslog_ctx->file_ctx);
+    LogCustomFormatFree(tlslog_ctx->cf);
     SCFree(tlslog_ctx);
     SCFree(output_ctx);
 }
@@ -253,11 +283,28 @@ static OutputCtx *LogTlsLogInitCtx(ConfNode *conf)
     tlslog_ctx->file_ctx = file_ctx;
 
     const char *extended = ConfNodeLookupChildValue(conf, "extended");
-    if (extended == NULL) {
-        tlslog_ctx->flags |= LOG_TLS_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)) {
+        tlslog_ctx->cf = LogCustomFormatAlloc();
+        if (!tlslog_ctx->cf) {
+            goto tlslog_error;
+        }
+
+        tlslog_ctx->flags |= LOG_TLS_CUSTOM;
+        /* Parsing */
+        if ( ! LogCustomFormatParse(tlslog_ctx->cf, customformat)) {
+            goto parser_error;
+        }
     } else {
-        if (ConfValIsTrue(extended)) {
-            tlslog_ctx->flags |= LOG_TLS_EXTENDED;
+        if (extended == NULL) {
+            tlslog_ctx->flags |= LOG_TLS_DEFAULT;
+        } else {
+            if (ConfValIsTrue(extended)) {
+                tlslog_ctx->flags |= LOG_TLS_EXTENDED;
+            }
         }
     }
 
@@ -273,14 +320,119 @@ static OutputCtx *LogTlsLogInitCtx(ConfNode *conf)
     AppLayerParserRegisterLogger(IPPROTO_TCP, ALPROTO_TLS);
 
     return output_ctx;
-
+parser_error:
+    SCLogError(SC_ERR_INVALID_ARGUMENT,"Syntax error in custom tls log format string.");
 tlslog_error:
+    LogCustomFormatFree(tlslog_ctx->cf);
     SCFree(tlslog_ctx);
 filectx_error:
     LogFileFreeCtx(file_ctx);
     return NULL;
 }
 
+/* Custom format logging */
+static void LogTlsLogCustom(LogTlsLogThread *aft, SSLState *ssl_state, const struct timeval *ts,
+                            char *srcip, Port sp, char *dstip, Port dp)
+{
+    LogTlsFileCtx *tlslog_ctx = aft->tlslog_ctx;
+    uint32_t i;
+    char buf[6];
+
+    for (i = 0; i < tlslog_ctx->cf->cf_n; i++) {
+
+        LogCustomFormatNode * node = tlslog_ctx->cf->cf_nodes[i];
+        if (! node) /* Should never happen */
+            continue;
+
+        switch (node->type){
+            case LOG_CF_LITERAL:
+            /* LITERAL */
+                MemBufferWriteString(aft->buffer, "%s", node->data);
+                break;
+            case LOG_CF_TIMESTAMP:
+            /* TIMESTAMP */
+                LogCustomFormatWriteTimestamp(aft->buffer, node->data, ts);
+                break;
+            case LOG_CF_TIMESTAMP_U:
+            /* TIMESTAMP USECONDS */
+                snprintf(buf, 6, "%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_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_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_CF_CLIENT_PORT:
+            /* CLIENT PORT */
+                MemBufferWriteString(aft->buffer, "%" PRIu16 "", sp);
+                break;
+            case LOG_CF_SERVER_PORT:
+            /* SERVER PORT */
+                MemBufferWriteString(aft->buffer, "%" PRIu16 "", dp);
+                break;
+            case LOG_TLS_CF_VERSION:
+                LogTlsLogVersion(aft->buffer, ssl_state->server_connp.version);
+                break;
+            case LOG_TLS_CF_DATE_NOT_BEFORE:
+                LogTlsLogDate(aft->buffer, "NOTBEFORE", &ssl_state->server_connp.cert0_not_before);
+                break;
+            case LOG_TLS_CF_DATE_NOT_AFTER:
+                LogTlsLogDate(aft->buffer, "NOTAFTER", &ssl_state->server_connp.cert0_not_after);
+                break;
+            case LOG_TLS_CF_SHA1:
+                if (ssl_state->server_connp.cert0_fingerprint != NULL) {
+                    MemBufferWriteString(aft->buffer, "%s",
+                                         ssl_state->server_connp.cert0_fingerprint);
+                } else {
+                    LOG_CF_WRITE_UNKNOWN_VALUE(aft->buffer);
+                }
+                break;
+            case LOG_TLS_CF_SNI:
+                if (ssl_state->client_connp.sni != NULL) {
+                    MemBufferWriteString(aft->buffer, "%s",
+                                         ssl_state->client_connp.sni);
+                } else {
+                    LOG_CF_WRITE_UNKNOWN_VALUE(aft->buffer);
+                }
+                break;
+            case LOG_TLS_CF_SUBJECT:
+                if (ssl_state->server_connp.cert0_subject != NULL) {
+                    MemBufferWriteString(aft->buffer, "%s",
+                                         ssl_state->server_connp.cert0_subject);
+                } else {
+                    LOG_CF_WRITE_UNKNOWN_VALUE(aft->buffer);
+                }
+                break;
+            case LOG_TLS_CF_ISSUER:
+                if (ssl_state->server_connp.cert0_issuerdn != NULL) {
+                    MemBufferWriteString(aft->buffer, "%s",
+                                         ssl_state->server_connp.cert0_issuerdn);
+                } else {
+                    LOG_CF_WRITE_UNKNOWN_VALUE(aft->buffer);
+                }
+                break;
+            case LOG_TLS_CF_EXTENDED:
+            /* Extended format  */
+                LogTlsLogExtended(aft, ssl_state);
+                break;
+            default:
+            /* NO MATCH */
+                MemBufferWriteString(aft->buffer, LOG_CF_NONE);
+                SCLogDebug("No matching parameter %%%c for custom tls log.", node->type);
+                break;
+        }
+    }
+    MemBufferWriteString(aft->buffer, "\n");
+}
+
+
 static int LogTlsLogger(ThreadVars *tv, void *thread_data, const Packet *p,
                         Flow *f, void *state, void *tx, uint64_t tx_id)
 {
@@ -299,7 +451,6 @@ static int LogTlsLogger(ThreadVars *tv, void *thread_data, const Packet *p,
         return 0;
     }
 
-    CreateTimeString(&p->ts, timebuf, sizeof(timebuf));
 #define PRINT_BUF_LEN 46
     char srcip[PRINT_BUF_LEN], dstip[PRINT_BUF_LEN];
     Port sp, dp;
@@ -308,17 +459,25 @@ static int LogTlsLogger(ThreadVars *tv, void *thread_data, const Packet *p,
         return 0;
     }
 
-    MemBufferReset(aft->buffer);
-    MemBufferWriteString(aft->buffer,
-                         "%s %s:%d -> %s:%d  TLS: Subject='%s' Issuerdn='%s'",
-                         timebuf, srcip, sp, dstip, dp,
-                         ssl_state->server_connp.cert0_subject,
-                         ssl_state->server_connp.cert0_issuerdn);
-
-    if (hlog->flags & LOG_TLS_EXTENDED) {
-        LogTlsLogExtended(aft, ssl_state);
+    /* Custom format */
+    if (hlog->flags & LOG_TLS_CUSTOM) {
+        LogTlsLogCustom(aft, ssl_state, &p->ts, srcip, sp, dstip, dp);
     } else {
-        MemBufferWriteString(aft->buffer, "\n");
+
+        MemBufferReset(aft->buffer);
+        CreateTimeString(&p->ts, timebuf, sizeof(timebuf));
+        MemBufferWriteString(aft->buffer,
+                "%s %s:%d -> %s:%d  TLS: Subject='%s' Issuerdn='%s'",
+                timebuf, srcip, sp, dstip, dp,
+                ssl_state->server_connp.cert0_subject,
+                ssl_state->server_connp.cert0_issuerdn);
+
+        if (hlog->flags & LOG_TLS_EXTENDED) {
+            LogTlsLogExtended(aft, ssl_state);
+            MemBufferWriteString(aft->buffer, "\n");
+        } else {
+            MemBufferWriteString(aft->buffer, "\n");
+        }
     }
 
     aft->tls_cnt++;

diff --git a/src/util-time.c b/src/util-time.c
index 0dd00953a1ca577a3c2d04c64f10d28347480bfa..b8f646f9ee63f1ca216383c7cfa38330544bdf4f 100644 (file)
--- a/src/util-time.c
+++ b/src/util-time.c
@@ -210,7 +210,7 @@ void CreateUtcIsoTimeString (const struct timeval *ts, char *str, size_t size)
 
 void CreateFormattedTimeString (const struct tm *t, const char *fmt, char *str, size_t size)
 {
-    if (likely(t != NULL) && likely(fmt != NULL) && likely(str != NULL) ) {
+    if (likely(t != NULL && fmt != NULL && str != NULL)) {
         strftime(str, size, fmt, t);
     } else {
         snprintf(str, size, "ts-error");

diff --git a/suricata.yaml.in b/suricata.yaml.in
index a91d1fe85efb550d701981c321f9e7d5dedd65bd..df5b146af5d8eb1a360a0cf90be0b28c43083e10 100644 (file)
--- a/suricata.yaml.in
+++ b/suricata.yaml.in
@@ -301,8 +301,10 @@ outputs:
       enabled: no  # Log TLS connections.
       filename: tls.log # File to store TLS logs.
       append: yes
+      #extended: yes     # Log extended information like fingerprint
+      #custom: yes       # enabled the custom logging format (defined by customformat)
+      #customformat: "%{%D-%H:%M:%S}t.%z %a:%p -> %A:%P %v %n %d %D"
       #filetype: regular # 'regular', 'unix_stream' or 'unix_dgram'
-      #extended: yes # Log extended information like fingerprint
 
   # output module to store certificates chain to disk
   - tls-store: