Peppermint OS Community Forum

Support => Advanced Topics => Topic started by: stevesveryown on September 27, 2018, 10:49:07 am

Title: systemd-journal-flush.service gobbling boot time [Solved]
Post by: stevesveryown on September 27, 2018, 10:49:07 am
Hi, all my Peppermint friends!

I've been enjoying Pepp 9 on my HP 8440p laptop.  The only issue I have is the long boot time. over 25 seconds are gobbled up with  systemd-journal-flush.service.  Is there a way to reduce the time on this? Here is the out put from systemd-analyze blame

Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ systemd-analyze blame
         25.982s systemd-journal-flush.service
         23.411s dev-sda1.device
         17.319s keyboard-setup.service
         13.684s systemd-sysctl.service
         12.277s systemd-udevd.service
         10.576s nmbd.service
          8.482s NetworkManager-wait-online.service
          6.706s snapd.service
          6.064s NetworkManager.service
          5.321s apparmor.service
          4.352s udisks2.service
          4.254s mintsystem.service
          4.214s accounts-daemon.service
          4.140s grub-common.service
          3.689s gpu-manager.service
          3.118s ModemManager.service
          2.659s systemd-tmpfiles-setup-dev.service
          2.581s networkd-dispatcher.service
          2.580s avahi-daemon.service
          2.569s iio-sensor-proxy.service
          2.229s smbd.service
          1.912s systemd-rfkill.service
          1.899s rpcbind.service
          1.498s plymouth-start.service
          1.443s snap-wallpaperdownloader-21.mount
lines 1-25...skipping...
         25.982s systemd-journal-flush.service
         23.411s dev-sda1.device
         17.319s keyboard-setup.service
         13.684s systemd-sysctl.service
         12.277s systemd-udevd.service
         10.576s nmbd.service
          8.482s NetworkManager-wait-online.service
          6.706s snapd.service
          6.064s NetworkManager.service
          5.321s apparmor.service
          4.352s udisks2.service
          4.254s mintsystem.service
          4.214s accounts-daemon.service
          4.140s grub-common.service
          3.689s gpu-manager.service
          3.118s ModemManager.service
          2.659s systemd-tmpfiles-setup-dev.service
          2.581s networkd-dispatcher.service
          2.580s avahi-daemon.service
          2.569s iio-sensor-proxy.service
          2.229s smbd.service
          1.912s systemd-rfkill.service
          1.899s rpcbind.service
          1.498s plymouth-start.service
          1.443s snap-wallpaperdownloader-21.mount
          1.372s snap-wallpaperdownloader-22.mount
          1.361s binfmt-support.service
          1.354s systemd-modules-load.service
          1.333s snap-core18-19.mount
          1.331s plymouth-read-write.service
          1.237s snap-skype-57.mount
          1.234s snap-core-5145.mount
          1.123s rsyslog.service
          1.113s systemd-update-utmp.service
          1.107s snap-gimp-47.mount
          1.066s run-rpc_pipefs.mount
           966ms snap-skype-51.mount
           759ms sys-kernel-debug.mount
           721ms dev-mqueue.mount
           720ms dev-hugepages.mount
           693ms systemd-remount-fs.service
           689ms snap-skype-54.mount
           657ms swapfile.swap
           657ms systemd-random-seed.service
lines 1-44
[close]
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: PCNetSpec on September 27, 2018, 11:46:56 am
What's the output from
Code: [Select]
journalctl --verify
and
Code: [Select]
journalctl --disk-usage
and
Code: [Select]
du -hs /var/log/journal/



This link is only here for my future reference
https://forum.peppermintos.com/index.php/topic,7482.msg76881.html#msg76881
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: stevesveryown on September 28, 2018, 09:53:05 am
journalctl --verify
Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ journalctl --verify
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000038786-000573c1a1b4a0ad.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@0005706f0e43b59f-309cb8862a07b6b9.journal~
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000001cebe-000570ff044efdc3.journal
000000: Invalid tail monotonic timestamp                             
File corruption detected at /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000001cec0-000570ff046d5996.journal:ac2398 (of 16777216 bytes, 67%).
FAIL: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000001cec0-000570ff046d5996.journal (Bad message)
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-00000000000005d3-00056f650d9a7ffa.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000005c085-000575688fafd712.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@00056f94b35c8c34-5942fea09ff99934.journal~
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000038787-000573c1a1c514b4.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1001.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000005c0b3-000575689d768bdc.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000003854c-000573c19f510e6f.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000000001-0005706f0db8e4aa.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000004e5f-00056f661679a55e.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@2c8c6b5cd8ab4670acc6d0b4a85e9e85-0000000000000001-00056f650aef014f.journal
[close]
The File corruption detected is interesting.

