"A start job is running" problem after upgrade to Stretch

Kernels & Hardware, configuring network, installing services

"A start job is running" problem after upgrade to Stretch

Postby elvicomte » 2018-01-24 14:51

Hi everyone!

I've been googling around for this issue for quite some time, without finding any satisfactory answer to it, so here I am...

I have a Dell Latitude E6520 laptop that was running running Jessie (amd64) in a multi-boot config with Windows10.
I decided to upgrade to Stretch, following this procedure: https://www.debian.org/releases/stable/i386/release-notes/ch-upgrading.en.html
At the end of the process, I did a bit of cleanup, using
Code: Select all
#apt-get autoremove
#apt-get purge $(dpkg -l | awk '/^rc/ { print $2 }')

So far, so good... the system was able to boot without problem with the 4.9.0-5-amd64 kernel image freshly installed.
At some point, I also removed the old linux-image-3.16.0-5 still on the system.

Then a couple of days later, I got the "a start job is running ..." error message at every boot, apparently complaining for my /data and swap partitions.
The system hangs for 1min30, and then falls into emergency mode. If I press Ctrl-D, the remaining of the boot process seems to complete correctly and everything looks fine.

I tried reformatting the swap, updating initramfs, re-installing/updating grub without success. I also noticed that I don't get the error message when booting into recovery mode, but the system still falls back into emergency mode. (nothing found in journalctl in that case)

I'm not sure to understand how systemd/grub/fstab interact together, but it looks as if something was not ready when the system is trying to mount extended partitions...

Here are some relevant parts of boot logs:

