Strange behaviour of the facility value by using syslog/tcp

[volker_zeihs]

Hi,

I want to send all my JBoss log information to a sylog-ng server, by using tcp.

I found the following redhat solution:

https://access.redhat.com/solutions/1119893

So I implement that in a simple test environment and get some strange behaviour in relation to the facility value.

If I use TCP and one of the local facility’s, the first log line has the correct facility, but all lines below get the facility "user".

To localize the error I have made three simple tests. They are described below.

I also double checked the syslog-ng server witch some other application under use of tcp and some different facility’s.

First some global configurations and versions.

syslog-ng 2.0.9

Red Hat JBoss Enterprise Application Platform - Version 6.4.6.GA

SUSE Linux Enterprise Server 11 (x86_64) VERSION = 11 PATCHLEVEL = 3

JAVA_VERSION="1.8.0_66"

root logger configuration in the standalone.xml

...
<root-logger>
  <level name="INFO"/>
  <handlers>
    <handler name="CONSOLE"/>
    <handler name="FILE"/>
    <handler name="SYSLOG"/>
  </handlers>
</root-logger>
...

The important parts of the syslog configfile.

...
source src_net {
        tcp(ip("0.0.0.0") port(5141));
        udp(ip("0.0.0.0") port(514));
};
...
destination networkMessages { file("/var/log/networkMessages"
template("ISODATE=$ISODATE FACILITY=$FACILITY PROGRAM=$PROGRAM TAG=$TAG FULLHOST=$FULLHOST MSG=$MESSAGE \n")  ); };
log { source(src_net); destination(networkMessages); };
...

TEST ONE

JBoss logging handler (uses TCP and facility=user)

<custom-handler name="SYSLOG" class="org.jboss.logmanager.handlers.SyslogHandler" module="org.jboss.logmanager">
  <encoding value="ISO-8859-1"/>
  <formatter>
    <pattern-formatter pattern="%-5p [%c] (%t) %s%E%n"/>
  </formatter>
  <properties>
    <property name="appName" value="JBossEAP-SYSLOG-TEST"/>
    <property name="facility" value="USER_LEVEL"/>
    <property name="serverHostname" value="*.*.*.*"/>
    <property name="hostname" value="-"/>
    <property name="port" value="5141"/>
    <property name="syslogType" value="RFC5424"/>
    <property name="protocol" value="TCP"/>
    <property name="messageDelimiter" value="-"/>
    <property name="useMessageDelimiter" value="true"/>
  </properties>
</custom-handler>

The first two lines of the syslog output

ISODATE=2016-04-20T10:02:14+02:00 FACILITY=user PROGRAM=1 TAG=0e FULLHOST=***** MSG=1 2016-04-20T10:02:13.990+02:00 - JBossEAP-SYSLOG-TEST 62384 org.jboss.modules - INFO  [org.jboss.modules] (main) JBoss Modules version 1.3.7.Final-redhat-1
ISODATE=2016-04-20T10:02:14+02:00 FACILITY=user PROGRAM=-<14>1 TAG=0d FULLHOST=***** MSG=-<14>1 2016-04-20T10:02:14.309+02:00 - JBossEAP-SYSLOG-TEST 62384 org.jboss.msc - INFO  [org.jboss.msc] (main) JBoss MSC version 1.1.5.Final-redhat-1

NOTE: all like expected

TEST TWO

JBoss logging handler (uses UDP and facility=local1)

<custom-handler name="SYSLOG" class="org.jboss.logmanager.handlers.SyslogHandler" module="org.jboss.logmanager">
  <encoding value="ISO-8859-1"/>
  <formatter>
    <pattern-formatter pattern="%-5p [%c] (%t) %s%E%n"/>
  </formatter>
  <properties>
    <property name="appName" value="JBossEAP-SYSLOG-TEST"/>
    <property name="facility" value="LOCAL_USE_1"/>
    <property name="serverHostname" value="*.*.*.*"/>
    <property name="hostname" value="-"/>
    <property name="port" value="514"/>
    <property name="syslogType" value="RFC5424"/>
    <property name="protocol" value="UDP"/>
    <property name="messageDelimiter" value="-"/>
    <property name="useMessageDelimiter" value="true"/>
  </properties>
</custom-handler>

The first two lines of the syslog output

