Sometimes lack of dbus event about wps failure

[Radoslaw Martyniszyn]

Hello,

One of our testers has observed an issue with lack of dbus WPS fail or
WPS timeout messages. Most of the time WPS works fine but tester
sometimes sees an issue with WPS connecting, We only have default
loglevel from wpa supplicant at the moment. If I manage to reproduce
that issue I can provide 'debug' logs.

What tester did:
* On STA he started WPS request, Role: "enrolee", Type: "pbc"
* On AP he pressed WPS button
* He was waiting for more than two minutes but Event wps timeout nor
wps fail were not received

In the log I can see the "wlan2: WPS-FAIL" and after that network dbus
object is removed and iface changes state to inactive.

Question:
1) Should we always expect signal
fi.w1.wpa_supplicant1.Interface.WPS.Event finishing WPS configuration?
Apparently in our case this Event did not arrive and iface changed
state to idle.
2) Should wps_supplicant.c::wpas_wps_eapol_cb notify dbus about wps
fail? It only prints a log wpa_msg(wpa_s, MSG_INFO, WPS_EVENT_FAIL);


Log is below:

// First method fi.w1.wpa_supplicant1.Interface.WPS.Start was called
Jan 12 10:29:53 connectWPS in PBC mode, enrollee

Jan 12 10:30:02 wlan2: Trying to associate with 90:5c:44:56:0f:78
(SSID='Shayo2' freq=2437 MHz)

// Our application received the following event
Jan 12 10:30:02 onWifiIfaceStateChanged WpaSupplicant WPA status:associating

Jan 12 10:30:02 wlan2: Associated with 90:5c:44:56:0f:78
Jan 12 10:30:02 wlan2: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0

// Our application received the following events
Jan 12 10:30:03 onIfacePropertiesChanged CurrentNetwork:
/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0
Jan 12 10:30:03 onCurrentNetworkChanged
path:/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0
Jan 12 10:30:03 onWifiIfaceStateChanged WpaSupplicant WPA status:associated
Jan 12 10:30:03 onIfacePropertiesChanged lCurrentBSS:
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/154

Jan 12 10:30:03 wlan2: CTRL-EVENT-EAP-STARTED EAP authentication started

Jan 12 10:31:03 wlan2: CTRL-EVENT-EAP-FAILURE EAP authentication failed

// This log is from wps_supplicant.c::wpas_wps_eapol_cb function
Jan 12 10:31:03 wlan2: WPS-FAIL

Jan 12 10:31:03 wlan2: CTRL-EVENT-DISCONNECTED bssid=90:5c:44:56:0f:78
reason=3 locally_generated=1
Jan 12 10:31:03 nl80211: Was expecting local disconnect but got
another disconnect event first


Jan 12 10:31:03 onIfacePropertiesChanged DisconnectReason:-3, status:associated
Jan 12 10:31:03 onNetworkRemovedSignal
path:/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0
Jan 12 10:31:03 onWifiIfaceStateChanged WpaSupplicant WPA status:disconnected
Jan 12 10:31:03 onIfacePropertiesChanged lCurrentBSS: /
Jan 12 10:31:03 onIfacePropertiesChanged DisconnectReason:3, status:disconnected
Jan 12 10:31:03 onWifiIfaceStateChanged WpaSupplicant WPA status:inactive

Thanks
Radek