Slow boot - What is "A start job is running for dev-disk-by..." ?

Hi,

I’ve got a clean install from the Gnome Live CD - installed via USB-stick.

When I boot it’s quite slow, and I see this entry:
A start job is running for dev-disk-by\x2uuid-f782f311<more numbers>.device [1min 30s]

And then it counts to 1 minute and 30 seconds before moving on.

How do I find out what this is and remove it?

  • Ronni

Hi Ronni,

please, post the result of this code:


systemd-analyze critical-chain

And post the results of the command to see if you are suffering of a possible bug in systemd.


journalctl -a|grep flushing
journalctl -a|grep journal

In addition, see this thread: https://forums.opensuse.org/showthread.php/503347-Opensuse-Boot-Time
Maybe have something useful for your problem there.

Best Regards,

Marcus.

Output from commands:


linux:~ # systemd-analyze critical-chain
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

graphical.target @1min 32.108s
└─display-manager.service @1min 31.398s +710ms
  └─systemd-user-sessions.service @1min 31.316s +61ms
    └─basic.target @1min 31.293s
      └─timers.target @1min 31.292s
        └─systemd-tmpfiles-clean.timer @1min 31.292s
          └─sysinit.target @1min 31.292s
            └─systemd-update-utmp.service @11.127s +440ms
              └─auditd.service @11.120s +5ms
                └─systemd-tmpfiles-setup.service @10.814s +302ms
                  └─local-fs.target @10.808s
                    └─boot-grub2-i386\x2dpc.mount @10.774s +23ms
                      └─local-fs-pre.target @9.979s
                        └─systemd-remount-fs.service @1.770s +8.205s
                          └─systemd-readahead-replay.service @1.245s +480ms
                            └─system.slice
                              └─-.slice


