Bug 54215 - Journalctl crash
Summary: Journalctl crash
Status: RESOLVED FIXED
Alias: None
Product: systemd
Classification: Unclassified
Component: general (show other bugs)
Version: unspecified
Hardware: Other All
: high normal
Assignee: systemd-bugs
QA Contact: systemd-bugs
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-08-29 14:52 UTC by Oleksii Shevchuk
Modified: 2012-11-01 17:43 UTC (History)
1 user (show)

See Also:
i915 platform:
i915 features:


Attachments

Description Oleksii Shevchuk 2012-08-29 14:52:54 UTC
I got some low level reading error from disk (individual, SMART/tests ok for now). At that moment it wrote something to logs. journalctl crashes at that entry.
I can get last messages with -n 1 etc.

Backtrace: 
> gdb --args journalctl -n 100 --no-pager
Logs begin at Thu, 23 Aug 2012 02:00:07 +0300, end at Thu, 23 Aug 2012 03:47:17 +0300.

Program received signal SIGSEGV, Segmentation fault.

$ bt
#0  0x8000c0f5 in compare_order (bo=0xa9846e90, bf=0x8003b320, ao=0xa68677e8, af=0x8003e928) at src/journal/sd-journal.c:368
#1  real_journal_next (j=0x80026028, direction=direction@entry=DIRECTION_UP) at src/journal/sd-journal.c:837
#2  0x8000c6eb in real_journal_next_skip (skip=0x42, direction=<optimized out>, j=<optimized out>) at src/journal/sd-journal.c:884
#3  real_journal_next_skip (j=<optimized out>, direction=DIRECTION_UP, skip=0x64) at src/journal/sd-journal.c:868
#4  0x80004e33 in main (argc=0x4, argv=0xbfffe674) at src/journal/journalctl.c:805

// systemd 189
Comment 1 Oleksii Shevchuk 2012-08-29 15:04:08 UTC
I copied that journal part. If i view it directly with -D option (in other directory, without older logs), all ok.

Here it is that part:

Aug 29 17:34:12 CLU kernel: ata1.00: exception Emask 0x0 SAct 0xff SErr 0x0 action 0x0
Aug 29 17:34:12 CLU kernel: ata1.00: irq_stat 0x40000008
Aug 29 17:34:12 CLU kernel: ata1.00: failed command: READ FPDMA QUEUED
Aug 29 17:34:12 CLU kernel: ata1.00: cmd 60/08:00:0f:35:7e/00:00:0a:00:00/40 tag 0 ncq 4096 in
         res 51/40:08:0f:35:7e/00:00:0a:00:00/40 Emask 0x409 (media error) <F>
Aug 29 17:34:12 CLU kernel: ata1.00: status: { DRDY ERR }
Aug 29 17:34:12 CLU kernel: ata1.00: error: { UNC }
Aug 29 17:34:12 CLU kernel: ata1.00: configured for UDMA/133
Aug 29 17:34:12 CLU kernel: sd 0:0:0:0: [sda] Unhandled sense code
Aug 29 17:34:12 CLU kernel: sd 0:0:0:0: [sda]  
Aug 29 17:34:12 CLU kernel: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Aug 29 17:34:12 CLU kernel: sd 0:0:0:0: [sda]  
Aug 29 17:34:12 CLU kernel: Sense Key : Medium Error [current] [descriptor]
Aug 29 17:34:12 CLU kernel: Descriptor sense data with sense descriptors (in hex):
Aug 29 17:34:12 CLU kernel:         72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00 
Aug 29 17:34:12 CLU kernel:         0a 7e 35 0f 
Aug 29 17:34:12 CLU kernel: sd 0:0:0:0: [sda]  
Aug 29 17:34:12 CLU kernel: Add. Sense: Unrecovered read error - auto reallocate failed
Aug 29 17:34:12 CLU kernel: sd 0:0:0:0: [sda] CDB: 
Aug 29 17:34:12 CLU kernel: Read(10): 28 00 0a 7e 35 0f 00 00 08 00
Aug 29 17:34:12 CLU kernel: end_request: I/O error, dev sda, sector 176043279
Aug 29 17:34:12 CLU kernel: Buffer I/O error on device dm-8, logical block 122027
Aug 29 17:34:12 CLU kernel: ata1: EH complete

---> journalctl always fails here, when view with older logs <---
Aug 29 17:34:26 CLU kernel: journalctl[22132]: segfault at a9b41fe8 ip b77e6b98 sp bfef4d20 error 4 in journalctl[b77da000+24000]
Comment 2 Vlad 2012-09-13 08:17:39 UTC
Starting with systemd-189 I have segfaults of systemd-journal as well (see below). However, I don't have any of these ata related exceptions reported by the bug creator. 

