System takes longer to start due to "flush journal" job

Excuse me, hello?

So, yes, a Btrfs issue.
I also use a separate “/var/” partition on this Leap 42.2 system but, “ext4”:

Okt 18 08:15:30 XXX systemd-journald[437]: Time spent on flushing to /var is 808.950ms for 1049 entries.

Please inspect the ‘cron’ directories in “/etc/”:

  • /etc/cron.weekly/ : ‘btrfs-balance’ and ‘btrfs-trim’
  • /etc/cron.monthly/ : ‘btrfs-scrub’

These ‘cron’ entries point to Shell scripts located in “/usr/share/btrfsmaintenance/” and use the following Shell variables to determine which Btrfs mount-points need to be regularly ‘balanced’, ‘trimmed’ and ‘scrubbed’:

  • BTRFS_BALANCE_MOUNTPOINTS
  • BTRFS_SCRUB_MOUNTPOINTS
  • BTRFS_TRIM_MOUNTPOINTS

Please, for the user “root”, check the values of these Shell variables.It seems that, for whatever reason, these “cron” jobs – assuming that they are in fact being periodically executed – are not checking the Btrfs mount-point of the “/var/” partition – and, possibly other Btrfs mount-points on the misbehaving system.

Yes, yes, “root” is “The root of all evil”!!! – and this has been a continuing theme with all UNIX® and *NIX systems – and, will possibly continue to be an often discussed theme.

But, the system architecture of *NIX machines is such that, someone has to do the low level system maintenance and, that “someone” is never a “normal” user . . .

Therefore, for most non-commercial (non-business) *NIX systems, the user “root” remains as the user for system maintenance and system administration.Yes, given the power of *NIX User IDs and *NIX Group IDs, it is possible to define administrator accounts to perform specific system administration and specific system maintenance tasks – and, this makes sense in large *NIX shops with more than a few system administrators.
[HR][/HR]For further reading, please inspect the “Security-Enhanced Linux” (SELinux) world.

Yes, Btrfs . . . – now on my Leap 42.3 Laptop – the Btrfs maintenance ‘cron’ jobs do not get executed as planned . . .
[HR][/HR]First boot today after several days of non-usage:

Okt 18 16:59:23 XXX systemd-journald[419]: Time spent on flushing to /var is 10.666556s for 1163 entries.

With the user “root”, executed the Btrfs maintenance ‘cron’ jobs in “/etc/cron.weekly/” and “/etc/cron.monthly/” and then rebooted:

Okt 18 17:19:30 XXX systemd-journald[407]: Time spent on flushing to /var is 1.105568s for 1177 entries.

Systemd “Blame” also looks better:


XXX:/root # systemd-analyze blame | head
          4.810s apparmor.service
          3.801s dev-sda3.device
          3.339s systemd-journal-flush.service
          1.817s SuSEfirewall2_init.service
          1.511s ModemManager.service
          1.320s SuSEfirewall2.service
          1.241s NetworkManager-wait-online.service
          1.178s home.mount
          1.173s systemd-udevd.service
          1.163s mcelog.service
XXX:/root # 

[HR][/HR]BTW: the content of “BTRFS_BALANCE_MOUNTPOINTS”, “BTRFS_SCRUB_MOUNTPOINTS” and “BTRFS_TRIM_MOUNTPOINTS” is defined in “/etc/sysconfig/btrfsmaintenance” – which is called by each of the Btrfs maintenance ‘cron’ jobs. :shame: [HR][/HR]Those who don’t allow the Btrfs maintenance to be done will experience slow journal flushes . . .

It gets worse – applied the Leap 42.3 updates which were lurking in background – new Kernel and so on . . . Rebooted, and:

Okt 18 17:55:23 XXX systemd-journald[410]: Time spent on flushing to /var is **353.414ms** for 1157 entries.

And, no – I didn’t re-execute the Btrfs maintenance tasks after the updates were applied . . .

