From: Rajesh Bhagat <rajesh.bhagat@nxp.com>
To: Mathias Nyman <mathias.nyman@linux.intel.com>
CC: "gregkh@linuxfoundation.org" <gregkh@linuxfoundation.org>,
        "linux-usb@vger.kernel.org" <linux-usb@vger.kernel.org>,
        "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
        Sriram Dash <sriram.dash@nxp.com>
Subject: RE: [PATCH] usb: xhci: Fix incomplete PM resume operation due to XHCI
 commmand timeout
Thread-Topic: [PATCH] usb: xhci: Fix incomplete PM resume operation due to
 XHCI commmand timeout
Thread-Index: AQHRgOP0koj0An7NrUiFwLeaADZ9zZ9fDpyAgAQ7AdCAAFktgIABTHuggAB1NoCAAQay8A==
Date: Wed, 23 Mar 2016 03:53:36 +0000
Message-ID: <HE1PR0401MB20280AAAEC685FF3FC1DBF0EE3810@HE1PR0401MB2028.eurprd04.prod.outlook.com>
References: <1458284463-12743-1-git-send-email-rajesh.bhagat@nxp.com>
 <56EBE485.1060301@linux.intel.com>
 <HE1PR0401MB202857F4B183B84FCEDFBDA6E38F0@HE1PR0401MB2028.eurprd04.prod.outlook.com>
 <56EFBBD1.6080600@intel.com>
 <HE1PR0401MB20282AD00F64A8AC716C2E24E3800@HE1PR0401MB2028.eurprd04.prod.outlook.com>
 <56F1350B.7000006@linux.intel.com>
In-Reply-To: <56F1350B.7000006@linux.intel.com>
Accept-Language: en-US
Content-Language: en-US
spamdiagnosticoutput: 1:23
spamdiagnosticmetadata: NSPM
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 8BIT
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-originalarrivaltime: 23 Mar 2016 03:53:36.8654
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 686ea1d3-bc2b-4c6f-a92c-d99c5c301635
X-MS-Exchange-Transport-CrossTenantHeadersStamped: DB3PR04MB0555
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 5524
Lines: 140


