Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On 10/23/2017 7:55 PM, deoren wrote:

On 10/23/2017 7:51 PM, deoren wrote:

On 10/23/2017 7:38 PM, deoren wrote:

On 10/23/2017 7:11 PM, David Lang wrote:
do you have a tcpdump or info from Qualys saying what it sends as 
part of the scan?


David Lang




Thankfully (for troubleshooting purposes), the problem isn't specific 
to the Qualys scan. I later learned that messages coming from our 
ESXi hosts trigger the problem as well. It may be that ANY message 
arriving on an input where I'm attempting to check for an empty 
$!origin!hostname property is enough to trigger the segfault.


That said, the messages sent by the Qualys scan along with messages 
I've seen coming from our ESXi hosts are often missing information 
(such as the hostname).


I'll do further testing and post back.


According to what I captured with tcpdump, this is what Wireshark 
translated the conversation as:


<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [23140B70 
verbose 'Solo.VmwareCLI' opID=hostd-3963 user=root] Result (type 
boolean) (wsdl boolean) (kind 1)
<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [22DC2B70 
verbose 'Hostsvc.SyslogConfigProvider'] Received syslog cli 
invalidation message
<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [22DC2B70 
verbose 'Hostsvc.SyslogConfigProvider'] Running '/sbin/localcli system 
syslog config get'
<166>2017-10-24T00:48:08.073Z vms1.example.com Hostd: [22DC2B70 info 
'SysCommandPosix'] ForkExec(/sbin/localcli)  9164454
<166>2017-10-24T00:48:08.077Z vms1.example.com Hostd: [226B0B70 
verbose 'Default' opID=hostd-10a7 user=root] CloseSession called for 
session id=0896d7c3-f4a1-d872-7b76-a01bf0543edf
<166>2017-10-24T00:48:08.077Z vms1.example.com Hostd: [226B0B70 info 
'Vimsvc.ha-eventmgr' opID=hostd-10a7 user=root] Event 743 : User 
root@127.0.0.1 logged out (login time: Tuesday, 24 October, 2017 
00:48:07, number of API invocations: 0, user agent: )
<166>2017-10-24T00:48:08.106Z vms1.example.com Rhttpproxy: [FF9CFB70 
verbose 'Proxy Req 85506'] The client closed the stream, not 
unexpectedly.
<166>2017-10-24T00:48:08.408Z vms1.example.com Hostd: [22DC2B70 
verbose 'Hostsvc.SyslogConfigProvider'] Running '/sbin/localcli system 
syslog config logger list'
<166>2017-10-24T00:48:08.409Z vms1.example.com Hostd: [22DC2B70 info 
'SysCommandPosix'] ForkExec(/sbin/localcli)  916445


I'll next test with the logger command from a remote host and see 
where that goes.


logger --tcp --port 514 --server sawmill3.example.com "hello!"

That's enough to cause a segfault.


https://github.com/rsyslog/rsyslog/issues/1920

I've tried to supply everything I could to help reproduce the problem. 
Based on my testing, the problem also exists in the 8.16 version that is 
included with Ubuntu 16.04.

___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On 10/23/2017 7:51 PM, deoren wrote:

On 10/23/2017 7:38 PM, deoren wrote:

On 10/23/2017 7:11 PM, David Lang wrote:
do you have a tcpdump or info from Qualys saying what it sends as 
part of the scan?


David Lang




Thankfully (for troubleshooting purposes), the problem isn't specific 
to the Qualys scan. I later learned that messages coming from our ESXi 
hosts trigger the problem as well. It may be that ANY message arriving 
on an input where I'm attempting to check for an empty 
$!origin!hostname property is enough to trigger the segfault.


That said, the messages sent by the Qualys scan along with messages 
I've seen coming from our ESXi hosts are often missing information 
(such as the hostname).


I'll do further testing and post back.


According to what I captured with tcpdump, this is what Wireshark 
translated the conversation as:


