Should Connman Receive All Supplicant State Changes?

Wed Jul 27 08:54:59 PDT 2011

On Jul 26, 2011, at 6:12 PM, Grant Erickson wrote:
> Is it expected that connman should receive and process all supplicant state changes? If so, I am seeing cases where the supplicant fails to signal or connman misses GROUP_HANDSHAKE always and occasionally ASSOCIATED, 4WAY_HANDSHAKE, and DISCONNECTED as below:
> 
> 	2011-07-26 21:34:22.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> ASSOCIATING
> 	2011-07-26 21:34:22.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associating (5)
> 	2011-07-26 21:34:22.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associating (5)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:22.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATING -> DISCONNECTED
> 	2011-07-26 21:34:22.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state disconnected (1)
> 	2011-07-26 21:34:22.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state disconnected (1)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:22.000000 daemon.debug wpa_supplicant[1530]: State: DISCONNECTED -> DISCONNECTED
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:34:23.000000 daemon.debug wpa_supplicant[1530]: State: DISCONNECTED -> ASSOCIATED
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:23.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATED -> 4WAY_HANDSHAKE
> 	2011-07-26 21:34:23.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state 4way_handshake (7)
> 	2011-07-26 21:34:23.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state 4way_handshake (7)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:23.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:34:23.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:23.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:34:23.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:34:23.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:24.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> 4WAY_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:24.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:24.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:34:24.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:34:24.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:25.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> 4WAY_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:25.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:25.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:34:25.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:34:25.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:26.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> 4WAY_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:26.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:26.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:34:26.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:34:26.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:27.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> ASSOCIATED
> 	2011-07-26 21:34:27.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associated (6)
> 	2011-07-26 21:34:27.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associated (6)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:27.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATED -> 4WAY_HANDSHAKE
> 	2011-07-26 21:34:27.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state 4way_handshake (7)
> 	2011-07-26 21:34:27.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state 4way_handshake (7)
> 	
> 	### OK
> 	
> 	2011-07-26 21:34:28.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:34:28.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:34:28.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:34:28.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:34:28.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:34:28.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:35:21.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:35:21.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:35:21.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:35:21.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:35:21.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:35:21.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:35:21.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:35:21.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	2011-07-26 21:35:46.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:35:46.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:35:46.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:35:46.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:35:46.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:35:46.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:35:46.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:35:46.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:36:10.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:36:10.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:36:10.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:36:10.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:05.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:39:05.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:39:05.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:39:05.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:09.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:39:09.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:39:09.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:39:09.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:34.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> ASSOCIATING
> 	2011-07-26 21:39:34.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associating (5)
> 	2011-07-26 21:39:34.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associating (5)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:34.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATING -> DISCONNECTED
> 	2011-07-26 21:39:34.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state disconnected (1)
> 	2011-07-26 21:39:34.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state disconnected (1)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:34.000000 daemon.debug wpa_supplicant[1530]: State: DISCONNECTED -> ASSOCIATED
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:39:34.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATED -> 4WAY_HANDSHAKE
> 	2011-07-26 21:39:34.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state 4way_handshake (7)
> 	2011-07-26 21:39:34.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state 4way_handshake (7)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:35.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> DISCONNECTED
> 	2011-07-26 21:39:35.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state disconnected (1)
> 	2011-07-26 21:39:35.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state disconnected (1)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:35.000000 daemon.debug wpa_supplicant[1530]: State: DISCONNECTED -> DISCONNECTED
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:39:35.000000 daemon.debug wpa_supplicant[1530]: State: DISCONNECTED -> SCANNING
> 	2011-07-26 21:39:35.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state scanning (3)
> 	2011-07-26 21:39:35.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state scanning (3)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:40.000000 daemon.debug wpa_supplicant[1530]: State: SCANNING -> ASSOCIATING
> 	2011-07-26 21:39:40.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associating (5)
> 	2011-07-26 21:39:40.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associating (5)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:40.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATING -> ASSOCIATED
> 	2011-07-26 21:39:40.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associated (6)
> 	2011-07-26 21:39:40.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associated (6)
> 	
> 	### OK
> 	
> 	2011-07-26 21:39:40.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATED -> 4WAY_HANDSHAKE
> 	2011-07-26 21:39:40.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state 4way_handshake (7)
> 	2011-07-26 21:39:40.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state 4way_handshake (7)
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:39:41.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:39:41.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:39:41.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:39:41.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:39:41.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:39:41.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:40:47.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:40:47.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:40:47.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:40:47.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:40:52.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:40:52.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:40:52.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:40:52.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:40:55.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> ASSOCIATED
> 	2011-07-26 21:40:55.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associated (6)
> 	2011-07-26 21:40:55.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associated (6)
> 	
> 	### OK
> 	
> 	2011-07-26 21:40:55.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATED -> 4WAY_HANDSHAKE
> 	2011-07-26 21:40:55.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state 4way_handshake (7)
> 	2011-07-26 21:40:55.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state 4way_handshake (7)
> 	
> 	### OK
> 	
> 	2011-07-26 21:40:55.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:40:55.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:40:55.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:40:55.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:40:55.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:41:46.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:41:46.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:41:46.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:41:46.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:41:50.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:41:50.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:41:50.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:41:50.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:44:18.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:44:18.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:44:18.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:44:18.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:44:18.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:44:18.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:44:18.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:44:18.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	2011-07-26 21:46:01.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> ASSOCIATING
> 	2011-07-26 21:46:01.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associating (5)
> 	2011-07-26 21:46:01.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associating (5)
> 	
> 	### OK
> 	
> 	2011-07-26 21:46:01.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATING -> DISCONNECTED
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:46:01.000000 daemon.debug wpa_supplicant[1530]: State: DISCONNECTED -> ASSOCIATED
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:46:02.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATED -> 4WAY_HANDSHAKE
> 	2011-07-26 21:46:02.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state 4way_handshake (7)
> 	2011-07-26 21:46:02.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state 4way_handshake (7)
> 	
> 	### OK
> 	
> 	2011-07-26 21:46:02.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:46:02.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:46:02.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:46:02.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:46:02.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK
> 	
> 	2011-07-26 21:46:44.000000 daemon.debug wpa_supplicant[1530]: State: COMPLETED -> ASSOCIATED
> 	2011-07-26 21:46:44.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state associated (6)
> 	2011-07-26 21:46:44.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state associated (6)
> 	
> 	### OK
> 	
> 	2011-07-26 21:46:44.000000 daemon.debug wpa_supplicant[1530]: State: ASSOCIATED -> 4WAY_HANDSHAKE
> 	2011-07-26 21:46:44.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state 4way_handshake (7)
> 	2011-07-26 21:46:44.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state 4way_handshake (7)
> 	
> 	### OK
> 	
> 	2011-07-26 21:46:44.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
> 	
> 	### OK: Already there.
> 	
> 	2011-07-26 21:46:44.000000 daemon.debug wpa_supplicant[1530]: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
> 	
> 	### FAILED
> 	
> 	2011-07-26 21:46:44.000000 daemon.debug wpa_supplicant[1530]: State: GROUP_HANDSHAKE -> COMPLETED
> 	2011-07-26 21:46:45.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() received state completed (9)
> 	2011-07-26 21:46:45.000000 daemon.debug connmand[1532]: connman/gsupplicant/supplicant.c:interface_property() state completed (9)
> 	
> 	### OK

+hostap list.

Samuel and Daniel:

I should have mentioned that this was with connman-0.76 and wpa_supplicant-0.7.3, using the supplicant "new" DBus interface.

Thanks for the confirmation on IRC that the supplicant should absolutely transmit and that connman should absolutely receive and process all supplicant state change notifications (SCNs).

I'll try to run dbus-monitor and instrument the supplicant today to see if the missed SCNs are in fact going out on the bus or are simply not being emitted by the supplicant.

I'll also check against the supplicant GIT to see if there are already any resolved issues in this area.

Best,

Grant