ISODATE=2016-04-20T10:08:31+02:00 FACILITY=local1 PROGRAM=1 TAG=8e FULLHOST=***** MSG=1 2016-04-20T10:08:31.322+02:00 - JBossEAP-SYSLOG-TEST 63794 org.jboss.modules - INFO  [org.jboss.modules] (main) JBoss Modules version 1.3.7.Final-redhat-1 -
ISODATE=2016-04-20T10:08:31+02:00 FACILITY=local1 PROGRAM=1 TAG=8e FULLHOST=***** MSG=1 2016-04-20T10:08:31.620+02:00 - JBossEAP-SYSLOG-TEST 63794 org.jboss.msc - INFO  [org.jboss.msc] (main) JBoss MSC version 1.1.5.Final-redhat-1 -

NOTE: all like expected

TEST THREE

JBoss Loging handler (uses TCP and facility=local1)

<custom-handler name="SYSLOG" class="org.jboss.logmanager.handlers.SyslogHandler" module="org.jboss.logmanager">
  <encoding value="ISO-8859-1"/>
  <formatter>
    <pattern-formatter pattern="%-5p [%c] (%t) %s%E%n"/>
  </formatter>
  <properties>
    <property name="appName" value="JBossEAP-SYSLOG-TEST"/>
    <property name="facility" value="LOCAL_USE_1"/>
    <property name="serverHostname" value="*.*.*.*"/>
    <property name="hostname" value="-"/>
    <property name="port" value="5141"/>
    <property name="syslogType" value="RFC5424"/>
    <property name="protocol" value="TCP"/>
    <property name="messageDelimiter" value="-"/>
    <property name="useMessageDelimiter" value="true"/>
  </properties>
</custom-handler>

The first two lines of the syslog output

ISODATE=2016-04-20T10:03:58+02:00 FACILITY=local1 PROGRAM=1 TAG=8e FULLHOST=***** MSG=1 2016-04-20T10:03:58.663+02:00 - JBossEAP-SYSLOG-TEST 62775 org.jboss.modules - INFO  [org.jboss.modules] (main) JBoss Modules version 1.3.7.Final-redhat-1
ISODATE=2016-04-20T10:03:58+02:00 FACILITY=user PROGRAM=-<142>1 TAG=0d FULLHOST=***** MSG=-<142>1 2016-04-20T10:03:58.945+02:00 - JBossEAP-SYSLOG-TEST 62775 org.jboss.msc - INFO  [org.jboss.msc] (main) JBoss MSC version 1.1.5.Final-redhat-1

NOTE: first line like expected, all other have the facility user

Why is that?

Is there a Bug, or is there a mistake in the configuration?

Attachments: full standalone.xml

[jamezp]

The delimiter "-" seems a little odd. Especially since the log statement itself will likely have dashes in it. Have you tried using a different delimiter like \n or 0x00? I'm not sure what syslog-ng expects.

--

James R. Perkins

[volker_zeihs]

Hi James,

all works fine for UDP and TCP, if I let the messageDelimiter empty.

This is a sufficient solution for me.

But there is still an inconsistency between UDP and TCP.

I cannot say whether this is a JBoss or a syslog-ng matter at this time.

Thank you for your attention to this matter.

Volker Zeihs

[jamezp]

If syslog-ng supports octet counting that would eliminate the need for a delimiter. You'd use the useCountingFraming property and set it to true. That sends the size of the message to the syslog server so it knows what to expect. This is only for TCP.

It's likely UDP works because the message is sent in one chunk and the size can easily be determined.

--

James R. Perkins

[volker_zeihs]

This could be the last missing piece in the puzzle.

It seems that my old syslog-ng doesn’t support the TCP_Framing mode octet-counted.

So I changed to rsyslog 8.4.0 under SLES 12 and all worked out of the box.

I therefore assume that my old syslog-ng was the reason for my Problems.

my config (standalone.xml)

<custom-handler name="SYSLOG" class="org.jboss.logmanager.handlers.SyslogHandler" module="org.jboss.logmanager">
  <encoding value="ISO-8859-1"/>
  <formatter>
    <pattern-formatter pattern="%-5p [%c] (%t) %s%E%n"/>
  </formatter>
    <properties>
    <property name="appName" value="JBossEAP-SYSLOG-TEST"/>
    <property name="facility" value="LOCAL_USE_2"/>
    <property name="serverHostname" value="*.*.*.*"/>
    <property name="hostname" value="****"/>
    <property name="port" value="5141"/>
    <property name="syslogType" value="RFC5424"/>
    <property name="protocol" value="TCP"/>
    <property name="useCountingFraming" value="true"/>
  </properties>
</custom-handler>

SyslogHandler (JBoss Enterprise Application Platform 6.2.0.GA public API)

useCountingFraming: Prefixes the size of the message, mainly used for TCP or SSL_TCP, connections to the message being sent to the syslog server See http://tools.ietf.org/html/rfc6587for more details on framing types

Thanks for keeping up.