debug kernel commandline break snap service refreshes

Bug #1885597 reported by Ian Johnson on 2020-06-29
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
snapd
High
Ian Johnson

Bug Description

With the debug kernel command line (or alternatively the systemd.log_level=debug kernel command line parameter or setting SYSTEMD_LOG_LEVEL=debug), snapd does not work as expected.

Specifically, our usages of the systemctl command will fail to run properly, because systemd will see that we are running systemctl from inside a systemd unit (i.e. as a child process of snapd.service), and it will add debugging messages like this:

```
$ systemctl show --property=Id,ActiveState,UnitFileState,Type snap.lxd.benchmark.service
Bus n/a: changing state UNSET → OPENING
Bus n/a: changing state OPENING → AUTHENTICATING
Successfully forked off '(pager)' as PID 25124.
Showing one /org/freedesktop/systemd1/unit/snap_2elxd_2ebenchmark_2eservice
Bus n/a: changing state AUTHENTICATING → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1/unit/snap_2elxd_2ebenchmark_2eservice interface=org.freedesktop.DBus.Properties member=GetAll cookie=1
Got message type=method_return sender=org.freedesktop.systemd1 destination=n/a path=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 signature=a{sv} error-name=n/a error-message=n/a
Unit snap.lxd.benchmark.service could not be found.
Bus n/a: changing state RUNNING → CLOSED
Type=
Id=snap.lxd.benchmark.service
ActiveState=inactive
UnitFileState=
```

When our code expects only this output (which is also what you see without these debug options set):

```
$ systemctl show --property=Id,ActiveState,UnitFileState,Type snap.lxd.benchmark.service
Type=
Id=snap.lxd.benchmark.service
ActiveState=inactive
UnitFileState=
```

Confusingly, running systemctl from a normal shell even with these options enabled does not trigger the additional output, the systemctl command must be run from a systemd unit.

This affects the `snap services` command any any refreshes of snaps with services as snapd will fail to understand the status of the service when refreshing and thus will fail the refresh.

Changed in snapd:
importance: Undecided → High
status: New → Triaged
assignee: nobody → Ian Johnson (anonymouse67)
Ian Johnson (anonymouse67) wrote :

It seems that systemctl in this state will output the debug commands to stderr and the normal output we parse to stdout, but in snapd we are combining those two streams when running the command, so the fix for now is just to not combine those streams when running systemctl.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers