# Trivial syslog processing not working

**URL:** <https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848>\
**Category:** Logstash\
**Created:** [May 7, 2017, 1:01pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848 "2017-05-07T13:01:07Z")\
**Posts on this page:** 17\
**Page:** 1

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 7, 2017, 1:01pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/1 "2017-05-07T13:01:07Z")

</div>

I'm sorry to post here if the answer is finally trivial too, but I've now past countless hours reading everywhere trying to solve it.

I'm basically sending syslog message to Logstash:

```
input {
        tcp {
                host => "127.0.0.1"
                port => 10514
                codec => "json"
                type => "rsyslog"
        }
}

```

I'm copying logs on flat files for debug/history:

`May 7 14:50:08 core postfix/smtpd[4180]: disconnect from unknown[149.56.0.30]`

Logstash is configured to progress syslogs such as described in official configuration examples:

```
if [type] == "rsyslog" {
                grok {
                        match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:\[%{POSINT:syslog_pid}\])?: %{GREEDYDATA:syslog_message}" }
                        add_field => ["received_at", "%{@timestamp}"]
                        add_field => ["received_from", "%{host}"]
                }
                date {
                        match => ["syslog_timestamp", "MMM d HH:mm:ss", "MMM dd HH:mm:ss"]
                }
        }

```

However when inspecting Kibana, the syslog message processing seem to fail:

May 7th 2017, 14:50:08.896

```
host: core
severity: info
@timestamp: May 7th 2017, 14:50:08.896
port: 34,668
@version: 1
message: disconnect from unknown[149.56.0.30]
type: rsyslog
facility: mail
syslog-tag: postfix/smtpd[4180]:
timestamp: May 7th 2017, 14:50:08.000
tags: _grokparsefailure
_id: AVvi9cOM40sPYnZsVv-C
_type: rsyslog
_index: logstash-2017.05.07
_score: - 

```

\_grokparsefailure tag obviously says I'm wrong somewhere...  
Logs don't say much either.  
Could it be default configuration I don't know about, or specific thing I missed?  
I'm running Logstash 5.4.0, Elasticsearch 5.4.0, Kibana 5.4.0, on Ubuntu 16.04 x86-64.

---

<div class="post-metadata">

**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\
**Post date:** [May 7, 2017, 1:14pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/3 "2017-05-07T13:14:28Z")

</div>

What does a raw event look like? What does the result of your config look like if you output to a stdout filter with a rubydebug codec?

> [@dcn](#):
>
> codec =\> "json"

Is your input format really JSON?

---

<div class="post-metadata">

**Author:** ![magnusbaeck](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/magnusbaeck/32/44943_2.png) [@magnusbaeck](https://discuss.elastic.co/u/magnusbaeck)\
**Post date:** [May 7, 2017, 2:24pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/4 "2017-05-07T14:24:54Z")

</div>

Do you have any extra files in /etc/logstash/conf.d? Logstash reads _all_ files there.

---

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 7, 2017, 7:13pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/5 "2017-05-07T19:13:40Z")

</div>

The syslog line comes directly from my central rsyslog server file output.  
Here's my rsyslog config: /etc/rsyslog.d/60-output.conf

```
*.* @@127.0.0.1:10514;json-template
*.* -/var/log/siem_debug.log

```

I don't recall where the json-template comes from but it seems part of the syslog messages are sent in json otherwize logstash would'nt understand at all.

---

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 7, 2017, 7:14pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/6 "2017-05-07T19:14:19Z")

</div>

Nope, no other file.

---

<div class="post-metadata">

**Author:** ![jupp](https://avatars.discourse-cdn.com/v4/letter/j/e36b37/32.png) [@jupp](https://discuss.elastic.co/u/jupp)\
**Post date:** [May 7, 2017, 7:17pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/7 "2017-05-07T19:17:47Z")

</div>

Can you put the whole configfile?

---

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 7, 2017, 7:22pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/8 "2017-05-07T19:22:25Z")

</div>

I've enabled the rubydebug codec, but I'm not sure how it exactly works.  
Here's one of the json pack I got:

```
{
      "severity" => "info",
    "@timestamp" => 2017-05-07T19:20:01.560Z,
          "port" => 36736,
          "host" => "core",
      "@version" => "1",
       "message" => " pam_unix(cron:session): session closed for user root",
          "type" => "rsyslog",
      "facility" => "authpriv",
    "syslog-tag" => "CRON[11011]:",
     "timestamp" => "2017-05-07T21:20:01+02:00",
          "tags" => [
        [0] "_grokparsefailure"
    ]
}
```