<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [23140B70 verbose 
'Solo.VmwareCLI' opID=hostd-3963 user=root] Result (type boolean) (wsdl 
boolean) (kind 1)
<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [22DC2B70 verbose 
'Hostsvc.SyslogConfigProvider'] Received syslog cli invalidation message
<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [22DC2B70 verbose 
'Hostsvc.SyslogConfigProvider'] Running '/sbin/localcli system syslog 
config get'
<166>2017-10-24T00:48:08.073Z vms1.example.com Hostd: [22DC2B70 info 
'SysCommandPosix'] ForkExec(/sbin/localcli)  9164454
<166>2017-10-24T00:48:08.077Z vms1.example.com Hostd: [226B0B70 verbose 
'Default' opID=hostd-10a7 user=root] CloseSession called for session 
id=0896d7c3-f4a1-d872-7b76-a01bf0543edf
<166>2017-10-24T00:48:08.077Z vms1.example.com Hostd: [226B0B70 info 
'Vimsvc.ha-eventmgr' opID=hostd-10a7 user=root] Event 743 : User 
root@127.0.0.1 logged out (login time: Tuesday, 24 October, 2017 
00:48:07, number of API invocations: 0, user agent: )
<166>2017-10-24T00:48:08.106Z vms1.example.com Rhttpproxy: [FF9CFB70 
verbose 'Proxy Req 85506'] The client closed the stream, not unexpectedly.
<166>2017-10-24T00:48:08.408Z vms1.example.com Hostd: [22DC2B70 verbose 
'Hostsvc.SyslogConfigProvider'] Running '/sbin/localcli system syslog 
config logger list'
<166>2017-10-24T00:48:08.409Z vms1.example.com Hostd: [22DC2B70 info 
'SysCommandPosix'] ForkExec(/sbin/localcli)  916445


I'll next test with the logger command from a remote host and see where 
that goes.


logger --tcp --port 514 --server sawmill3.example.com "hello!"

That's enough to cause a segfault.
___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On 10/23/2017 7:38 PM, deoren wrote:

On 10/23/2017 7:11 PM, David Lang wrote:
do you have a tcpdump or info from Qualys saying what it sends as part 
of the scan?


David Lang




Thankfully (for troubleshooting purposes), the problem isn't specific to 
the Qualys scan. I later learned that messages coming from our ESXi 
hosts trigger the problem as well. It may be that ANY message arriving 
on an input where I'm attempting to check for an empty $!origin!hostname 
property is enough to trigger the segfault.


That said, the messages sent by the Qualys scan along with messages I've 
seen coming from our ESXi hosts are often missing information (such as 
the hostname).


I'll do further testing and post back.


According to what I captured with tcpdump, this is what Wireshark 
translated the conversation as:


<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [23140B70 verbose 
'Solo.VmwareCLI' opID=hostd-3963 user=root] Result (type boolean) (wsdl 
boolean) (kind 1)
<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [22DC2B70 verbose 
'Hostsvc.SyslogConfigProvider'] Received syslog cli invalidation message
<166>2017-10-24T00:48:08.071Z vms1.example.com Hostd: [22DC2B70 verbose 
'Hostsvc.SyslogConfigProvider'] Running '/sbin/localcli system syslog 
config get'
<166>2017-10-24T00:48:08.073Z vms1.example.com Hostd: [22DC2B70 info 
'SysCommandPosix'] ForkExec(/sbin/localcli)  9164454
<166>2017-10-24T00:48:08.077Z vms1.example.com Hostd: [226B0B70 verbose 
'Default' opID=hostd-10a7 user=root] CloseSession called for session 
id=0896d7c3-f4a1-d872-7b76-a01bf0543edf
<166>2017-10-24T00:48:08.077Z vms1.example.com Hostd: [226B0B70 info 
'Vimsvc.ha-eventmgr' opID=hostd-10a7 user=root] Event 743 : User 
root@127.0.0.1 logged out (login time: Tuesday, 24 October, 2017 
00:48:07, number of API invocations: 0, user agent: )
<166>2017-10-24T00:48:08.106Z vms1.example.com Rhttpproxy: [FF9CFB70 
verbose 'Proxy Req 85506'] The client closed the stream, not unexpectedly.
<166>2017-10-24T00:48:08.408Z vms1.example.com Hostd: [22DC2B70 verbose 
'Hostsvc.SyslogConfigProvider'] Running '/sbin/localcli system syslog 
config logger list'
<166>2017-10-24T00:48:08.409Z vms1.example.com Hostd: [22DC2B70 info 
'SysCommandPosix'] ForkExec(/sbin/localcli)  916445


I'll next test with the logger command from a remote host and see where 
that goes.

___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On 10/23/2017 7:11 PM, David Lang wrote:
do you have a tcpdump or info from Qualys saying what it sends as part 
of the scan?


David Lang




Thankfully (for troubleshooting purposes), the problem isn't specific to 
the Qualys scan. I later learned that messages coming from our ESXi 
hosts trigger the problem as well. It may be that ANY message arriving 
on an input where I'm attempting to check for an empty $!origin!hostname 
property is enough to trigger the segfault.


That said, the messages sent by the Qualys scan along with messages I've 
seen coming from our ESXi hosts are often missing information (such as 
the hostname).


I'll do further testing and post back.

___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[David Lang]

do you have a tcpdump or info from Qualys saying what it sends as part of the 
scan?


David Lang
___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On 10/7/2017 10:44 AM, deoren wrote:

On 10/7/2017 5:25 AM, Rainer Gerhards wrote:

2017-10-07 7:57 GMT+02:00 deoren
:

