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

Bug #1481671 reported by Andrey Bubyr on 2015-08-05
14
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Mirantis OpenStack
Medium
MOS Linux
rsyslog (Ubuntu)
Undecided
Unassigned

Bug Description

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) wrote :
description: updated
Andrey Bubyr (abubyr) wrote :

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

Andrey Bubyr (abubyr) on 2015-08-05
affects: fuel → mos
Changed in mos:
assignee: nobody → MOS Linux (mos-linux)

> 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?

Changed in mos:
assignee: MOS Linux (mos-linux) → Andrey Bubyr (abubyr)
status: New → Incomplete
importance: Undecided → Medium
Andrey Bubyr (abubyr) wrote :

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) wrote :

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) wrote :

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

no longer affects: mos/6.0-updates
Changed in mos:
milestone: none → 6.0-updates
status: Incomplete → Confirmed
assignee: Andrey Bubyr (abubyr) → MOS Linux (mos-linux)
Vitaly Sedelnik (vsedelnik) wrote :

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

Changed in mos:
milestone: 6.0-updates → 6.0.1
Vitaly Sedelnik (vsedelnik) wrote :

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

Changed in mos:
status: Confirmed → Won't Fix
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.