Re: [PATCH 1/2] mwifiex: Use non-posted PCI register writes

[Jonas Dreßler]

On 9/1/21 11:07 PM, Brian Norris wrote:
> Apologies for the brain-dead mailer. I forget that I should only reply
> via web when I _want_ text wrapping:
>
> On Wed, Sep 01, 2021 at 02:04:04PM -0700, Brian Norris wrote:
> > (b) latency spikes to ~6ms:
> > # trace-cmd record -p function_graph -O funcgraph-abstime -l
> > mwifiex_pm_wakeup_card
> > # trace-cmd report
> >     kworker/u13:0-199   [003]   348.987306: funcgraph_entry:      #
> > 6219.500 us |  mwifiex_pm_wakeup_card();
> >     kworker/u13:0-199   [003]   349.316312: funcgraph_entry:      #
> > 6267.625 us |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-4057  [001]   352.238530: funcgraph_entry:      #
> > 6184.250 us |  mwifiex_pm_wakeup_card();
> >     kworker/u13:0-199   [002]   356.626366: funcgraph_entry:      #
> > 6553.166 us |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-4057  [002]   356.709389: funcgraph_entry:      #
> > 6212.500 us |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-4057  [002]   356.847215: funcgraph_entry:      #
> > 6230.292 us |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-4057  [000]   356.897576: funcgraph_entry:      #
> > 6451.667 us |  mwifiex_pm_wakeup_card();
> >     kworker/u13:0-199   [004]   357.175025: funcgraph_entry:      #
> > 6204.042 us |  mwifiex_pm_wakeup_card();
> >
> > whereas it used to look more like:
> >
> >     kworker/u13:1-173   [005]   212.230542: funcgraph_entry:
> > 7.000 us   |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-1768  [005]   213.886063: funcgraph_entry:
> > 9.334 us   |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-1768  [002]   214.473273: funcgraph_entry:      +
> > 11.375 us  |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-1768  [005]   214.530705: funcgraph_entry:
> > 5.542 us   |  mwifiex_pm_wakeup_card();
> >     kworker/u13:1-173   [002]   215.050168: funcgraph_entry:      +
> > 13.125 us  |  mwifiex_pm_wakeup_card();
> >     kworker/u13:1-173   [002]   215.106492: funcgraph_entry:      +
> > 11.959 us  |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-1768  [005]   215.484807: funcgraph_entry:
> > 8.459 us   |  mwifiex_pm_wakeup_card();
> >     kworker/u13:1-173   [003]   215.515238: funcgraph_entry:      +
> > 15.166 us  |  mwifiex_pm_wakeup_card();
> >     kworker/u13:3-1768  [001]   217.175691: funcgraph_entry:      +
> > 11.083 us  |  mwifiex_pm_wakeup_card();
>
> That should read:
>
> # trace-cmd record -p function_graph -O funcgraph-abstime -l mwifiex_pm_wakeup_card
> # trace-cmd report
>     kworker/u13:0-199   [003]   348.987306: funcgraph_entry:      # 6219.500 us |  mwifiex_pm_wakeup_card();
>     kworker/u13:0-199   [003]   349.316312: funcgraph_entry:      # 6267.625 us |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-4057  [001]   352.238530: funcgraph_entry:      # 6184.250 us |  mwifiex_pm_wakeup_card();
>     kworker/u13:0-199   [002]   356.626366: funcgraph_entry:      # 6553.166 us |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-4057  [002]   356.709389: funcgraph_entry:      # 6212.500 us |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-4057  [002]   356.847215: funcgraph_entry:      # 6230.292 us |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-4057  [000]   356.897576: funcgraph_entry:      # 6451.667 us |  mwifiex_pm_wakeup_card();
>     kworker/u13:0-199   [004]   357.175025: funcgraph_entry:      # 6204.042 us |  mwifiex_pm_wakeup_card();
>
> vs.
>
>     kworker/u13:1-173   [005]   212.230542: funcgraph_entry:        7.000 us   |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-1768  [005]   213.886063: funcgraph_entry:        9.334 us   |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-1768  [002]   214.473273: funcgraph_entry:      + 11.375 us  |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-1768  [005]   214.530705: funcgraph_entry:        5.542 us   |  mwifiex_pm_wakeup_card();
>     kworker/u13:1-173   [002]   215.050168: funcgraph_entry:      + 13.125 us  |  mwifiex_pm_wakeup_card();
>     kworker/u13:1-173   [002]   215.106492: funcgraph_entry:      + 11.959 us  |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-1768  [005]   215.484807: funcgraph_entry:        8.459 us   |  mwifiex_pm_wakeup_card();
>     kworker/u13:1-173   [003]   215.515238: funcgraph_entry:      + 15.166 us  |  mwifiex_pm_wakeup_card();
>     kworker/u13:3-1768  [001]   217.175691: funcgraph_entry:      + 11.083 us  |  mwifiex_pm_wakeup_card();
>
> Brian

Thanks for the pointer to that commit Brian, it turns out this is 
actually the change that causes the "Firmware wakeup failed" issues that 
I'm trying to fix with the second patch here.

Also my approach is a lot messier than just reverting 
062e008a6e83e7c4da7df0a9c6aefdbc849e2bb3 and also appears to be blocking 
even longer...

Does anyone have an idea what could be the reason for the posted write 
not going through, or could that also be a potential firmware bug in the 
chip?

Jonas