As I dig more into this, I'm beginning to think the only thing the 
Qualys

scan did was aggravate an existing problem and cause rsyslog to tip over
more quickly.

While I didn't observe the problem at the time, I recently made some
configuration changes to introduce a lookup table to map known IPs to 
known
hostnames (something I plan to programmatically build from a central 
db at
some point in the future). I opted to try this in an effort to stop 
using

$hostname directly (which gives odd results with invalid messages) for
dynamic directory/filenames.

A long story short, I found that systemd is now (without a Qualys scan
actively running) restarting rsyslog after it dies within a minute or 
so of

running. My guess is that when a remote client sees that the rsyslog
receiver is running again it retries delivery and when the receiver is
passed the message it performs the lookup. At that point the real 
cause for

the segfault is triggered and rsyslog goes down.

Looking at the output of the dmesg command I found many instances of
messages like this one:

[364581.440049] rs:main Q:Reg[82570]: segfault at 0 ip 
7faeb1fa55f4 sp

7faeaac431d0 error 4 in libfastjson.so.4.1.0[7faeb1fa1000+a000]

I stopped rsyslog and then manually started it up like so:

rsyslogd -dn > rsyslog-debug.log 2>&1

This was printed to the console:

Segmentation fault (core dumped)

Here are the last 20 lines from the debug log file:

