Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.

Bug 563348

Summary:	rsyslog-4.4.2-4.fc13 fails to start
Product:	[Fedora] Fedora	Reporter:	Bruno Wolff III <bruno>
Component:	rsyslog	Assignee:	Tomas Heinrich <theinric>
Status:	CLOSED RAWHIDE	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	urgent	Docs Contact:
Priority:	low
Version:	rawhide	CC:	antonio.montagnani, awilliam, dcantrell, mtasaka, pebolle, pvrabec, rnovacek, selinux, theinric
Target Milestone:	---	Keywords:	Triaged
Target Release:	---
Hardware:	All
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2010-02-12 16:53:23 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	538273

Description Bruno Wolff III 2010-02-09 22:32:25 UTC

Description of problem:
rsyslog fails to start both at boot (eventually there is a timeout and the boot succeeds, though rsyslog fails) and using service rsyslog restart. The latter hangs. I didn't wait long enough for a timeout to occur, but it's over a minute.

Version-Release number of selected component (if applicable):
rsyslog-4.4.2-4.fc13.i686

How reproducible:
Seems to happen all of the time.

Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:

Additional info:

The last thing in var log messages after the yum update was:
Feb  9 12:11:20 bruno kernel: Kernel logging (proc) stopped.
This was 7 minutes later than the last entry from the yum update.

Comment 1 Tomas Heinrich 2010-02-10 10:58:39 UTC

Thanks for the report.
Could you please try out this build:
http://koji.fedoraproject.org/koji/taskinfo?taskID=1973781

Comment 2 Bruno Wolff III 2010-02-10 14:13:29 UTC

I installed that build and the service started up and I was able to generate some log entries in /var/log/messages. So I think it is fixed.

Comment 3 Mamoru TASAKA 2010-02-11 07:54:47 UTC

I still observe "service rsyslog start" hang even with -5.fc13
on i686. -3.fc13 was the last rpm with which hang did not occur.

Comment 4 Tom London 2010-02-11 15:16:22 UTC

I'm getting a segfault with rsyslog-4.4.2-5.fc13.x86_64:

Core was generated by `rsyslogd -d -c 4'.
Program terminated with signal 11, Segmentation fault.
#0  0x0000000000000000 in ?? ()
(gdb) where
#0  0x0000000000000000 in ?? ()
#1  0x00007f437ce6f471 in runInput (pThrd=<value optimized out>)
    at imuxsock.c:250
#2  0x000000000042dcee in thrdStarter (arg=0x1aefbb0) at ../threads.c:139
#3  0x0000003c3ce06caa in start_thread (arg=0x7f437c265710)
    at pthread_create.c:297
#4  0x0000003c3cae25bd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
(gdb) set pagination off
(gdb) thread apply all bt full

Thread 4 (Thread 6009):
#0  clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:84
No locals.
#1  0x0000003c3ce06bf0 in ?? () at allocatestack.c:743 from /lib64/libpthread-2.11.90.so
No symbol table info available.
#2  0x00007f437b864710 in ?? ()
No symbol table info available.
#3  0x0000000000000000 in ?? ()
No symbol table info available.

Thread 3 (Thread 6006):
#0  0x0000003c3ce0e74d in write () at ../sysdeps/unix/syscall-template.S:82
No locals.
#1  0x000000000041c776 in dbgprint (pObj=<value optimized out>, pszMsg=0x7fffac8a2280 "\n", lenMsg=1) at debug.c:902
        ptLastThrdID = 139927839274752
        bWasNL = 1
        pszThrdName = "main thread\000Sp}*@\005\a}C\177\000\000@\"\212\254\377\177\000\000\000\000\000\000\000\000\000\000\003\000\000\000\000\000\000\000h'\212\254\377\177\000\000ڨ\024\306Sp}*"
        pszWriteBuf = "main thread: \000:\000 \036\212\254\377\177\000\000\237@`=<\000\000\000\060\036\212\254\377\177\000\000Y\347\340<<", '\000' <repeats 11 times>"\251, \307A\000\000\000\000\000\375\215\\$\000\000\000\000\020'\212\254\377\177\000\000\067\036tK\000\000\000\000\375\215\\$\000\000\000\000main thread: \000:\000g source = /proc/kmsg started.\000\000\001\000\000\000\000\000\000\000\000 \212\254\377\177\000\000\377\003\000\000\000\000\000\000\240wC\000\000\000\000\000  \212\254\377\177\000\000\060\216\257<<\000\000\000\001\200\255\373\377\177\000\000\340\036\212\254\377\177\000\000p \212\254\377\177\000\000\320\037\212\254\377\177\000\000\001\000\000\000\000\000\000\000P \212\254\377\177\000\000\377\003\000\000\000\000\000\000"...
        lenWriteBuf = <value optimized out>
        t = {tv_sec = 1265901111, tv_nsec = 610541950}
        pszObjName = <value optimized out>