But:


XXX:/root # systemd-analyze blame | head
         41.587s purge-kernels.service
          5.223s apparmor.service
          3.547s dev-sda3.device
          2.603s systemd-journal-flush.service
          2.019s SuSEfirewall2_init.service
          1.965s ModemManager.service
          1.543s rc-local.service
          1.542s vboxdrv.service
          1.474s SuSEfirewall2.service
          1.401s alsa-restore.service
XXX:/root # 

Hi
Check the systemd service?


systemctl status btrfsmaintenance-refresh.service
systemctl start btrfsmaintenance-refresh.service
systemctl status btrfsmaintenance-refresh.service

@arvidjaar, @malcolmlewis:
D**N IT!! So I did damage my system foru running systemd-analyze as root and now I should clean-re-install Leap from zero!!??

  • No!
  • Why?

‘systemd-analyze’ is located in /usr/bin/ and, can therefore be executed by “normal” users – and executing as the user “root” doesn’t have, AFAICS, any advantages – there ain’t any data points which a “normal” user can’t read . . .

And, AFAICS, ‘systemd-analyze’ is non-destructive – therefore the user “root” cannot execute system damage by calling ‘systemd-analyze’ . . .


XXX:/root # systemctl status btrfsmaintenance-refresh.service
● btrfsmaintenance-refresh.service - Update cron periods from /etc/sysconfig/btrfsmaintenance
   Loaded: loaded (/usr/lib/systemd/system/btrfsmaintenance-refresh.service; disabled; vendor preset: disabled)
   Active: inactive (dead)
XXX:/root # systemctl start btrfsmaintenance-refresh.service
XXX:/root # systemctl status btrfsmaintenance-refresh.service
● btrfsmaintenance-refresh.service - Update cron periods from /etc/sysconfig/btrfsmaintenance
   Loaded: loaded (/usr/lib/systemd/system/btrfsmaintenance-refresh.service; disabled; vendor preset: disabled)
   Active: inactive (dead)

Okt 19 16:08:45 XXX systemd[1]: Starting Update cron periods from /etc/sysconfig/btrfsmaintenance...
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-scrub.sh for monthly                
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-defrag.sh for none                  
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-balance.sh for weekly               
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-trim.sh for weekly                  
Okt 19 16:08:45 XXX systemd[1]: Started Update cron periods from /etc/sysconfig/btrfsmaintenance.                    
XXX:/root # 

Systemd Journal:


Okt 19 16:08:45 XXX systemd[1]: Starting Update cron periods from /etc/sysconfig/btrfsmaintenance...
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-scrub.sh for monthly
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-defrag.sh for none
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-balance.sh for weekly
Okt 19 16:08:45 XXX btrfsmaintenance-refresh-cron.sh[3763]: Refresh script btrfs-trim.sh for weekly
Okt 19 16:08:45 XXX systemd[1]: Started Update cron periods from /etc/sysconfig/btrfsmaintenance.
Okt 19 16:10:20 XXX systemd[1]: Starting Cleanup of Temporary Directories...
Okt 19 16:10:20 XXX systemd[1]: Started Cleanup of Temporary Directories.

Checking if any of the Btrfs ‘cron’ jobs ran:


XXX:/root # l /var/spool/cron/lastrun/
insgesamt 0
drwxr-xr-x 1 root root 88 19. Okt 16:15 ./
drwx------ 1 root root 22  7. Jul 19:26 ../
-rw-r--r-- 1 root root  0 18. Okt 17:00 cron.daily
-rw-r--r-- 1 root root  0 19. Okt 15:45 cron.hourly
-rw-r--r-- 1 root root  0 30. Sep 18:01 cron.monthly
-rw-r--r-- 1 root root  0 14. Okt 18:00 cron.weekly
XXX:/root # 

I’ve enabled the Systemd ‘btrfsmaintenance-refresh.service’ – will know in a week or so if it helps . . .