Actions
action #64042
closed[qe-core][functional][sporadic] test fails in NM_wpa2_enterprise: "dhcp4 (wlan1): request timed out" Leap15.2 ppc64le
Status:
Resolved
Priority:
Normal
Assignee:
Category:
Bugs in existing tests
Target version:
SUSE QA - Milestone 30
Start date:
2020-03-02
Due date:
% Done:
0%
Estimated time:
42.00 h
Difficulty:
Description
Observation¶
As per journalctl extract, seems to have a timing issue that make the wlan activation to fail.
extract journalctl: https://openqa.opensuse.org/tests/1191824/file/NM_wpa2_enterprise-journal.log
Mar 01 02:20:19 susetest kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Mar 01 02:20:19 susetest NetworkManager[3168]: <info> [1583047219.8364] device (wlan1): supplicant interface state: associated -> completed
Mar 01 02:20:19 susetest NetworkManager[3168]: <info> [1583047219.8364] device (wlan1): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "foobar"
Mar 01 02:20:19 susetest NetworkManager[3168]: <info> [1583047219.8365] device (p2p-dev-wlan1): supplicant management interface state: associated -> completed
Mar 01 02:20:19 susetest NetworkManager[3168]: <info> [1583047219.8714] device (wlan1): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Mar 01 02:20:19 susetest NetworkManager[3168]: <info> [1583047219.8719] dhcp4 (wlan1): activation: beginning transaction (timeout in 45 seconds)
Mar 01 02:20:19 susetest avahi-daemon[953]: Joining mDNS multicast group on interface wlan1.IPv6 with address fe80::f270:84c:a7c5:2604.
Mar 01 02:20:19 susetest avahi-daemon[953]: New relevant interface wlan1.IPv6 for mDNS.
Mar 01 02:20:19 susetest avahi-daemon[953]: Registering new address record for fe80::f270:84c:a7c5:2604 on wlan1.*.
Mar 01 02:20:24 susetest systemd[1334]: Started Application launched by gnome-shell.
Mar 01 02:20:34 susetest su[3458]: The gnome keyring socket is not owned with the same credentials as the user login: /run/user/1000/keyring/control
Mar 01 02:20:34 susetest su[3458]: gkr-pam: couldn't unlock the login keyring.
Mar 01 02:20:34 susetest su[3458]: (to root) bernhard on pts/0
Mar 01 02:20:35 susetest su[3458]: pam_unix(su:session): session opened for user root by bernhard(uid=1000)
Mar 01 02:21:05 susetest NetworkManager[3168]: <warn> [1583047265.5070] dhcp4 (wlan1): request timed out
Mar 01 02:21:05 susetest NetworkManager[3168]: <info> [1583047265.5072] dhcp4 (wlan1): state changed unknown -> timeout
Mar 01 02:21:05 susetest NetworkManager[3168]: <info> [1583047265.5074] dhcp4 (wlan1): canceled DHCP transaction
Mar 01 02:21:05 susetest NetworkManager[3168]: <info> [1583047265.5074] dhcp4 (wlan1): state changed timeout -> done
Mar 01 02:21:05 susetest NetworkManager[3168]: <info> [1583047265.5078] device (wlan1): state change: ip-config -> failed (reason 'ip-config-unavailable', sys-iface-state: 'managed')
Mar 01 02:21:05 susetest NetworkManager[3168]: <warn> [1583047265.5100] device (wlan1): Activation: failed for connection 'foobar'
Mar 01 02:21:05 susetest kernel: wlan1: deauthenticating from be:86:91:4d:82:32 by local choice (Reason: 3=DEAUTH_LEAVING)
Some logs difference after connection_uuid.
Broken:
[ 1580.153779] NetworkManager[3974]: <warn> [1591164299.7843] sup-iface[0xaaaaeadb8110,wlan1]: connection disconnected (reason -3)
[ 1580.155855] NetworkManager[3974]: <info> [1591164299.7850] device (wlan1): supplicant interface state: completed -> scanning
[ 1580.157839] NetworkManager[3974]: <info> [1591164299.7850] device (p2p-dev-wlan1): supplicant management interface state: completed -> scanning
[ 1584.157562] NetworkManager[3974]: <info> [1591164303.8502] device (wlan1): supplicant interface state: scanning -> disconnected
[ 1584.159879] NetworkManager[3974]: <info> [1591164303.8503] device (p2p-dev-wlan1): supplicant management interface state: scanning -> disconnected
Working:
[ 1624.224134] NetworkManager[3935]: <warn> [1590759093.7651] sup-iface[0xaaaab9670910,wlan1]: connection disconnected (reason -3)
[ 1624.232670] NetworkManager[3935]: <info> [1590759093.7673] device (wlan1): supplicant interface state: completed -> disabled
[ 1624.249780] NetworkManager[3935]: <info> [1590759093.7674] device (p2p-dev-wlan1): supplicant management interface state: completed -> disabled
[ 1624.253398] NetworkManager[3935]: <info> [1590759093.7678] device (wlan1): supplicant interface state: disabled -> inactive
[ 1624.261844] NetworkManager[3935]: <info> [1590759093.7681] device (p2p-dev-wlan1): supplicant management interface state: disabled -> inactive
38c0h-0-
Acceptance criteria¶
- AC: The test module NM_wpa2_enterprise passes or fail in a product bug.
Exit criteria¶
- AC: The test module is unscheduled for ppc
Tasks¶
- Confirm with openSUSE if it makes sense to test network manager on PPC. If not, unschedule test module for PPC.
- If it makes sense: Figure out how the WIFI setup is done for that test.
- Find possible week points of that setup that could be causing those timeouts. 4a. Fix the setup or adapt the test module to retry WIFI connection. 4b. Or file a product bug
Reproducible¶
- Fails since Build 123.1 in scenario opensuse-15.2-DVD-ppc64le-extra_tests_on_gnome@ppc64le
- Fail example: 313.1
- Expected result: 314.3
- Latest result in this scenario: opensuse-15.2-DVD-ppc64le-extra_tests_on_gnome@ppc64le
Actions