udevadm: ensure 'udevadm info -w' show updated result #12901

yuwata · 2019-06-27T18:22:31Z

Prompted by systemd/systemd-centos-ci#117 (comment).

@mrc0mmand If possible, please test this.

keszybz · 2019-06-28T08:16:21Z

Looks good. I don't understand what fails in bionic-i386 though.

evverx · 2019-06-28T10:33:31Z

Apparently the "upstream" test timeouts on i386 from time to time. The same happened in #12897. I'd turn it off if I could. Though I'm not sure what @ddstreet, @martinpitt and @mbiebl think. As far as I know, as a compromise, it should be possible to turn it off only upstream by putting it in the "NOUPSTREAM" section at https://salsa.debian.org/systemd-team/systemd/blob/master/debian/tests/control#L186 but frankly I don't think the test is helpful at this point.

evverx · 2019-06-29T13:15:27Z

From https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1829829/comments/21

Regarding i386, I downloaded the log and took a look at what failed there. Turns out all the tests except for TEST-34-DYNAMICUSERMIGRATE, where the global timeout kicked in, passed. Apparently, to judge from https://salsa.debian.org/systemd-team/systemd/blob/master/debian/tests/upstream, on Ubuntu CI the tests are still run one by one whereas on CentOS CI we started to run them in parallel back in March (systemd/systemd-centos-ci#78) so it's no wonder the whole test times out sporadically. I don't expect the script in the Debian package to be fixed any time soon so could anyone either bump up the timeout or turn the test off?

mrc0mmand · 2019-06-29T15:30:29Z

@yuwata sorry for a late response, I was without internet for two days and then had some issues with Vagrant. Anyway, here are the results:

[root@arch build]# gcc --version
gcc (GCC) 9.1.0
Copyright (C) 2019 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

[root@arch build]# build/systemctl --version
systemd 242 (242-1105-g1120897)
+PAM +AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified
[root@arch build]# git describe
v242-1105-g11208976da
[root@arch build]# test/test-network/systemd-networkd-tests.py --build-dir=$PWD/build --debug 2>&1 | tee log.txt
<..snip..>
test_udev_driver (__main__.NetworkctlTests) ... Bus n/a: changing state UNSET → OPENING
Bus n/a: changing state OPENING → AUTHENTICATING
Trying to open "/etc/systemd/hwdb/hwdb.bin"...
Trying to open "/etc/udev/hwdb.bin"...
Trying to open "/usr/lib/systemd/hwdb/hwdb.bin"...
Trying to open "/usr/lib/udev/hwdb.bin"...
=== trie on-disk ===
tool version:          242
file size:         9556707 bytes
header size             80 bytes
strings            2082667 bytes
nodes              7473960 bytes
Bus n/a: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.29 path=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.network1 path=/org/freedesktop/network1/link/_313 interface=org.freedesktop.DBus.Properties member=Get cookie=2 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Got message type=error sender=:1.28 destination=:1.29 path=n/a interface=n/a member=n/a cookie=36 reply_cookie=2 signature=s error-name=org.freedesktop.network1.SpeedMeterInactive error-message=Speed meter is disabled.
Failed to query link bit rates: Speed meter is disabled.
Bus n/a: changing state RUNNING → CLOSED
Bus n/a: changing state UNSET → OPENING
Bus n/a: changing state OPENING → AUTHENTICATING
Trying to open "/etc/systemd/hwdb/hwdb.bin"...
Trying to open "/etc/udev/hwdb.bin"...
Trying to open "/usr/lib/systemd/hwdb/hwdb.bin"...
Trying to open "/usr/lib/udev/hwdb.bin"...
=== trie on-disk ===
tool version:          242
file size:         9556707 bytes
header size             80 bytes
strings            2082667 bytes
nodes              7473960 bytes
Bus n/a: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.30 path=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.network1 path=/org/freedesktop/network1/link/_315 interface=org.freedesktop.DBus.Properties member=Get cookie=2 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Got message type=error sender=:1.28 destination=:1.30 path=n/a interface=n/a member=n/a cookie=37 reply_cookie=2 signature=s error-name=org.freedesktop.network1.SpeedMeterInactive error-message=Speed meter is disabled.
Failed to query link bit rates: Speed meter is disabled.
Bus n/a: changing state RUNNING → CLOSED
Bus n/a: changing state UNSET → OPENING
Bus n/a: changing state OPENING → AUTHENTICATING
Trying to open "/etc/systemd/hwdb/hwdb.bin"...
Trying to open "/etc/udev/hwdb.bin"...
Trying to open "/usr/lib/systemd/hwdb/hwdb.bin"...
Trying to open "/usr/lib/udev/hwdb.bin"...
=== trie on-disk ===
tool version:          242
file size:         9556707 bytes
header size             80 bytes
strings            2082667 bytes
nodes              7473960 bytes
Bus n/a: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.31 path=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.network1 path=/org/freedesktop/network1/link/_314 interface=org.freedesktop.DBus.Properties member=Get cookie=2 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Got message type=error sender=:1.28 destination=:1.31 path=n/a interface=n/a member=n/a cookie=38 reply_cookie=2 signature=s error-name=org.freedesktop.network1.SpeedMeterInactive error-message=Speed meter is disabled.
Failed to query link bit rates: Speed meter is disabled.
Bus n/a: changing state RUNNING → CLOSED