7587.842410212:main Q:Reg/w0  : ../action.c: action 'action 21': set
suspended state to 0
7587.842412422:main Q:Reg/w0  : rainerscript.c: STOP
7587.842418787:main Q:Reg/w0  : ruleset.c: processBATCH: next msg 44:
<167>2017-10-07T01:15:37.701Z vms2.example.com Rhttpproxy: verbose
rhttpproxy[79FC5B70] [Originator@6876 sub=Proxy Req 829
7587.842421471:main Q:Reg/w0  : rainerscript.c: CALL
[receiver-origin-hostname-lookup, queue:0]
7587.842427317:main Q:Reg/w0  : rainerscript.c: IF
7587.842433062:main Q:Reg/w0  : rainerscript.c: var 
'fromhost-ip'

7587.842442260:main Q:Reg/w0  : rainerscript.c:   ==
7587.842449663:main Q:Reg/w0  : rainerscript.c: string 
'127.0.0.1'
7587.842460890:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, 
type

'CMP_EQ'
7587.842463187:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, 
type

'V'
7587.842466060:main Q:Reg/w0  : rainerscript.c: rainerscript: 
(string) var

8: '192.168.5.142'
7587.842468406:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, 
return

datatype 'S':0
7587.842470812:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, 
return

datatype 'N':0
7587.842473056:main Q:Reg/w0  : ruleset.c: if condition result is 0
7587.842475315:main Q:Reg/w0  : rainerscript.c: IF
7587.842480945:main Q:Reg/w0  : rainerscript.c: var
'!origin!hostname'
7587.842490085:main Q:Reg/w0  : rainerscript.c:   ==
7587.842497393:main Q:Reg/w0  : rainerscript.c: string ''
7587.842508499:main Q:Reg/w0  : rainerscript.c: eval expr 0x22148f0, 
type

'CMP_EQ'
7587.842511262:main Q:Reg/w0  : rainerscript.c: eval expr 0x22146f0, 
type

'V'

I checked my JSON lookup table file and found a duplicate key (but with
different values). This was unintentional and was a result of a 
mistake when

building out the file (copy, paste, modify, oops!).

I was hopeful that fixing that would resolve the issue, but no such 
luck.


Just in case it isn't readable above, here is the same output plus the
ruleset I'm using:

https://gist.github.com/deoren/7e8e799428d0d87c4e467fd4add51d09

Anything stand out as obviously wrong?

I've gone back over the Expressions, Control Structures and Variable
(Property) types docs and it doesn't appear that I'm attempting to
access/set the variables improperly, but I could be missing something.


The lookup table feature was added in 8.17.0 as an experimental
feature. There seems to be at least one hard-to-find bug inside it,
see here:

https://github.com/rsyslog/rsyslog/issues/1071

In the past days, I have looked at the issue as the original
contributor seems to have lost interest in it. It sounds like what you
experience is related to this problem. It would be great if you could
run rsyslog under valgrind and see if the problem persists and, if so,
what valgrind reports. You can use valgrind simply by installing the
distro-provided valgrind package and prefixing the command with
"valgrind", as such:

$ valgrind rsyslogd -dn > rsyslog-debug.log 2>&1

This would be very helpful. It might also be very, very useful if you
could add your findings to above-mentioned github issue tracker. I am
99.999% sure it is the same root cause.

Rainer



Thanks in advance for your help.


Sure, I can do that.

I ended up eventually getting my configuration to a "stable" point where 
where rsyslog was no longer crashing, though I don't yet fully 

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On 10/7/2017 5:25 AM, Rainer Gerhards wrote:

2017-10-07 7:57 GMT+02:00 deoren
:


As I dig more into this, I'm beginning to think the only thing the Qualys
scan did was aggravate an existing problem and cause rsyslog to tip over
more quickly.

While I didn't observe the problem at the time, I recently made some
configuration changes to introduce a lookup table to map known IPs to known
hostnames (something I plan to programmatically build from a central db at
some point in the future). I opted to try this in an effort to stop using
$hostname directly (which gives odd results with invalid messages) for
dynamic directory/filenames.

A long story short, I found that systemd is now (without a Qualys scan
actively running) restarting rsyslog after it dies within a minute or so of
running. My guess is that when a remote client sees that the rsyslog
receiver is running again it retries delivery and when the receiver is
passed the message it performs the lookup. At that point the real cause for
the segfault is triggered and rsyslog goes down.

Looking at the output of the dmesg command I found many instances of
messages like this one:

[364581.440049] rs:main Q:Reg[82570]: segfault at 0 ip 7faeb1fa55f4 sp
7faeaac431d0 error 4 in libfastjson.so.4.1.0[7faeb1fa1000+a000]

I stopped rsyslog and then manually started it up like so:

rsyslogd -dn > rsyslog-debug.log 2>&1

This was printed to the console:

Segmentation fault (core dumped)

Here are the last 20 lines from the debug log file:

7587.842410212:main Q:Reg/w0  : ../action.c: action 'action 21': set
suspended state to 0
7587.842412422:main Q:Reg/w0  : rainerscript.c: STOP
7587.842418787:main Q:Reg/w0  : ruleset.c: processBATCH: next msg 44:
<167>2017-10-07T01:15:37.701Z vms2.example.com Rhttpproxy: verbose
rhttpproxy[79FC5B70] [Originator@6876 sub=Proxy Req 829
7587.842421471:main Q:Reg/w0  : rainerscript.c: CALL
[receiver-origin-hostname-lookup, queue:0]
7587.842427317:main Q:Reg/w0  : rainerscript.c: IF
7587.842433062:main Q:Reg/w0  : rainerscript.c: var 'fromhost-ip'
7587.842442260:main Q:Reg/w0  : rainerscript.c:   ==
7587.842449663:main Q:Reg/w0  : rainerscript.c: string '127.0.0.1'
7587.842460890:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, type
'CMP_EQ'
7587.842463187:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, type
'V'
7587.842466060:main Q:Reg/w0  : rainerscript.c: rainerscript: (string) var
8: '192.168.5.142'
7587.842468406:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, return
datatype 'S':0
7587.842470812:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, return
datatype 'N':0
7587.842473056:main Q:Reg/w0  : ruleset.c: if condition result is 0
7587.842475315:main Q:Reg/w0  : rainerscript.c: IF
7587.842480945:main Q:Reg/w0  : rainerscript.c: var
'!origin!hostname'
7587.842490085:main Q:Reg/w0  : rainerscript.c:   ==
7587.842497393:main Q:Reg/w0  : rainerscript.c: string ''
7587.842508499:main Q:Reg/w0  : rainerscript.c: eval expr 0x22148f0, type
'CMP_EQ'
7587.842511262:main Q:Reg/w0  : rainerscript.c: eval expr 0x22146f0, type
'V'

I checked my JSON lookup table file and found a duplicate key (but with
different values). This was unintentional and was a result of a mistake when
building out the file (copy, paste, modify, oops!).

I was hopeful that fixing that would resolve the issue, but no such luck.

Just in case it isn't readable above, here is the same output plus the
ruleset I'm using:

https://gist.github.com/deoren/7e8e799428d0d87c4e467fd4add51d09

Anything stand out as obviously wrong?

I've gone back over the Expressions, Control Structures and Variable
(Property) types docs and it doesn't appear that I'm attempting to
access/set the variables improperly, but I could be missing something.


The lookup table feature was added in 8.17.0 as an experimental
feature. There seems to be at least one hard-to-find bug inside it,
see here:

https://github.com/rsyslog/rsyslog/issues/1071

In the past days, I have looked at the issue as the original
contributor seems to have lost interest in it. It sounds like what you
experience is related to this problem. It would be great if you could
run rsyslog under valgrind and see if the problem persists and, if so,
what valgrind reports. You can use valgrind simply by installing the
distro-provided valgrind package and prefixing the command with
"valgrind", as such:

$ valgrind rsyslogd -dn > rsyslog-debug.log 2>&1

This would be very helpful. It might also be very, very useful if you
could add your findings to above-mentioned github issue tracker. I am
99.999% sure it is the same root cause.

Rainer



Thanks in advance for your help.


Sure, I can do that.

I ended up eventually getting my configuration to a "stable" point where 
where rsyslog was no longer crashing, though I don't yet fully 
understand why what I changed worked.


In my current "stable" configuration 

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[Rainer Gerhards]

2017-10-07 7:57 GMT+02:00 deoren
:

> As I dig more into this, I'm beginning to think the only thing the Qualys
> scan did was aggravate an existing problem and cause rsyslog to tip over
> more quickly.
>
> While I didn't observe the problem at the time, I recently made some
> configuration changes to introduce a lookup table to map known IPs to known
> hostnames (something I plan to programmatically build from a central db at
> some point in the future). I opted to try this in an effort to stop using
> $hostname directly (which gives odd results with invalid messages) for
> dynamic directory/filenames.
>
> A long story short, I found that systemd is now (without a Qualys scan
> actively running) restarting rsyslog after it dies within a minute or so of
> running. My guess is that when a remote client sees that the rsyslog
> receiver is running again it retries delivery and when the receiver is
> passed the message it performs the lookup. At that point the real cause for
> the segfault is triggered and rsyslog goes down.
>
> Looking at the output of the dmesg command I found many instances of
> messages like this one:
>
> [364581.440049] rs:main Q:Reg[82570]: segfault at 0 ip 7faeb1fa55f4 sp
> 7faeaac431d0 error 4 in libfastjson.so.4.1.0[7faeb1fa1000+a000]
>
> I stopped rsyslog and then manually started it up like so:
>
> rsyslogd -dn > rsyslog-debug.log 2>&1
>
> This was printed to the console:
>
> Segmentation fault (core dumped)
>
> Here are the last 20 lines from the debug log file:
>
> 7587.842410212:main Q:Reg/w0  : ../action.c: action 'action 21': set
> suspended state to 0
> 7587.842412422:main Q:Reg/w0  : rainerscript.c: STOP
> 7587.842418787:main Q:Reg/w0  : ruleset.c: processBATCH: next msg 44:
> <167>2017-10-07T01:15:37.701Z vms2.example.com Rhttpproxy: verbose
> rhttpproxy[79FC5B70] [Originator@6876 sub=Proxy Req 829
> 7587.842421471:main Q:Reg/w0  : rainerscript.c: CALL
> [receiver-origin-hostname-lookup, queue:0]
> 7587.842427317:main Q:Reg/w0  : rainerscript.c: IF
> 7587.842433062:main Q:Reg/w0  : rainerscript.c: var 'fromhost-ip'
> 7587.842442260:main Q:Reg/w0  : rainerscript.c:   ==
> 7587.842449663:main Q:Reg/w0  : rainerscript.c: string '127.0.0.1'
> 7587.842460890:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, type
> 'CMP_EQ'
> 7587.842463187:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, type
> 'V'
> 7587.842466060:main Q:Reg/w0  : rainerscript.c: rainerscript: (string) var
> 8: '192.168.5.142'
> 7587.842468406:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, return
> datatype 'S':0
> 7587.842470812:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, return
> datatype 'N':0
> 7587.842473056:main Q:Reg/w0  : ruleset.c: if condition result is 0
> 7587.842475315:main Q:Reg/w0  : rainerscript.c: IF
> 7587.842480945:main Q:Reg/w0  : rainerscript.c: var
> '!origin!hostname'
> 7587.842490085:main Q:Reg/w0  : rainerscript.c:   ==
> 7587.842497393:main Q:Reg/w0  : rainerscript.c: string ''
> 7587.842508499:main Q:Reg/w0  : rainerscript.c: eval expr 0x22148f0, type
> 'CMP_EQ'
> 7587.842511262:main Q:Reg/w0  : rainerscript.c: eval expr 0x22146f0, type
> 'V'
>
> I checked my JSON lookup table file and found a duplicate key (but with
> different values). This was unintentional and was a result of a mistake when
> building out the file (copy, paste, modify, oops!).
>
> I was hopeful that fixing that would resolve the issue, but no such luck.
>
> Just in case it isn't readable above, here is the same output plus the
> ruleset I'm using:
>
> https://gist.github.com/deoren/7e8e799428d0d87c4e467fd4add51d09
>
> Anything stand out as obviously wrong?
>
> I've gone back over the Expressions, Control Structures and Variable
> (Property) types docs and it doesn't appear that I'm attempting to
> access/set the variables improperly, but I could be missing something.

The lookup table feature was added in 8.17.0 as an experimental
feature. There seems to be at least one hard-to-find bug inside it,
see here:

https://github.com/rsyslog/rsyslog/issues/1071

In the past days, I have looked at the issue as the original
contributor seems to have lost interest in it. It sounds like what you
experience is related to this problem. It would be great if you could
run rsyslog under valgrind and see if the problem persists and, if so,
what valgrind reports. You can use valgrind simply by installing the
distro-provided valgrind package and prefixing the command with
"valgrind", as such:

$ valgrind rsyslogd -dn > rsyslog-debug.log 2>&1

This would be very helpful. It might also be very, very useful if you
could add your findings to above-mentioned github issue tracker. I am
99.999% sure it is the same root cause.

Rainer

>
> Thanks in advance for your help.
>
>
> ___
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
> 

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On 10/6/2017 4:42 PM, David Lang wrote:

On Fri, 6 Oct 2017, deoren wrote:

I'm going to retest soon, one port at a time to see if the segfault is 
specific to one of the inputs.


Once I determine that I'll likely setup a vanilla installation of 
rsyslog with imudp, imptcp and imrelp enabled and try to replicate the 
segfault. If I can isolate a generic configuration that results in a 
segfault, I assume the best place to report this will be via a GitHub 
ticket? I also assume that a debug log would be useful in pinpointing 
the exact cause.


If I can get to that point, where should I send the debug log?


A debug log is of limited use in a segfault situation (the application 
isn't able to log what causes the segfault)


But if you are testing the ports one at a time, getting a tcpdump 
capture of the traffic to that port that triggers the segfault will 
allow someone else to try and replicate it by sending the same data to 
their system.


David Lang


As I dig more into this, I'm beginning to think the only thing the 
Qualys scan did was aggravate an existing problem and cause rsyslog to 
tip over more quickly.


While I didn't observe the problem at the time, I recently made some 
configuration changes to introduce a lookup table to map known IPs to 
known hostnames (something I plan to programmatically build from a 
central db at some point in the future). I opted to try this in an 
effort to stop using $hostname directly (which gives odd results with 
invalid messages) for dynamic directory/filenames.


A long story short, I found that systemd is now (without a Qualys scan 
actively running) restarting rsyslog after it dies within a minute or so 
of running. My guess is that when a remote client sees that the rsyslog 
receiver is running again it retries delivery and when the receiver is 
passed the message it performs the lookup. At that point the real cause 
for the segfault is triggered and rsyslog goes down.


Looking at the output of the dmesg command I found many instances of 
messages like this one:


[364581.440049] rs:main Q:Reg[82570]: segfault at 0 ip 7faeb1fa55f4 
sp 7faeaac431d0 error 4 in libfastjson.so.4.1.0[7faeb1fa1000+a000]


I stopped rsyslog and then manually started it up like so:

rsyslogd -dn > rsyslog-debug.log 2>&1

This was printed to the console:

Segmentation fault (core dumped)

Here are the last 20 lines from the debug log file:

7587.842410212:main Q:Reg/w0  : ../action.c: action 'action 21': set 
suspended state to 0

7587.842412422:main Q:Reg/w0  : rainerscript.c: STOP
7587.842418787:main Q:Reg/w0  : ruleset.c: processBATCH: next msg 44: 
<167>2017-10-07T01:15:37.701Z vms2.example.com Rhttpproxy: verbose 
rhttpproxy[79FC5B70] [Originator@6876 sub=Proxy Req 829
7587.842421471:main Q:Reg/w0  : rainerscript.c: CALL 
[receiver-origin-hostname-lookup, queue:0]

7587.842427317:main Q:Reg/w0  : rainerscript.c: IF
7587.842433062:main Q:Reg/w0  : rainerscript.c: var 'fromhost-ip'
7587.842442260:main Q:Reg/w0  : rainerscript.c:   ==
7587.842449663:main Q:Reg/w0  : rainerscript.c: string '127.0.0.1'
7587.842460890:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, 
type 'CMP_EQ'
7587.842463187:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, 
type 'V'
7587.842466060:main Q:Reg/w0  : rainerscript.c: rainerscript: (string) 
var 8: '192.168.5.142'
7587.842468406:main Q:Reg/w0  : rainerscript.c: eval expr 0x22138e0, 
return datatype 'S':0
7587.842470812:main Q:Reg/w0  : rainerscript.c: eval expr 0x22147a0, 
return datatype 'N':0

7587.842473056:main Q:Reg/w0  : ruleset.c: if condition result is 0
7587.842475315:main Q:Reg/w0  : rainerscript.c: IF
7587.842480945:main Q:Reg/w0  : rainerscript.c: var 
'!origin!hostname'

7587.842490085:main Q:Reg/w0  : rainerscript.c:   ==
7587.842497393:main Q:Reg/w0  : rainerscript.c: string ''
7587.842508499:main Q:Reg/w0  : rainerscript.c: eval expr 0x22148f0, 
type 'CMP_EQ'
7587.842511262:main Q:Reg/w0  : rainerscript.c: eval expr 0x22146f0, 
type 'V'


I checked my JSON lookup table file and found a duplicate key (but with 
different values). This was unintentional and was a result of a mistake 
when building out the file (copy, paste, modify, oops!).


I was hopeful that fixing that would resolve the issue, but no such luck.

Just in case it isn't readable above, here is the same output plus the 
ruleset I'm using:


https://gist.github.com/deoren/7e8e799428d0d87c4e467fd4add51d09

Anything stand out as obviously wrong?

I've gone back over the Expressions, Control Structures and Variable 
(Property) types docs and it doesn't appear that I'm attempting to 
access/set the variables improperly, but I could be missing something.


Thanks in advance for your help.

___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow 

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[David Lang]

On Fri, 6 Oct 2017, deoren wrote:

I'm going to retest soon, one port at a time to see if the segfault is 
specific to one of the inputs.


Once I determine that I'll likely setup a vanilla installation of rsyslog 
with imudp, imptcp and imrelp enabled and try to replicate the segfault. If I 
can isolate a generic configuration that results in a segfault, I assume the 
best place to report this will be via a GitHub ticket? I also assume that a 
debug log would be useful in pinpointing the exact cause.


If I can get to that point, where should I send the debug log?


A debug log is of limited use in a segfault situation (the application isn't 
able to log what causes the segfault)


But if you are testing the ports one at a time, getting a tcpdump capture of the 
traffic to that port that triggers the segfault will allow someone else to try 
and replicate it by sending the same data to their system.


David Lang
___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

2017-10-06 8:27 GMT+02:00 deoren
:



On October 6, 2017 1:03:32 AM CDT, Thomas Deutschmann via rsyslog 
 wrote:

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On 2017-10-06 07:45, deoren wrote:

Is this expected? I recall reading that rsyslog should be properly
firewalled to protect it from malicious traffic, but I couldn't
recall what would happen if it were exposed to scans: fall over vs
trash data logged.


More details please.

What kind of rsyslog service was exposed (imuxsock, imudp, imtcp,
imrelp...)?

Do have some details about the scan itself? Can you share steps how to
reproduce?

If it is true what you are saying "you" found a DoS vulnerability in
rsyslog. No service should crash when receiving/processing
invalid/malformed data.


- --
Regards,
Thomas


I will gather more info and post back.

Quick info:

imrelp, imudp, imptcp exposed.

I believe I used two scans to repro: authenticated scan and remote port scan.

Will gather more info later today if I can, later this weekend if not. I just 
wanted to make sure this wasn't a known issue before digging too deep into it.

Thanks.


On 10/6/2017 1:34 AM, Rainer Gerhards wrote:> In any case, I think it 
would make sense to use the current 8.29.0

> version if not installed.
>
> Just a thought.
>
> Rainer


We're using Ubuntu 16.04 x64 as the OS within a VMware ESXi 6.0.x 
environment. We are running the latest stable v8.29.0 from your PPA on 
all of our Ubuntu nodes. I've confirmed segfaults for each of our 
receivers (all Ubuntu 16.04, all v8.29.0), but I've not retested since 
my first email about this to see which specific port is receiving the 
invalid data.


I'm going to retest soon, one port at a time to see if the segfault is 
specific to one of the inputs.


Once I determine that I'll likely setup a vanilla installation of 
rsyslog with imudp, imptcp and imrelp enabled and try to replicate the 
segfault. If I can isolate a generic configuration that results in a 
segfault, I assume the best place to report this will be via a GitHub 
ticket? I also assume that a debug log would be useful in pinpointing 
the exact cause.


If I can get to that point, where should I send the debug log?

Thanks.
___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[Rainer Gerhards]

In any case, I think it would make sense to use the current 8.29.0
version if not installed.

Just a thought.

Rainer

2017-10-06 8:27 GMT+02:00 deoren
:
>
>
> On October 6, 2017 1:03:32 AM CDT, Thomas Deutschmann via rsyslog 
>  wrote:
>>-BEGIN PGP SIGNED MESSAGE-
>>Hash: SHA512
>>
>>On 2017-10-06 07:45, deoren wrote:
>>> Is this expected? I recall reading that rsyslog should be properly
>>> firewalled to protect it from malicious traffic, but I couldn't
>>> recall what would happen if it were exposed to scans: fall over vs
>>> trash data logged.
>>
>>More details please.
>>
>>What kind of rsyslog service was exposed (imuxsock, imudp, imtcp,
>>imrelp...)?
>>
>>Do have some details about the scan itself? Can you share steps how to
>>reproduce?
>>
>>If it is true what you are saying "you" found a DoS vulnerability in
>>rsyslog. No service should crash when receiving/processing
>>invalid/malformed data.
>>
>>
>>- --
>>Regards,
>>Thomas
>
> I will gather more info and post back.
>
> Quick info:
>
> imrelp, imudp, imptcp exposed.
>
> I believe I used two scans to repro: authenticated scan and remote port scan.
>
> Will gather more info later today if I can, later this weekend if not. I just 
> wanted to make sure this wasn't a known issue before digging too deep into it.
>
> Thanks.
>
> ___
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
> http://www.rsyslog.com/professional-services/
> What's up with rsyslog? Follow https://twitter.com/rgerhards
> NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
> sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T 
> LIKE THAT.
___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[deoren]

On October 6, 2017 1:03:32 AM CDT, Thomas Deutschmann via rsyslog 
 wrote:
>-BEGIN PGP SIGNED MESSAGE-
>Hash: SHA512
>
>On 2017-10-06 07:45, deoren wrote:
>> Is this expected? I recall reading that rsyslog should be properly 
>> firewalled to protect it from malicious traffic, but I couldn't
>> recall what would happen if it were exposed to scans: fall over vs
>> trash data logged.
>
>More details please.
>
>What kind of rsyslog service was exposed (imuxsock, imudp, imtcp,
>imrelp...)?
>
>Do have some details about the scan itself? Can you share steps how to
>reproduce?
>
>If it is true what you are saying "you" found a DoS vulnerability in
>rsyslog. No service should crash when receiving/processing
>invalid/malformed data.
>
>
>- -- 
>Regards,
>Thomas

I will gather more info and post back.

Quick info:

imrelp, imudp, imptcp exposed.

I believe I used two scans to repro: authenticated scan and remote port scan.

Will gather more info later today if I can, later this weekend if not. I just 
wanted to make sure this wasn't a known issue before digging too deep into it.

Thanks.

___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Re: [rsyslog] Qualys scan against rsyslog causes it to segfault

[Thomas Deutschmann via rsyslog]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On 2017-10-06 07:45, deoren wrote:
> Is this expected? I recall reading that rsyslog should be properly 
> firewalled to protect it from malicious traffic, but I couldn't
> recall what would happen if it were exposed to scans: fall over vs
> trash data logged.

More details please.

What kind of rsyslog service was exposed (imuxsock, imudp, imtcp,
imrelp...)?

Do have some details about the scan itself? Can you share steps how to
reproduce?

If it is true what you are saying "you" found a DoS vulnerability in
rsyslog. No service should crash when receiving/processing
invalid/malformed data.


- -- 
Regards,
Thomas
-BEGIN PGP SIGNATURE-
Version: GnuPG v2

iQKTBAEBCgB9FiEEM8WEgsQCKS0uPFwGlwn5DDyW/8gFAlnXHK1fFIAALgAo
aXNzdWVyLWZwckBub3RhdGlvbnMub3BlbnBncC5maWZ0aGhvcnNlbWFuLm5ldDMz
QzU4NDgyQzQwMjI5MkQyRTNDNUMwNjk3MDlGOTBDM0M5NkZGQzgACgkQlwn5DDyW
/8j6HA/5AbSkSVWAhM28QiOHhd4UagZkvCYdtQiOmH8N1gTcsSDFhndIKJhnuVyd
fESSiYuP1Llj3RAQzq49N/7LG6fteIRx4LpeJ0Qy1frLEFUzg9w39cpXSw6n+qRD
A0dofjEwTEu8cdivWwnJ4nIfDP4949F367n8L/gsc18OFuJ5hCGDLX7qO8wxucoO
9SW++w0dp9m9U475myPwK/sXxvJS4tqhPH8Tp4yrCFBYpMONP+TFPY6C43jUqjaG
X77z2hvIIQTtz0Z3Kfs/+zjUc1y5UVeYhW3ABPacG1xrFseBzbhr1o5UhyRrWoVo
bMDFSPnXGDQNAhl7KojuuVEcC0hGb10Rs0721/VUk7s6q7glIcPetWUw+VSv2qW+
2bayVpt3utzbYK5jwVoiR4AgvJb0wgtAkMlX2btsQ0gyhaUr9MoyMHVLDu2YznO9
CR2c5CDATul8w6YCsOQNOncQVAzlGQ0nu35CTZFYZRkqbfTC+tU/dhHF7MDkM/B7
nApHb+y+zCIQdAZeUqFiMa2SSDNp7wVMcUf9hogwBwNcx2IaJwDQ8vpYXZFQaEyZ
1JNpS0PGNV/CJK3VemvquxfkBLKk4i4jMnSBwiJuw/G1k00xFUkB70o2Q66d861d
pyZKhNYaCIHxQMtACvnbhbSzAyoMSZEUZskpkIKsIKteNWg8K68=
=RQHM
-END PGP SIGNATURE-
___
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.