---

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 7, 2017, 7:24pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/9 "2017-05-07T19:24:36Z")

</div>

Here is the whole logstash.conf file, without comments:

```
input {
        tcp {
                host => "127.0.0.1"
                port => 10514
                codec => "json"
                type => "rsyslog"
        }
}
filter { 
        if [type] == "rsyslog" {
                # create "syslog_service" and syslog_process_id fields out of syslog-tag content
                grok {
                        #match => { "message" => "%{SYSLOGTIMESTAMP} %{SYSLOGHOST} %{SYSLOGPROG} %{GREEDYDATA:syslog_message}" }
                        match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:\[%{POSINT:syslog_pid}\])?: %{GREEDYDATA:syslog_message}" }
                        add_field => ["received_at", "%{@timestamp}"]
                        add_field => ["received_from", "%{host}"]
                }
                date {
                        match => ["syslog_timestamp", "MMM d HH:mm:ss", "MMM dd HH:mm:ss"]
                }
        }
}

output {
        if [type] == "rsyslog" {
                elasticsearch { hosts => ["127.0.0.1:9200"] }
                stdout { codec => rubydebug }
        }
}
```

---

<div class="post-metadata">

**Author:** ![jupp](https://avatars.discourse-cdn.com/v4/letter/j/e36b37/32.png) [@jupp](https://discuss.elastic.co/u/jupp)\
**Post date:** [May 7, 2017, 7:41pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/10 "2017-05-07T19:41:57Z")

</div>

I replaced the tcp input with stdin...i sent the following line and it get no grokparsefailure.:

```
May 7 14:50:08 core postfix/smtpd[4180]: disconnect from unknown[149.56.0.30]

{
       "received_from" => "jupp-laptop-e530",
          "@timestamp" => 2017-05-07T12:50:08.000Z,
          "syslog_pid" => "4180",
     "syslog_hostname" => "core",
    "syslog_timestamp" => "May 7 14:50:08",
         "received_at" => "2017-05-07T19:30:43.171Z",
            "@version" => "1",
                "host" => "jupp-laptop-e530",
      "syslog_program" => "postfix/smtpd",
             "message" => "May 7 14:50:08 core postfix/smtpd[4180]: disconnect from unknown[149.56.0.30]",
                "type" => "rsyslog",
      "syslog_message" => "disconnect from unknown[149.56.0.30]"
}

```

Disable your grok an print the incoming message directly to stdout. So you can see whats flying in. I think the problem lies there.

```
input {
        #stdin {
        # type => "rsyslog"
        #}
        tcp {
                host => "127.0.0.1"
                port => 10514
                codec => "json"
                type => "rsyslog"
        }
}
filter { 
        if [type] == "rsyslog" {
                # create "syslog_service" and syslog_process_id fields out of syslog-tag content
               # grok {
                # #match => { "message" => "%{SYSLOGTIMESTAMP} %{SYSLOGHOST} %{SYSLOGPROG} %{GREEDYDATA:syslog_message}" }
                # match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:\[%{POSINT:syslog_pid}\])?: %{GREEDYDATA:syslog_message}" }
                # add_field => ["received_at", "%{@timestamp}"]
                # add_field => ["received_from", "%{host}"]
                #}
                #date {
                # match => ["syslog_timestamp", "MMM d HH:mm:ss", "MMM dd HH:mm:ss"]
                #}
        }
}

output {
        if [type] == "rsyslog" {
                #elasticsearch { hosts => ["127.0.0.1:9200"] }
                stdout { codec => rubydebug }
        }
}
```

---

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 7, 2017, 7:58pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/11 "2017-05-07T19:58:55Z")

</div>

Seems like this is really json coming in (output from rubydebug in console):

```
{
      "severity" => "info",
    "@timestamp" => 2017-05-07T19:55:01.332Z,
          "port" => 37000,
          "host" => "core",
      "@version" => "1",
       "message" => " pam_unix(cron:session): session closed for user root",
          "type" => "rsyslog",
      "facility" => "authpriv",
    "syslog-tag" => "CRON[12073]:",
     "timestamp" => "2017-05-07T21:55:01.330590+02:00"
}

```

But I'm a bit puzzled by the syslog-tag tag

---

<div class="post-metadata">