Code: Select all
#journalctl -b
...
many lines
...
Jan 24 13:56:06 ET-LT034 systemd[1]: Started Load Kernel Modules.
Jan 24 13:56:06 ET-LT034 systemd[1]: Starting Apply Kernel Variables...
Jan 24 13:56:06 ET-LT034 systemd[1]: Started Apply Kernel Variables.
Jan 24 13:57:36 ET-LT034 systemd[1]: dev-disk-by\x2duuid-4ed736f2\x2d956b\x2d400b\x2d8555\x2d826825ae28ec.device: Job dev-disk-by\x2duuid-4ed736f2\x2d956b\x2d400b\x2d8555\x2d826825ae28ec.device/start timed out.
Jan 24 13:57:36 ET-LT034 systemd[1]: Timed out waiting for device dev-disk-by\x2duuid-4ed736f2\x2d956b\x2d400b\x2d8555\x2d826825ae28ec.device.
Jan 24 13:57:36 ET-LT034 systemd[1]: Dependency failed for /data.
Jan 24 13:57:36 ET-LT034 systemd[1]: Dependency failed for Local File Systems.
Jan 24 13:57:36 ET-LT034 systemd[1]: local-fs.target: Job local-fs.target/start failed with result 'dependency'.
Jan 24 13:57:36 ET-LT034 systemd[1]: local-fs.target: Triggering OnFailure= dependencies.
Jan 24 13:57:36 ET-LT034 systemd[1]: Dependency failed for /srv.
Jan 24 13:57:36 ET-LT034 systemd[1]: srv.mount: Job srv.mount/start failed with result 'dependency'.
Jan 24 13:57:36 ET-LT034 systemd[1]: Dependency failed for /home.
Jan 24 13:57:36 ET-LT034 systemd[1]: home.mount: Job home.mount/start failed with result 'dependency'.
Jan 24 13:57:36 ET-LT034 systemd[1]: data.mount: Job data.mount/start failed with result 'dependency'.
Jan 24 13:57:36 ET-LT034 systemd[1]: Dependency failed for File System Check on /dev/disk/by-uuid/4ed736f2-956b-400b-8555-826825ae28ec.
Jan 24 13:57:36 ET-LT034 systemd[1]: systemd-fsck@dev-disk-by\x2duuid-4ed736f2\x2d956b\x2d400b\x2d8555\x2d826825ae28ec.service: Job systemd-fsck@dev-disk-by\x2duuid-4ed736f2\x2d956b\x2d400b\x2d8555\x2d826825ae28ec.service/start failed with result 'dependency'.
Jan 24 13:57:36 ET-LT034 systemd[1]: dev-disk-by\x2duuid-4ed736f2\x2d956b\x2d400b\x2d8555\x2d826825ae28ec.device: Job dev-disk-by\x2duuid-4ed736f2\x2d956b\x2d400b\x2d8555\x2d826825ae28ec.device/start failed with result 'timeout'.
Jan 24 13:57:36 ET-LT034 systemd[1]: dev-disk-by\x2duuid-66aebf0b\x2d4ca4\x2d4d01\x2d8d51\x2d6f8655f5bc89.device: Job dev-disk-by\x2duuid-66aebf0b\x2d4ca4\x2d4d01\x2d8d51\x2d6f8655f5bc89.device/start timed out.
Jan 24 13:57:36 ET-LT034 systemd[1]: Timed out waiting for device dev-disk-by\x2duuid-66aebf0b\x2d4ca4\x2d4d01\x2d8d51\x2d6f8655f5bc89.device.
Jan 24 13:57:36 ET-LT034 systemd[1]: Dependency failed for /dev/disk/by-uuid/66aebf0b-4ca4-4d01-8d51-6f8655f5bc89.
Jan 24 13:57:36 ET-LT034 systemd[1]: Dependency failed for Swap.
Jan 24 13:57:36 ET-LT034 systemd[1]: swap.target: Job swap.target/start failed with result 'dependency'.
Jan 24 13:57:36 ET-LT034 systemd[1]: dev-disk-by\x2duuid-66aebf0b\x2d4ca4\x2d4d01\x2d8d51\x2d6f8655f5bc89.swap: Job dev-disk-by\x2duuid-66aebf0b\x2d4ca4\x2d4d01\x2d8d51\x2d6f8655f5bc89.swap/start failed with result 'dependency'.
Jan 24 13:57:36 ET-LT034 systemd[1]: dev-disk-by\x2duuid-66aebf0b\x2d4ca4\x2d4d01\x2d8d51\x2d6f8655f5bc89.device: Job dev-disk-by\x2duuid-66aebf0b\x2d4ca4\x2d4d01\x2d8d51\x2d6f8655f5bc89.device/start failed with result 'timeout'.
Jan 24 13:57:36 ET-LT034 systemd[1]: Starting Preprocess NFS configuration...
Jan 24 13:57:36 ET-LT034 systemd[1]: Starting Set console font and keymap...
Jan 24 13:57:36 ET-LT034 systemd[1]: Starting Raise network interfaces...
...
many lines
...
Jan 24 13:57:38 ET-LT034 systemd[1]: Activating swap /dev/disk/by-uuid/66aebf0b-4ca4-4d01-8d51-6f8655f5bc89...
Jan 24 13:57:38 ET-LT034 systemd[1]: Started Load/Save RF Kill Switch Status.
Jan 24 13:57:38 ET-LT034 kernel: Adding 15624188k swap on /dev/sda5.  Priority:-1 extents:1 across:15624188k FS
Jan 24 13:57:38 ET-LT034 systemd[1]: Activated swap /dev/disk/by-uuid/66aebf0b-4ca4-4d01-8d51-6f8655f5bc89.
Jan 24 13:57:38 ET-LT034 systemd-udevd[373]: Error calling EVIOCSKEYCODE on device node '/dev/input/event11' (scan code 0x150, key code 190): Invalid argument
Jan 24 13:57:38 ET-LT034 kernel: intel_rapl: Found RAPL domain package
Jan 24 13:57:38 ET-LT034 kernel: intel_rapl: Found RAPL domain core
Jan 24 13:57:38 ET-LT034 kernel: intel_rapl: Found RAPL domain uncore
Jan 24 13:57:38 ET-LT034 kernel: intel_rapl: RAPL package 0 domain package locked by BIOS
Jan 24 13:57:38 ET-LT034 systemd-fsck[479]: /dev/sda6: clean, 565535/12222464 files, 9823031/48863232 blocks
Jan 24 13:57:38 ET-LT034 systemd[1]: Started File System Check on /dev/disk/by-uuid/4ed736f2-956b-400b-8555-826825ae28ec.
Jan 24 13:57:38 ET-LT034 systemd[1]: Mounting /data...
Jan 24 13:57:38 ET-LT034 kernel: input: HDA NVidia HDMI/DP,pcm=3 as /devices/pci0000:00/0000:00:01.0/0000:01:00.1/sound/card1/input19
Jan 24 13:57:38 ET-LT034 kernel: input: HDA NVidia HDMI/DP,pcm=7 as /devices/pci0000:00/0000:00:01.0/0000:01:00.1/sound/card1/input20
Jan 24 13:57:38 ET-LT034 kernel: input: HDA NVidia HDMI/DP,pcm=8 as /devices/pci0000:00/0000:00:01.0/0000:01:00.1/sound/card1/input21
Jan 24 13:57:38 ET-LT034 systemd[1]: Mounted /data.
Jan 24 13:57:38 ET-LT034 kernel: EXT4-fs (sda6): mounted filesystem with ordered data mode. Opts: (null)
Jan 24 13:57:49 ET-LT034 systemd[1]: Mounting /srv...
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopping Load/Save Screen Backlight Brightness of backlight:acpi_video0...
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopped target Sound Card.
Jan 24 13:57:49 ET-LT034 systemd[1]: Reached target Swap.
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopping File System Check Daemon to report status...
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopping Load/Save Screen Backlight Brightness of leds:dell::kbd_backlight...
Jan 24 13:57:49 ET-LT034 systemd[1]: Mounting /home...
Jan 24 13:57:49 ET-LT034 systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch.
Jan 24 13:57:49 ET-LT034 systemd[1]: Listening on Syslog Socket.
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopped target Emergency Mode.
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopping Emergency Shell...
Jan 24 13:57:49 ET-LT034 systemd[1]: Mounted /srv.
Jan 24 13:57:49 ET-LT034 systemd[1]: Mounted /home.
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopped Emergency Shell.
Jan 24 13:57:49 ET-LT034 systemd[1]: Stopped File System Check Daemon to report status.
Jan 24 13:57:49 ET-LT034 systemd[1]: Reached target Local File Systems.
...


