systemd-rfkill service times out when a new rfkill device is added

[Kleber Sacilotto de Souza]

[Impact]

The following issue was observed while running network-manager=1.8.4-1ubuntu3 autopkgtest on Artful with systemd=234-2ubuntu12.1:

-----------------------------------------------------------
Nov 21 17:00:32 autopkgtest systemd[1]: Starting Load/Save RF Kill Switch Status...
Nov 21 17:01:02 autopkgtest systemd[1]: systemd-rfkill.service: Start operation timed out. Terminating.
Nov 21 17:01:02 autopkgtest systemd[1]: Failed to start Load/Save RF Kill Switch Status.
Nov 21 17:01:02 autopkgtest systemd[1]: systemd-rfkill.service: Unit entered failed state.
Nov 21 17:01:02 autopkgtest systemd[1]: systemd-rfkill.service: Failed with result 'timeout'.
-----------------------------------------------------------

This happens after the testcase inserts the fake-rfkill module (a module shipped with network-manager tests that registers a new fake device with the rfkill subsystem).

On Artful, it causes the network-manager autopkgtest killswitches-no-urfkill to fail (see bug 1733321). The testcase reveals that when running network-manager cli to query the status of a WiFi interface ('nmcli radio wifi') it can report the wrong state of the device after 'rfkill block/unblock' is run to change the device 'Soft blocked' state. This can affect the state of the device presented to the user.

[Fix]

The issue is fixed by the following systemd upstream patches:

-----------------------------------------------------------
https://github.com/systemd/systemd/commit/8ec1a07998758f6a85f3ea5bf2ed14d87609398f#diff-275947967677827e2b72930d97f1b8ac

commit 8ec1a07998758f6a85f3ea5bf2ed14d87609398f
Author: S. Fan <email address hidden>
Date: Mon Jul 31 05:10:10 2017 -0500

    rfkill: fix erroneous behavior when polling the udev monitor (#6489)

    Comparing udev_device_get_sysname(device) and sysname will always return
    true. We need to check the device received from udev monitor instead.

    Also, fd_wait_for_event() sometimes never exits. Better set a timeout
    here.
-----------------------------------------------------------

-----------------------------------------------------------
https://github.com/systemd/systemd/commit/c7f6ca9379279affa8f22d15fa13063491f86a49#diff-275947967677827e2b72930d97f1b8ac

commit c7f6ca9379279affa8f22d15fa13063491f86a49
Author: Xiang Fan <email address hidden>
Date: Wed Aug 9 05:51:53 2017 -0500

    rfkill: fix typo (#6574)
-----------------------------------------------------------

With the fixes, the output from systemd-rfkill is:

-----------------------------------------------------------
Nov 28 15:27:54 autopkgtest systemd[1]: Starting Load/Save RF Kill Switch Status...
Nov 28 15:27:59 autopkgtest systemd-rfkill[14843]: Timed out waiting for udev monitor.
Nov 28 15:27:59 autopkgtest systemd[1]: Started Load/Save RF Kill Switch Status.
-----------------------------------------------------------

The patches are needed to fix the ADT tests observed with Artful tests on ppc64el architecture:
https://objectstorage.prodstack4-5.canonical.com/v1/AUTH_77e2ada1e7a84929a74ba3b87153c0ac/autopkgtest-artful/artful/ppc64el/n/network-manager/20171120_100719_28642@/log.gz

[Test Case]

2.1. Download network-manager package source code
$ apt-get source network-manager

2.2. Run killswitches-no-urfkill testcase
$ cd network-manager-1.8.4
$ sudo ./debian/tests/killswitches-no-urfkill

[Regression Potential]

Most of the network-manager and rfkill functionalities that can be affected by this change are tested by killswitches-no-urfkill testcase. It covers querying the WiFi device state using nmcli and the following rfkill commands: list, block and unblock. These have been verified to be either fixed or not having regressions.

The only rfkill command that is not covered by the testcase is 'event', which listens to rfkill events and display them. I have run tests manually and verified that it's not affected by these changes. These are the outputs from the unpatched and patched systemd versions while running the killswitches-no-urfkill testcase, which adds the rfkill device, blocks and unbloks it and removes the device (the idx value is expected to be different):

systemd 234-2ubuntu12.1:
-----------------------------------------------------------------------
$ sudo rfkill event
1513163787.877080: idx 3 type 1 op 0 soft 0 hard 0
1513163818.118695: idx 3 type 1 op 2 soft 1 hard 0
1513163818.222639: idx 3 type 1 op 2 soft 0 hard 0
1513163818.254778: idx 3 type 1 op 1 soft 0 hard 0
-----------------------------------------------------------------------

systemd 234-2ubuntu12.2:
-----------------------------------------------------------------------
$ sudo rfkill event
1513164121.690285: idx 0 type 1 op 0 soft 0 hard 0
1513164151.996227: idx 0 type 1 op 2 soft 1 hard 0
1513164152.114794: idx 0 type 1 op 2 soft 0 hard 0
1513164152.140536: idx 0 type 1 op 1 soft 0 hard 0
-----------------------------------------------------------------------

Regression potential is also minimized by the fact that the fix has been applied some months ago on upstream github repo and it's being shipped with systemd on Bionic (systemd=235-3ubuntu2).

[Kleber Sacilotto de Souza (kleber-souza)]

This is a debdiff for Artful applicable to systemd 234-2ubuntu12.1. This was built with pbuilder and tested in an Artful VM and the fix works as expected.

[Brian Murray (brian-murray)]

Is this fixed in Bionic yet?

[Kleber Sacilotto de Souza (kleber-souza)]

Yes, this has already been fixed in Bionic. The fix was applied upstream on systemd v235, so it's shipped with systemd=235-3ubuntu2.

[Brian Murray (brian-murray)]

Hello Kleber, or anyone else affected,

Accepted systemd into artful-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/systemd/234-2ubuntu12.2 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-artful to verification-done-artful. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-artful. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Kleber Sacilotto de Souza (kleber-souza)]

Confirmed that systemd=234-2ubuntu12.2 fixes the issue.

-------------------------------------------------------
Dec 5 17:14:44 autopkgtest systemd[1]: Starting Load/Save RF Kill Switch Status...
Dec 5 17:14:49 autopkgtest systemd-rfkill[7400]: Timed out waiting for udev monitor.
Dec 5 17:14:49 autopkgtest systemd[1]: Started Load/Save RF Kill Switch Status.
-------------------------------------------------------

Thanks!

[Robie Basak (racb)]

08:44 <rbasak> bdmurray, xnox, klebers: I don't understand why we're SRUing bug 1734908. It seems to have no user impact?

08:44 <rbasak> Additionally the Regression Potential and SRU verification process seems to have made no consideration for how to test or verify that rfkill hasn't otherwise regressed by this patch.

08:44 <rbasak> So I'm reluctant to release it.

[Kleber Sacilotto de Souza (kleber-souza)]

I have extended the bug description to include the additional information requested by @racb.

[Robie Basak (racb)]

Thanks. I'm happy with the additional information provided.

autopkgtests are still failing on this, including the amd64 one for systemd which seems somewhat essential and has failed on retry, so right now this is blocked on those.

If the autopkgtests failures can be resolved (fix or confirm not a problem) then I'd be happy to release this.

[Brian Murray (brian-murray)]

Hello Kleber, or anyone else affected,

Accepted systemd into artful-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/systemd/234-2ubuntu12.3 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-artful to verification-done-artful. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-artful. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Dimitri John Ledkov (xnox)]

