Bug 1324663

Summary: Busy loop in `journalctl --list-boots`
Product: [Fedora] Fedora Reporter: Christian Stadelmann <fedora>
Component: systemdAssignee: systemd-maint
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 24CC: fat.lobyte9, fedora, johannbg, jsynacek, lnykryn, mikhail.v.gavrilov, msekleta, muadda, ssahani, s, systemd-maint, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-07-21 11:13:30 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Attachments:
Description Flags
Backtrace from gdb attached to `journalctl --list-boots` none

Description Christian Stadelmann 2016-04-06 22:04:46 UTC
Created attachment 1144452 [details]
Backtrace from gdb attached to `journalctl --list-boots`

Description of problem:
When running `journalctl --list-boots`, it does never finish.

Version-Release number of selected component (if applicable):
systemd-229-7.fc24.x86_64

How reproducible:
on this machine: always

Steps to Reproduce:
1. run `journalctl --list-boots`
2. watch it fail

Actual results:
journalctl runs at 100% CPU on one core and never returns.

Expected results:
pretty instant result

Additional info:
A possible cause: I changed my system time, so it is not linear.

Comment 1 Christian Stadelmann 2016-04-06 22:05:53 UTC
This might be a duplicate of bug #1244388 or bug #1155697

Comment 2 Michal Sekletar 2016-04-07 16:30:28 UTC
Is all the CPU time spend in user mode or journalctl is calling the kernel? Can you attach strace to the journalctl process one it enters busy loop and provide the output?

Comment 3 Christian Stadelmann 2016-04-07 16:42:49 UTC
According to htop, roughly 80% of its CPU time is spend in kernel (STIME+ as opposed to UTIME+).

short strace output:

munmap(0x7f658bce5000, 8388608)         = 0
mmap(NULL, 7557120, PROT_READ, MAP_SHARED, 37, 0x60cb000) = 0x7f658f4b0000
munmap(0x7f658a547000, 7987200)         = 0
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 38, 0x1223000) = 0x7f658d4e5000
munmap(0x7f659be17000, 4198400)         = 0
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 38, 0x34eb000) = 0x7f659bce7000
munmap(0x7f6595ac1000, 8388608)         = 0
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 39, 0x32d9000) = 0x7f6595cd5000
munmap(0x7f65978d6000, 8388608)         = 0
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 39, 0x577000) = 0x7f65978d6000
munmap(0x7f659042f000, 8388608)         = 0
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 39, 0x114c000) = 0x7f659042f000
munmap(0x7f659d0e8000, 8388608)         = 0
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 39, 0x3c0e000) = 0x7f659d0e8000
munmap(0x7f658c4e5000, 8388608)         = 0
mmap(NULL, 7086080, PROT_READ, MAP_SHARED, 39, 0x713e000) = 0x7f658edee000
munmap(0x7f659a0d6000, 4263936)         = 0
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 40, 0x3c04000) = 0x7f658c4e5000
munmap(0x7f65930d6000, 8388608)         = 0
mmap(NULL, 4198400, PROT_READ, MAP_SHARED, 40, 0x7bff000) = 0x7f659a0e6000

This is repeating all the time, just addresses and file descriptors are changing.

Comment 4 Susant Sahani 2016-05-17 05:14:31 UTC
This is now fixed in upstream.

https://github.com/systemd/systemd/issues/617
https://github.com/systemd/systemd/pull/3114

Comment 5 Susant Sahani 2016-05-17 06:55:32 UTC
*** Bug 1155697 has been marked as a duplicate of this bug. ***

Comment 6 Susant Sahani 2016-05-17 07:29:23 UTC
*** Bug 1244388 has been marked as a duplicate of this bug. ***

Comment 7 Jan Synacek 2016-07-21 06:49:58 UTC
Could you please try with https://bodhi.fedoraproject.org/updates/systemd-229-9.fc24? I didn't backport any patches from the comment 4, but I can't reproduce the issue with the update.

Comment 8 Christian Stadelmann 2016-07-21 07:42:08 UTC
This issue isn't present any more for me with systemd-229-8.fc24 either.