linux:~ # man journalctl
linux:~ # journalctl -a | grep flushing
Dec 15 18:06:16 linux systemd-journal[1723]: Time spent on flushing to /var is 15.321ms for 811 entries.
Dec 15 18:47:26 linux systemd-journal[339]: Time spent on flushing to /var is 35.498ms for 803 entries.
Dec 15 18:56:45 linux systemd-journal[333]: Time spent on flushing to /var is 763.305ms for 797 entries.
Dec 15 19:19:13 linux systemd-journal[336]: Time spent on flushing to /var is 899.960ms for 786 entries.
Dec 15 20:04:23 linux systemd-journal[330]: Time spent on flushing to /var is 18.436ms for 798 entries.
Dec 15 20:27:51 linux systemd-journal[335]: Time spent on flushing to /var is 917.428ms for 805 entries.
Dec 17 19:20:39 linux systemd-journal[338]: Time spent on flushing to /var is 3.127492s for 814 entries.
Dec 17 20:01:26 linux systemd-journal[340]: Time spent on flushing to /var is 3.998405s for 816 entries.
Dec 17 20:29:02 linux systemd-journal[339]: Time spent on flushing to /var is 3.162114s for 815 entries.
Dec 17 20:49:19 linux systemd-journal[339]: Time spent on flushing to /var is 6.833561s for 820 entries.
linux:~ # journalctl -a | grep journal
Dec 15 18:06:13 linux systemd-journal[1723]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.6G available → current limit 393.8M).
Dec 15 18:06:13 linux systemd-journal[1723]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.6G available → current limit 393.8M).
Dec 15 18:06:13 linux systemd-journal[1723]: Journal started
Dec 15 18:06:16 linux systemd-journal[1723]: Permanent journal is using 9.0M (max allowed 309.4M, trying to leave 464.1M free of 2.6G available → current limit 309.4M).
Dec 15 18:06:16 linux systemd-journal[1723]: Time spent on flushing to /var is 15.321ms for 811 entries.
Dec 15 18:47:19 linux systemd-journal[112]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:47:19 linux systemd-journal[112]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:47:20 linux systemd-journal[112]: Journal started
Dec 15 18:47:20 linux systemd-journal[112]: Journal stopped
Dec 15 18:47:25 linux systemd-journal[339]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:47:25 linux systemd-journal[339]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:47:25 linux systemd-journal[339]: Journal started
Dec 15 18:47:26 linux systemd-journal[339]: Permanent journal is using 16.0M (max allowed 4.0G, trying to leave 4.0G free of 139.8G available → current limit 4.0G).
Dec 15 18:47:26 linux systemd-journal[339]: Time spent on flushing to /var is 35.498ms for 803 entries.
Dec 15 18:56:17 linux.site systemd-journal[339]: Journal stopped
Dec 15 18:56:36 linux systemd-journal[112]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:56:36 linux systemd-journal[112]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:56:37 linux systemd-journal[112]: Journal started
Dec 15 18:56:37 linux systemd-journal[112]: Journal stopped
Dec 15 18:56:40 linux systemd-journal[333]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:56:40 linux systemd-journal[333]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 18:56:40 linux systemd-journal[333]: Journal started
Dec 15 18:56:44 linux systemd-journal[333]: Permanent journal is using 24.0M (max allowed 4.0G, trying to leave 4.0G free of 139.8G available → current limit 4.0G).
Dec 15 18:56:45 linux systemd-journal[333]: Time spent on flushing to /var is 763.305ms for 797 entries.
Dec 15 19:18:46 linux.site systemd-journal[333]: Journal stopped
Dec 15 19:19:05 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 19:19:05 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 19:19:05 linux systemd-journal[111]: Journal started
Dec 15 19:19:06 linux systemd-journal[111]: Journal stopped
Dec 15 19:19:09 linux systemd-journal[336]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 19:19:09 linux systemd-journal[336]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 19:19:09 linux systemd-journal[336]: Journal started
Dec 15 19:19:12 linux systemd-journal[336]: Permanent journal is using 32.0M (max allowed 4.0G, trying to leave 4.0G free of 139.7G available → current limit 4.0G).
Dec 15 19:19:13 linux systemd-journal[336]: Time spent on flushing to /var is 899.960ms for 786 entries.
Dec 15 20:04:13 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:04:13 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:04:13 linux systemd-journal[111]: Journal started
Dec 15 20:04:14 linux systemd-journal[111]: Journal stopped
Dec 15 20:04:17 linux systemd-journal[330]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:04:17 linux systemd-journal[330]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:04:17 linux systemd-journal[330]: Journal started
Dec 15 20:04:23 linux systemd-journal[330]: Permanent journal is using 43.5M (max allowed 4.0G, trying to leave 4.0G free of 139.7G available → current limit 4.0G).
Dec 15 20:04:23 linux systemd-journal[330]: Time spent on flushing to /var is 18.436ms for 798 entries.
Dec 15 20:27:23 linux.site systemd-journal[330]: Journal stopped
Dec 15 20:27:41 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:27:41 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:27:42 linux systemd-journal[111]: Journal started
Dec 15 20:27:42 linux systemd-journal[111]: Journal stopped
Dec 15 20:27:45 linux systemd-journal[335]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:27:45 linux systemd-journal[335]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 15 20:27:45 linux systemd-journal[335]: Journal started
Dec 15 20:27:50 linux systemd-journal[335]: Permanent journal is using 40.0M (max allowed 4.0G, trying to leave 4.0G free of 137.9G available → current limit 4.0G).
Dec 15 20:27:51 linux systemd-journal[335]: Time spent on flushing to /var is 917.428ms for 805 entries.
Dec 15 22:32:12 linux.site systemd-journal[335]: Journal stopped
Dec 17 19:20:25 linux systemd-journal[112]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 19:20:25 linux systemd-journal[112]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 19:20:25 linux systemd-journal[112]: Journal started
Dec 17 19:20:26 linux systemd-journal[112]: Journal stopped
Dec 17 19:20:29 linux systemd-journal[338]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 19:20:29 linux systemd-journal[338]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 19:20:29 linux systemd-journal[338]: Journal started
Dec 17 19:20:36 linux systemd-journal[338]: Permanent journal is using 40.0M (max allowed 4.0G, trying to leave 4.0G free of 137.8G available → current limit 4.0G).
Dec 17 19:20:39 linux systemd-journal[338]: Time spent on flushing to /var is 3.127492s for 814 entries.
Dec 17 20:00:24 linux.site systemd-journal[338]: Journal stopped
Dec 17 20:01:12 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:01:12 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:01:12 linux systemd-journal[111]: Journal started
Dec 17 20:01:13 linux systemd-journal[111]: Journal stopped
Dec 17 20:01:15 linux systemd-journal[340]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:01:15 linux systemd-journal[340]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:01:15 linux systemd-journal[340]: Journal started
Dec 17 20:01:22 linux systemd-journal[340]: Permanent journal is using 40.0M (max allowed 4.0G, trying to leave 4.0G free of 137.4G available → current limit 4.0G).
Dec 17 20:01:26 linux systemd-journal[340]: Time spent on flushing to /var is 3.998405s for 816 entries.
Dec 17 20:28:16 linux.site systemd-journal[340]: Journal stopped
Dec 17 20:28:34 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:28:34 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:28:34 linux systemd-journal[111]: Journal started
Dec 17 20:28:35 linux systemd-journal[111]: Journal stopped
Dec 17 20:28:40 linux systemd-journal[339]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:28:40 linux systemd-journal[339]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:28:40 linux systemd-journal[339]: Journal started
Dec 17 20:28:59 linux systemd-journal[339]: Permanent journal is using 48.0M (max allowed 4.0G, trying to leave 4.0G free of 137.4G available → current limit 4.0G).
Dec 17 20:29:02 linux systemd-journal[339]: Time spent on flushing to /var is 3.162114s for 815 entries.
Dec 17 20:48:37 linux.site systemd-journal[339]: Journal stopped
Dec 17 20:48:56 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:48:56 linux systemd-journal[111]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:48:56 linux systemd-journal[111]: Journal started
Dec 17 20:48:57 linux systemd-journal[111]: Journal stopped
Dec 17 20:48:59 linux systemd-journal[339]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:48:59 linux systemd-journal[339]: Runtime journal is using 8.0M (max allowed 393.8M, trying to leave 590.7M free of 3.8G available → current limit 393.8M).
Dec 17 20:48:59 linux systemd-journal[339]: Journal started
Dec 17 20:49:12 linux systemd-journal[339]: Permanent journal is using 48.0M (max allowed 4.0G, trying to leave 4.0G free of 137.3G available → current limit 4.0G).
Dec 17 20:49:19 linux systemd-journal[339]: Time spent on flushing to /var is 6.833561s for 820 entries.