Some info about the system:
/ is on /dev/sda1. Windows takes the 2 next partition plus one at the end of the drive (extended)
/dev/sda6 is on /data, and /dev/sda5 is swap area.
Code: Select all
# cat /etc/fstab
# /etc/fstab: static file system information.
#
# Use 'blkid' to print the universally unique identifier for a
# device; this may be used with UUID= as a more robust way to name devices
# that works even if disks are added and removed. See fstab(5).
#
# <file system> <mount point>   <type>  <options>       <dump>  <pass>

# / on /dev/sda1
UUID=e574fc45-2a3b-4cad-ae8c-918d1a1f4fd7 /     ext4     errors=remount-ro 0   1

# /data on /dev/sda6 on this
UUID=4ed736f2-956b-400b-8555-826825ae28ec /data   ext4    defaults     0   2
/data/home              /home   none   defaults,bind     0   0
/data/srv              /srv   none   defaults,bind     0   0

# swap on /dev/sda5
UUID=66aebf0b-4ca4-4d01-8d51-6f8655f5bc89 swap   swap    defaults     0   0

/dev/sr0              /media/cdrom0   udf,iso9660 user,noauto     0   0
/dev/sdb1             /media/usb0     auto    rw,user,noauto    0   0


Code: Select all
# lsblk -f
NAME   FSTYPE LABEL           UUID                                 MOUNTPOINT
sda                                                               
├─sda1 ext4   boot            e574fc45-2a3b-4cad-ae8c-918d1a1f4fd7 /
├─sda2 ntfs   System Reserved 7440D3BE40D384F0                     
├─sda3 ntfs                   368EDAE88EDA9FA3                     
├─sda4                                                             
├─sda5 swap                   66aebf0b-4ca4-4d01-8d51-6f8655f5bc89 [SWAP]
├─sda6 ext4                   4ed736f2-956b-400b-8555-826825ae28ec /data
└─sda7 ntfs                   7CE3CC713581620B                     
sr0                                           


