Re: [PATCH 10/21] offchannel: add support to issue multiple offchannel requests

[Denis Kenzior <denkenz@gmail.com>]

Hi James,

> 
> So I'm not sure what exactly is going on here. I have yet to see this on actual 
> hardware, but it happens in hwsim frequently. You are right that the offchannel 
> module gates all the work items, and correctly waits for one to finish. So I was 
> wrong that it needed "fixing" in that regard. Here are some logs with the ack 
> coming out of order, maybe this is some UML scheduling thing, not sure:
> 
> src/dpp.c:dpp_start_pkex_enrollee() PKEX start enrollee (id=test)
> src/wiphy.c:wiphy_radio_work_insert() Inserting work item 1
> src/wiphy.c:wiphy_radio_work_next() Starting work item 1
> src/offchannel.c:offchannel_work_ready() Issuing ROC
> src/offchannel.c:offchannel_roc_cb() cookie=1
> src/netdev.c:netdev_mlme_notify() MLME notification Remain on Channel(55)
> src/offchannel.c:offchannel_mlme_notify() ROC notify, cookie=1
> src/dpp.c:dpp_send_frame() Sending frame on frequency 2437
> src/netdev.c:netdev_unicast_notify() Unicast notification Frame(59)
> src/dpp.c:dpp_handle_pkex_exchange_request() PKEX exchange request 
> 02:00:00:00:02:00
> src/dpp.c:dpp_send_frame() Sending frame on frequency 2437
> src/netdev.c:netdev_mlme_notify() MLME notification Frame TX Status(60)
> src/netdev.c:netdev_unicast_notify() Unicast notification Frame(59)
> src/dpp.c:dpp_handle_pkex_commit_reveal_request() PKEX commit-reveal request 
> 02:00:00:00:02:00
> src/dpp.c:dpp_send_frame() Sending frame on frequency 2437
> src/netdev.c:netdev_mlme_notify() MLME notification Frame TX Status(60)
> src/netdev.c:netdev_unicast_notify() Unicast notification Frame(59)
> src/dpp.c:dpp_handle_pkex_exchange_response() PKEX response 02:00:00:00:03:00
> 
> # Got a response, so the prior offchannel work (1) was canceled, and a new item 
> inserted (2)
> 
> src/wiphy.c:wiphy_radio_work_insert() Inserting work item 2
> src/netdev.c:netdev_mlme_notify() MLME notification Cancel Remain on Channel(56)

So is this iwd sending a NL80211_CMD_CANCEL_REMAIN_ON_CHANNEL?  Should we also 
wait for the ack of this one too?

> src/offchannel.c:offchannel_mlme_notify() ROC cancel, cookie=1
> 
> # Cancel ROC is correctly waited for before starting the next item
> src/wiphy.c:wiphy_radio_work_done() Work item 1 done
> src/wiphy.c:wiphy_radio_work_next() Starting work item 2
> src/offchannel.c:offchannel_work_ready() Issuing ROC
> src/netdev.c:netdev_mlme_notify() MLME notification Remain on Channel(55)

This seems fishy?  What else is going offchannel?

> 
> # Then immediately we get a Remain on Channel event
> src/offchannel.c:offchannel_mlme_notify() ROC notify, cookie=3
> src/offchannel.c:offchannel_mlme_notify() ROC started prior to ACK, setting 
> cookie 3
> src/dpp.c:dpp_send_frame() Sending frame on frequency 2437
> 
> # And finally the ack comes in
> src/offchannel.c:offchannel_roc_cb() cookie=3

Yeah, why is the cookie 3?  Shouldn't it be 2?

> 
> I need to look at the kernel a bit more to see how this can happen, but apart 
> from me removing some of the commit description I do think the patch is required 
> to handle this case.
> 

Regards,
-Denis