#2  0x000000000041c9d8 in dbgprintf (fmt=0x2 <Address 0x2 out of bounds>) at debug.c:961
        ap = {{gp_offset = 8, fp_offset = 48, overflow_arg_area = 0x7fffac8a2750, reg_save_area = 0x7fffac8a2690}}
        pszWriteBuf = "\n\000evious is suspended: 0\n\000\000\000\000\000\000\000\263\064C\000\000\000\000\000\272\064C\000\000\000\000\000I\b\257\001\000\000\000\000\330\311A\000\000\000\000\000\b\000\000\000\060\000\000\000\260'\212\254\377\177\000\000\360&\212\254\377\177\000\000\000\000\000\000\000\000\000\000\nActions:\n\000\n\000tors:\n\000e is initialized and running\n\000\000\000\001\000\000\000\220#\212\254\377\177\000\000\250#\212\254\377\177\000\000x^)}C\177\000\000\220$\212\254\377\177\000\000\000\000\000\000\000\000\000\000P\231'}C\177\000\000\270$\212\254\377\177\000\000 [)}C\177\000\000\212\245`<<", '\000' <repeats 11 times>, "P\231"...
        lenWriteBuf = <value optimized out>
#3  0x00000000004098e0 in dbgPrintInitInfoAction (pData=<value optimized out>, pParam=<value optimized out>) at syslogd.c:2459
        iRet = <value optimized out>
#4  0x000000000041937f in llExecFunc (pThis=0x1af0878, pFunc=0x4098c0 <dbgPrintInitInfoAction>, pParam=0x0) at linkedlist.c:391
        iRet = RS_RET_OK
        iRetLL = <value optimized out>
        pData = 0x1af0a10
        llCookie = 0x1af03d0
        llCookiePrev = 0x0
#5  0x000000000040c748 in dbgPrintInitInfo () at syslogd.c:2509
        f = 0x1af0830
        iSelNbr = 3
#6  init () at syslogd.c:2791
        iRet = RS_RET_OK
        localRet = 28248112
        iNbrActions = 7
        bHadConfigErr = <value optimized out>
        cbuf = '\000' <repeats 1752 times>"\260, \004\000\000\000\000\000\000\200\336\327<<\000\000\000\200\336\327<<\000\000\000\241\004\000\000\000\000\000\000\340\r\256\001\000\000\000\000\200\336\327<<\000\000\000\214\365`<<", '\000' <repeats 11 times>"\242, \\\241<<", '\000' <repeats 11 times>"\212, \202`<<", '\000' <repeats 11 times>"\214, \365`<<\000\000\000B\000\000\000\000\000\000\000p\034\a}C\177\000\000\267\\\241<<\000\000\000\001\000\000\000<", '\000' <repeats 11 times>"\216, i`<<", '\000' <repeats 19 times>"\322, \035\340G<\000\000\000\002", '\000' <repeats 15 times>, "\003\000\000\000|\000\000\000w\000\000\000n\000\000\000[\000\000\000\060", '\000' <repeats 12 times>, "P\000\000\000\000\000\000|I\000\000\000\000\000\000"...
        bufStartUpMsg = "@\024\202<<\000\000\000\020I\212\254\377\177\000\000(I\212\254\377\177\000\000\020-\340<\001\000\000\000fII\"\000\000\000\000wM@\000\000\000\000\000\217\000\000\000\001", '\000' <repeats 11 times>, "(i\240<<\000\000\000\000\220'}C\177\000\000@J\212\254\377\177\000\000\377\377\377\377\000\000\000\000\230\226'}C\177\000\000\200\033\001", '\000' <repeats 29 times>, "P\033\001", '\000' <repeats 29 times>, "\002\000\000\000\000\000\000\000\260\000\000\000\000\000\000\000\t\000\000\000|\000\000\000w\000\000\000n\000\000\000[\000\000\000\062\000\000\000\260î\001\000\000\000\000\260î\001\000\000\000\000\210\000\000\000\000\000\000\000\200\336\327<<\000\000\000P\033\001\000\000\000\000\000\260\344\256\001\000\000\000\000\200\336\327<<\000\000\000*\274\247<<\000\000\000 \000\000\000\000\000\000\000\220"...
        sigAct = {__sigaction_handler = {sa_handler = 0, sa_sigaction = 0}, sa_mask = {__val = {0 <repeats 16 times>}}, sa_flags = 0, sa_restorer = 0}