I read the thread you link to - thank you for the help so far.

  • Ronni

How do I see the status of services staring at boot time?

dmesg doesn’t show them.

  • Ronni

I had this issue in the past also with install openSUSE 13.2.
My problem was double entry in etc/fstab of the same device (swap partition)
i removed with kwrite the two lines, and then i added over Yast a new swap :wink:

Found this in /var/log/boot.log

[K[** ] A start job is running for dev-disk-by\x2duuid-f782f311\x2dd41c\x2d4bfc\x2dbcb5\x2d477d872641dc.device (10s / 1min 30s)

[K[ TIME ] Timed out waiting for device dev-disk-by\x2duuid-f782f311\x2dd41c\x2d4bfc\x2dbcb5\x2d477d872641dc.device.
[DEPEND] Dependency failed for /dev/disk/by-uuid/f782f311-d41c-4bfc-bcb5-477d872641dc.

[DEPEND] Dependency failed for Swap.

OK ] Started /etc/init.d/boot.local Compatibility.

      Expecting device dev-disk-by\x2duuid-f782f311\x2dd41c\x2d4bfc\x2dbcb5\x2d477d872641dc.device...

      Starting Authorization Manager...
  • Ronni

You have some partition in the /etc/fstab file that does not exist or is not functioning. Could be a removable disk or it could be a partition that contains Win8 that has not been shut down properly ie fast boot is set on. Or could be some other partition files system corruption. Only you can tell are crystal balls are all broken

No; the message means systemd is waiting for device. So it cannot be related to dirty shutdown. Something (probably /etc/fstab) refers to device name that does not exist during boot.

Hi again,

Found the problem in /etc/fstab
The swap partition wasn’t created correct in some way, and couldn’t be mounted, so I deleted it and created it again using the Disk utility/GParted and asked it to be mounted on startup.

So now it all works.

Thank you for your help!

Best regards
Ronni

thanks for the snippet

same problem on this pc, boot time was 18s longer than on similar machines

deleted swap via -yast --partitioner

rebooted and created new swap
verified with cmd

sudo swapon -afv

cheers

hello,

maybe this will help someone else;
i had chosen to “edit” my /etc/fstab and use the “shorter version” of the device /partition names in /dev/disk/by-id
e.g. wwn-0x5000cca77ef6007f-part1
instead of ata-HGST_HTS725050A7E630_TF655AWH3UTPLL-part1
for readability reasons

this lead to the 1m30s “a start job is running for dev-disk-by …]” also at shutdown time.
returning to the original device / partition designation solved it instantly.

Hello I had the same problem after deleting swap partition (sda4).
In etc/fstab it was all correct, but in yast2->bootloader there was specified kernel parameter:
resume=/dev/sda4

Deleting that all fixed.