> -----Original Message-----
> From: Mathias Nyman [mailto:mathias.nyman@linux.intel.com]
> Sent: Tuesday, March 22, 2016 5:36 PM
> To: Rajesh Bhagat <rajesh.bhagat@nxp.com>
> Cc: gregkh@linuxfoundation.org; linux-usb@vger.kernel.org; linux-
> kernel@vger.kernel.org; Sriram Dash <sriram.dash@nxp.com>
> Subject: Re: [PATCH] usb: xhci: Fix incomplete PM resume operation due to XHCI
> commmand timeout
> 
> On 22.03.2016 07:19, Rajesh Bhagat wrote:
> >
> >
> >> -----Original Message-----
> >> From: Mathias Nyman [mailto:mathias.nyman@intel.com]
> >> Sent: Monday, March 21, 2016 2:46 PM
> >> To: Rajesh Bhagat <rajesh.bhagat@nxp.com>; Mathias Nyman
> >> <mathias.nyman@linux.intel.com>; linux-usb@vger.kernel.org; linux-
> >> kernel@vger.kernel.org
> >> Cc: gregkh@linuxfoundation.org; Sriram Dash <sriram.dash@nxp.com>
> >> Subject: Re: [PATCH] usb: xhci: Fix incomplete PM resume operation
> >> due to XHCI commmand timeout
> >>
> >> On 21.03.2016 06:18, Rajesh Bhagat wrote:
> >>>
> >>>
> >>>>
> >>>> Hi
> >>>>
> >>>> I think clearing the whole command ring is a bit too much in this case.
> >>>> It may cause issues for all attached devices when one command times out.
> >>>>
> >>>
> >>> Hi Mathias,
> >>>
> >>> I understand your point, But I want to understand how would
> >>> completion handler be called if a command is timed out and
> >>> xhci_abort_cmd_ring is successful. In this case all the code would be waiting on
> completion handler forever.
> >>>
> >>>
> >>> 2. xhci_handle_command_timeout -> xhci_abort_cmd_ring(failure) ->
> >>> xhci_cleanup_command_queue -> xhci_complete_del_and_free_cmd
> >>>
> >>> In our case command is timed out, Hence we hit the case #2 but
> >>> xhci_abort_cmd_ring is success which does not calls complete.
> >>
> >> xhci_abort_cmd_ring() will write CA bit (CMD_RING_ABORT) to CRCR register.
> >> This will generate a command completion event with status "command
> >> aborted" for the pending command.
> >> This event is then followed by a "command ring stopped" command completion
> event.
> >>
> >> See xHCI specs 5.4.5 and 4.6.1.2
> >>
> >> handle_cmd_completion() will check if cmd_comp_code ==
> >> COMP_CMD_ABORT, goto event_handled, and call
> >> xhci_complete_del_and_free_cmd(cmd, cmd_comp_code) for the aborted
> command.
> >>
> >> If xHCI already processed the aborted command, we might only get a
> >> command ring stopped event, in this case handle_cmd_completion() will
> >> call xhci_handle_stopped_cmd_ring(xhci, cmd), which will turn the
> >> commands that were tagged for "abort" that still remain on the command ring to
> NO-OP commands.
> >>
> >> The completion callback will be called for these NO-OP command later
> >> when we get a command completion event for them.
> >>
> >
> > Thanks Mathias for detailed explanation. Now I understand how
> > completion handler is supposed to be called in this scenario.
> >
> > But in our case, somehow we are not getting any event and
> > handle_cmd_completion function is not getting called even after successful
> xhci_abort_cmd_ring when command timed out.
> >
> > Now, my point here is code prior to this patch xhci: rework command
> > timeout and cancellation, Code would have returned in case command timed out in
> xhci_alloc_dev itself.
> >
> > -       /* XXX: how much time for xHC slot assignment? */
> > -       timeleft = wait_for_completion_interruptible_timeout(
> > -                       command->completion,
> > -                       XHCI_CMD_DEFAULT_TIMEOUT);
> > -       if (timeleft <= 0) {
> > -               xhci_warn(xhci, "%s while waiting for a slot\n",
> > -                               timeleft == 0 ? "Timeout" : "Signal");
> > -               /* cancel the enable slot request */
> > -               ret = xhci_cancel_cmd(xhci, NULL, command->command_trb);
> > -               return ret;
> > -       }
> > +       wait_for_completion(command->completion);
> >
> > But after this patch, we are waiting for hardware event, which is
> > somehow not generated and causing a hang scenario.
> >
> > IMO, The assumption that "xhci_abort_cmd_ring would always generate an
> > event and handle_cmd_completion would be called" will not be always be true if HW
> is in bad state.
> >
> > Please share your opinion.
> >
> 
> writing the CA (command abort) bit in CRCR (command ring control register)  will stop
> the command ring, and CRR (command ring running) will be set to 0 by xHC.
> xhci_abort_cmd_ring() polls this bit up to 5 seconds.
> If it's not 0 then the driver considers the command abort as failed.
> 
> The scenario you're thinking of is that xHC would still react to CA bit set, it would stop
> the command ring and set CRR 0, but not send a command completion event.
> 
> Have you tried adding some debug to handle_cmd_completion() and see if you receive
> any event after command abortion?
> 

Yes. We have added debug prints at first line of handle_cmd_completion, and we are not getting 
those prints. The last print messages that we get are as below from xhci_alloc_dev while resume 
operation: 

xhci-hcd xhci-hcd.0.auto: Command timeout
xhci-hcd xhci-hcd.0.auto: Abort command ring

May be somehow, USB controller is in bad state and not responding to the commands. 

Please suggest how XHCI driver can handle such situations. 

> The patches I mentioned earlier are also worth trying out, they might fix the cause
> why command aborts in the first place.
> 

We tried both the patches you mentioned. But they dint come to rescue here. 

> -Mathias
> 
> 
> 
> 
>