Code: Select all
# cat /proc/swaps
Filename            Type      Size   Used   Priority
/dev/sda5                               partition   15624188   0   -1


Please let me know if you need more details!
Thanks for your help! :D
elvicomte
 
Posts: 5
Joined: 2018-01-24 09:29
Location: Switzerland

Re: "A start job is running" problem after upgrade to Stretc

Postby Thorny » 2018-01-24 15:16

elvicomte wrote:I tried reformatting the swap,

Did you amend your fstab after reformatting swap?

What is the return from
Code: Select all
# blkid -c /dev/null


Is sdb still attached?
User avatar
Thorny
 
Posts: 542
Joined: 2011-02-27 13:40

Re: "A start job is running" problem after upgrade to Stretc

Postby bw123 » 2018-01-24 15:54


/data/srv /srv none defaults,bind

UUID=66aebf0b-4ca4-4d01-8d51-6f8655f5bc89 swap swap defaults


I think swap should be mounted on 'none' not on swap. If you are using gpt then I don't even think you need this, systemd seems to find mine whether or not I list it in fstab.

I use bind mounts in fstab, but usually leave out 'defaults' because I think these mounts inherit the parent options anyway.

I'm not sure to understand how systemd/grub/fstab interact together...


I am sure I don't understand, but I don't think it's grub. Try simplifying your fstab first.
User avatar
bw123
 
Posts: 3088
Joined: 2011-05-09 06:02
Location: TN_USA

Re: "A start job is running" problem after upgrade to Stretc

Postby elvicomte » 2018-01-24 15:57

Yes, fstab is up to date.

Code: Select all
# blkid -c /dev/null
/dev/sda1: LABEL="boot" UUID="e574fc45-2a3b-4cad-ae8c-918d1a1f4fd7" TYPE="ext4" PARTUUID="9b3022f6-01"
/dev/sda2: LABEL="System Reserved" UUID="7440D3BE40D384F0" TYPE="ntfs" PARTUUID="9b3022f6-02"
/dev/sda3: UUID="368EDAE88EDA9FA3" TYPE="ntfs" PARTUUID="9b3022f6-03"
/dev/sda5: UUID="66aebf0b-4ca4-4d01-8d51-6f8655f5bc89" TYPE="swap" PARTUUID="9b3022f6-05"
/dev/sda6: UUID="4ed736f2-956b-400b-8555-826825ae28ec" TYPE="ext4" PARTUUID="9b3022f6-06"
/dev/sda7: UUID="7CE3CC713581620B" TYPE="ntfs" PARTUUID="9b3022f6-07"


sdb is not attached.
elvicomte
 
Posts: 5
Joined: 2018-01-24 09:29
Location: Switzerland

Re: "A start job is running" problem after upgrade to Stretc

Postby Thorny » 2018-01-24 16:07

bw123 wrote:I think swap should be mounted on 'none' not on swap. If you are using gpt then I don't even think you need this, systemd seems to find mine whether or not I list it in fstab.

Good catch, I missed that, just read right over it, oops.

So, now elvicomte has all the answers needed. Corroboration, is one of the strengths of a forum, eh?

[Edit] crap! I'm in a hurry because I have to go catch a ferry, I forgot to mention that you probably want nofail in the fs_mntops field for sdb.
User avatar
Thorny
 
Posts: 542
Joined: 2011-02-27 13:40

Re: "A start job is running" problem after upgrade to Stretc

Postby elvicomte » 2018-01-25 06:31

Thanks a lot for your answers! :D

So I changed the swap mount point in fstab to "none"
Unfortunately, it did not solve the problem. Also, there is still the data partition (sda6) that triggers it.

Maybe I'll have to try and change my partitions to GPT, but I would be glad to understand what causes this issue anyway...

Just for info, here is my partition table:
Code: Select all
# parted -l
Model: ATA ST500LM000-1EJ16 (scsi)
Disk /dev/sda: 500GB
Sector size (logical/physical): 512B/4096B
Partition Table: msdos
Disk Flags:

