JSON and JSON_LINES delimiter

[fabian.vanderhoeven]

I've build my own log forwarder using python (using inotify). The reason beinig the logstash-forwarder is to heavy for our systems (accessing directory listings a lot). The way our application write logs is very inefficient (logswitch ones or twice a minute) and logstash-forwarder can't cope with that.

Anyway, the issue i've come accross is as follows. My logforwarder worked fine using UDP and JSON input filter, but when I switched to TCP (because we wanted to use multiline), it didn't work anymore (yes, i've allready decreased the workers).

When I used the shipper.py script provided with Nagios logserver, the logs DID get pushed to elasticsearch. I compared the messages my logforwarder made and the ones the shipper.py made, and they were identical.
I tried 2 days of trying it to get to work (a lot of frustration)

Finally is used tcpdump to analyse the payload and found that the message sent with shipper.py had a linefeed (\n, "0A") at the end of the message. My logforwarder didn't have it (the payload was 1 byte shorter).

Last line from shipper.py:
0x0280: 2241 7070 6c2d 4841 524d 227d 0a "Appl-HARM"}.
Last line from my logforwarder:
0x0280: 2241 7070 6c2d 4841 524d 227d "Appl-HARM"}

I think this is a bug because according to the documentation from elasticsearch's logstash (https://www.elastic.co/guide/en/logstas ... -json.html) the JSON input doesn't need a \n as a delimiter. If you want to use a \n as a delimiter, you should use JSON_LINES. But apparently the JSON input also needs \n as a delimiter. I don't know if this bug is know or allready fixed in the newer 1.5.3 logstash, but it is worth mentioning.

[jolson]

Thank you for the bug report. In addition to the packet difference you've noted, are you certain that the TCP transactions are the same?

The multiline codec/filter expects that your logs are all transferred as a single TCP stream - meaning that a single four-way handshake takes place and the rest of the log data is transferred within that session.

It's possible that your custom application is opening a new TCP stream (new four-way handshake) for every line that it sends to Nagios Log Server, which would stop the multiline filter from functioning properly. You can verify this with a TCPdump as you had before - is there a different in handshakes between shipper.py and your custom shipper, or is the only different the missing byte?

Let me know, thanks!

Best,


Jesse

[fabian.vanderhoeven]

Hi Jesse,

This test I ran was only whit 1 logline (I used just 1 line for easy testing purposes). The multiline tests are next. But my logshipper does send multiple lines in just 1 stream.

I just mentioned the multiline part because that was the reason we jumper from UDP to TCP.

Regards,

Fabian.

[jolson]

Would you please provide me with an example input and an example filter so that I may reproduce your results in a test environment? After reproduction, I am happy to submit a bug report to our developers. Thank you!

[fabian.vanderhoeven]

This is the input i'm using:
tcp {
type => 'import_json'
tags => 'import_json'
port => 2057
codec => json
}

I have no filters defined in my dev environment.

This is a small python script which demonstrates the issue:

Code: Select all

#!/usr/bin/python

import socket
try:
        import json
except ImportError:
        import simplejson as json

logserver_ip   = '192.168.5.100'
logserver_port = 2057
json_message   = {}

json_message['message']    = 'test'
json_message['sourcetype'] = 'Appl-Test'
json_message['logfile']    = '/tmp/test.log'

s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
s.connect((logserver_ip, logserver_port))
#s.send(json.dumps(json_message))
s.send((json.dumps(json_message) + '\n'))
s.close()

The first send line doesn't work, the second send line does work.

[jolson]

Yup - the script and input that you've given me show that this is a bug, plain as day. I've submitted an issue to the Logstash team: https://github.com/logstash-plugins/log ... /issues/15

Let's follow it over there and check on the response. If we come up with a solution in-house, we'll submit a pull request to the Logstash team. Thanks!

Jesse

[vAJ]

What about forwarding JSON log files from a linux host, using rsyslogd.

Found a post from 2012: http://untergeek.com/2012/10/11/using-r ... -logstash/ that discusses rsyslogd with JSON over to Logstash.

However, when I do this, it's only sending individual lines of my test log:

Code: Select all

{
  "id": 1,
  "gender": "Female",
  "first_name": "Rachel",
  "last_name": "Porter",
  "email": "[email protected]",
  "ip_address": "243.123.228.116"
}, {
  "id": 2,
  "gender": "Male",
  "first_name": "Fred",
  "last_name": "Dunn",
  "email": "[email protected]",
  "ip_address": "106.47.41.159"
}, {
  "id": 3,
  "gender": "Female",
  "first_name": "Brenda",
  "last_name": "Alvarez",
  "email": "[email protected]",
  "ip_address": "134.95.107.229"
}

