Bug 563348 - rsyslog-4.4.2-4.fc13 fails to start
Summary: rsyslog-4.4.2-4.fc13 fails to start
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: rsyslog
Version: rawhide
Hardware: All
OS: Linux
low
urgent
Target Milestone: ---
Assignee: Tomas Heinrich
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 563954 (view as bug list)
Depends On:
Blocks: F13Alpha, F13AlphaBlocker
TreeView+ depends on / blocked
 
Reported: 2010-02-09 22:32 UTC by Bruno Wolff III
Modified: 2016-09-20 04:49 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2010-02-12 16:53:23 UTC


Attachments (Terms of Use)

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


Note You need to log in before you can comment on or make changes to this bug.