Closed Bug 921620 Opened 13 years ago Closed 12 years ago

Sporadic failures in test_set_wifi (unittest)/connecting to Wi-Fi on master, Hamachi builds

Categories

(Firefox OS Graveyard :: Gaia::UI Tests, defect)

Product:
Firefox OS Graveyard
Component:
Gaia::UI Tests
Platform:
ARM
Gonk (Firefox OS)
Type:
defect
Priority:
Not set
Severity:
critical

Tracking

(Not tracked)

Status:
VERIFIED FIXED

People

(Reporter: stephend, Assigned: chucklee)

References

(
URL
)

Details

(Keywords: regression)

Attachments

(2 files, 3 obsolete files)

failing logcat from b2g-3
250.63 KB, text/plain
Details
Change trigger point of wifi down. V2
4.90 KB, patch
Details | Diff | Splinter Review
STR: Do multiple runs of test_set_wifi [1] on a (preferably) Hamachi/Buri device [2], using a Marionette-enabled engineering build, from master Actual Results: When it fails, the exception is: Traceback (most recent call last): File "/var/jenkins/workspace/b2g.hamachi.mozilla-central.unittests.wifi/.env/local/lib/python2.7/site-packages/marionette_client-0.5.37-py2.7.egg/marionette/marionette_test.py", line 132, in run testMethod() File "/var/jenkins/workspace/b2g.hamachi.mozilla-central.unittests.wifi/tests/python/gaia-ui-tests/gaiatest/tests/unit/settings/test_wifi_settings.py", line 11, in test_set_wifi self.data_layer.enable_wifi() File "/var/jenkins/workspace/b2g.hamachi.mozilla-central.unittests.wifi/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 247, in enable_wifi result = self.marionette.execute_async_script("return GaiaDataLayer.enableWiFi()", special_powers=True) File "/var/jenkins/workspace/b2g.hamachi.mozilla-central.unittests.wifi/.env/local/lib/python2.7/site-packages/marionette_client-0.5.37-py2.7.egg/marionette/marionette.py", line 1060, in execute_async_script filename=os.path.basename(frame[0])) File "/var/jenkins/workspace/b2g.hamachi.mozilla-central.unittests.wifi/.env/local/lib/python2.7/site-packages/marionette_client-0.5.37-py2.7.egg/marionette/marionette.py", line 570, in _send_message self._handle_error(response) File "/var/jenkins/workspace/b2g.hamachi.mozilla-central.unittests.wifi/.env/local/lib/python2.7/site-packages/marionette_client-0.5.37-py2.7.egg/marionette/marionette.py", line 619, in _handle_error raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace) ScriptTimeoutException: timed out I'll attach the relevant logcat. [1] https://github.com/mozilla-b2g/gaia/blob/master/tests/python/gaia-ui-tests/gaiatest/tests/unit/settings/test_wifi_settings.py#L10 [2] in this case, b2g-3: Credentials/settings: https://github.com/mozilla/webqa-credentials/blob/master/b2g/b2g-3.json
Hi Vincent -- can you help us work through this? Thanks!
Flags: needinfo?(vchang)
A regression range here would make this really easy to identify the regressing patch. When is the last time this passed on master? When is the first time it failed?
Keywords: regression, regressionwindow-wanted
(In reply to Jason Smith [:jsmith] from comment #3) > A regression range here would make this really easy to identify the > regressing patch. When is the last time this passed on master? When is the > first time it failed? It's not a "regression range" that we need, really, it's "help triaging and addressing" the sporadic nature of our Wi-Fi-connection logic/setup/infra -- we don't even really know what it is. One thing we do know, though, is that while it does affect Hamachis more than Unagis/Inaris, it affects them all. 1. Our trend is pretty much a 50% pass rate (when we can run, which we can't right now, due to bug 922467); see http://qa-selenium.mv.mozilla.com:8080/view/B2G%20Hamachi/job/b2g.hamachi.mozilla-central.unittests.wifi/buildTimeTrend 2. Compare the above with our Unagi run (again, engineering builds on mozilla-central), and you'll see why we've filed this as being Hamachi-specific: http://qa-selenium.mv.mozilla.com:8080/view/B2G%20Unagi/job/b2g.unagi.mozilla-central.unittests.wifi/buildTimeTrend
I just run gaia_ui_test 10 times on buri with below command successfully. gaiatest --address 127.0.0.1:2828 --testvars=testvars_my.json gaiatest/tests/settings/test_settings_wifi.py I was in master branch for mozilla central and gaia. gaia ui test => commit e8fc6ea679aa864dfc9a10d2a95d7ddbee1d62d7 gaia => commit 177fc68d3648666cbc21670cd23f39b4b7bb7515 mozilla central => changeset: 149342:d71579c316c1(mercurial) BTW, when working on buri, you should burn the partner build first, After that, don't update the system.img using "flash.sh". Instead, you do "flash.sh gecko" and "flash.sh gaia" to update gecko and gaia respectively. The other issue I could think is the scan result. Sometimes the SSID you specify in testvars json file may not show in scan result. It's the natural of wifi. You can reretry scan or use associate API with correct network information to connect.
Flags: needinfo?(vchang)
(In reply to Vincent Chang[:vchang] from comment #5) > BTW, when working on buri, you should burn the partner build first, > After that, don't update the system.img using "flash.sh". Instead, you do > "flash.sh gecko" and "flash.sh gaia" to update gecko and gaia respectively. We currently running "./fullflash_gecko_ril_gaia.sh -n" should we be running the commands Vincent is suggesting instead?
Flags: needinfo?(nhirata.bugzilla)
Flash gecko/flash gaia is more or less what the fullflash script is doing. There's some things that the flash.sh gaia does that fullflash doesn't do; we're trying to resolve those issues now.
Flags: needinfo?(nhirata.bugzilla)
Vincent, fyi, I modified the B2G flash.sh so that if it is a buri device by default it does gecko and gaia flash. You need to -f to flash the images : https://github.com/mozilla-b2g/B2G/blob/master/flash.sh#L265
(In reply to Vincent Chang[:vchang] from comment #5) > I just run gaia_ui_test 10 times on buri with below command successfully. > gaiatest --address 127.0.0.1:2828 --testvars=testvars_my.json > gaiatest/tests/settings/test_settings_wifi.py > > I was in master branch for mozilla central and gaia. > gaia ui test => commit e8fc6ea679aa864dfc9a10d2a95d7ddbee1d62d7 > gaia => commit 177fc68d3648666cbc21670cd23f39b4b7bb7515 > mozilla central => changeset: 149342:d71579c316c1(mercurial) > > BTW, when working on buri, you should burn the partner build first, > After that, don't update the system.img using "flash.sh". Instead, you do > "flash.sh gecko" and "flash.sh gaia" to update gecko and gaia respectively. > > The other issue I could think is the scan result. Sometimes the SSID you > specify in testvars json file may not show in scan result. It's the natural > of wifi. You can reretry scan or use associate API with correct network > information to connect. Does the logcat indicate that this is the problem? E/GeckoConsole( 138): Content JS LOG at dummy file:499 in GaiaDataLayer.setSetting: setting wifi.enabled to true E/GeckoConsole( 138): Content JS LOG at dummy file:502 in GaiaDataLayer.setSetting/req.onsuccess: setting changed I/Diag_Lib( 141): rpc_handle_rpc_call: for Xid: 7e, Prog: 31000000, Vers: d17ed9ea, Proc: 00000014 D/QCRIL_RPC( 141): Enter qcril_cm_srvsys_event_callback D/QCRIL_RPC( 141): Exit qcril_cm_srvsys_event_callback I/Diag_Lib( 141): rpc_handle_rpc_call: Find Status: 0 Xid: 7e I/ONCRPC ( 141): oncrpc_proxy_handle_cmd_rpc_call: Dispatching xid: 7e I/ONCRPC ( 141): oncrpc_xdr_reply_msg_start: Prog: 00000000, Ver: 00000000, Proc: 00000000 Xid: 0000007e I/ONCRPC ( 141): oncrpc_msg_reply: Prog: 00000000, Ver: 00000000, Proc: 00000000 Xid: 0000007e I/ONCRPC ( 141): oncrpc_proxy_handle_cmd_rpc_call: Dispatch returned for xid: 7e E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] D/wpa_supplicant( 485): wpa_supplicant v2.0-devel-4.0.4 D/wpa_supplicant( 485): Add randomness: count=1 entropy=0 D/wpa_supplicant( 485): random pool - hexdump(len=128): [REMOVED] D/wpa_supplicant( 485): random_mix_pool - hexdump(len=8): [REMOVED] D/wpa_supplicant( 485): random_mix_pool - hexdump(len=20): [REMOVED] D/wpa_supplicant( 485): random pool - hexdump(len=128): [REMOVED] D/wpa_supplicant( 485): random: Added entropy from /data/misc/wifi/entropy.bin (own_pool_ready=2) D/wpa_supplicant( 485): random: Trying to read entropy from /dev/random D/wpa_supplicant( 485): Get randomness: len=20 entropy=1 D/wpa_supplicant( 485): random from os_get_random - hexdump(len=20): [REMOVED] D/wpa_supplicant( 485): random_mix_pool - hexdump(len=20): [REMOVED] D/wpa_supplicant( 485): random from internal pool - hexdump(len=16): [REMOVED] D/wpa_supplicant( 485): random_mix_pool - hexdump(len=20): [REMOVED] D/wpa_supplicant( 485): random from internal pool - hexdump(len=16): [REMOVED] D/wpa_supplicant( 485): mixed random - hexdump(len=20): [REMOVED] D/wpa_supplicant( 485): random: Updated entropy file /data/misc/wifi/entropy.bin (own_pool_ready=2) D/wpa_supplicant( 485): Initializing interface 'wlan0' conf '/data/misc/wifi/wpa_supplicant.conf' driver 'nl80211' ctrl_interface 'N/A' bridge 'N/A' D/wpa_supplicant( 485): Configuration file '/data/misc/wifi/wpa_supplicant.conf' -> '/data/misc/wifi/wpa_supplicant.conf' D/wpa_supplicant( 485): Reading configuration file '/data/misc/wifi/wpa_supplicant.conf' D/wpa_supplicant( 485): ctrl_interface='DIR=/data/system/wpa_supplicant GROUP=wifi' D/wpa_supplicant( 485): update_config=1 D/wpa_supplicant( 485): wfd_session_mgmt_ctrl_port=554 D/wpa_supplicant( 485): wfd_device_max_throughput=10 D/wpa_supplicant( 485): nl80211: interface wlan0 in phy phy0 I/wpa_supplicant( 485): rfkill: Cannot open RFKILL control device D/wpa_supplicant( 485): nl80211: RFKILL status not available D/wpa_supplicant( 485): nl80211: Set mode ifindex 13 iftype 2 (STATION) D/wpa_supplicant( 485): nl80211: Subscribe to mgmt frames with non-AP handle 0x2058180 D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=2): 04 0a D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=2): 04 0b D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=2): 04 0c D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=2): 04 0d D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=6): 04 09 50 6f 9a 09 D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=5): 7f 50 6f 9a 09 D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=1): 06 D/wpa_supplicant( 485): nl80211: Register frame type=0xd0 nl_handle=0x2058180 D/wpa_supplicant( 485): nl80211: Register frame match - hexdump(len=2): 0a 07 D/wpa_supplicant( 485): netlink: Operstate: linkmode=1, operstate=5 D/wpa_supplicant( 485): nl80211: Using driver-based roaming D/wpa_supplicant( 485): nl80211: Supports Probe Response offload in AP mode D/wpa_supplicant( 485): nl80211: Disable use_monitor with device_ap_sme since no monitor mode support detected D/wpa_supplicant( 485): nl80211: driver param='(null)' D/wpa_supplicant( 485): nl80211: Regulatory information - country=CN D/wpa_supplicant( 485): nl80211: 2402-2482 @ 40 MHz D/wpa_supplicant( 485): nl80211: 5735-5835 @ 40 MHz D/wpa_supplicant( 485): nl80211: Added 802.11b mode based on 802.11g information D/wpa_supplicant( 485): wlan0: Own MAC address: 90:5f:2e:43:3c:38 D/wpa_supplicant( 485): wpa_driver_nl80211_set_key: ifindex=13 alg=0 addr=0x0 key_idx=0 set_tx=0 seq_len=0 key_len=0 D/wpa_supplicant( 485): wpa_driver_nl80211_set_key: ifindex=13 alg=0 addr=0x0 key_idx=1 set_tx=0 seq_len=0 key_len=0 D/wpa_supplicant( 485): wpa_driver_nl80211_set_key: ifindex=13 alg=0 addr=0x0 key_idx=2 set_tx=0 seq_len=0 key_len=0 D/wpa_supplicant( 485): wpa_driver_nl80211_set_key: ifindex=13 alg=0 addr=0x0 key_idx=3 set_tx=0 seq_len=0 key_len=0 D/wpa_supplicant( 485): wlan0: RSN: flushing PMKID list in the driver D/wpa_supplicant( 485): nl80211: Flush PMKIDs D/wpa_supplicant( 485): wlan0: State: DISCONNECTED -> INACTIVE D/wpa_supplicant( 485): WPS: Set UUID for interface wlan0 D/wpa_supplicant( 485): WPS: UUID based on MAC address - hexdump(len=16): a3 d7 98 fb 7d 6a 5b 19 8b 19 b6 28 bc 6d 73 80 D/wpa_supplicant( 485): EAPOL: SUPP_PAE entering state DISCONNECTED D/wpa_supplicant( 485): EAPOL: Supplicant port status: Unauthorized D/wpa_supplicant( 485): EAPOL: KEY_RX entering state NO_KEY_RECEIVE D/wpa_supplicant( 485): EAPOL: SUPP_BE entering state INITIALIZE D/wpa_supplicant( 485): EAP: EAP entering state DISABLED D/wpa_supplicant( 485): EAPOL: Supplicant port status: Unauthorized D/wpa_supplicant( 485): EAPOL: Supplicant port status: Unauthorized D/wpa_supplicant( 485): Using existing control interface directory. D/wpa_supplicant( 485): ctrl_interface_group=1010 (from group name 'wifi') D/wpa_supplicant( 485): ctrl_iface bind(PF_UNIX) failed: Address already in use D/wpa_supplicant( 485): ctrl_iface exists, but does not allow connections - assuming it was leftover from forced program termination D/wpa_supplicant( 485): Successfully replaced leftover ctrl_iface socket '/data/system/wpa_supplicant/wlan0' D/wpa_supplicant( 485): P2P: Own listen channel: 1 D/wpa_supplicant( 485): P2P: Random operating channel: 81:6 D/wpa_supplicant( 485): P2P: Add operating class 81 D/wpa_supplicant( 485): P2P: Channels - hexdump(len=13): 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d D/wpa_supplicant( 485): P2P: Add operating class 124 D/wpa_supplicant( 485): P2P: Channels - hexdump(len=4): 95 99 9d a1 D/wpa_supplicant( 485): P2P: Add operating class 125 D/wpa_supplicant( 485): P2P: Channels - hexdump(len=5): 95 99 9d a1 a5 D/wpa_supplicant( 485): P2P: Add operating class 126 D/wpa_supplicant( 485): P2P: Channels - hexdump(len=2): 95 9d D/wpa_supplicant( 485): P2P: Add operating class 127 D/wpa_supplicant( 485): P2P: Channels - hexdump(len=2): 99 a1 D/wpa_supplicant( 485): wlan0: Added interface wlan0 D/wpa_supplicant( 485): RTM_NEWLINK: operstate=0 ifi_flags=0x1043 ([UP][RUNNING]) D/wpa_supplicant( 485): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added D/wpa_supplicant( 485): nl80211: if_removed already cleared - ignore event D/wpa_supplicant( 485): RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) D/wpa_supplicant( 485): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added D/wpa_supplicant( 485): nl80211: if_removed already cleared - ignore event D/wpa_supplicant( 485): CTRL_IFACE monitor attached - hexdump(len=39): 2f 64 61 74 61 2f 6d 69 73 63 2f 77 69 66 69 2f 73 6f 63 6b 65 74 73 2f 77 70 61 5f 63 74 72 6c ... D/wpa_supplicant( 485): RX ctrl_iface - hexdump(len=9): 4c 4f 47 5f 4c 45 56 45 4c D/wpa_supplicant( 485): RX ctrl_iface - hexdump(len=6): 53 54 41 54 55 53 D/wpa_supplicant( 485): RX ctrl_iface - hexdump(len=13): 4c 49 53 54 5f 4e 45 54 57 4f 52 4b 53 D/wpa_supplicant( 485): RX ctrl_iface - hexdump(len=14): 44 52 49 56 45 52 20 4d 41 43 41 44 44 52 D/wpa_supplicant( 485): RX ctrl_iface - hexdump(len=9): 41 50 5f 53 43 41 4e 20 31 D/wpa_supplicant( 485): RX ctrl_iface - hexdump(len=11): 53 41 56 45 5f 43 4f 4e 46 49 47 D/wpa_supplicant( 485): Writing configuration file '/data/misc/wifi/wpa_supplicant.conf' D/wpa_supplicant( 485): Configuration file '/data/misc/wifi/wpa_supplicant.conf' written successfully D/wpa_supplicant( 485): CTRL_IFACE: SAVE_CONFIG - Configuration updated D/wpa_supplicant( 485): EAPOL: disable timer tick D/wpa_supplicant( 485): EAPOL: Supplicant port status: Unauthorized E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/Profiler( 138): BPUnw: [1 total] thread_unregister_for_profiling(me=0x1e9a120) (NOT REGISTERED) I/Gecko ( 138): HWComposer: FPS is 0 E/Profiler( 138): BPUnw: [1 total] thread_unregister_for_profiling(me=0x1ea05f8) (NOT REGISTERED) E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/Profiler( 138): BPUnw: [1 total] thread_unregister_for_profiling(me=0x1e9a9b0) (NOT REGISTERED) E/Profiler( 138): BPUnw: [1 total] thread_unregister_for_profiling(me=0x1e9a970) (NOT REGISTERED) E/Profiler( 138): BPUnw: [1 total] thread_unregister_for_profiling(me=0x1e9a8f0) (NOT REGISTERED) E/Profiler( 138): BPUnw: [1 total] thread_unregister_for_profiling(me=0x1e9a9f0) (NOT REGISTERED) D/QCRIL_RPC( 141): Enter qcril_cm_srvsys_event_callback D/QCRIL_RPC( 141): Exit qcril_cm_srvsys_event_callback I/Diag_Lib( 141): rpc_handle_rpc_call: for Xid: 88, Prog: 31000000, Vers: d17ed9ea, Proc: 00000014 I/Diag_Lib( 141): rpc_handle_rpc_call: Find Status: 0 Xid: 88 I/ONCRPC ( 141): oncrpc_proxy_handle_cmd_rpc_call: Dispatching xid: 88 I/ONCRPC ( 141): oncrpc_xdr_reply_msg_start: Prog: 00000000, Ver: 00000000, Proc: 00000000 Xid: 00000088 I/ONCRPC ( 141): oncrpc_msg_reply: Prog: 00000000, Ver: 00000000, Proc: 00000000 Xid: 00000088 I/ONCRPC ( 141): oncrpc_proxy_handle_cmd_rpc_call: Dispatch returned for xid: 88 E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] D/QCRIL_RPC( 141): Enter qcril_cm_srvsys_event_callback D/QCRIL_RPC( 141): Exit qcril_cm_srvsys_event_callback I/Diag_Lib( 141): rpc_handle_rpc_call: for Xid: 8c, Prog: 31000000, Vers: d17ed9ea, Proc: 00000014 I/Diag_Lib( 141): rpc_handle_rpc_call: Find Status: 0 Xid: 8c I/ONCRPC ( 141): oncrpc_proxy_handle_cmd_rpc_call: Dispatching xid: 8c I/ONCRPC ( 141): oncrpc_xdr_reply_msg_start: Prog: 00000000, Ver: 00000000, Proc: 00000000 Xid: 0000008c I/ONCRPC ( 141): oncrpc_msg_reply: Prog: 00000000, Ver: 00000000, Proc: 00000000 Xid: 0000008c I/ONCRPC ( 141): oncrpc_proxy_handle_cmd_rpc_call: Dispatch returned for xid: 8c E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWiFi-PE] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XT-CS] unknown deliver target [OS-Agent] E/QCALOG ( 192): [MessageQ] ProcessNewMessage: [XTWWAN-PE] unknown deliver target [OS-Agent] The tests don't use the UI to scan network names; they use https://github.com/mozilla-b2g/gaia/blob/master/tests/python/gaia-ui-tests/gaiatest/atoms/gaia_data_layer.js#L250, and the manager.onenabled callback is never getting fired. Note, this problem is not seen with other devices with the same test, so I suspect it's a device problem and not general wifi flakiness.
Flags: needinfo?(vchang)
It might be good to see what the wifi worker is doing as well. Could you turn on the wifi output to ADB in the developer settings? Settings -> Device info -> more info -> developer -" Wifi output in adb" … And then capture the ADB logcat once again please? I noticed on jbonacci's inari, for some reason the ip config was failing to get an ip address. I'm not sure why... It would succeed on the first attempt after flashing to get connceted, then would fail on any consecutive try to the network unless you changed networks. Deleting the wpa_supplicant info located : /data/misc/wifi/wpa_supplicant.conf seemed to reset it so that it tries to find it. I'm not sure if this is the same issue. I would like to ask that you try to do adb shell rm /data/misc/wifi/wpa_supplicant.conf and trying on the first attempt to see if it becomes more reliable. It might be something in the code that's not liking the consecutive attempt to connect?
(In reply to Jonathan Griffin (:jgriffin) from comment #11) > Note, this problem is not seen with other devices with the same test, so I > suspect it's a device problem and not general wifi flakiness. Thx, Jonathan. Just to be clear: this seems especially problematic with Hamachis, as we don't see this (much) with Unagis on master -- same tests: http://qa-selenium.mv.mozilla.com:8080/view/B2G%20Unagi/job/b2g.unagi.mozilla-central.unittests.wifi/
Does it work correctly if you use settings app to connect to Wifi AP ? The logcat doesn't seem to indicate error.
Flags: needinfo?(vchang)
That's interesting. So the unagis get a flash of the images where as the buri will get files removed and pushed via adb. I noticed that the bluetooth, wifi, and a few other things are stored in the /data/misc directory in terms of the network connected to and such. The first time we connect seems to be ok for some devices, it's the consecutive reconnects that we may end up having issues sometimes. It's hard to get a consistent repro except on the inari : For this situation, we could try removing the /data/misc/wifi and seeing if that resolves this specific issue. We have a couple of other bugs in regards to the wifi; the only bug that has consistently seen issues is Bug 890974 . adb shell rm -r /data/misc/wifi/* Are we showing any issues with bluetooth? Because we may just want to end up doing : adb shell rm -r /data/misc/* instead if that's the case. I haven't consistently seen the issue so I can't really test appropriately.
added to the Jenkins script to see if that helps the issue.
(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #16) > added to the Jenkins script to see if that helps the issue. So, finally, a great update here -- huge thanks, again, to Naoki for implementing, today, a call from comment 15. Naoki, can you comment further on the specific change (with a link to the file?) This -- but only when coupled with a removal of the "--restart" option -- positively fixed (100%) this particular job. We should: a) consider if there's a latent bug here b) once a) is determined implement the appropriate, suggested call from comment 15 -- we'll likely need to figure out if the rm -r /data/misc/* -- or -- /data/misc/wifi/* call is more appropriately called from within the --restart flag's routine, or elsewhere
(In reply to Stephen Donner [:stephend] from comment #17) > (In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from > comment #16) > > added to the Jenkins script to see if that helps the issue. > > So, finally, a great update here -- huge thanks, again, to Naoki for > implementing, today, a call from comment 15. Naoki, can you comment further > on the specific change (with a link to the file?) > > This -- but only when coupled with a removal of the "--restart" option -- > positively fixed (100%) this particular job. We should: > > a) consider if there's a latent bug here > b) once a) is determined implement the appropriate, suggested call from > comment 15 -- we'll likely need to figure out if the rm -r /data/misc/* -- > or -- /data/misc/wifi/* call is more appropriately called from within the > --restart flag's routine, or elsewhere Hi Stephen, thanks for your help to point out this. chulee is working on this with Askeing.
I did a rm -r /data/misc/wifi/* The other items still in there is bluetooth and a few others like tethering and such if I recall correctly. I think we currently don't have any automation on bluetooth... so there may be a chance in the future we would have to remove more for stability... I just decided to go one step at a time.
Just to note, this may have to tie in with bug 890974. I had been playing around with jbonacci's inari device. In trying to figure out his wifi issue, I figured the portion out for this.
(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #19) > I did a rm -r /data/misc/wifi/* > > The other items still in there is bluetooth and a few others like tethering > and such if I recall correctly. I think we currently don't have any > automation on bluetooth... so there may be a chance in the future we would > have to remove more for stability... I just decided to go one step at a > time. Yes, we do actually have at least one Bluetooth test: 06:14:25 TEST-START test_bluetooth_discoverable.py 06:14:25 test_discoverable (test_bluetooth_discoverable.TestBluetoothDiscoverable) ... ok
Are you suggesting that we remove /data/misc/* between tests? Do we need to remove these files while b2g is stopped to have the desired effect?
My trace result is that, the |WifiManager.ondisabled| is triggered before wifi driver is unloaded completed, as mentioned in bug 924277. When running unit test repeatedly with reset option, the b2g process will be killed right after |WifiManager.ondisabled| is triggered, while wifi driver is unloading. And this might cause the wifi driver can't be loaded again until reboot. I have a WIP patch that can make unit test pass, but I have to discuss with :vchang to make sure if its a proper way. Although the root cause is the timing of wifi disable event, the trigger of this bug is resetting test environment by killing b2g process instead of reboot the phone, which I think unlikely to happen in normal use. If QA need a temporarily fix, I think adding a 5 second delay after disabling wifi could do the job.
Assignee: nobody → chulee
Comment on attachment 824436 [details] [diff] [review] WIP - Change trigger point of wifi down. Review of attachment 824436 [details] [diff] [review]: ----------------------------------------------------------------- I have talked to chulee last week. He has a better solution than this. So cancel the feedback request and wait for the new patch coming.
Attachment #824436 - Flags: feedback?(vchang)
Add a transition state |DISABLING| for wifi is running the disable progress, and send out wifi down event after driver is unloaded. If wpa_supplicant is terminated unexpectly, then it will send out wifi down event directly.
Attachment #824436 - Attachment is obsolete: true
Attachment #827327 - Flags: review?(vchang)
I have tested this patch with gaia-ui-test on buri, it works fine.
Comment on attachment 827327 [details] [diff] [review] Change trigger point of wifi down Review of attachment 827327 [details] [diff] [review]: ----------------------------------------------------------------- ::: dom/wifi/WifiWorker.js @@ -680,5 @@ > // supplicant and we can stop waiting for more events and > // simply exit here (we don't have to notify about having lost > // the connection). > if (eventData.indexOf("connection closed") !== -1) { > - notify("supplicantlost", { success: true }); Do we still need to notify supplicantlost event here if it's not triggered by active disable ? @@ +699,5 @@ > > notifyStateChange({ state: "DISCONNECTED", BSSID: null, id: -1 }); > + if (manager.state !== "DISABLING" && manager.state !== "UNINITIALIZED") { > + notify("supplicantlost", { success: true }); > + } Please add the comments here to describe the reason.
Attachment #827327 - Flags: review?(vchang)
Address comment 29.
Attachment #827327 - Attachment is obsolete: true
Attachment #828406 - Flags: review?(vchang)
Comment on attachment 828406 [details] [diff] [review] Change trigger point of wifi down. V2 Review of attachment 828406 [details] [diff] [review]: ----------------------------------------------------------------- Looks good.
Attachment #828406 - Flags: review?(vchang) → review+
https://hg.mozilla.org/mozilla-central/rev/33ea93bc985f
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Thanks so much, all! This is now verified fixed on mozilla-central, with today's Hamachi-engineering build, running http://qa-selenium.mv.mozilla.com:8080/view/B2G%20Hamachi/job/b2g.hamachi.mozilla-central.unittests.wifi/ with --restart (and without). Beautiful :-)
Status: RESOLVED → VERIFIED
Depends on: 937752
No longer depends on: 937752
Depends on: 938044
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: