[rsyslog-notify] Forum Thread: Re: Strange linebreak with Jboss access logs - (Mode 'reply')

[noreply at adiscon.com]

User: Chriss.ko 
Forumlink: http://kb.monitorware.com/viewtopic.php?p=24272#p24272

Message: 
----------
Hi David,

thanks for the idea with the debug of the incoming messages. But this ended
up into a disaster.

Here is the current setup of the server.:
[code:3kbotmit]#debug
$template debug,"Debug line with all properties:\nFROMHOST:
'%FROMHOST%', fromhost-ip: '%fromhost-ip%', HOSTNAME: '%HOSTNAME%',
PRI: %PRI%,\nsyslogtag '%syslogtag%', programname: '%programname%',
APP-NAME: '%APP-NAME%', PROCID: '%PROCID%', MSGID:
'%MSGID%',\nTIMESTAMP: '%TIMESTAMP%', STRUCTURED-DATA:
'%STRUCTURED-DATA%',\nmsg: '%msg%'\nescaped msg:
'%msg:::drop-cc%'\nrawmsg: '%rawmsg%'\n\n"

# All Logs to one file
$template AllPerHostLogs,"/own/log/%FROMHOST%/all.log"
if \
        $source != 'adm' \
                and not ( \
        $app-name contains 'TC1catalina-out' \
                or \
        $app-name contains 'TC1access-log' \
                or \
        $app-name contains 'JB1access-log' \
                ) \
then -?AllPerHostLogs;debug

$template
Jboss1AccessLogHostLogs,"/own/log/%FROMHOST%/jboss-1-access.log"
if \
        $source != 'adm' \
                and \
        $app-name contains 'JB1access-log' \
then -?Jboss1AccessLogHostLogs;debug
[/code:3kbotmit]

I do have one sender only.
[code:3kbotmit]
$template FormatJB1Access,"<188>%protocol-version%
%TIMESTAMP:::date-rfc8601A% %HOSTNAME% %app-name% %syslogtag%
%msg:::sp-if-no-1st-sp%%msg%\n"

$InputFileName /own/log/jboss/access_log.2014-02-28
#$InputFileName /own/log/jboss/access_log.%$YEAR%-%$MONTH%-%$DAY%

$InputFileTag JB1access-log
$InputFileStateFile stat-JB1access-log
#$InputFileReadMode 2
$InputFileSeverity info
$InputRunFileMonitor
if $app-name == 'JB1access-log' then @@loghost:514;FormatJB1Access
if $app-name == 'JB1access-log' then ~
[/code:3kbotmit]

But now I have two completely different debug logs:
jboss-1-access.log:
[code:3kbotmit]
Debug line with all properties:
FROMHOST: 'devfe1.example.de', fromhost-ip:
'10.0.1.36', HOSTNAME: 'devfe1', PRI: 134,
syslogtag 'JB1access-log', programname: 'JB1access-log', APP-NAME:
'JB1access-log', PROCID: '', MSGID: '-',
TIMESTAMP: 'Feb 28 08:49:02', STRUCTURED-DATA: '-',
msg: ' 10.0.0.30 [28/Feb/2014:08:48:50
+0100] 0 HTTP/1.1 11001 http-executor-threads - 137 / 200 GET 2432
'
escaped msg: ' 10.0.0.30
[28/Feb/2014:08:48:50 +0100] 0 HTTP/1.1 11001
http-executor-threads - 137 / 200 GET 2432 '
rawmsg: '<134>Feb 28 08:49:02 devfe1 JB1access-log
10.0.0.30 [28/Feb/2014:08:48:50 +0100] 0
HTTP/1.1 11001 http-executor-threads - 137 / 200 GET 2432 '
[/code:3kbotmit]

all.log:
[code:3kbotmit]
Debug line with all properties:
FROMHOST: 'devfe1.example.de', fromhost-ip:
'10.0.1.36', HOSTNAME: '0', PRI: 188,
syslogtag 'Feb', programname: 'Feb', APP-NAME: 'Feb', PROCID:
'', MSGID: '-',
TIMESTAMP: 'Feb 28 08:48:57', STRUCTURED-DATA: '-',
msg: ' 28 08:49:02 devfe1 JB1access-log JB1access-log 
10.0.0.30 [28/Feb/2014:08:48:50 +0100] 0
HTTP/1.1 11001 http-executor-threads - 137 / 200 GET 2432 '
escaped msg: ' 28 08:49:02 devfe1 JB1access-log JB1access-log 
10.0.0.30 [28/Feb/2014:08:48:50 +0100] 0
HTTP/1.1 11001 http-executor-threads - 137 / 200 GET 2432 '
rawmsg: '<188>0 Feb 28 08:49:02 devfe1 JB1access-log
JB1access-log  10.0.0.30 [28/Feb/2014:08:48:50
+0100] 0 HTTP/1.1 11001 http-executor-threads - 137 / 200 GET 2432
'
[/code:3kbotmit]

I do not understand that both lines look different and both came from the
exact same log line from one file, came from the exact same sender. How can
they look so different when it is coming from the same input channel? The
sender is a rsyslog in the same version, so I guess that the server should
understand the sender without any dialect issues.

So I wrote the same messages to a local file on the sender site:
[code:3kbotmit]
Debug line with all properties:
FROMHOST: '', fromhost-ip: '', HOSTNAME: 'devfe1', PRI:
134,
syslogtag 'JB1access-log', programname: 'JB1access-log', APP-NAME:
'JB1access-log', PROCID: '', MSGID: '-',
TIMESTAMP: 'Feb 28 09:13:14', STRUCTURED-DATA: '-',
msg: '10.0.0.30 [28/Feb/2014:09:13:04
+0100] 0 HTTP/1.1 11001 http-executor-threads - 1080
/as7_logo.png 200 GET 22866 '
escaped msg: '10.0.0.30
[28/Feb/2014:09:13:04 +0100] 0 HTTP/1.1 11001
http-executor-threads - 1080 /as7_logo.png 200 GET 22866 '
rawmsg: '10.0.0.30 [28/Feb/2014:09:13:04
+0100] 0 HTTP/1.1 11001 http-executor-threads - 1080
/as7_logo.png 200 GET 22866 '
[/code:3kbotmit]

So the message on the sender looks exactly like the correct one which is
written to the correct jboss-1-access.log. I do not understand where this
"broken" messages in the all.log are coming from.


Cheers,

Chriss