Bug 1023612

Summary: systemd-journald.service makes system unbearable slow
Product: [Fedora] Fedora Reporter: Shawn Sterling <shawn>
Component: systemdAssignee: systemd-maint
Status: CLOSED NOTABUG QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 19CC: igeorgex, johannbg, lnykryn, msekleta, plautrba, rh-bugzilla, sts, systemd-maint, vpavlin, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-11-18 17:22:53 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
dmidecode |grep -vi serial
none
ps aux
none
systemd-analyze blame
none
sar -A none

Description Shawn Sterling 2013-10-26 01:33:13 UTC
Created attachment 816331 [details]
dmidecode |grep -vi serial

Description of problem:

I switched from fedora 17 to fedora 19 on my laptop (Lenovo Thinkpad W530) (did a fresh install).

Version-Release number of selected component (if applicable):

systemd-204-17.fc19.x86_64
systemd-libs-204-17.fc19.x86_64
systemd-sysv-204-17.fc19.x86_64
systemd-python-204-17.fc19.x86_64

How reproducible:

100%

Steps to Reproduce:
1. boot system
2. cry because it's so slow
3. systemctl disable systemd-journald.service
4. systemctl stop systemd-journald.service
5. rejoice at use-able system

Actual results:
Dear god everything is slow. See additional info.

Expected results:
Not slow?

Additional info:
When I say everything is slow, I mean everything!

with systemd-journald.service running:

# time ls
derf  lost+found  phone  shawn  steve

real	0m6.364s
user	0m0.000s
sys	0m0.002s

$ time google-chrome

real	0m13.819s
user	0m0.999s
sys	0m0.409s

(load chrome and close it as fast as I can)

$ time top

real	0m6.757s
user	0m0.300s
sys	0m0.128s

(load top and hit q before screen comes up)

WITHOUT systemd-journald.service running:

$ time ls
derf  lost+found  phone  shawn  steve

real	0m0.001s
user	0m0.000s
sys	0m0.000s

$ time google-chrome

real	0m1.582s
user	0m0.355s
sys	0m0.126s

$ time top

real	0m0.161s
user	0m0.004s
sys	0m0.007s

I did an 'strace -f -p `pidof systemd-journald`' and it wasn't really doing anything, just sitting there mostly. 

# strace -f -p  3191
Process 3191 attached
epoll_wait(7, {{EPOLLIN, {u32=8, u64=8}}}, 1, -1) = 1
read(8, "7,1082,2829408725,-;SELinux: ini"..., 8192) = 84
uname({sys="Linux", node="me", ...}) = 0
ftruncate(11, 3719168)                  = 0
epoll_wait(7, 

{{EPOLLIN, {u32=8, u64=8}}}, 1, -1) = 1
read(8, "7,1083,2864461256,-;SELinux: ini"..., 8192) = 84
uname({sys="Linux", node="me", ...}) = 0
ftruncate(11, 3719168)                  = 0
epoll_wait(7, {{EPOLLIN, {u32=9, u64=9}}}, 1, -1) = 1
read(9, "\1\0\0\0\0\0\0\0", 8)          = 8
fsync(11)                               = 0
fsync(11)                               = 0
timerfd_settime(9, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
epoll_wait(7, ^CProcess 3191 detached
 <detached ...>

tried with setenforce=0, no help. 

am already booting with kernel option slub_debug=0 (from googling fedora 19 slow)

Here's where I talk crazy for a bit. When systemd-journal.service is running I don't actually have a high load. Nothing is pinning the cpu. iotop looks bored. 

serveral attachments on their way.

Comment 1 Shawn Sterling 2013-10-26 01:35:20 UTC
Created attachment 816332 [details]
ps aux

Comment 2 Shawn Sterling 2013-10-26 01:36:12 UTC
Created attachment 816333 [details]
systemd-analyze blame

Comment 3 Shawn Sterling 2013-10-26 01:37:54 UTC
Created attachment 816334 [details]
sar -A

Comment 4 Shawn Sterling 2013-10-26 01:42:03 UTC
I should also mention deleted everything in the /var/log/journal and then /var/log directories as I read about a previous version causing possible corruptions. This did not help me. 

And that I'm running the latest version of everything as of today (trying to figure out the slowness). 

Other than chrome this is stock f19 running mate for a desktop. Was about to downgrade back to F17 until i figured out killing journald makes the sytem useable. 

If there is anything you want me to run, or binaries you want me to try I am happy to oblige.

Have a good day.

-Shawn

Comment 5 Martin Kho 2013-11-14 11:57:01 UTC
Hi,

The only way I found to workaround the slowness is renaming the directory /var/log/journal to e.g. /var/log/journal.org. This prevents systemd-journald from keeping persisting log files. For Fedora 19 this seems reasonable because rsyslog is the primary logging facility.

Haven't looked at any config options in /etc/systemd/journald.conf. I'm not sure if they will help solve the slowness issue, because the removal of all .journal files in /var/log/journal didn't help for me too.

Hope this halps a little,

Martin Kho

Comment 6 Shawn Sterling 2013-11-18 17:22:53 UTC
Thank you for the reply Martin, sorry for my late reply I was at a conference.

I have since spent quite a bit of time troubleshooting this issue. Long story short, this turned out to be a BIOS update problem.

After upgrading the BIOS on my thinkpad W530 to version 2.55 (Released Oct 24, 2013) my system works fine now, WITH systemd-journald.service running. I have 2 identical thinkpad W530's and can remove my hard drive and place it into the one with the old BIOS and the problem returns. Putting the same hard drive into the new bios updated laptop, there is no problem.

Bios update notes are here: http://download.lenovo.com/ibmdl/pub/pc/pccbbs/mobiles/g5uj17uc.txt

I'm scratching my head on what kind of a issue lenovo messed up in the bios that would be worked around by stopping journald.service; but it did work.

Everything is working fine now, will close issue.