Bug 1054473

Workaround found for this problem:

systemctl list-jobs
systemctl cancel <for all job ids listed>
systemctl isolate intird.target

Could this caused by the line 

OnFailureJobMode=replace-irreversibly

in /usr/lib/systemd/system/initrd-root-fs.target?

But that line exists in SLE12 too, and I've never observed "Transaction is destructive" on SLE12.

FTR, the two jobs that need to be canceled are

55 emergency.target (waiting)
56 emergency.service (running)

Sorry for the delay, hopefully it's not too late...

Once you entered the emergency shell can you:

 - enable the debug log with "systemd-analyze set-log-level debug" 

 - run "logger FOO"

 - run "exit" or "^D" (this should fail)

 - show the output of "journalctl -b"

I'm not sure to understand why you tried to isolate initrd.target though.

Also you used "logout" to exit from the emergency shell. Here it fails as the shell is not a login one.

Thanks.

(In reply to Franck Bui from comment #3)
> Sorry for the delay, hopefully it's not too late...

I don't think so. I recently saw the problem again. May take while to reproduce, though.

> Once you entered the emergency shell can you:
> 
>  - enable the debug log with "systemd-analyze set-log-level debug" 
> 
>  - run "logger FOO"
> 
>  - run "exit" or "^D" (this should fail)
> 
>  - show the output of "journalctl -b"
> 
> I'm not sure to understand why you tried to isolate initrd.target though.

IIUC that should have the same effect as "^D" - finish initrd processing, switch root, and continue booting. Is that wrong?

> Also you used "logout" to exit from the emergency shell. Here it fails as
> the shell is not a login one.

I tried "^D" as well, same effect. However, I'll retry.

(In reply to Franck Bui from comment #3)
> Sorry for the delay, hopefully it's not too late...
> 
> Once you entered the emergency shell can you:
> 
>  - enable the debug log with "systemd-analyze set-log-level debug" 

We're still in the initrd. systemd-analyze is not present. I can "kill -s 56 1" though.

>  - run "logger FOO"

no "logger", either. I tried to write to /dev/log directly, but that didn't work.

>  - run "exit" or "^D" (this should fail)

Once the shell has exited, I can't type anymore. I can try with "systemd.journald.log_target=console", that may work.

>  - show the output of "journalctl -b"

See above

> Also you used "logout" to exit from the emergency shell. Here it fails as
> the shell is not a login one.

Actually, I didn't type "logout". I typed "^D" and the shell prints "logout".

I believe this behavior is caused by the following code in "emergency.service":

ExecStart=/bin/dracut-emergency
ExecStopPost=-/usr/bin/systemctl --fail --no-block default

When the shell is left with "exit" or "^D", the default target (which is "initrd.target" at this point is set to "failed", and the system effectively hangs.

(In reply to Martin Wilck from comment #4)
> IIUC that should have the same effect as "^D" - finish initrd processing,
> switch root, and continue booting. Is that wrong?

"^D" is equivalent to run "systemctl isolate default.target" after the shell exits.

OTOH "systemctl isolate initrd.target" will start initrd.target and only services pulled in by it. Basically they're used to setup the root file system device but nothing more.

So you likely don't want to isolate initrd.target since the system won't switch to the final rootfs and won't continue to boot the system normally, actually the system will be stuck.

(In reply to Martin Wilck from comment #5)
> (In reply to Franck Bui from comment #3)
> > Sorry for the delay, hopefully it's not too late...
> > 
> > Once you entered the emergency shell can you:
> > 
> >  - enable the debug log with "systemd-analyze set-log-level debug" 
> 
> We're still in the initrd. systemd-analyze is not present. I can "kill -s 56
> 1" though.

You can include extra tools in the initramfs by running "dracut -I /usr/bin/systemd-analyze" for example.

But if "56" means SIGRTMIN+22, then you're right you can send this signal to PID1 instead.

> 
> >  - run "logger FOO"
> 
> no "logger", either. I tried to write to /dev/log directly, but that didn't
> work.
>

You can include logger in in the initramfs (see above) or just skip this part as it's not mandatory.
 
> >  - run "exit" or "^D" (this should fail)
> 
> Once the shell has exited, I can't type anymore. I can try with
> "systemd.journald.log_target=console", that may work.

Then I think the easiest would be to boot with the following kernel options:

 "printk.devkmsg=on systemd.log_level=debug systemd.log_target=console console=ttyS0"

and record the logs sent to the serial console once you type "^D".

Thanks.

(In reply to Martin Wilck from comment #1)
> Workaround found for this problem:
> 
> systemctl list-jobs
> systemctl cancel <for all job ids listed>
> systemctl isolate intird.target
> 
> Could this caused by the line 
> 
> OnFailureJobMode=replace-irreversibly
>
> in /usr/lib/systemd/system/initrd-root-fs.target?

Indeed, that could be the culprit.
 
> But that line exists in SLE12 too, and I've never observed "Transaction is
> destructive" on SLE12.

That could also have been a bug in systemd-v228.
In the upstream code, it seems that emergency.target is considered irreversible when started via a failure in the initrd boot sequence.
At least, I only see this job mode for irreversible targets, e.g.:

-->
src/systemctl/systemctl.c:        [ACTION_HALT]         = { SPECIAL_HALT_TARGET,         "halt",         "replace-irreversibly" },
src/systemctl/systemctl.c:        [ACTION_POWEROFF]     = { SPECIAL_POWEROFF_TARGET,     "poweroff",     "replace-irreversibly" },
src/systemctl/systemctl.c:        [ACTION_REBOOT]       = { SPECIAL_REBOOT_TARGET,       "reboot",       "replace-irreversibly" },
src/systemctl/systemctl.c:        [ACTION_KEXEC]        = { SPECIAL_KEXEC_TARGET,        "kexec",        "replace-irreversibly" },
src/systemctl/systemctl.c:        [ACTION_EXIT]         = { SPECIAL_EXIT_TARGET,         "exit",         "replace-irreversibly" },
src/systemctl/systemctl.c:        [ACTION_SUSPEND]      = { SPECIAL_SUSPEND_TARGET,      "suspend",      "replace-irreversibly" },
src/systemctl/systemctl.c:        [ACTION_HIBERNATE]    = { SPECIAL_HIBERNATE_TARGET,    "hibernate",    "replace-irreversibly" },
src/systemctl/systemctl.c:        [ACTION_HYBRID_SLEEP] = { SPECIAL_HYBRID_SLEEP_TARGET, "hybrid-sleep", "replace-irreversibly" },
--<

The emergency target documentation shows:

-->
In many ways booting into emergency.target is similar to the effect of booting with "init=/bin/sh" on the kernel command line, except that emergency mode provides you with the full system and service manager, and allows starting individual units in order to continue the boot process in steps.
--<

So, it seems that it is only considered reversible when directly booting into it.
We should probably check with upstream whether this is the case.

(In reply to Franck Bui from comment #8)
> (In reply to Martin Wilck from comment #4)

> So you likely don't want to isolate initrd.target since the system won't
> switch to the final rootfs and won't continue to boot the system normally,
> actually the system will be stuck.

Not confirmed. As I tried to point out already, exiting the shell by whatever command leads to a stuck system which can only be reset e.g. with alt-sysrq-b.

But the procedure described in comment 1 (cancel pending jobs and isolate intird.target) has the desired effect - the system boots normally.

Let me summarize some observations:

 1) failure of initrd-root-fs.target causes emergency.target to be started with job mode "replace-irreversibly". This causes other jobs to be rejected as long as emergency.target is pending.

 2) While in the shell, emergency.target is in "waiting" state. emergency.target depends only on emergency.service, which is basically the emergency shell. But although the shell is running, the respective job is still "running" (comment 2). Note that emergency.service is not an original systemd file but comes from dracut. This file has notable differences from systemd's original file:

> --- usr/lib/systemd/system/emergency.service    2017-08-08 13:18:48.000000000 +0200
> +++ usr/lib/dracut/modules.d/98dracut-systemd/emergency.service 2015-11-25 14:22:28.000000000 +0100
> @@ -5,23 +5,28 @@
>  #  the Free Software Foundation; either version 2.1 of the License, or
>  #  (at your option) any later version.
>  
> +# See systemd.special(7) for details
> +
>  [Unit]
>  Description=Emergency Shell
> -Documentation=man:sulogin(8)
>  DefaultDependencies=no
> -Conflicts=shutdown.target
> -Conflicts=rescue.service
> -Conflicts=syslog.socket
> -Before=shutdown.target
> +After=systemd-vconsole-setup.service
> +Wants=systemd-vconsole-setup.service
>  
>  [Service]
> -Environment=HOME=/root
> -WorkingDirectory=-/root
> -ExecStart=-/usr/lib/systemd/systemd-sulogin-shell emergency
> -Type=idle
> +Environment=HOME=/
> +Environment=DRACUT_SYSTEMD=1
> +Environment=NEWROOT=/sysroot
> +WorkingDirectory=/
> +ExecStart=/bin/dracut-emergency
> +ExecStopPost=-/usr/bin/systemctl --fail --no-block default
> +Type=oneshot
>  StandardInput=tty-force
>  StandardOutput=inherit
>  StandardError=inherit
>  KillMode=process
>  IgnoreSIGPIPE=no
> -SendSIGHUP=yes
> +
> +# Bash ignores SIGTERM, so we send SIGHUP instead, to ensure that bash
> +# terminates cleanly.
> +KillSignal=SIGHUP

"Type=oneshot" probably causes the above behavior of the job and
therefore the "transaction is desctructive", and
"ExecStopPost=-/usr/bin/systemctl --fail --no-block default" causes the
failure to continue booting after the shell exits.

(In reply to Franck Bui from comment #9)

>  "printk.devkmsg=on systemd.log_level=debug systemd.log_target=console
> console=ttyS0"
> 
> and record the logs sent to the serial console once you type "^D".

Here you are. Unfortunately the output is a bit messed up where it really matters. Apparently the command /usr/bin/systemctl --fail --no-block default fails because to a problem with cgroups (?). Anyway, the enqueued job "initrd.target/start/isolate" never starts.

> :/# exit 0
> logout
> Received SIGCHLD from PID 1235 (sh).
> Child 1235 (sh) died (code=exited, status=0/SUCCESS)
> emergency.service: Child 1235 belongs to emergency.service
> emergency.service: Main process exited, code=exited, status=0/SUCCESS
> emergency.service: About to execute: /usr/bin/systemctl --fail --no-block default
> emergency.service: Forked /usr/bin/systemctl as 1920
> emergency.service: Changed start -> stop-post
> emergency.service: Executing: /usr/bin/systemctl --fail --no-block default
> Accepted new private connection.
> Got message type=method_call sender=n/a destination=org.freedesktop.systemd1 object=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=StartUnit cookie=1 reply_cookie=0 error=n/a
> initrd.target: Trying to enqueue job initrd.target/start/isolate
> tmp.mount: Cannot add dependencemergency.service: cgroup is empty
> Received SIGCHLD from PID 1920 (systemctl).
> Child 1920 (systemctl) died (code=exited, status=4/NOPERMISSION)
> emergency.service: Child 1920 belongs to emergency.service
> emergency.service: Control process exited, code=exited status=4
> emergency.service: Got final SIGCHLD for state stop-post.
> emergency.service: Changed stop-post -> dead
> emergency.service: Job emergency.service/start finished, result=done
> [  OK  ] Started Emergency Shell.
> emergency.target changed dead -> active
> emergency.target: Job emergency.target/start finished, result=done
> [  OK  ] Reached target Emergency Mode.
> Startup finished in 28.400s (kernel) + 0 (initrd) + 4min 57.014s (userspace) = 5min 25.414s.

As I already said, the system is now hanging in idle and can only be hard-reset.

(In reply to Martin Wilck from comment #11)

> "ExecStopPost=-/usr/bin/systemctl --fail --no-block default" causes the
> failure to continue booting after the shell exits.

That was nonsense. The actual problem seems to be that the command fails, see comment 12.

(In reply to Martin Wilck from comment #11)
> Note that emergency.service is not an original systemd file but comes from dracut.

here we are ... I wasn't aware that dracut has its own emergency service.

> This file has notable differences from
> systemd's original file:
> 
> > --- usr/lib/systemd/system/emergency.service    2017-08-08 13:18:48.000000000 +0200
> > +++ usr/lib/dracut/modules.d/98dracut-systemd/emergency.service 2015-11-25 14:22:28.000000000 +0100
> > -Type=idle
> > +Type=oneshot
>
> "Type=oneshot" probably causes the above behavior of the job and
> therefore the "transaction is desctructive"

That's correct. Could you try to use "idle" type instead of the "oneshot" one ?

For that, edit /usr/lib/dracut/modules.d/98dracut-systemd/emergency.service and run "mkinitrd".

Basically the problem is that with "oneshot" type, systemd is waiting for the emergency service to exit before the service is considered activated. The emergency target in its turn wait for emergency.service.

So 2 jobs are pending. And when exiting from the shell, (dracut) emergency service run "systemctl --fail default".  The side effect would cancel the emergency pending jobs (destructive transaction) therefore systemctl fails. The emergency service as well as the target are now considered as done and nothing more needs to be done: you're stuck.

Adding Daniel in Cc (for now).

Created attachment 743359 [details]
serial log with systemd.log_level=debug

FTR, here's a full serial log with systemd debugging, without applying the change Franck suggested yet.

Again, the log is garbled at the most interesting point, even more as in the previous case. But I included "systemd-cgls -a" output, hoping that might provide some further insight.

I'm pretty sure now that the issue is due to (dracut) emergency service using "Type=oneshot".

Please give "idle" type a test.

(In reply to Franck Bui from comment #17)

> Please give "idle" type a test.

Confirmed, with "idle" the shell can be exited as usual and boot continues successfully.

Created attachment 743540 [details]
serial log after changing Type=oneshot to Type=idle

FTR: Type=oneshot has been introduced in dracut commit c85cda9e:

commit c85cda9e2f72c655c01452956bda629bbecb9e55
Author: Harald Hoyer <harald@redhat.com>
Date:   Wed Mar 13 08:04:25 2013 +0100

    systemd: local-fs.target is now root-fs.target and initrd-fs.target
    
    Also rename dracut.target to initrd.target
    
    see also systemd commit 700e07f
    http://cgit.freedesktop.org/systemd/systemd/commit/?id=700e07f

The commit does not explain why the unit type of emergency.service had been changed. The same commit also introduced a change for "ExecStopPost" which was later reverted, but "Type=oneshot" remained.

The commit seems to have been part of a larger rewrite of the systemd/dracut boot concept which ended with 85c85f07 "systemd: switch to new initrd.target".

Anyway, "Type=oneshot" is also used in SLE12, where I haven't observed this behavior so far.

I have to correct my former statement that this does not occur on SLE-12.
It does, if I force a timeout with "rd.timeout=90":

:/# systemctl list-jobs
JOB UNIT              TYPE  STATE  
 56 emergency.target  start waiting
 57 emergency.service start running

2 jobs listed.
:/# exit
logout
Failed to start default.target: Transaction is destructive.

The reason that I didn't encounter this problem on SLE-12 is that, on Tumbleweed, I ran into bug 1048605. IOW, on TW I got a timeout for the root FS while SLE12 would simply wait forever. It I force SLE12 to time out like TW does, I find the same situation with the running emergency.service job.

So, this is not a regression after all. I apologize for the wrong information provided.

Upstream issue opened: https://github.com/dracutdevs/dracut/issues/291

(In reply to Martin Wilck from comment #22)
> Upstream issue opened: https://github.com/dracutdevs/dracut/issues/291

Thanks Martin for raising this to upstream.

Meanwhile this appears to be a dracut issue some I'm reassigning this to Daniel.

Merged upstream:

https://github.com/dracutdevs/dracut/commit/4c2d98c75b0dd3dad45430becb78c9d40bc6be1b

Good ! weird that this issue wasn't spotted earlier.

Thanks Martin. I cherry-picked this into the dracut devel repo: https://build.opensuse.org/package/show/home:dmolkentin:dracut:devel:git/dracut. Will transition into staging repo early next week.

Submitted to Factory and will be in RC2. Probably needs backport.

Closing as fixed.