journalctl --disk-usage
Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ journalctl --disk-usage
Archived and active journals take up 496.0M in the file system.
[close]

du -hs /var/log/journal/
stephen@stephen-HP-EliteBook-8440p ~ $ du -hs /var/log/journal/
497M   /var/log/journal/
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: PCNetSpec on September 28, 2018, 11:35:49 am
Okay run:
Code: [Select]
journalctl --vacuum-time=2d
then post the output from
Code: [Select]
journalctl --verify
again.
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: stevesveryown on September 28, 2018, 12:22:56 pm
Here you go.  Looks like an issue.

Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ journalctl --vacuum-time=2d
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@2c8c6b5cd8ab4670acc6d0b4a85e9e85-0000000000000001-00056f650aef014f.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-00000000000005d3-00056f650d9a7ffa.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@00056f94b35c8c34-5942fea09ff99934.journal~: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000004e5f-00056f661679a55e.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@0005706f0e43b59f-309cb8862a07b6b9.journal~: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000000001-0005706f0db8e4aa.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000001cebe-000570ff044efdc3.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000001cec0-000570ff046d5996.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000003854c-000573c19f510e6f.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000038786-000573c1a1b4a0ad.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000038787-000573c1a1c514b4.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000005c085-000575688fafd712.journal: Permission denied
Failed to delete archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000005c0b3-000575689d768bdc.journal: Permission denied
Vacuuming done, freed 0B of archived journals from /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8.
[close]

Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ journalctl --verify
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000038786-000573c1a1b4a0ad.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@0005706f0e43b59f-309cb8862a07b6b9.journal~
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000001cebe-000570ff044efdc3.journal
000000: Invalid tail monotonic timestamp                             
File corruption detected at /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000001cec0-000570ff046d5996.journal:ac2398 (of 16777216 bytes, 67%).
FAIL: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000001cec0-000570ff046d5996.journal (Bad message)
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-00000000000005d3-00056f650d9a7ffa.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000005c085-000575688fafd712.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@00056f94b35c8c34-5942fea09ff99934.journal~
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000038787-000573c1a1c514b4.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1001.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000005c0b3-000575689d768bdc.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000003854c-000573c19f510e6f.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000000001-0005706f0db8e4aa.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000004e5f-00056f661679a55e.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@2c8c6b5cd8ab4670acc6d0b4a85e9e85-0000000000000001-00056f650aef014f.journal
[close]
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: PCNetSpec on September 28, 2018, 12:50:47 pm
Sorry, try
Code: [Select]
sudo journalctl --vacuum-time=2d
then post the output from
Code: [Select]
journalctl --verify
and
Code: [Select]
journalctl --disk-usage
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: stevesveryown on September 29, 2018, 10:36:41 am
Here's the output:

Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ sudo journalctl --vacuum-time=2d
[sudo] password for stephen:
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@2c8c6b5cd8ab4670acc6d0b4a85e9e85-0000000000000001-00056f650aef014f.journal (24.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-00000000000005d3-00056f650d9a7ffa.journal (8.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@00056f94b35c8c34-5942fea09ff99934.journal~ (16.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000004e5f-00056f661679a55e.journal (16.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@0005706f0e43b59f-309cb8862a07b6b9.journal~ (40.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000000001-0005706f0db8e4aa.journal (40.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000001cebe-000570ff044efdc3.journal (80.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000001cec0-000570ff046d5996.journal (16.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000003854c-000573c19f510e6f.journal (8.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-0000000000038786-000573c1a1b4a0ad.journal (16.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-0000000000038787-000573c1a1c514b4.journal (112.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system@b33d09bfa8b043e2898af13b0724e568-000000000005c085-000575688fafd712.journal (72.0M).
Deleted archived journal /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000@6b4de6dc9daa4f55b1437c4129fbca4d-000000000005c0b3-000575689d768bdc.journal (16.0M).
Vacuuming done, freed 464.0M of archived journals from /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8.
stephen@stephen-HP-EliteBook-8440p ~ $ journalctl --verify
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/system.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1001.journal
PASS: /var/log/journal/f26bab37888a4b04a599e97bfcdbcae8/user-1000.journal
stephen@stephen-HP-EliteBook-8440p ~ $ journalctl --disk-usage
Archived and active journals take up 32.0M in the file system.
[close]
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: PCNetSpec on September 29, 2018, 10:38:14 am
Okay have the boot times improved ?
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: stevesveryown on September 29, 2018, 11:42:30 am
Boot time hasn't improved much.  systemd-journal-flush.service has dropped down in the rank.

systemd-analyze blame
Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ systemd-analyze blame
         21.848s dev-sda1.device
         20.559s nmbd.service
         20.432s systemd-journal-flush.service
         17.653s keyboard-setup.service
         11.536s systemd-udevd.service
          7.491s NetworkManager-wait-online.service
          5.705s snapd.service
          4.504s apparmor.service
          4.464s NetworkManager.service
          4.190s mintsystem.service
          4.012s udisks2.service
          3.760s gpu-manager.service
          3.580s networkd-dispatcher.service
          3.368s accounts-daemon.service
          3.342s systemd-tmpfiles-setup-dev.service
          2.958s ModemManager.service
          1.834s snap-skype-57.mount
          1.658s binfmt-support.service
          1.428s avahi-daemon.service
          1.354s systemd-modules-load.service
          1.218s nfs-config.service
          1.218s plymouth-read-write.service
          1.218s console-setup.service
          1.094s rsyslog.service
          1.075s run-rpc_pipefs.mount
[close]

So I know for the future, what were the commands doing?

As always, thanks for taking the time out to answer my questiion.
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: PCNetSpec on September 29, 2018, 11:47:39 am
Trimming down the systemd log files

What you need is an SSD :)
Title: Re: systemd-journal-flush.service gobbling boot time
Post by: stevesveryown on September 29, 2018, 02:25:43 pm
Yes.  Just old school and still not 100% sure of them.   :-\

I'll mark the post solved.   

Thanks!  ;)
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: PCNetSpec on September 29, 2018, 02:34:35 pm
I'll absolutely guarantee, an SSD would be the best purchase you've ever made (as long as your SATA port is SATA III), and once you use one you'll never touch a 'spinner' again ;)
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: AndyInMokum on September 29, 2018, 03:49:26 pm
I'll absolutely guarantee, an SSD would be the best purchase you've ever made (as long as your SATA port is SATA III), and once you use one you'll never touch a 'spinner' again ;)

Dito  ;).
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: stevesveryown on September 30, 2018, 11:18:45 am
I'll absolutely guarantee, an SSD would be the best purchase you've ever made (as long as your SATA port is SATA III), and once you use one you'll never touch a 'spinner' again ;)

My HP specs labels the interface as a serial ata-300, which I understand to be a sata II.
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: PCNetSpec on September 30, 2018, 11:32:39 am
What's the output from
Code: [Select]
dmesg | grep -i ahci | grep -i Gbps
and
Code: [Select]
dmesg | grep -i sata | grep -i  'link up'
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: stevesveryown on September 30, 2018, 12:52:07 pm
What's the output from
Code: [Select]
dmesg | grep -i ahci | grep -i Gbps
and
Code: [Select]
dmesg | grep -i sata | grep -i  'link up'

Spoiler (click here to view / hide)
stephen@stephen-HP-EliteBook-8440p ~ $ dmesg | grep -i ahci | grep -i Gbps
[    1.784854] ahci 0000:00:1f.2: AHCI 0001.0300 32 slots 6 ports 3 Gbps 0x37 impl SATA mode
stephen@stephen-HP-EliteBook-8440p ~ $ dmesg | grep -i sata | grep -i  'link up'
[    2.146756] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[    2.463614] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[close]
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: PCNetSpec on September 30, 2018, 01:20:55 pm
Yep, SATA II (3.0 Gbps) .. you'd possibly still notice a slight difference, but not much :(

I take it we're not talking about the system in your sig then ?
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: stevesveryown on October 01, 2018, 11:11:01 am
Yep, SATA II (3.0 Gbps) .. you'd possibly still notice a slight difference, but not much :(

I take it we're not talking about the system in your sig then ?

No I am not, PCNetSpec.  I was talking about my HP laptop.  I am lookinginto an ssd for my main machine, though.  Before I do that I need to get my external drive cleaned up and back up my system.  I'm getting my son his own so I can format mine in ext4.

I want to say thanks, not just for me, but all us Peppermint users, for you help.  I know it's not always easy.
Title: Re: systemd-journal-flush.service gobbling boot time [Solved]
Post by: PCNetSpec on October 01, 2018, 11:42:36 am
It's a pleasure my mate, you're more than welcome :)