#7  0x000000000040ce5a in mainThread () at syslogd.c:3256
        iRet = RS_RET_OK
        pTmp = 0x643f98 ""
#8  0x000000000040de61 in realMain (argc=<value optimized out>, argv=<value optimized out>) at syslogd.c:3955
        iRet = <value optimized out>
        p = <value optimized out>
        ch = <value optimized out>
        hent = <value optimized out>
        bEOptionWasGiven = 0
        bImUxSockLoaded = 0
        iHelperUOpt = 1
        bChDirRoot = 1
        arg = <value optimized out>
        legacyConfLine = '\000' <repeats 72 times>, "\004\000\000\000\000\000\000"
        LocalHostName = <value optimized out>
        LocalDomain = <value optimized out>
        LocalFQDNName = 0x1ae1560 "tlondon.innopath.com"
#9  0x0000003c3ca1ed2d in __libc_start_main (main=<value optimized out>, argc=<value optimized out>, ubp_av=<value optimized out>, init=<value optimized out>, fini=<value optimized out>, rtld_fini=<value optimized out>, stack_end=0x7fffac8a4d48) at libc-start.c:226
        result = <value optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0, -114778364810699976, 4231312, 140736088132944, 0, 0, 114666675698064184, -139540203267237064}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x430a50, 0x7fffac8a4d58}, data = {prev = 0x0, cleanup = 0x0, canceltype = 4393552}}}
        not_first_call = <value optimized out>
#10 0x00000000004090b9 in _start ()
No symbol table info available.

Thread 2 (Thread 6007):
#0  __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:136
No locals.
#1  0x0000003c3ce0949c in _L_lock_1202 () from /lib64/libpthread-2.11.90.so
No symbol table info available.
#2  0x0000003c3ce092bb in __pthread_mutex_lock (mutex=0x647560) at pthread_mutex_lock.c:61
        ignore1 = 128
        ignore2 = 6583648
        ignore3 = -512
        __PRETTY_FUNCTION__ = "__pthread_mutex_lock"
        type = <value optimized out>
        id = 6007
#3  0x000000000041c61b in dbgprint (pObj=<value optimized out>, pszMsg=0x7f437cc65910 "main queue:Reg/w0: receiving command 4\n", lenMsg=39) at debug.c:857
        ptLastThrdID = 139927839274752
        bWasNL = 1
        pszThrdName = '\000' <repeats 63 times>
        pszWriteBuf = '\000' <repeats 471 times>, "4", '\000' <repeats 40 times>, "\b\000\000\000\060\000\000\000\340]\306|C\177\000\000 ]\306|C\177", '\000' <repeats 194 times>"\200, W\306|C\177\000\000\020Y\306|C\177\000\000pX\306|C\177\000\000\001\000\000\000\000\000\000\000\360X\306|C\177\000\000\377\003\000\000\000\000\000\000\240wC\000\000\000\000\000\020Y\306|C\177\000\000\060\216\257<<\000\000\000\001\200\255\373\000\000\000\000\020Y\306|C\177\000\000\020Y\306|C\177\000\000\020Y\306|C\177\000\000\020Y\306|C\177\000\000\067Y\306|C\177\000\000\017]\306|C\177\000\000\020Y\306|C\177\000\000\017]\306|C\177", '\000' <repeats 46 times>, "\004", '\000' <repeats 75 times>"\377, \377\377\377", '\000' <repeats 20 times>...
        lenWriteBuf = <value optimized out>
        t = {tv_sec = 0, tv_nsec = 0}
        pszObjName = 0x0
