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

[James Prestwood <prestwoj@gmail.com>]

Hi Denis,

On 10/19/23 7:51 AM, Denis Kenzior wrote:
> Hi James,
> 
> On 10/12/23 15:01, James Prestwood wrote:
>> There was nothing which prevented this, but due to the behavior of
>> some drivers multiple offchannel requests on the same channel
> 
> Isn't the point of offchannel API to serialize all such requests so this 
> does not happen?
> 
>> resulted in the second request never starting and eventually timing
>> out. This is because some drivers combine offchannel requests if
>> they are on the same channel and this ultimately results in the
>> netlink ACK coming after the ROC started event. This patch fixes
>> some logic to allow for this case.
> 
> Kernel ROC APIs have no enforcement of semantics at all.  Different 
> drivers just do whatever.  Have you tested that this works on brcmfmac 
> for example?  It might be better to explicitly wait for the ROC event to 
> be ended before starting a new one.
> 
>>
>> The motivation to support this is so modules can start offchannel
>> work items for short durations and wait for a response, if a frame
>> is received the offchannel request can be canceled/restarted for
>> a longer duration.
>>
>> This could also be done instead by using a long duration initially
>> and an extra timer to cancel, but its more convenient if offchannel
>> supports this natively. In addition, this driver quirk should be
>> supported regardless (e.g. if two IWD modules happen to issue ROC's
>> on the same channel).
> 
> Then shouldn't offchannel serialize such requests?
> 
>>
>> Furthermore, the offchannel module was only looking up requests by
>> wdev_id which could result in the wrong request being found.
>> Instead the request should be looked up by both wdev_id and cookie
>> (when possible), or the ID in the case of canceling.
> 
> This part makes sense and probably belongs in a separate patch.

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)
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)

# 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

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.

Thanks,
James