Logstash Multiline with Syslog

Question

Have some difficulties with Logstash and multiline working together

I am using the Logspout container that forwards all stdout log entries as syslog to logstash.

This is the final content that logstash receives. Here are multiple lines that should represent two events.

<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]: 2015-02-10 11:55:38.496  INFO 1 --- [tp1302304527-19] c.z.service.DefaultInvoiceService        : Creating with DefaultInvoiceService started...
<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]: 2015-02-10 11:55:48.596  WARN 1 --- [tp1302304527-19] o.eclipse.jetty.servlet.ServletHandler   : 
<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]: 
<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.springframework.dao.DataAccessResourceFailureException: Timed out after 10000 ms while waiting for a server that matches AnyServerSelector{}. Client view of cluster state is {type=Unknown, servers=[{address=mongo:27017, type=Unknown, state=Connecting, exception={com.mongodb.MongoException$Network: Exception opening the socket}, caused by {java.net.UnknownHostException: mongo: unknown error}}]; nested exception is com.mongodb.MongoTimeoutException: Timed out after 10000 ms while waiting for a server that matches AnyServerSelector{}. Client view of cluster state is {type=Unknown, servers=[{address=mongo:27017, type=Unknown, state=Connecting, exception={com.mongodb.MongoException$Network: Exception opening the socket}, caused by {java.net.UnknownHostException: mongo: unknown error}}]
<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]:    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:978)
<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]:    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:868)
<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]:    at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
<14>2015-02-09T14:25:01Z logspout dev_zservice_1[1]:    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842)

Every log line is starts with syslog head.

Based on the above log content I created logstash config file.

input {
  udp {
    port => 5000
    type => syslog
  }
}

filter {
  multiline {
    pattern => "^<%{NUMBER}>%{TIMESTAMP_ISO8601} %{SYSLOGHOST:container_name} %{DATA}(?:\[%{POSINT}\])?:%{SPACE}%{TIMESTAMP_ISO8601}"
    negate => true
    what => "previous"
    stream_identity => "%{container_name}"
  }

  grok {
    match => [ "message", "(?m)^<%{NUMBER}>%{TIMESTAMP_ISO8601} %{SYSLOGHOST} %{DATA:container_name}(?:\[%{POSINT}\])?:%{SPACE}%{TIMESTAMP_ISO8601:timestamp}%{SPACE}%{LOGLEVEL:loglevel}%{SPACE}%{NUMBER}%{SPACE}---%{SPACE}(?:\[%{DATA:threadname}\])?%{SPACE}%{JAVACLASS:clas
  }

  date {
    match => [ "timestamp", "yyyy-MM-dd HH:mm:ss.SSS" ]
    remove_field => ["timestamp"]
  }
  if !("_grokparsefailure" in [tags]) {
    mutate {
      replace => [ "source_host", "%{container_name}" ]
      replace => [ "raw_message", "%{message}" ]
      replace => [ "message", "%{logmessage}" ]
      remove_field => [ "logmessage", "host", "source_host" ]
    }
  }
  mutate {
    strip => [ "threadname" ]
  }
}

output {
  elasticsearch { }
}

Now when the above events arrives the first event is correct parsed and displayed:

message = "Creating with DefaultInvoiceService started..."

The second event contains this message which contains three issues:

<14>2015-02-10T12:59:09Z logspout dev_zservice_1[1]: 

<14>2015-02-10T12:59:09Z logspout dev_zservice_1[1]: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.springframework.dao.DataAccessResourceFailureException: Timed out after 10000 ms while waiting for a server that matches AnyServerSelector{}. Client view of cluster state is {type=Unknown, servers=[{address=mongo:27017, type=Unknown, state=Connecting, exception={com.mongodb.MongoException$Network: Exception opening the socket}, caused by {java.net.UnknownHostException: mongo: unknown error}}]; nested exception is com.mongodb.MongoTimeoutException: Timed out after 10000 ms while waiting for a server that matches AnyServerSelector{}. Client view of cluster state is {type=Unknown, servers=[{address=mongo:27017, type=Unknown, state=Connecting, exception={com.mongodb.MongoException$Network: Exception opening the socket}, caused by {java.net.UnknownHostException: mongo: unknown error}}]

<14>2015-02-10T12:59:09Z logspout dev_zservice_1[1]:    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:978)

<14>2015-02-10T12:59:09Z logspout dev_zservice_1[1]:    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:868)

<14>2015-02-10T12:59:09Z logspout dev_zservice_1[1]:    at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)

<14>2015-02-10T12:59:09Z logspout dev_zservice_1[1]:    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842)

<14>2015-02-10T12:59:09Z logspout dev_nginx_1[1]: 192.168.59.3 - - [10/Feb/2015:12:59:09 +0000] "POST /api/invoice/ HTTP/1.1" 500 1115 "http://192.168.59.103/"; "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.94 Safari/537.36" "-"

1. The message text contains a line with an dev_nginx_1 entry which does not belong here. This should be treated as an separate event.

2. Each line contains the prefix. <14>2015-02-10T12:59:09Z logspout dev_zservice_1[1]:

3. Each line has an additional new line

Question. Why is the dev_nginx_1 entry not an event on its own. Why is it considered to belong to the previous one? How can I get rid of the syslog prefix in each line of the message. How can I get rid of the additional new line?

Answer 1

As for (1), you're using container_name in the multiline. This is the field after the timestamp. In your example, they're all "logspout". Seems right to me.

As for (2), each line comes in with the prefix and the timestamp, so you would expect them to be there by default. You are doing a mutate{} to replace message with log_message, but I don't see that you're setting log_message. So, how did you think the prefix and timestamp were being removed?

Answer 2

For (1), replace %{SYSLOGHOST:container_name} %{DATA} in your multline pattern with %{SYSLOGHOST} %{DATA:container_name} (as you use in your grok).

For (2) and (3), you can try something like this:

mutate {
    gsub => [ "message", "<\d+>.*?:\s", "", "message", "\n(\n)", "\1" ]
}

Here, the gsub setting is performing two operations:

1. Examine the field "message", find the substrings from "<14>" to a colon followed by a whitespace, and replace those substrings with empty strings.
2. Examine the field "message", find the substrings consisting of two consecutive newline characters, and replace them with one newline character. It performs the substitution using the \1 backrefernce to the group (\n), because if you try to use \n itself, Logstash will actually replace it with \\n, which won't work.