Here's my supplemental rsyslogd conf:

Code: Select all

 cat 90-nagioslogserver_var_log_ssoAudit.log.conf
$ModLoad imfile
$InputFilePollInterval 10
$PrivDropToGroup adm
$WorkDirectory /var/lib/rsyslog

# Input for ssoAudit
$InputFileName /var/log/ssoAudit.log
$InputFileTag ssoAudit:
$InputFileStateFile nls-state-var_log_ssoAudit.log # Must be unique for each file being polled
# Uncomment the folowing line to override the default severity for messages
# from this file.
#$InputFileSeverity info
$InputFilePersistStateInterval 20000
$InputRunFileMonitor

$template ls_json,"{%timestamp:::date-rfc3339,jsonf:@timestamp%,%source:::jsonf:@source_host%,\"@source\":\"syslog://%fromhost-ip:::json%\",\"@message\":\"%timestamp% %app-name%:%msg:::json%\",\"@fields\":{%syslogfacility-text:::jsonf:facility%,%syslogseverity-text:::jsonf:severity%,%app-name:::jsonf:program%,%procid:::jsonf:processid%}}"


# Forward to Nagios Log Server and then discard, otherwise these messages
# will end up in the syslog file (/var/log/messages) unless there are other
# overriding rules.
if $programname == 'ssoAudit' then @@brnagiosls1.ux.corp.local:2057;ls_json
if $programname == 'ssoAudit' then ~

LogServer results:

Code: Select all

{
  "_index": "logstash-2016.04.08",
  "_type": "import_json",
  "_id": "AVP3cA5MGlbcNFEpbl_z",
  "_score": null,
  "_source": {
    "@timestamp": "2016-04-08T19:53:46.208Z",
    "@source_host": "brnagios1",
    "@source": "syslog://",
    "@message": "Apr  8 15:53:46 ssoAudit:  \"gender\": \"Female\",",
    "@fields": {
      "facility": "local0",
      "severity": "notice",
      "program": "ssoAudit",
      "processid": "-"
    },
    "@version": "1",
    "host": "10.10.25.39",
    "type": "import_json",
    "tags": [
      "import_json",
      "_grokparsefailure"
    ],
    "syslog_severity_code": 5,
    "syslog_facility_code": 1,
    "syslog_facility": "user-level",
    "syslog_severity": "notice"
  },
  "sort": [
    1460145226208,
    1460145226208
  ]
}

[hsmith]

Are all of the lines showing up in your server, just one at a time? Or are you missing lines completely?

[vAJ]

We were getting single lines.

The unix admin has since updated the supplement config file as:

Code: Select all

$ModLoad imfile
$InputFilePollInterval 10
$PrivDropToGroup sys
$WorkDirectory /var/lib/rsyslog

# Input for ssoAudit
$InputFileName /apps/forgerock/openam-config/auth/debug/ssoAudit.log
$InputFileTag ssoAudit:
$InputFileStateFile ssoAudit.log # Must be unique for each file being polled
# Uncomment the folowing line to override the default severity for messages
# from this file.
#$InputFileSeverity info
#$InputFilePersistStateInterval 20000
$InputFileSeverity error
$InputFileFacility local7
$InputRunFileMonitor

# Forward to Nagios Log Server and then discard, otherwise these messages
# will end up in the syslog file (/var/log/messages) unless there are other
# overriding rules.
if $programname == 'ssoAudit' then @@brnagiosls1.ux.corp.local:2057
if $programname == 'ssoAudit' then stop

We're now getting every thing as one message, but it's JSON inside SYSLOG:

Code: Select all

<187>Apr  8 13:24:19 slfroamd1 ssoAudit: {"employeeId":"couldn\u0027t retireve the emplID, persistntID is ","companyId":"couldn\u0027t retireve the companyID for persistantID \u003d ","timeStamp":"2016/04/07 13:11:48 Pacific Daylight Time","userIP":"10.30.27.85","environment":"ssodev.t.com","serverIP":"10.30.27.131","application":"SSO","feature":"CLIENT INTIATED SSO","resource":"smoketest","method":"POST","statusCode":200,"userAgentInfo":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_3) AppleWebKit/601.4.4 (KHTML, like Gecko) Version/9.0.3 Safari/601.4.4"}

[vAJ]

Found this as well http://www.rsyslog.com/coupling-with-lo ... #more-2356 but NLS doesn't use redis.