On Wed, 9 Jun 2010, Gwendal Raoul wrote: > Hello Alan, > > I did the test on a 2.6.34 kernel that includes your patch for the race > condition. In the test, a remote wakeup is generated on the device every > 6s. > But unfortunately our test still fails. The race seems to be detected > because the messages added in your patch are logged (time 2566.000116 in > the log). > I'm not very confident with the linux USB code but it seems that when > the race occurs, the remote wakeup doesn't end correctly. The 0507 > status at time 2566.000154 looks weird as it still have the > USB_PORT_STAT_C_SUSPEND bit set. > Do you have any idea? No, I don't. I made a similar test on my computer under 2.6.34, and it worked perfectly. > Here is the log: ... > [ 2563.002734] usb 2-1: usb auto-suspend > [ 2565.988533] ehci_hcd 0000:00:1d.7: port 1 remote wakeup > [ 2566.000083] hub 2-0:1.0: hub_suspend > [ 2566.000099] usb usb2: bus auto-suspend > [ 2566.000107] ehci_hcd 0000:00:1d.7: suspend root hub > [ 2566.000116] ehci_hcd 0000:00:1d.7: suspend failed because port 1 is resuming > [ 2566.000126] usb usb2: bus suspend fail, err -16 > [ 2566.000133] hub 2-0:1.0: hub_resume > [ 2566.000154] hub 2-0:1.0: port 1: status 0507 change 0000 > [ 2566.000198] hub 2-0:1.0: state 7 ports 6 chg 0000 evt 0000 > [ 2569.000327] hub 2-0:1.0: hub_suspend Nothing happened for three seconds between the last two lines. There should have been a resume notification at about 2566.014 -- 25 ms after the "port 1 remote wakeup" message. Here's my log. The 1-8 device was a hub, and I caused it to send a wakeup request by plugging a USB flash drive into it when the "usb auto-suspend" message appeared on the console. [ 211.816999] usb 1-8: usb auto-suspend [ 213.455843] ehci_hcd 0000:00:1d.7: port 8 remote wakeup [ 214.816266] hub 1-0:1.0: hub_suspend [ 214.816486] usb usb1: bus auto-suspend [ 214.816624] ehci_hcd 0000:00:1d.7: suspend root hub [ 214.816766] ehci_hcd 0000:00:1d.7: suspend failed because port 8 is resuming [ 214.816907] usb usb1: bus suspend fail, err -16 [ 214.817043] hub 1-0:1.0: hub_resume [ 214.817332] hub 1-0:1.0: port 8: status 0507 change 0000 [ 214.817502] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0000 [ 216.952090] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100 [ 216.952409] ehci_hcd 0000:00:1d.7: GetStatus port 8 status 601005 POWER sig=se0 PE CONNECT [ 216.968034] usb 1-8: usb wakeup-resume [ 216.968223] usb 1-8: finish resume As you can see, it worked. The key wakeup event is reported at 216.952090. Before running this test, I applied the patch below. It increases the delay during the port resume from 25 ms to 3.5 s, making it certain that the race will occur every time. It should help your testing. To get more information about what's wrong, you might add some debugging messages to ehci_hub_status_data(). Alan Stern Index: 2.6.34/drivers/usb/host/ehci-hcd.c =================================================================== --- 2.6.34.orig/drivers/usb/host/ehci-hcd.c +++ 2.6.34/drivers/usb/host/ehci-hcd.c @@ -791,7 +791,7 @@ static irqreturn_t ehci_irq (struct usb_ * stop that signaling. Use 5 ms extra for safety, * like usb_port_resume() does. */ - ehci->reset_done[i] = jiffies + msecs_to_jiffies(25); + ehci->reset_done[i] = jiffies + msecs_to_jiffies(3500); ehci_dbg (ehci, "port %d remote wakeup\n", i + 1); mod_timer(&hcd->rh_timer, ehci->reset_done[i]); } -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