Sep 07 10:00:45 xxxx kernel: systemd-journal[154]: segfault at 7f29b4fd3480 ip 0000000000416ebb sp 00007fffb6ba6100 error 4 in systemd-journald[400000+28000]
Sep 08 03:00:01 xxxx kernel: systemd-journal[5633]: segfault at 7f9551319390 ip 0000000000416ebb sp 00007fff31eb0f50 error 4 in systemd-journald[400000+28000]
Sep 10 10:28:14 xxxx kernel: systemd-journal[150]: segfault at 7f03ce211e48 ip 0000000000417255 sp 00007fff7252fe90 error 4 in systemd-journald[400000+28000]
Sep 11 05:48:25 xxxx kernel: systemd-journal[5073]: segfault at 7f7f56142390 ip 0000000000416ebb sp 00007fff1edc93a0 error 4 in systemd-journald[400000+28000]
Sep 12 06:40:09 xxxx kernel: systemd-journal[31793]: segfault at 7fb62fffc990 ip 0000000000416ebb sp 00007fff92a6ab50 error 4 in systemd-journald[400000+28000]
Sep 12 09:11:58 xxxx kernel: systemd-journal[154]: segfault at 7fcf0756a480 ip 0000000000416ebb sp 00007fffa1152be0 error 4 in systemd-journald[400000+28000]
Sep 13 02:33:23 xxxx kernel: systemd-journal[4853]: segfault at 7f0181cfa480 ip 0000000000416ebb sp 00007fffbe2d86d0 error 4 in systemd-journald[400000+28000]
Sep 13 09:05:48 xxxx kernel: systemd-journal[153]: segfault at 7fa450257480 ip 0000000000416ebb sp 00007fff95521b10 error 4 in systemd-journald[400000+28000]
Comment 3 Lennart Poettering 2012-09-13 11:22:34 UTC
Hmm, if you have a journal file which I can run here that triggers this problem I'd be thankful if you could send it to me (will delete it after debugging).

Vlad, Alexey experiences segfaults in journalctl, not journald. Could you please open a separate bug and attach backtraces of these crashes, please?
Comment 4 Vlad 2012-09-13 11:41:03 UTC
(In reply to comment #3)
> Hmm, if you have a journal file which I can run here that triggers this problem
> I'd be thankful if you could send it to me (will delete it after debugging).
> 
> Vlad, Alexey experiences segfaults in journalctl, not journald. Could you
> please open a separate bug and attach backtraces of these crashes, please?

Lennart,

I don't get it... I was(am) under impression that the systemd-journal process segfaulted (see below). I don't have any segfaults with journalctl. 


Sep 13 09:05:48 xxxxx systemd-journal[13445]: Journal started
Sep 13 09:05:48 xxxxx systemd[1]: systemd-journald.service: main process exited, code=dumped, status=11
Sep 13 09:05:48 xxxxx kernel: systemd-journal[153]: segfault at 7fa450257480 ip 0000000000416ebb sp 00007fff95521b10 error 4 in systemd-journald[400000+28000]
Sep 13 09:05:48 xxxxx systemd-coredump[13443]: Detected coredump of the journal daemon itself, diverting coredump to /var/lib/systemd/coredump/.
Sep 13 09:05:48 xxxxx systemd[1]: Unit systemd-journald.service entered failed state.
Sep 13 09:05:48 xxxxx systemd[1]: systemd-journald.service holdoff time over, scheduling restart.
Comment 5 Lennart Poettering 2012-09-13 12:21:41 UTC
Alexey opened the bug regarding a crasher in journalctl (as even the one line summary of this bug says...)

Vlad, you, however have a crashed in journald. So it's two different things. Hence, please open a separate bug report about that, and please include a backtrace, otherwise we'll have a hard time to help you.
Comment 6 Vlad 2012-09-13 12:32:45 UTC
(In reply to comment #5)
> Alexey opened the bug regarding a crasher in journalctl (as even the one line
> summary of this bug says...)
> 
> Vlad, you, however have a crashed in journald. So it's two different things.
> Hence, please open a separate bug report about that, and please include a
> backtrace, otherwise we'll have a hard time to help you.

Oke, I didn't pay attention on the bug description... I'll open a new bug regarding this.
Comment 7 Lennart Poettering 2012-09-24 08:30:25 UTC
I am quite sure this is fixed with 191. Please check if you can reproduce this with 191, if so open a new bug with a bt from 191. Thanks!
Comment 8 Oleksii Shevchuk 2012-11-01 17:43:46 UTC
Couldn't reproduce


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.