urfkill switch autopkgtest testcases of network manager are passing with this new systemd still.
(there are other nm regressions in other test cases however)

[Launchpad Janitor (janitor)]

This bug was fixed in the package systemd - 234-2ubuntu12.3

---------------
systemd (234-2ubuntu12.3) artful; urgency=medium

  [ Dimitri John Ledkov ]
  * Fix test-functions failing with Ubuntu units. LP: #1750608
  * tests: switch to using ext4 by default, instead of ext3. LP: #1750608
  * Fix kdump service not starting, due to systemd not loading dropins.
    Cherrypick a fix from upstream. (LP: #1708409)
  * systemd-fsckd: Fix ADT tests to work on s390x too. (LP: #1736955)
  * netwokrd: add support for RequiredForOnline stanza. (LP: #1737570)
  * resolved.service: set DefaultDependencies=no (LP: #1734167)
  * systemd.postinst: enable persistent journal. (LP: #1618188)
  * core: add support for non-writable unified cgroup hierarchy for container support.
    Rebase and de-fuzz. (LP: #1734410)
  * Prevent MemoryDenyWriteExecution policy bypass, by disallowing pkey_mprotect when mprotect is disallowed.
    CVE-2017-15908 (LP: #1725348)
  * networkd: enable promote_secondaries on networkd managed dhcp links.
    This fixes failing to renew DHCP lease, on networkd managed devices.
    (LP: #1721223)

  [ Kleber Sacilotto de Souza ]
  * systemd-rfkill service times out when a new rfkill device is added
    - rfkill-fix-erroneous-behavior-when-polling-the-udev-.patch: Comparing
    udev_device_get_sysname(device) and sysname will always return true. We need to
    check the device received from udev monitor instead.
    - rfkill-fix-typo.patch: Fix typo in rfkill log message. (LP: #1734908)

 -- Dimitri John Ledkov <email address hidden> Tue, 20 Feb 2018 16:11:58 +0000

[Łukasz Zemczak (sil2100)]

The verification of the Stable Release Update for systemd has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.