#4  0x000000000041c9d8 in dbgprintf (fmt=0x647560 "\002") at debug.c:961
        ap = {{gp_offset = 24, fp_offset = 48, overflow_arg_area = 0x7f437cc65de0, reg_save_area = 0x7f437cc65d20}}
        pszWriteBuf = "main queue:Reg/w0: receiving command 4\n", '\000' <repeats 465 times>, "9\231`<<", '\000' <repeats 11 times>"\300, [\306|C\177\000\000\000\000\000\000\000\000\000\000X\226'}C\177\000\000H]\306|C\177\000\000\b\000\000\000\000\000\000\000\373uu\204\000\000\000\000Ǣ`<<", '\000' <repeats 11 times>"\327, \325\021\002\000\000\000\000;\000\000\000\000\000\000\000\f!\240<<", '\000' <repeats 11 times>"\300, [\306|C\177\000\000@<\240<<\000\000\000\350c\240<<", '\000' <repeats 51 times>"\350, \020\202<<", '\000' <repeats 11 times>"\260, \226'}C\177\000\000\000\220'}C\177\000\000*"...
        lenWriteBuf = <value optimized out>
#5  0x0000000000424b4e in wtiSetState (pThis=0x1aee6c0, tCmd=eWRKTHRD_RUNNING, bActiveOnly=<value optimized out>, bLockMutex=<value optimized out>) at wti.c:122
        iCancelStateSave = <value optimized out>
        bLockedOpIsLocked = 0
#6  0x0000000000423fba in wtpWorker (arg=0x1aee6c0) at wtp.c:447
        iRet = RS_RET_OK
        iCancelStateSave = 0
        bLockedOpIsLocked = 1
        pWti = 0x1aee6c0
        pThis = 0x1aee550
        sigSet = {__val = {18446744067267100671, 18446744073709551615 <repeats 15 times>}}
#7  0x0000003c3ce06caa in start_thread (arg=0x7f437cc66710) at pthread_create.c:297
        __res = <value optimized out>
        pd = 0x7f437cc66710
        now = <value optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139927832913680, -114778364810699976, 258719422272, 0, 0, 3, 67202304443341624, -139540740120323272}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <value optimized out>
        sp = <value optimized out>
        freesize = <value optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#8  0x0000003c3cae25bd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
No locals.

Thread 1 (Thread 6008):
#0  0x0000000000000000 in ?? ()
No symbol table info available.
#1  0x00007f437ce6f471 in runInput (pThrd=<value optimized out>) at imuxsock.c:250
        maxfds = <value optimized out>
        nfds = <value optimized out>
        i = <value optimized out>
        fd = <value optimized out>
#2  0x000000000042dcee in thrdStarter (arg=0x1aefbb0) at ../threads.c:139
        iRet = RS_RET_OK
        sigSet = {__val = {18446744067267100671, 18446744073709551615 <repeats 15 times>}}
#3  0x0000003c3ce06caa in start_thread (arg=0x7f437c265710) at pthread_create.c:297
        __res = <value optimized out>
        pd = 0x7f437c265710
        now = <value optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139927822423824, -114778364810699976, 258719422272, 0, 0, 3, 67204229125561144, -139540740120323272}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <value optimized out>
        sp = <value optimized out>
        freesize = <value optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#4  0x0000003c3cae25bd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
No locals.
(gdb)

Comment 5 Tomas Heinrich 2010-02-11 16:11:22 UTC

OK, here's another scratch build:
http://koji.fedoraproject.org/koji/taskinfo?taskID=1977645
Please give it a try.

Comment 6 Tom London 2010-02-11 16:24:53 UTC

rsyslog-4.4.2-6.fc13.x86_64.rpm "works for me".

Thanks!

Comment 7 Mamoru TASAKA 2010-02-11 16:44:12 UTC

-6 seems to work for me, too.

Comment 8 Tomas Heinrich 2010-02-11 17:01:18 UTC

Also seems to work on another i686. I'll do an official build.

Comment 9 Adam Williamson 2010-02-11 18:57:16 UTC


-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 10 Chris Lumens 2010-02-12 00:46:12 UTC

*** Bug 563954 has been marked as a duplicate of this bug. ***

Comment 11 Chris Lumens 2010-02-12 00:46:54 UTC

*** Bug 564213 has been marked as a duplicate of this bug. ***

Comment 12 Adam Williamson 2010-02-12 16:53:23 UTC

The fixed build, -6, has gone through Koji and should be in Rawhide now or soon:

http://koji.fedoraproject.org/koji/buildinfo?buildID=155653

since we have three confirmations that it works above, let's just close this.



-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers