Bug#934992: [Pkg-utopia-maintainers] Bug#934992: network-manager breaks systemd autopkgtest

Sun Aug 18 18:22:02 BST 2019

Am 18.08.19 um 13:01 schrieb Andreas Henriksson:
> So apparently polkitd is not running after the first reboot attempt. I
> have no clue why or how to investigate why so I guess I'll leave that to
> the professionals.
> 
> Maybe it would be useful to change the test to do
> "pidof polkitd || fail" to gather more autopkgtest artifacts information
> for debugging purposes? i.e. the boot-smoke-journal.txt file.

Hm, I have to say I don't quite get the check for
"pidof polkitd" either.

polkit.service is a dbus activated service, i.e. it is started on demand
and not statically during boot.
So boot-smoke was relying on "something" triggering the start of
polkit.service.

Seems that older network manager versions did trigger the start of
polkit.service, so this test only worked "by accident".
See the attached bullseye.txt and sid.txt which confirm this suspicion.

Martin, do you remember why you chose to check for "pidof polkitd"?
This seems rather unreliable when we rely on "some other component" to
trigger it's start.
Shouldn't we rather check for a service which is installed by the test
and hooked into multi-user.target, like "pidof NetworkManager"?

Afaics, this looks like a bug in boot-smoke to me for making wrong
assumption. I would like Martin's feedback on this though.

-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?
-------------- next part --------------
root at autopkgtest-bullseye:/tmp/autopkgtest-lxc.qoaowm2l/downtmp/build.Ira/src# systemctl status polkit.service NetworkManager.service
* polkit.service - Authorization Manager
   Loaded: loaded (/lib/systemd/system/polkit.service; static; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:polkit(8)

* NetworkManager.service - Network Manager
   Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Sun 2019-08-18 17:16:00 UTC; 11s ago
     Docs: man:NetworkManager(8)
  Process: 63 ExecStart=/usr/sbin/NetworkManager --no-daemon (code=exited, status=0/SUCCESS)
 Main PID: 63 (code=exited, status=0/SUCCESS)

root at autopkgtest-bullseye:/tmp/autopkgtest-lxc.qoaowm2l/downtmp/build.Ira/src# systemctl start NetworkManager.service

root at autopkgtest-bullseye:/tmp/autopkgtest-lxc.qoaowm2l/downtmp/build.Ira/src# systemctl status polkit.service NetworkManager.service
* polkit.service - Authorization Manager
   Loaded: loaded (/lib/systemd/system/polkit.service; static; vendor preset: enabled)
   Active: active (running) since Sun 2019-08-18 17:16:25 UTC; 1s ago
     Docs: man:polkit(8)
 Main PID: 225 (polkitd)
    Tasks: 4 (limit: 4915)
   Memory: 3.4M
   CGroup: /system.slice/polkit.service
           `-225 /usr/lib/policykit-1/polkitd --no-debug

Aug 18 17:16:25 autopkgtest-bullseye systemd[1]: Starting Authorization Manager...
Aug 18 17:16:25 autopkgtest-bullseye polkitd[225]: started daemon version 0.105 using authority implementation `local' version `0.105'
Aug 18 17:16:25 autopkgtest-bullseye systemd[1]: Started Authorization Manager.

* NetworkManager.service - Network Manager
   Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2019-08-18 17:16:24 UTC; 1s ago
     Docs: man:NetworkManager(8)
 Main PID: 215 (NetworkManager)
    Tasks: 4 (limit: 4915)
   Memory: 2.9M
   CGroup: /system.slice/NetworkManager.service
           `-215 /usr/sbin/NetworkManager --no-daemon

Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4084] Loaded device plugin: NMAtmManager (/usr/lib/x86_64-linux-gnu/NetworkManager/1.1
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4101] Loaded device plugin: NMWwanFactory (/usr/lib/x86_64-linux-gnu/NetworkManager/1.
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4106] Loaded device plugin: NMBluezManager (/usr/lib/x86_64-linux-gnu/NetworkManager/1
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4123] Loaded device plugin: NMTeamFactory (/usr/lib/x86_64-linux-gnu/NetworkManager/1.
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4133] device (lo): carrier: link connected
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4137] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4144] device (eth0): carrier: link connected
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4147] manager: (eth0): new Veth device (/org/freedesktop/NetworkManager/Devices/2)
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4154] manager: NetworkManager state is now CONNECTED_GLOBAL
Aug 18 17:16:25 autopkgtest-bullseye NetworkManager[215]: <info>  [1566148585.4196] manager: startup complete

root at autopkgtest-bullseye:/tmp/autopkgtest-lxc.qoaowm2l/downtmp/build.Ira/src# apt-cache policy network-manager
network-manager:
  Installed: 1.18.0-3
  Candidate: 1.18.0-3
  Version table:
 *** 1.18.0-3 500
        500 http://deb.debian.org/debian bullseye/main amd64 Packages
        100 /var/lib/dpkg/status
-------------- next part --------------
root at autopkgtest-sid:/tmp/autopkgtest-lxc.1vvt45m9/downtmp/build.X70/src# systemctl status polkit.service NetworkManager.service
● polkit.service - Authorization Manager
   Loaded: loaded (/lib/systemd/system/polkit.service; static; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:polkit(8)

Aug 18 17:19:44 autopkgtest-sid systemd[1]: Starting Authorization Manager...
Aug 18 17:19:44 autopkgtest-sid polkitd[5586]: started daemon version 0.105 using authority implementation `local' version `0.105'
Aug 18 17:19:44 autopkgtest-sid systemd[1]: Started Authorization Manager.
Aug 18 17:20:04 autopkgtest-sid systemd[1]: Stopping Authorization Manager...
Aug 18 17:20:04 autopkgtest-sid systemd[1]: polkit.service: Main process exited, code=killed, status=15/TERM
Aug 18 17:20:04 autopkgtest-sid systemd[1]: polkit.service: Succeeded.
Aug 18 17:20:04 autopkgtest-sid systemd[1]: Stopped Authorization Manager.

● NetworkManager.service - Network Manager
   Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Sun 2019-08-18 17:20:24 UTC; 4s ago
     Docs: man:NetworkManager(8)
  Process: 65 ExecStart=/usr/sbin/NetworkManager --no-daemon (code=exited, status=0/SUCCESS)
 Main PID: 65 (code=exited, status=0/SUCCESS)

Aug 18 17:20:07 autopkgtest-sid NetworkManager[65]: <info>  [1566148807.7846] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
Aug 18 17:20:07 autopkgtest-sid NetworkManager[65]: <info>  [1566148807.7859] device (eth0): carrier: link connected
Aug 18 17:20:07 autopkgtest-sid NetworkManager[65]: <info>  [1566148807.7864] manager: (eth0): new Veth device (/org/freedesktop/NetworkManager/Devices/2)
Aug 18 17:20:07 autopkgtest-sid NetworkManager[65]: <info>  [1566148807.7876] manager: NetworkManager state is now CONNECTED_GLOBAL
Aug 18 17:20:07 autopkgtest-sid NetworkManager[65]: <info>  [1566148807.7916] manager: startup complete
Aug 18 17:20:24 autopkgtest-sid systemd[1]: Stopping Network Manager...
Aug 18 17:20:24 autopkgtest-sid NetworkManager[65]: <info>  [1566148824.5244] caught SIGTERM, shutting down normally.
Aug 18 17:20:24 autopkgtest-sid NetworkManager[65]: <info>  [1566148824.5299] exiting (success)
Aug 18 17:20:24 autopkgtest-sid systemd[1]: NetworkManager.service: Succeeded.
Aug 18 17:20:24 autopkgtest-sid systemd[1]: Stopped Network Manager.

root at autopkgtest-sid:/tmp/autopkgtest-lxc.1vvt45m9/downtmp/build.X70/src# systemctl start NetworkManager

root at autopkgtest-sid:/tmp/autopkgtest-lxc.1vvt45m9/downtmp/build.X70/src# systemctl status polkit.service NetworkManager.service
● polkit.service - Authorization Manager
   Loaded: loaded (/lib/systemd/system/polkit.service; static; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:polkit(8)

Aug 18 17:19:44 autopkgtest-sid systemd[1]: Starting Authorization Manager...
Aug 18 17:19:44 autopkgtest-sid polkitd[5586]: started daemon version 0.105 using authority implementation `local' version `0.105'
Aug 18 17:19:44 autopkgtest-sid systemd[1]: Started Authorization Manager.
Aug 18 17:20:04 autopkgtest-sid systemd[1]: Stopping Authorization Manager...
Aug 18 17:20:04 autopkgtest-sid systemd[1]: polkit.service: Main process exited, code=killed, status=15/TERM
Aug 18 17:20:04 autopkgtest-sid systemd[1]: polkit.service: Succeeded.
Aug 18 17:20:04 autopkgtest-sid systemd[1]: Stopped Authorization Manager.

● NetworkManager.service - Network Manager
   Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2019-08-18 17:20:40 UTC; 1s ago
     Docs: man:NetworkManager(8)
 Main PID: 209 (NetworkManager)
    Tasks: 4 (limit: 4915)
   Memory: 3.0M
   CGroup: /system.slice/NetworkManager.service
           └─209 /usr/sbin/NetworkManager --no-daemon

Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0706] ifupdown:       interface-parser: parsing file /etc/network/interfaces
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0706] ifupdown:       interface-parser: source line includes interfaces file(s) /etc/networ
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0706] ifupdown:       interface-parser: finished parsing file /etc/network/interfaces
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0709] ifupdown: guessed connection type (eth0) = 802-3-ethernet
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0719] device (lo): carrier: link connected
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0722] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0730] device (eth0): carrier: link connected
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0733] manager: (eth0): new Veth device (/org/freedesktop/NetworkManager/Devices/2)
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0742] manager: NetworkManager state is now CONNECTED_GLOBAL
Aug 18 17:20:41 autopkgtest-sid NetworkManager[209]: <info>  [1566148841.0791] manager: startup complete

root at autopkgtest-sid:/tmp/autopkgtest-lxc.1vvt45m9/downtmp/build.X70/src# apt-cache policy network-manager
network-manager:
  Installiert:           1.20.0-1
  Installationskandidat: 1.20.0-1
  Versionstabelle:
 *** 1.20.0-1 500
        500 http://deb.debian.org/debian sid/main amd64 Packages
        100 /var/lib/dpkg/status
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: OpenPGP digital signature
URL: <http://alioth-lists.debian.net/pipermail/pkg-systemd-maintainers/attachments/20190818/09aebb90/attachment.sig>