Number  Start   End     Size    Type      File system     Flags
 1      1049kB  53.1GB  53.1GB  primary   ext4
 2      53.1GB  53.2GB  105MB   primary   ntfs            boot
 3      53.2GB  179GB   126GB   primary   ntfs
 4      179GB   500GB   321GB   extended
 5      179GB   195GB   16.0GB  logical   linux-swap(v1)
 6      195GB   395GB   200GB   logical   ext4
 7      395GB   500GB   105GB   logical   ntfs
elvicomte
 
Posts: 5
Joined: 2018-01-24 09:29
Location: Switzerland

Re: "A start job is running" problem after upgrade to Stretc

Postby Thorny » 2018-01-25 09:40

I don't really understand systemd yet but I'll try to make a guess.

Since you said you've verified your fstab, that should now be okay.

I did see this in your log results.
Dependency failed for File System Check on /dev/disk/by-uuid/4ed736f2-956b-400b-8555-826825ae28ec
Maybe try booting a live system and doing a manual filesystem check on that partition.

There are other posters here that understand systemd well, so maybe this bump will attract the attention of one of them.
User avatar
Thorny
 
Posts: 542
Joined: 2011-02-27 13:40

Re: "A start job is running" problem after upgrade to Stretc

Postby dcihon » 2018-01-25 11:25

I found this bug report that looks similar to your issue. It might have some suggestions to try:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1597415
dcihon
 
Posts: 212
Joined: 2012-09-23 16:18

Re: "A start job is running" problem after upgrade to Stretc

Postby cfb » 2018-01-25 12:40

What happens if you manually mount sda6 from the command line?
cfb
 
Posts: 28
Joined: 2017-01-08 16:39

Re: "A start job is running" problem after upgrade to Stretc

Postby acewiza » 2018-01-25 15:28

I use probably more than the usual number of both local and remote mounts, so the systemd behavior in this regard was a little unnerving to me at first. But I soon realized it enforced stricter awareness of exactly what was being mounted when and how, so I now prefer this behavior.
Nobody would ever ask questions If everyone possessed encyclopedic knowledge of the man pages.
User avatar
acewiza
 
Posts: 358
Joined: 2013-05-28 12:38
Location: Out West

Re: "A start job is running" problem after upgrade to Stretc

Postby elvicomte » 2018-02-01 05:20

Okay, I finally resolved to format the first partition and did a clean install... Boots without problem now.
The mystery remains...
elvicomte
 
Posts: 5
Joined: 2018-01-24 09:29
Location: Switzerland

Re: "A start job is running" problem after upgrade to Stretc

Postby Zjho » 2018-02-01 17:25

Have seen "A start job is running" on my system in past.
Be interested to know if clean install was done using lvm or not ?
Although i never identified lvm as the cause, if it isn't needed then would avoid using as only increases bug risk.
User avatar
Zjho
 
Posts: 29
Joined: 2016-09-15 17:46

Re: "A start job is running" problem after upgrade to Stretc

Postby elvicomte » 2018-02-05 07:00

This install is not using LVM. :)
elvicomte
 
Posts: 5
Joined: 2018-01-24 09:29
Location: Switzerland

Re: "A start job is running" problem after upgrade to Stretc

Postby shiremog » 2018-02-18 19:02

The problem occurs when doing a fresh install of Debian ( don't know about others), when dual booting. Any partitions which are formatted have their UUIDs changed, so existing installs end up with the wrong UUIDs in /etc/fstab. When booting, any partitions with a UUID not matching the /etc/fstab entry will fail after trying for 1m 30s.
Get the correct UUIDs using blkid & make sure all /etc/fstab entries are correct.
Also look at /etc/initramfs-tools/conf.d/resume. This needs the correct UUID for the swap partition, as the system looks for resume data here. If it's wrong, there's a delay until it gives up & carries on regardless. If you change this file, do an update-initramfs -u ( as su )
Ian
shiremog
 
Posts: 3
Joined: 2018-02-18 18:32


Return to System configuration

Who is online

Users browsing this forum: No registered users and 11 guests

fashionable