unexpected success

<...snip...>
======================================================================
FAIL: test_dhcp_client_route_remove_on_renew (__main__.NetworkdDHCPClientTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 2461, in test_dhcp_client_route_remove_on_renew
    self.assertRegex(output, 'inet 192.168.5.2[0-9]*/24 brd 192.168.5.255 scope global dynamic veth99')
AssertionError: Regex didn't match: 'inet 192.168.5.2[0-9]*/24 brd 192.168.5.255 scope global dynamic veth99' not found in '51: veth99@veth-peer: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000\n    inet 192.168.5.230/24 brd 192.168.5.255 scope global secondary dynamic veth99\n       valid_lft 96sec preferred_lft 96sec'

======================================================================
FAIL: test_dhcp_client_with_ipv4ll_fallback_with_dhcp_server (__main__.NetworkdDHCPClientTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 2405, in test_dhcp_client_with_ipv4ll_fallback_with_dhcp_server
    self.assertRegex(output, 'inet 192.168.5.[0-9]*/24 brd 192.168.5.255 scope global dynamic veth99')
AssertionError: Regex didn't match: 'inet 192.168.5.[0-9]*/24 brd 192.168.5.255 scope global dynamic veth99' not found in '60: veth99@veth-peer: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000\n    inet 192.168.5.181/24 brd 192.168.5.255 scope global secondary dynamic veth99\n       valid_lft 109sec preferred_lft 109sec'

======================================================================
FAIL: test_ip_link_unmanaged (__main__.NetworkdNetworkTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 1464, in test_ip_link_unmanaged
    self.check_operstate('dummy98', 'off', setup_state='unmanaged')
  File "test/test-network/systemd-networkd-tests.py", line 305, in check_operstate
    self.assertRegex(get_operstate(link, show_status, setup_state), expected)
AssertionError: Regex didn't match: 'off' not found in 'degraded'

======================================================================
FAIL: test_link_local_addressing (__main__.NetworkdNetworkTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 1498, in test_link_local_addressing
    self.assertNotRegex(output, 'inet6* .* scope link')
AssertionError: Regex matched: 'inet6 fe80::4bf9:2fb7:feca:9bab/64 scope link' matches 'inet6* .* scope link' in '203: dummy98: <BROADCAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default qlen 1000\n    link/ether 72:c0:e0:9a:a4:fc brd ff:ff:ff:ff:ff:ff\n    inet6 fe80::4bf9:2fb7:feca:9bab/64 scope link \n       valid_lft forever preferred_lft forever'

----------------------------------------------------------------------
Ran 87 tests in 1546.067s

FAILED (failures=4, unexpected successes=1)

Full log: https://paste.fedoraproject.org/paste/2F1-b0TA73cLGoETeapsyQ

yuwata · 2019-06-29T15:55:32Z

@mrc0mmand Thank you. Hmm, this does not help the issue...

mrc0mmand · 2019-06-29T18:23:00Z

Results for 61ce0ad:

======================================================================
ERROR: test_dhcp_client_route_remove_on_renew (__main__.NetworkdDHCPClientTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 2454, in test_dhcp_client_route_remove_on_renew
    start_dnsmasq(ipv4_range='192.168.5.200,192.168.5.250', lease_time='2m')
  File "test/test-network/systemd-networkd-tests.py", line 237, in start_dnsmasq
    check_output(dnsmasq_command)
  File "test/test-network/systemd-networkd-tests.py", line 38, in check_output
    return subprocess.check_output(command, universal_newlines=True, **kwargs).rstrip()
  File "/usr/lib/python3.7/subprocess.py", line 395, in check_output
    **kwargs).stdout
  File "/usr/lib/python3.7/subprocess.py", line 487, in run
    output=stdout, stderr=stderr)
subprocess.CalledProcessError: Command '['dnsmasq', '-8', '/var/run/networkd-ci/test-dnsmasq-log-file', '--log-queries=extra', '--log-dhcp', '--pid-file=/var/run/networkd-ci/test-test-dnsmasq.pid', '--conf-file=/dev/null', '--interface=veth-peer', '--enable-ra', '--dhcp-range=2600::10,2600::20,2m', '--dhcp-range=192.168.5.200,192.168.5.250,2m', '-R', '--dhcp-leasefile=/var/run/networkd-ci/lease', '--dhcp-option=26,1492', '--dhcp-option=option:router,192.168.5.1', '--dhcp-option=33,192.168.5.4,192.168.5.5', '--port=0']' returned non-zero exit status 2.

======================================================================
FAIL: test_dhcp_client_with_ipv4ll_fallback_with_dhcp_server (__main__.NetworkdDHCPClientTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 2405, in test_dhcp_client_with_ipv4ll_fallback_with_dhcp_server
    self.assertRegex(output, 'inet 192.168.5.[0-9]*/24 brd 192.168.5.255 scope global dynamic veth99')
AssertionError: Regex didn't match: 'inet 192.168.5.[0-9]*/24 brd 192.168.5.255 scope global dynamic veth99' not found in '269: veth99@veth-peer: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000\n    inet 192.168.5.181/24 brd 192.168.5.255 scope global secondary dynamic veth99\n       valid_lft 108sec preferred_lft 108sec'

======================================================================
FAIL: test_ip_link_unmanaged (__main__.NetworkdNetworkTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 1464, in test_ip_link_unmanaged
    self.check_operstate('dummy98', 'off', setup_state='unmanaged')
  File "test/test-network/systemd-networkd-tests.py", line 305, in check_operstate
    self.assertRegex(get_operstate(link, show_status, setup_state), expected)
AssertionError: Regex didn't match: 'off' not found in 'degraded'

======================================================================
FAIL: test_link_local_addressing (__main__.NetworkdNetworkTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/test-network/systemd-networkd-tests.py", line 1498, in test_link_local_addressing
    self.assertNotRegex(output, 'inet6* .* scope link')
AssertionError: Regex matched: 'inet6 fe80::4bf9:2fb7:feca:9bab/64 scope link' matches 'inet6* .* scope link' in '405: dummy98: <BROADCAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default qlen 1000\n    link/ether 72:c0:e0:9a:a4:fc brd ff:ff:ff:ff:ff:ff\n    inet6 fe80::4bf9:2fb7:feca:9bab/64 scope link \n       valid_lft forever preferred_lft forever'

----------------------------------------------------------------------
Ran 87 tests in 1434.820s

FAILED (failures=3, errors=1, unexpected successes=1)

https://paste.fedoraproject.org/paste/woxDsbiAhpUotfDZumA~8A

This seems not necessary, but just for safety.

yuwata · 2019-06-29T20:17:27Z

OK. I am not sure why this does not help the issue in test-network. But I hope the change is good for safety.

yuwata added the udev label Jun 27, 2019

yuwata force-pushed the udevadm-info-w-fix branch from 91371c8 to beebe8b Compare June 28, 2019 17:56

yuwata added dont-merge 💣 and removed dont-merge 💣 labels Jun 28, 2019

yuwata force-pushed the udevadm-info-w-fix branch from beebe8b to 61ce0ad Compare June 29, 2019 16:48

mrc0mmand mentioned this pull request Jun 29, 2019

test: introduce TEST-36-NUMAPOLICY #12884

Merged

udevadm: ensure 'udevadm info -w' show updated result

08d78fb

This seems not necessary, but just for safety.

yuwata force-pushed the udevadm-info-w-fix branch from 61ce0ad to 08d78fb Compare June 29, 2019 20:16

yuwata changed the title ~~udevadm: make 'udevadm info -w' show updated result~~ udevadm: ensure 'udevadm info -w' show updated result Jun 29, 2019

poettering merged commit 7a55521 into systemd:master Jul 11, 2019

yuwata deleted the udevadm-info-w-fix branch July 11, 2019 21:53

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

udevadm: ensure 'udevadm info -w' show updated result #12901

udevadm: ensure 'udevadm info -w' show updated result #12901

yuwata commented Jun 27, 2019

keszybz commented Jun 28, 2019

evverx commented Jun 28, 2019

evverx commented Jun 29, 2019

mrc0mmand commented Jun 29, 2019

yuwata commented Jun 29, 2019

mrc0mmand commented Jun 29, 2019

yuwata commented Jun 29, 2019

udevadm: ensure 'udevadm info -w' show updated result #12901

udevadm: ensure 'udevadm info -w' show updated result #12901

Conversation

yuwata commented Jun 27, 2019

keszybz commented Jun 28, 2019

evverx commented Jun 28, 2019

evverx commented Jun 29, 2019

mrc0mmand commented Jun 29, 2019

yuwata commented Jun 29, 2019

mrc0mmand commented Jun 29, 2019

yuwata commented Jun 29, 2019