[mos] rsyslog periodically crashes with *** glibc detected *** rsyslogd: double free or corruption (fasttop) preventing log into the system

[Andrey Bubyr]

Rsyslog crashes every 10-14 days on MogoDB nodes with coredump in /var/log/messages:
<46>Aug 4 15:01:56 node-115 rsyslogd: rsyslogd's groupid changed to 103
<46>Aug 4 15:01:56 node-115 rsyslogd: rsyslogd's userid changed to 101
<6>Aug 4 15:02:12 node-115 kernel: imklog 5.8.6, log source = /proc/kmsg started.
<46>Aug 4 15:02:12 node-115 rsyslogd: [origin software="rsyslogd" swVersion="5.8.6" x-pid="58757" x-info="http://www.
rsyslog.com"] start
<46>Aug 4 15:02:12 node-115 rsyslogd: rsyslogd's groupid changed to 103
<46>Aug 4 15:02:12 node-115 rsyslogd: rsyslogd's userid changed to 101
<6>Aug 4 15:02:13 node-115 kernel: imklog 5.8.6, log source = /proc/kmsg started.
<46>Aug 4 15:02:13 node-115 rsyslogd: [origin software="rsyslogd" swVersion="5.8.6" x-pid="58773" x-info="http://www.
rsyslog.com"] start
<46>Aug 4 15:02:13 node-115 rsyslogd: rsyslogd's groupid changed to 103
<46>Aug 4 15:02:13 node-115 rsyslogd: rsyslogd's userid changed to 101
<6>Aug 4 15:02:21 node-115 kernel: imklog 5.8.6, log source = /proc/kmsg started.
<46>Aug 4 15:02:21 node-115 rsyslogd: [origin software="rsyslogd" swVersion="5.8.6" x-pid="58788" x-info="http://www.
rsyslog.com"] start
<46>Aug 4 15:02:21 node-115 rsyslogd: rsyslogd's groupid changed to 103
<46>Aug 4 15:02:21 node-115 rsyslogd: rsyslogd's userid changed to 101
*** glibc detected *** rsyslogd: double free or corruption (fasttop): 0x00007f5e88032100 ***
======= Backtrace: =========
/lib/x86_64-linux-gnu/libc.so.6(+0x7e846)[0x7f5ea2101846]
rsyslogd[0x42ee36]
rsyslogd[0x431697]
rsyslogd[0x431ce7]
rsyslogd(wtiWorker+0xc3)[0x42b513]
rsyslogd[0x42a78a]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a)[0x7f5ea2855e9a]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f5ea217731d]
======= Memory map: ========
00400000-00456000 r-xp 00000000 08:03 8132346 /usr/sbin/rsyslogd
00656000-00658000 r--p 00056000 08:03 8132346 /usr/sbin/rsyslogd
00658000-0065e000 rw-p 00058000 08:03 8132346 /usr/sbin/rsyslogd
0065e000-0065f000 rw-p 00000000 00:00 0
00f18000-00f39000 rw-p 00000000 00:00 0 [heap]
00f39000-00f7b000 rw-p 00000000 00:00 0 [heap]
7f5e84000000-7f5e84040000 rw-p 00000000 00:00 0
7f5e84040000-7f5e88000000 ---p 00000000 00:00 0
7f5e88000000-7f5e88043000 rw-p 00000000 00:00 0
7f5e88043000-7f5e8c000000 ---p 00000000 00:00 0
7f5e8c000000-7f5e8c1eb000 rw-p 00000000 00:00 0
7f5e8c1eb000-7f5e90000000 ---p 00000000 00:00 0
< ... memory map ... >
Full memory map could be found in attached 'messages' log.
When rsyslog crashes in this manner it is impossible to login into the system. Process /bin/login successfully authenticates user, but does not born shell process, constantly waiting for rsyslog reading login log message from Unix socket.

Obviously Fuel master reports that node in 'False' state (because it becomes non-sshable too).

Workaround: fully restart rsyslog after crash (service rsyslog restart) if some active login session is present or reboot the server if not.

MOS 6.0, Ubuntu 12.04. Rsyslog v. 5.8.6 (from Fuel node repos). Rsyslog config files placed in rsyslog folder of attached archive.

[Andrey Bubyr (abubyr)]

Also it was found similar problem but with rsyslog 7.x.x branch - http://bugzilla.adiscon.com/show_bug.cgi?id=467

[Aleksander Mogylchenko (amogylchenko)]

> http://bugzilla.adiscon.com/show_bug.cgi?id=467
this bug is not relevant since memory map is completely different.

As I see from the output, rsyslog was restarted every 10 seconds or so for some time before the crash. Could you please clarify why it happens?

[Andrey Bubyr (abubyr)]

I don't exactly know but assume that this is due to logrotate run (but it should ve runned every hour, not every few minutes)
https://bugs.launchpad.net/ubuntu/+source/rsyslog/+bug/940030

[Andrey Bubyr (abubyr)]

In /etc/logrotate.d/10-fuel.conf we have:
 postrotate
      /bin/kill -HUP `cat /var/run/syslogd.pid 2> /dev/null` 2> /dev/null || true
      reload rsyslog >/dev/null 2>&1 || true
  endscript

[Vitaly Sedelnik (vsedelnik)]

Linux team - please try to reproduce this issue given the info provided by @abubyr.

[Vitaly Sedelnik (vsedelnik)]

Raised the priority to HIgh because after crash of rsyslog the node becomes not functional

[Vitaly Sedelnik (vsedelnik)]

Won't Fix for 6.0-updates because of Medium importance