Hmm, I was working on syslog this week, and it is possible this is a bad message while I was developing.

When I look now, the log lines look like

Dec 11 14:49:09 deployment-eventlogging04 eventlogging-service-eventbus[10063]: (MainThread) 400 POST /v1/events (10.68.16.127) 8.64ms

Is this sufficient? This has the process name followed by the pid in brackets followed by a colon. Should I remove the bracketed pid?

I have no idea honestly :( Based on the upstream bug ( https://github.com/elastic/logstash/issues/2552 ) seems the column should be sufficient for the Logstash input filter to properly identify the message.

Searching for "eventlogging-service-eventbus on https://logstash-beta.wmflabs.org/#/dashboard/elasticsearch/default still shows incorrect host fields. But I guess whatever patch you have isn't deployed on beta cluster yet :-}

Hm, no it is on beta...

@hashar, I'm happy to change the log line to whatever format makes sense, but I'm not sure what it should be from your linked issue. In /var/log/eventlogging/eventlogging-service-eventbus.log on deployment-eventlogging04, the log lines look like:

Dec 14 21:33:14 deployment-eventlogging04 eventlogging-service-eventbus[23828]: (MainThread) 400 POST /v1/events (10.68.16.127) 5.90ms

Seems that message is received as:

<12>Dec 14 21:33:14 deployment-eventlogging04 eventlogging-service-eventbus[23 (MainThread) 400 POST /v1/events (10.68.16.127) 5.90ms

Looks like the software name (38 characters with column) is stripped down to 32 characters:

$ echo -n 'eventlogging-service-eventbus[23'|wc -c
      32

Maybe it is a hard limit in the Logstash syslog input plugin or it is stripped when being emitted/relayed somehow.

The LogStash syslog plugin probably do not respect the syslog RFCs :( They are https://tools.ietf.org/html/rfc3164 and https://tools.ietf.org/html/rfc5424

The pattern seems to be "<%{POSINT:priority}>%{SYSLOGLINE}" with SYSLOGLINE being defined via:

https://github.com/logstash-plugins/logstash-patterns-core/blob/master/patterns/linux-syslog

Notably, it expects the program to be followed by a column: %{SYSLOGHOST:logsource}+(?: %{SYSLOGPROG}:|)

SYSLOGPROG being: %{PROG:program}(?:\[%{POSINT:pid}\])?

Not sure how that mess is of any help though :-(

Change 259271 had a related patch set uploaded (by Ottomata):
Increase size of programname field in remote syslog template

https://gerrit.wikimedia.org/r/259271

This seems to do the trick:

https://gerrit.wikimedia.org/r/#/c/259271/

The above change is live in beta and applied on deployment-eventlogging04

Theerree we go:

{
  "_index": "logstash-2015.12.15",
  "_type": "syslog",
  "_id": "AVGmtnTKa1EjumVdFTBo",
  "_score": null,
  "_source": {
    "message": "(MainThread) 201 POST /v1/events (10.68.23.204) 2.78ms",
    "@version": "1",
    "@timestamp": "2015-12-15T17:35:53.736Z",
    "type": "syslog",
    "host": "deployment-eventlogging04",
    "priority": 14,
    "timestamp8601": "2015-12-15T17:35:53.736268+00:00",
    "logsource": "deployment-eventlogging04",
    "program": "eventlogging-service-eventbus",
    "pid": "32682",
    "severity": 6,
    "facility": 1,
    "timestamp": "2015-12-15T17:35:53.736268+00:00",
    "facility_label": "user-level",
    "severity_label": "Informational",
    "level": "INFO",
    "tags": [
      "syslog",
      "es",
      "normalized_message_untrimmed"
    ],
    "normalized_message": "(MainThread) 201 POST /v1/events (10.68.23.204) 2.78ms"
  },
  "sort": [
    1450200953736
  ]
}

Change 259271 merged by Ottomata:
Increase size of programname field in remote syslog template

https://gerrit.wikimedia.org/r/259271

@Ottomata congratulations and figuring out rsyslog was trimming the program name when emitting the message! Looking at logstash the bulk of host:"%{logsource}" messages are now gone for EventBus.

I noticed a few remaining oddities though not related to EventBus itself:

And a few hours later, messages related to puppet-agent with different PID. The look like:

<29>2015-12-15T22:54:16.141771+00:00  puppet-agent[1234]: last message repeated 2 times

Eleven of them sent between 2015-12-15T22:52:55.24 UTC and 2015-12-15T23:14:46 UTC. Maybe rsyslog did not get reload entirely or something goes wrong with the last message repeated n times kind of messages.