2013-04-24 20:00:14

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, Apr 24, 2013 at 10:07 AM, Stephen Rothwell <[email protected]> wrote:
> Hi all,
>
> There will be no linux-next release tomorrow (April 25).
>
> Changes since 20130423:
>
> The net-next tree lost its build failure.
>
> The staging tree gained a build failure for which I disabled a driver.
>
> The arm-soc tree gained a conflict against the pm tree.
>
> ----------------------------------------------------------------------------
>

[ CC linux-pm and linux-usb (ehci) folks ]

This happens with my external USB mouse after suspend/resume.

Excerpt (full dmesg and kernel-config attached):

$ dmesg | egrep -i 'usb|async' | grep 1-1.2
[ 1.258602] usb 1-1.2: new low-speed USB device number 3 using ehci-pci
[ 1.368649] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
[ 1.368661] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[ 1.368668] usb 1-1.2: Product: USB-PS/2 Optical Mouse
[ 1.368672] usb 1-1.2: Manufacturer: Logitech
[ 1.957999] input: Logitech USB-PS/2 Optical Mouse as
/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input4
[ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
[ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
[ 64.243543] usb 1-1.2: USB disconnect, device number 3
[ 64.380328] usb 1-1.2: new low-speed USB device number 5 using ehci-pci
[ 64.477612] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
[ 64.477618] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[ 64.477621] usb 1-1.2: Product: USB-PS/2 Optical Mouse
[ 64.477623] usb 1-1.2: Manufacturer: Logitech
[ 64.481934] input: Logitech USB-PS/2 Optical Mouse as
/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input11

Any help/hints/infos welcome :-)!

Regards,
- Sedat .-


Attachments:
dmesg_3.9.0-rc8-next20130424-2-iniza-small_after-suspend-resume.txt (58.81 kB)
config-3.9.0-rc8-next20130424-2-iniza-small (109.81 kB)
Download all attachments

2013-04-24 20:09:21

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, Apr 24, 2013 at 10:00 PM, Sedat Dilek <[email protected]> wrote:
> On Wed, Apr 24, 2013 at 10:07 AM, Stephen Rothwell <[email protected]> wrote:
>> Hi all,
>>
>> There will be no linux-next release tomorrow (April 25).
>>
>> Changes since 20130423:
>>
>> The net-next tree lost its build failure.
>>
>> The staging tree gained a build failure for which I disabled a driver.
>>
>> The arm-soc tree gained a conflict against the pm tree.
>>
>> ----------------------------------------------------------------------------
>>
>
> [ CC linux-pm and linux-usb (ehci) folks ]
>
> This happens with my external USB mouse after suspend/resume.
>
> Excerpt (full dmesg and kernel-config attached):
>
> $ dmesg | egrep -i 'usb|async' | grep 1-1.2
> [ 1.258602] usb 1-1.2: new low-speed USB device number 3 using ehci-pci
> [ 1.368649] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
> [ 1.368661] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
> SerialNumber=0
> [ 1.368668] usb 1-1.2: Product: USB-PS/2 Optical Mouse
> [ 1.368672] usb 1-1.2: Manufacturer: Logitech
> [ 1.957999] input: Logitech USB-PS/2 Optical Mouse as
> /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input4
> [ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
> [ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
> [ 64.243543] usb 1-1.2: USB disconnect, device number 3
> [ 64.380328] usb 1-1.2: new low-speed USB device number 5 using ehci-pci
> [ 64.477612] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
> [ 64.477618] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
> SerialNumber=0
> [ 64.477621] usb 1-1.2: Product: USB-PS/2 Optical Mouse
> [ 64.477623] usb 1-1.2: Manufacturer: Logitech
> [ 64.481934] input: Logitech USB-PS/2 Optical Mouse as
> /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input11
>

Thos 3 lines IIRC are important (one line missing above):

[ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
[ 62.636877] dpm_run_callback(): usb_dev_resume+0x0/0x20 returns -32
[ 62.636893] PM: Device 1-1.2 failed to resume async: error -32

- Sedat -

> Any help/hints/infos welcome :-)!
>
> Regards,
> - Sedat .-

2013-04-24 20:32:34

by Alan Stern

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, 24 Apr 2013, Sedat Dilek wrote:

> > [ CC linux-pm and linux-usb (ehci) folks ]
> >
> > This happens with my external USB mouse after suspend/resume.
> >
> > Excerpt (full dmesg and kernel-config attached):
> >
> > $ dmesg | egrep -i 'usb|async' | grep 1-1.2
> > [ 1.258602] usb 1-1.2: new low-speed USB device number 3 using ehci-pci
> > [ 1.368649] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
> > [ 1.368661] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
> > SerialNumber=0
> > [ 1.368668] usb 1-1.2: Product: USB-PS/2 Optical Mouse
> > [ 1.368672] usb 1-1.2: Manufacturer: Logitech
> > [ 1.957999] input: Logitech USB-PS/2 Optical Mouse as
> > /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input4
> > [ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
> > [ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
> > [ 64.243543] usb 1-1.2: USB disconnect, device number 3
> > [ 64.380328] usb 1-1.2: new low-speed USB device number 5 using ehci-pci
> > [ 64.477612] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
> > [ 64.477618] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
> > SerialNumber=0
> > [ 64.477621] usb 1-1.2: Product: USB-PS/2 Optical Mouse
> > [ 64.477623] usb 1-1.2: Manufacturer: Logitech
> > [ 64.481934] input: Logitech USB-PS/2 Optical Mouse as
> > /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input11
> >

Did this work differently under earlier kernels?

> Thos 3 lines IIRC are important (one line missing above):
>
> [ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
> [ 62.636877] dpm_run_callback(): usb_dev_resume+0x0/0x20 returns -32
> [ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
>
> - Sedat -
>
> > Any help/hints/infos welcome :-)!

This indicates that the optical mouse didn't survive the suspend/resume
sequence and had to be reenumerated. Without more information, there's
no way to tell specifically what went wrong during the initial reset at
timestamp 62.353997.

If you want to pursue this farther, you could enable CONFIG_USB_DEBUG.
You could also collect a usbmon trace for bus 1 showing what happens
during the suspend and resume.

On the other hand, what difference does it really make if a mouse has
to be reenumerated?

Alan Stern

2013-04-24 20:41:00

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, Apr 24, 2013 at 10:32 PM, Alan Stern <[email protected]> wrote:
> On Wed, 24 Apr 2013, Sedat Dilek wrote:
>
>> > [ CC linux-pm and linux-usb (ehci) folks ]
>> >
>> > This happens with my external USB mouse after suspend/resume.
>> >
>> > Excerpt (full dmesg and kernel-config attached):
>> >
>> > $ dmesg | egrep -i 'usb|async' | grep 1-1.2
>> > [ 1.258602] usb 1-1.2: new low-speed USB device number 3 using ehci-pci
>> > [ 1.368649] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
>> > [ 1.368661] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
>> > SerialNumber=0
>> > [ 1.368668] usb 1-1.2: Product: USB-PS/2 Optical Mouse
>> > [ 1.368672] usb 1-1.2: Manufacturer: Logitech
>> > [ 1.957999] input: Logitech USB-PS/2 Optical Mouse as
>> > /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input4
>> > [ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
>> > [ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
>> > [ 64.243543] usb 1-1.2: USB disconnect, device number 3
>> > [ 64.380328] usb 1-1.2: new low-speed USB device number 5 using ehci-pci
>> > [ 64.477612] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
>> > [ 64.477618] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
>> > SerialNumber=0
>> > [ 64.477621] usb 1-1.2: Product: USB-PS/2 Optical Mouse
>> > [ 64.477623] usb 1-1.2: Manufacturer: Logitech
>> > [ 64.481934] input: Logitech USB-PS/2 Optical Mouse as
>> > /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input11
>> >
>
> Did this work differently under earlier kernels?
>

Unfortunately, s/r did not work for several Linux-Next releases as
there is missing tglx's patch pendinging in tip.git/timers/core.

The last days I also use the touchpad, so the issue is new to me,
which says not that much :-).

[1] http://git.kernel.org/cgit/linux/kernel/git/tip/tip.git/commit/?h=timers/core&id=77c675ba18836802f6b73d2d773481d06ebc0f04

>> Thos 3 lines IIRC are important (one line missing above):
>>
>> [ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
>> [ 62.636877] dpm_run_callback(): usb_dev_resume+0x0/0x20 returns -32
>> [ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
>>
>> - Sedat -
>>
>> > Any help/hints/infos welcome :-)!
>
> This indicates that the optical mouse didn't survive the suspend/resume
> sequence and had to be reenumerated. Without more information, there's
> no way to tell specifically what went wrong during the initial reset at
> timestamp 62.353997.
>
> If you want to pursue this farther, you could enable CONFIG_USB_DEBUG.
> You could also collect a usbmon trace for bus 1 showing what happens
> during the suspend and resume.
>

Hmm, I can try to enable CONFIG_USB_DEBUG and build a new kernel.

Can you give me more hints how to do a usbmon-trace?

> On the other hand, what difference does it really make if a mouse has
> to be reenumerated?
>

As a non-USB-expert it's hard to interprete such "bogus" lines in your logs.
I am curious enough to ask which is fair :-).
AFAICS in your eyes this is "harmless"?

Thanks for the fast as lightning reply!

- Sedat -

> Alan Stern
>

2013-04-24 21:14:26

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, Apr 24, 2013 at 10:40 PM, Sedat Dilek <[email protected]> wrote:
> On Wed, Apr 24, 2013 at 10:32 PM, Alan Stern <[email protected]> wrote:
>> On Wed, 24 Apr 2013, Sedat Dilek wrote:
>>
>>> > [ CC linux-pm and linux-usb (ehci) folks ]
>>> >
>>> > This happens with my external USB mouse after suspend/resume.
>>> >
>>> > Excerpt (full dmesg and kernel-config attached):
>>> >
>>> > $ dmesg | egrep -i 'usb|async' | grep 1-1.2
>>> > [ 1.258602] usb 1-1.2: new low-speed USB device number 3 using ehci-pci
>>> > [ 1.368649] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
>>> > [ 1.368661] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
>>> > SerialNumber=0
>>> > [ 1.368668] usb 1-1.2: Product: USB-PS/2 Optical Mouse
>>> > [ 1.368672] usb 1-1.2: Manufacturer: Logitech
>>> > [ 1.957999] input: Logitech USB-PS/2 Optical Mouse as
>>> > /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input4
>>> > [ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
>>> > [ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
>>> > [ 64.243543] usb 1-1.2: USB disconnect, device number 3
>>> > [ 64.380328] usb 1-1.2: new low-speed USB device number 5 using ehci-pci
>>> > [ 64.477612] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c00e
>>> > [ 64.477618] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
>>> > SerialNumber=0
>>> > [ 64.477621] usb 1-1.2: Product: USB-PS/2 Optical Mouse
>>> > [ 64.477623] usb 1-1.2: Manufacturer: Logitech
>>> > [ 64.481934] input: Logitech USB-PS/2 Optical Mouse as
>>> > /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/input/input11
>>> >
>>
>> Did this work differently under earlier kernels?
>>
>
> Unfortunately, s/r did not work for several Linux-Next releases as
> there is missing tglx's patch pendinging in tip.git/timers/core.
>
> The last days I also use the touchpad, so the issue is new to me,
> which says not that much :-).
>
> [1] http://git.kernel.org/cgit/linux/kernel/git/tip/tip.git/commit/?h=timers/core&id=77c675ba18836802f6b73d2d773481d06ebc0f04
>
>>> Thos 3 lines IIRC are important (one line missing above):
>>>
>>> [ 62.353997] usb 1-1.2: reset low-speed USB device number 3 using ehci-pci
>>> [ 62.636877] dpm_run_callback(): usb_dev_resume+0x0/0x20 returns -32
>>> [ 62.636893] PM: Device 1-1.2 failed to resume async: error -32
>>>
>>> - Sedat -
>>>
>>> > Any help/hints/infos welcome :-)!
>>
>> This indicates that the optical mouse didn't survive the suspend/resume
>> sequence and had to be reenumerated. Without more information, there's
>> no way to tell specifically what went wrong during the initial reset at
>> timestamp 62.353997.
>>
>> If you want to pursue this farther, you could enable CONFIG_USB_DEBUG.
>> You could also collect a usbmon trace for bus 1 showing what happens
>> during the suspend and resume.
>>
>
> Hmm, I can try to enable CONFIG_USB_DEBUG and build a new kernel.
>

With CONFIG_USB_DEBUG=y I do not see a PM/async line.

Might you have a look at the logs?

Thanks!

- Sedat -

> Can you give me more hints how to do a usbmon-trace?
>
>> On the other hand, what difference does it really make if a mouse has
>> to be reenumerated?
>>
>
> As a non-USB-expert it's hard to interprete such "bogus" lines in your logs.
> I am curious enough to ask which is fair :-).
> AFAICS in your eyes this is "harmless"?
>
> Thanks for the fast as lightning reply!
>
> - Sedat -
>
>> Alan Stern
>>


Attachments:
dmesg_3.9.0-rc8-next20130424-3-iniza-small_after-suspend-resume.txt (104.97 kB)
config-3.9.0-rc8-next20130424-3-iniza-small (109.80 kB)
dmesg_3.9.0-rc8-next20130424-3-iniza-small_after-s-r.diff (10.31 kB)
Download all attachments

2013-04-24 21:17:43

by Alan Stern

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, 24 Apr 2013, Sedat Dilek wrote:

> > Did this work differently under earlier kernels?
> >
>
> Unfortunately, s/r did not work for several Linux-Next releases as
> there is missing tglx's patch pendinging in tip.git/timers/core.

Have you tried testing under 3.8? Or earlier releases?

> > This indicates that the optical mouse didn't survive the suspend/resume
> > sequence and had to be reenumerated. Without more information, there's
> > no way to tell specifically what went wrong during the initial reset at
> > timestamp 62.353997.
> >
> > If you want to pursue this farther, you could enable CONFIG_USB_DEBUG.
> > You could also collect a usbmon trace for bus 1 showing what happens
> > during the suspend and resume.
> >
>
> Hmm, I can try to enable CONFIG_USB_DEBUG and build a new kernel.
>
> Can you give me more hints how to do a usbmon-trace?

See Documentation/usb/usbmon.txt.

> > On the other hand, what difference does it really make if a mouse has
> > to be reenumerated?
> >
>
> As a non-USB-expert it's hard to interprete such "bogus" lines in your logs.
> I am curious enough to ask which is fair :-).
> AFAICS in your eyes this is "harmless"?

If the device continues to work normally after the resume and none of
your programs are affected, then it is harmless.

Alan Stern

2013-04-24 21:25:40

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, Apr 24, 2013 at 11:17 PM, Alan Stern <[email protected]> wrote:
> On Wed, 24 Apr 2013, Sedat Dilek wrote:
>
>> > Did this work differently under earlier kernels?
>> >
>>
>> Unfortunately, s/r did not work for several Linux-Next releases as
>> there is missing tglx's patch pendinging in tip.git/timers/core.
>
> Have you tried testing under 3.8? Or earlier releases?
>
>> > This indicates that the optical mouse didn't survive the suspend/resume
>> > sequence and had to be reenumerated. Without more information, there's
>> > no way to tell specifically what went wrong during the initial reset at
>> > timestamp 62.353997.
>> >
>> > If you want to pursue this farther, you could enable CONFIG_USB_DEBUG.
>> > You could also collect a usbmon trace for bus 1 showing what happens
>> > during the suspend and resume.
>> >
>>
>> Hmm, I can try to enable CONFIG_USB_DEBUG and build a new kernel.
>>
>> Can you give me more hints how to do a usbmon-trace?
>
> See Documentation/usb/usbmon.txt.
>

Grrr, that docs do not mention which kernel-configs have to be set!

CONFIG_USB_DEBUG=y is not enough.

# modprobe -v usbmon
FATAL: Module usbmon not found.

# CONFIG_USB_MON is not set <--- Grrr!!!

Doing a -4 build...

- Sedat -

>> > On the other hand, what difference does it really make if a mouse has
>> > to be reenumerated?
>> >
>>
>> As a non-USB-expert it's hard to interprete such "bogus" lines in your logs.
>> I am curious enough to ask which is fair :-).
>> AFAICS in your eyes this is "harmless"?
>
> If the device continues to work normally after the resume and none of
> your programs are affected, then it is harmless.
>
> Alan Stern
>

2013-04-24 22:07:54

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, Apr 24, 2013 at 11:25 PM, Sedat Dilek <[email protected]> wrote:
> On Wed, Apr 24, 2013 at 11:17 PM, Alan Stern <[email protected]> wrote:
>> On Wed, 24 Apr 2013, Sedat Dilek wrote:
>>
>>> > Did this work differently under earlier kernels?
>>> >
>>>
>>> Unfortunately, s/r did not work for several Linux-Next releases as
>>> there is missing tglx's patch pendinging in tip.git/timers/core.
>>
>> Have you tried testing under 3.8? Or earlier releases?
>>
>>> > This indicates that the optical mouse didn't survive the suspend/resume
>>> > sequence and had to be reenumerated. Without more information, there's
>>> > no way to tell specifically what went wrong during the initial reset at
>>> > timestamp 62.353997.
>>> >
>>> > If you want to pursue this farther, you could enable CONFIG_USB_DEBUG.
>>> > You could also collect a usbmon trace for bus 1 showing what happens
>>> > during the suspend and resume.
>>> >
>>>
>>> Hmm, I can try to enable CONFIG_USB_DEBUG and build a new kernel.
>>>
>>> Can you give me more hints how to do a usbmon-trace?
>>
>> See Documentation/usb/usbmon.txt.
>>
>
> Grrr, that docs do not mention which kernel-configs have to be set!
>
> CONFIG_USB_DEBUG=y is not enough.
>
> # modprobe -v usbmon
> FATAL: Module usbmon not found.
>
> # CONFIG_USB_MON is not set <--- Grrr!!!
>
> Doing a -4 build...
>

[ Get VendorID/ProductID of affected USB-device ]

# dmesg | grep 1-1.2 | egrep -i 'vendor|product'
[ 1.372891] usb 1-1.2: New USB device found, idVendor=046d,
idProduct=c00e <--- ProductID!
[ 1.372899] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[ 1.372905] usb 1-1.2: Product: USB-PS/2 Optical Mouse

[ Check for corresponding USB-bus ]

# grep -B2 046d /sys/kernel/debug/usb/devices
T: Bus=01 Lev=02 Prnt=02 Port=01 Cnt=01 Dev#= 3 Spd=1.5 MxCh= 0
<--- USB-bus #01
D: Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs= 1
P: Vendor=046d ProdID=c00e Rev=11.10

[ Run logging on USB-bus #1 ]

# cat /sys/kernel/debug/usb/usbmon/1u > /tmp/usbmon-1u.txt <--- USB-bus #01

[ Do suspend plus resume ]

...

[ Check /tmp/usbmon-1u.txt file ]

...

File attached!

- Sedat -

> - Sedat -
>
>>> > On the other hand, what difference does it really make if a mouse has
>>> > to be reenumerated?
>>> >
>>>
>>> As a non-USB-expert it's hard to interprete such "bogus" lines in your logs.
>>> I am curious enough to ask which is fair :-).
>>> AFAICS in your eyes this is "harmless"?
>>
>> If the device continues to work normally after the resume and none of
>> your programs are affected, then it is harmless.
>>
>> Alan Stern
>>


Attachments:
usbmon-1u.txt (215.97 kB)

2013-04-25 15:45:00

by Alan Stern

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Wed, 24 Apr 2013, Sedat Dilek wrote:

> With CONFIG_USB_DEBUG=y I do not see a PM/async line.
>
> Might you have a look at the logs?

They look quite normal. Except for one thing: The built-in hubs appear
to have gotten reset during the suspend/resume, for no apparent reason.
That's probably the reason why the Logitech mouse needed a reset.

I don't know why the mouse reset worked this time but not before,
unless it's a subtle timing issue (the extra debugging output causes
the resume to go a little more slowly).

Alan Stern

2013-04-25 15:49:54

by Alan Stern

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Thu, 25 Apr 2013, Sedat Dilek wrote:

> [ Run logging on USB-bus #1 ]
>
> # cat /sys/kernel/debug/usb/usbmon/1u > /tmp/usbmon-1u.txt <--- USB-bus #01
>
> [ Do suspend plus resume ]
>
> ...
>
> [ Check /tmp/usbmon-1u.txt file ]
>
> ...
>
> File attached!

That also looks normal. Did you have CONFIG_USB_DEBUG enabled during
this test? If you did, you could try turning it back off to see if the
original problem returns while still doing a usbmon trace.

Alan Stern

2013-04-25 15:52:41

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Thu, Apr 25, 2013 at 5:44 PM, Alan Stern <[email protected]> wrote:
> On Wed, 24 Apr 2013, Sedat Dilek wrote:
>
>> With CONFIG_USB_DEBUG=y I do not see a PM/async line.
>>
>> Might you have a look at the logs?
>
> They look quite normal. Except for one thing: The built-in hubs appear
> to have gotten reset during the suspend/resume, for no apparent reason.
> That's probably the reason why the Logitech mouse needed a reset.
>
> I don't know why the mouse reset worked this time but not before,
> unless it's a subtle timing issue (the extra debugging output causes
> the resume to go a little more slowly).
>

Thanks for your patience, help, hints and explanations.

You want me to send a patch against usb-next to clarify a bit on the
kernel-config options to be enabled as prereqs in case of
usbmon-tracing. If you think it's worth or not let me know.

- Sedat -

> Alan Stern
>

2013-04-25 15:57:11

by Sedat Dilek

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Thu, Apr 25, 2013 at 5:49 PM, Alan Stern <[email protected]> wrote:
> On Thu, 25 Apr 2013, Sedat Dilek wrote:
>
>> [ Run logging on USB-bus #1 ]
>>
>> # cat /sys/kernel/debug/usb/usbmon/1u > /tmp/usbmon-1u.txt <--- USB-bus #01
>>
>> [ Do suspend plus resume ]
>>
>> ...
>>
>> [ Check /tmp/usbmon-1u.txt file ]
>>
>> ...
>>
>> File attached!
>
> That also looks normal. Did you have CONFIG_USB_DEBUG enabled during
> this test? If you did, you could try turning it back off to see if the
> original problem returns while still doing a usbmon trace.
>

As my system works as "expected" after suspend-resume and as you
pointed out "this is harmless" I am not really willing to do more
"homework".

The ipc-sem-next issue has stolen quite bit of my time.

Thanks for the usbmon hint, now I know for next USB issues what to do.
And I have never tried my USB-XHCI interface :-).

/me is just an encouraged Linux-kernel hobbyist.

- Sedat -

> Alan Stern
>

2013-04-25 16:02:21

by Alan Stern

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Thu, 25 Apr 2013, Sedat Dilek wrote:

> You want me to send a patch against usb-next to clarify a bit on the
> kernel-config options to be enabled as prereqs in case of
> usbmon-tracing. If you think it's worth or not let me know.

It's up to you. Documentation patches are always welcome.

Alan Stern

2013-04-25 17:02:23

by Alan Stern

[permalink] [raw]
Subject: Re: linux-next: Tree for Apr 24 [ PM: Device 1-1.2 failed to resume async: error -32 ]

On Thu, 25 Apr 2013, Sedat Dilek wrote:

> > That also looks normal. Did you have CONFIG_USB_DEBUG enabled during
> > this test? If you did, you could try turning it back off to see if the
> > original problem returns while still doing a usbmon trace.
> >
>
> As my system works as "expected" after suspend-resume and as you
> pointed out "this is harmless" I am not really willing to do more
> "homework".
>
> The ipc-sem-next issue has stolen quite bit of my time.
>
> Thanks for the usbmon hint, now I know for next USB issues what to do.
> And I have never tried my USB-XHCI interface :-).
>
> /me is just an encouraged Linux-kernel hobbyist.

Okay. Don't lose hope; lots of people face unexpected issues like
this. Good luck!

Alan Stern