**Author:** ![jupp](https://avatars.discourse-cdn.com/v4/letter/j/e36b37/32.png) [@jupp](https://discuss.elastic.co/u/jupp)\
**Post date:** [May 7, 2017, 8:08pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/12 "2017-05-07T20:08:03Z")

</div>

Ok, so you recieve directly a JSON but the message is not that what you expect in your grok.  
message = syslog\_message. This is the reason why you get the grokparsefailure.

The sender built this json....so the answer is there for the "syslog-tag"

---

<div class="post-metadata">

**Author:** ![jupp](https://avatars.discourse-cdn.com/v4/letter/j/e36b37/32.png) [@jupp](https://discuss.elastic.co/u/jupp)\
**Post date:** [May 7, 2017, 8:35pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/13 "2017-05-07T20:35:37Z")

</div>

I found this link..maybe it can help you by configuring rsyslog:

> **[How To Centralize Logs with Rsyslog, Logstash, and Elasticsearch on Ubuntu 14.04...](https://www.digitalocean.com/community/tutorials/how-to-centralize-logs-with-rsyslog-logstash-and-elasticsearch-on-ubuntu-14-04)**
>
> Rsyslog, Elasticsearch, and Logstash provide the tools to transmit, transform, and store your log data. In this tutorial, you will learn how to create a centralized rsyslog server to store log files from multiple systems and then use Logstash to send

---

<div class="post-metadata">

**Author:** ![jordansissel](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jordansissel/32/44957_2.png) [@jordansissel](https://discuss.elastic.co/u/jordansissel)\
**Post date:** [May 7, 2017, 11:43pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/14 "2017-05-07T23:43:28Z")

</div>

`*.* @@127.0.0.1:10514;json-template`

I'm making an assumption here that `json-template` does what you say, that it sends json instead of RFC3164 or RFC5424 format. This is OK to do.

My guess right now is that your grok pattern is _correctly_ indicating a failure to parse because your pattern is expecting RFC3164 format for the `message` field.

To strengthen my hypothesis, the sample JSON out from rsyslog-to-Logstash as you posted is this:

```auto
      "severity" => "info",
    "@timestamp" => 2017-05-07T19:20:01.560Z,
          "port" => 36736,
          "host" => "core",
      "@version" => "1",
       "message" => " pam_unix(cron:session): session closed for user root",
          "type" => "rsyslog",
      "facility" => "authpriv",
    "syslog-tag" => "CRON[11011]:",
     "timestamp" => "2017-05-07T21:20:01+02:00",
          "tags" => [
        [0] "_grokparsefailure"
    ]

```

Your grok is this:

```auto
                        match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:\[%{POSINT:syslog_pid}\])?: %{GREEDYDATA:syslog_message}" }

```

This will never produce the following fields that are existing in your event:

- severity
- facility
- syslog-tag
- timestamp

The message field, additionally, looks like this in your tcp-input event:

```auto
 pam_unix(cron:session): session closed for user root

```

Notice the lack of timestamp, hostname, syslog program, from this message.

I recommend using netcat or similar to watch the data sent by rsyslog to confirm exactly what form is being sent.

Best i can tell, grok is correctly indicating a parse failure because rsyslog is sending json with the `message` as shown above.

---

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 8, 2017, 7:28am UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/15 "2017-05-08T07:28:23Z")

</div>

Thanks, this is actually where I got my config 😉

---

<div class="post-metadata">

**Author:** ![dcn](https://avatars.discourse-cdn.com/v4/letter/d/3ab097/32.png) [@dcn](https://discuss.elastic.co/u/dcn)\
**Post date:** [May 8, 2017, 8:27am UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/16 "2017-05-08T08:27:30Z")

</div>

You nailed it. I was looking for patterns that where not in the message.  
Root cause analysis: confusion between message, msg, and what I understood as being the message.  
Since my initial need was to split program and pid, I just had to split syslog-tag in two, worked great.  
Thanks all of you for supporting me!

---

<div class="post-metadata">

**Author:** ![jordansissel](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jordansissel/32/44957_2.png) [@jordansissel](https://discuss.elastic.co/u/jordansissel)\
**Post date:** [May 8, 2017, 5:48pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/17 "2017-05-08T17:48:25Z")

</div>

@dcn I am happy to hear that you got things sorted out 🙂

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [June 5, 2017, 5:51pm UTC](https://discuss.elastic.co/t/trivial-syslog-processing-not-working/84848/18 "2017-06-05T17:51:25Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.