FAQ Search Today's Posts Mark Forums Read
» Video Reviews

» Linux Archive

Linux-archive is a website aiming to archive linux email lists and to make them easily accessible for linux users/developers.


» Sponsor

» Partners

» Sponsor

Go Back   Linux Archive > Debian > Debian Kernel

 
 
LinkBack Thread Tools
 
Old 02-17-2012, 10:51 PM
Steven Chamberlain
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

found 2.6.32-40
thanks

Hi,

Hope it's okay for me to reassign #409349 and #611646 as kernel bugs.
It may be only apcupsd users who experience this, but the process hangs
due to a system call failing to return, and there were reports of a
related error message in the kernel log (control queue full), which
seems to have been a precursor to this hang.

It's clear that this bug has existed for some time (the initial report
was on 2.6.17). I'll have difficulty testing this on 3.2.x kernels
because I require OpenVZ on the affected machine (and that's not ported
to 3.x kernels yet), and I was unsuccessful so far in reproducing it on
a spare box.

I notice that most reports were from users of OHCI hardware. I've even
seen this on a recent RHEL6-derived kernel just now (amd64 OpenVZ kernel
2.6.32-042stab049.6) :

> [425881.271304] INFO: task apcupsd:7104 blocked for more than 120 seconds.
> [425881.278546] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [425881.287407] apcupsd D ffff88004dc00680 0 7104 1 0 0x00000004
> [425881.295778] ffff880008f57d18 0000000000000082 0000000000000000 0000000000000286
> [425881.304301] 00000000fffffffe 0000000000000000 ffff88008f33b0a0 ffff8800762fe200
> [425881.312839] ffff880008f57cb8 ffff88004dc00c38 ffff880008f57fd8 ffff880008f57fd8
> [425881.321374] Call Trace:
> [425881.324325] [<ffffffff81396ef5>] usb_kill_urb+0x85/0xc0
> [425881.330289] [<ffffffff81095310>] ? autoremove_wake_function+0x0/0x40
> [425881.337470] [<ffffffff81406d79>] usbhid_init_reports+0xb9/0x120
> [425881.344191] [<ffffffff81408a68>] hiddev_ioctl+0x418/0x710
> [425881.350357] [<ffffffff81154ba4>] ? handle_mm_fault+0x1e4/0x2b0
> [425881.356967] [<ffffffff81042b54>] ? __do_page_fault+0x1e4/0x480
> [425881.363595] [<ffffffff811a0182>] vfs_ioctl+0x22/0xa0
> [425881.369277] [<ffffffff811a0324>] do_vfs_ioctl+0x84/0x5b0
> [425881.375361] [<ffffffff8118e9f9>] ? __fput+0x1e9/0x280
> [425881.381140] [<ffffffff811a089f>] sys_ioctl+0x4f/0x80
> [425881.386822] [<ffffffff8100b182>] system_call_fastpath+0x16/0x1b

Regards,
--
Steven Chamberlain
steven@pyro.eu.org


--
To UNSUBSCRIBE, email to debian-kernel-REQUEST@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmaster@lists.debian.org
Archive: 4F3EE7F8.2010706@pyro.eu.org">http://lists.debian.org/4F3EE7F8.2010706@pyro.eu.org
 
Old 02-18-2012, 07:20 AM
Jonathan Nieder
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

tags 611646 - unreproducible
quit

Hi Steven,

Steven Chamberlain wrote:

> It may be only apcupsd users who experience this, but the process hangs
> due to a system call failing to return, and there were reports of a
> related error message in the kernel log (control queue full), which
> seems to have been a precursor to this hang.

Thanks. Odd --- the "control queue full" messages were supposed to be
addressed by v2.6.32.10~116 which was included in 2.6.32-10. Alas.

Are the same symptoms present in 2.6.32-41?

I realize it may be hard to test, but results from 3.3-rc1 or newer
or 3.2.y with the attached patch applied[1] would also be interesting.

Curious,
Jonathan

[1] see http://kernel-handbook.alioth.debian.org/ch-common-tasks.html
or the corresponding page in the debian-kernel-handbook package
From: Daniel Kurtz <djkurtz@chromium.org>
Date: Thu, 17 Nov 2011 19:23:49 +0800
Subject: HID: usbhid: hid-core: submit queued urbs before suspend

commit f0befcd64bc57e6a0b7a96c37c55f79e6b999af7 upstream.

If any userspace program has opened a keyboard device, the input core
de-activates the keyboard's LEDs upon suspend(). It does this by sending
individual EV_LED[LED_X]=0 events to the underlying device driver by
directly calling the driver's registered event() handler.

The usb-hid driver event() handler processes each request by immediately
attempting to submit a CTRL URB to turn off the LED. USB URB submission
is asynchronous. First the URB is added to the head of the ctrl queue.
Then, if the CTRL_RUNNING flag is false, the URB is submitted immediately
(and CTRL_RUNNING is set). If the CTRL_RUNNING flag was already true,
then the newly queued URB is submitted in the ctrl completion handler when
all previously submitted URBs have completed. When all queued URBs have
been submitted, the completion handler clears the CTRL_RUNNING flag.

In the 2-LED suspend case, at input suspend(), 2 LED event CTRL URBs get
queued, with only the first actually submitted. Soon after input
suspend() handler finishes, the usb-hid suspend() handler gets called.
Since this is NOT a PM_EVENT_AUTO suspend, the handler sets
REPORTED_IDLE, then waits for io to complete.

Unfortunately, this usually happens while the first LED request is
actually still being processed. Thus when the completion handler tries
to submit the second LED request it fails, since REPORTED_IDLE is
already set! This REPORTED_IDLE check failure causes the completion
handler to complete, however without clearing the CTRL_RUNNING flag.
This, in turn, means that the suspend() handler's wait_io() condition
is never satisfied, and instead it times out after 10 seconds, aborting
the original system suspend.

This patch changes the behavior to the following:
(1) allow completion handler to finish submitting all queued URBs, even if
REPORTED_IDLE is set. This guarantees that all URBs queued before the
hid-core suspend() call will be submitted before the system is
suspended.
(2) if REPORTED_IDLE is set and the URB queue is empty, queue, but
don't submit, new URB submission requests. These queued requests get
submitted when resume() flushes the URB queue. This is similar to the
existing behavior, however, any requests that arrive while the queue is
not yet empty will still get submitted before suspend.
(3) set the RUNNING flag when flushing the URB queue in resume().
This keeps URBs that were queued in (2) from colliding with any new
URBs that are being submitted during the resume process. The new URB
submission requests upon resume get properly queued behind the ones
being flushed instead of the current situation where they collide,
causing memory corruption and oopses.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>
Acked-by: Oliver Neukum <oneukum@suse.de>
Signed-off-by: Jiri Kosina <jkosina@suse.cz>
Signed-off-by: Jonathan Nieder <jrnieder@gmail.com>
---
drivers/hid/usbhid/hid-core.c | 176 +++++++++++++++++++++++-----------------
1 files changed, 101 insertions(+), 75 deletions(-)

diff --git a/drivers/hid/usbhid/hid-core.c b/drivers/hid/usbhid/hid-core.c
index b403fce..5d2e922 100644
--- a/drivers/hid/usbhid/hid-core.c
+++ b/drivers/hid/usbhid/hid-core.c
@@ -197,16 +197,24 @@ static int usbhid_restart_out_queue(struct usbhid_device *usbhid)
{
struct hid_device *hid = usb_get_intfdata(usbhid->intf);
int kicked;
+ int r;

if (!hid)
return 0;

if ((kicked = (usbhid->outhead != usbhid->outtail))) {
dbg("Kicking head %d tail %d", usbhid->outhead, usbhid->outtail);
+
+ r = usb_autopm_get_interface_async(usbhid->intf);
+ if (r < 0)
+ return r;
+ /* Asynchronously flush queue. */
+ set_bit(HID_OUT_RUNNING, &usbhid->iofl);
if (hid_submit_out(hid)) {
clear_bit(HID_OUT_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
+ usb_autopm_put_interface_async(usbhid->intf);
}
+ wake_up(&usbhid->wait);
}
return kicked;
}
@@ -215,6 +223,7 @@ static int usbhid_restart_ctrl_queue(struct usbhid_device *usbhid)
{
struct hid_device *hid = usb_get_intfdata(usbhid->intf);
int kicked;
+ int r;

WARN_ON(hid == NULL);
if (!hid)
@@ -222,10 +231,17 @@ static int usbhid_restart_ctrl_queue(struct usbhid_device *usbhid)

if ((kicked = (usbhid->ctrlhead != usbhid->ctrltail))) {
dbg("Kicking head %d tail %d", usbhid->ctrlhead, usbhid->ctrltail);
+
+ r = usb_autopm_get_interface_async(usbhid->intf);
+ if (r < 0)
+ return r;
+ /* Asynchronously flush queue. */
+ set_bit(HID_CTRL_RUNNING, &usbhid->iofl);
if (hid_submit_ctrl(hid)) {
clear_bit(HID_CTRL_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
+ usb_autopm_put_interface_async(usbhid->intf);
}
+ wake_up(&usbhid->wait);
}
return kicked;
}
@@ -304,30 +320,21 @@ static int hid_submit_out(struct hid_device *hid)
report = usbhid->out[usbhid->outtail].report;
raw_report = usbhid->out[usbhid->outtail].raw_report;

- r = usb_autopm_get_interface_async(usbhid->intf);
- if (r < 0)
- return -1;
+ usbhid->urbout->transfer_buffer_length = ((report->size - 1) >> 3) +
+ 1 + (report->id > 0);
+ usbhid->urbout->dev = hid_to_usb_dev(hid);
+ memcpy(usbhid->outbuf, raw_report,
+ usbhid->urbout->transfer_buffer_length);
+ kfree(raw_report);

- /*
- * if the device hasn't been woken, we leave the output
- * to resume()
- */
- if (!test_bit(HID_REPORTED_IDLE, &usbhid->iofl)) {
- usbhid->urbout->transfer_buffer_length = ((report->size - 1) >> 3) + 1 + (report->id > 0);
- usbhid->urbout->dev = hid_to_usb_dev(hid);
- memcpy(usbhid->outbuf, raw_report, usbhid->urbout->transfer_buffer_length);
- kfree(raw_report);
+ dbg_hid("submitting out urb
");

- dbg_hid("submitting out urb
");
-
- if (usb_submit_urb(usbhid->urbout, GFP_ATOMIC)) {
- hid_err(hid, "usb_submit_urb(out) failed
");
- usb_autopm_put_interface_async(usbhid->intf);
- return -1;
- }
- usbhid->last_out = jiffies;
+ r = usb_submit_urb(usbhid->urbout, GFP_ATOMIC);
+ if (r < 0) {
+ hid_err(hid, "usb_submit_urb(out) failed: %d
", r);
+ return r;
}
-
+ usbhid->last_out = jiffies;
return 0;
}

@@ -343,50 +350,48 @@ static int hid_submit_ctrl(struct hid_device *hid)
raw_report = usbhid->ctrl[usbhid->ctrltail].raw_report;
dir = usbhid->ctrl[usbhid->ctrltail].dir;

- r = usb_autopm_get_interface_async(usbhid->intf);
- if (r < 0)
- return -1;
- if (!test_bit(HID_REPORTED_IDLE, &usbhid->iofl)) {
- len = ((report->size - 1) >> 3) + 1 + (report->id > 0);
- if (dir == USB_DIR_OUT) {
- usbhid->urbctrl->pipe = usb_sndctrlpipe(hid_to_usb_dev(hid), 0);
- usbhid->urbctrl->transfer_buffer_length = len;
- memcpy(usbhid->ctrlbuf, raw_report, len);
- kfree(raw_report);
- } else {
- int maxpacket, padlen;
+ len = ((report->size - 1) >> 3) + 1 + (report->id > 0);
+ if (dir == USB_DIR_OUT) {
+ usbhid->urbctrl->pipe = usb_sndctrlpipe(hid_to_usb_dev(hid), 0);
+ usbhid->urbctrl->transfer_buffer_length = len;
+ memcpy(usbhid->ctrlbuf, raw_report, len);
+ kfree(raw_report);
+ } else {
+ int maxpacket, padlen;

- usbhid->urbctrl->pipe = usb_rcvctrlpipe(hid_to_usb_dev(hid), 0);
- maxpacket = usb_maxpacket(hid_to_usb_dev(hid), usbhid->urbctrl->pipe, 0);
- if (maxpacket > 0) {
- padlen = DIV_ROUND_UP(len, maxpacket);
- padlen *= maxpacket;
- if (padlen > usbhid->bufsize)
- padlen = usbhid->bufsize;
- } else
- padlen = 0;
- usbhid->urbctrl->transfer_buffer_length = padlen;
- }
- usbhid->urbctrl->dev = hid_to_usb_dev(hid);
+ usbhid->urbctrl->pipe = usb_rcvctrlpipe(hid_to_usb_dev(hid), 0);
+ maxpacket = usb_maxpacket(hid_to_usb_dev(hid),
+ usbhid->urbctrl->pipe, 0);
+ if (maxpacket > 0) {
+ padlen = DIV_ROUND_UP(len, maxpacket);
+ padlen *= maxpacket;
+ if (padlen > usbhid->bufsize)
+ padlen = usbhid->bufsize;
+ } else
+ padlen = 0;
+ usbhid->urbctrl->transfer_buffer_length = padlen;
+ }
+ usbhid->urbctrl->dev = hid_to_usb_dev(hid);

- usbhid->cr->bRequestType = USB_TYPE_CLASS | USB_RECIP_INTERFACE | dir;
- usbhid->cr->bRequest = (dir == USB_DIR_OUT) ? HID_REQ_SET_REPORT : HID_REQ_GET_REPORT;
- usbhid->cr->wValue = cpu_to_le16(((report->type + 1) << 8) | report->id);
- usbhid->cr->wIndex = cpu_to_le16(usbhid->ifnum);
- usbhid->cr->wLength = cpu_to_le16(len);
+ usbhid->cr->bRequestType = USB_TYPE_CLASS | USB_RECIP_INTERFACE | dir;
+ usbhid->cr->bRequest = (dir == USB_DIR_OUT) ? HID_REQ_SET_REPORT :
+ HID_REQ_GET_REPORT;
+ usbhid->cr->wValue = cpu_to_le16(((report->type + 1) << 8) |
+ report->id);
+ usbhid->cr->wIndex = cpu_to_le16(usbhid->ifnum);
+ usbhid->cr->wLength = cpu_to_le16(len);

- dbg_hid("submitting ctrl urb: %s wValue=0x%04x wIndex=0x%04x wLength=%u
",
- usbhid->cr->bRequest == HID_REQ_SET_REPORT ? "Set_Report" : "Get_Report",
- usbhid->cr->wValue, usbhid->cr->wIndex, usbhid->cr->wLength);
+ dbg_hid("submitting ctrl urb: %s wValue=0x%04x wIndex=0x%04x wLength=%u
",
+ usbhid->cr->bRequest == HID_REQ_SET_REPORT ? "Set_Report" :
+ "Get_Report",
+ usbhid->cr->wValue, usbhid->cr->wIndex, usbhid->cr->wLength);

- if (usb_submit_urb(usbhid->urbctrl, GFP_ATOMIC)) {
- usb_autopm_put_interface_async(usbhid->intf);
- hid_err(hid, "usb_submit_urb(ctrl) failed
");
- return -1;
- }
- usbhid->last_ctrl = jiffies;
+ r = usb_submit_urb(usbhid->urbctrl, GFP_ATOMIC);
+ if (r < 0) {
+ hid_err(hid, "usb_submit_urb(ctrl) failed: %d
", r);
+ return r;
}
-
+ usbhid->last_ctrl = jiffies;
return 0;
}

@@ -423,11 +428,8 @@ static void hid_irq_out(struct urb *urb)
else
usbhid->outtail = (usbhid->outtail + 1) & (HID_OUTPUT_FIFO_SIZE - 1);

- if (usbhid->outhead != usbhid->outtail) {
- if (hid_submit_out(hid)) {
- clear_bit(HID_OUT_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
- }
+ if (usbhid->outhead != usbhid->outtail && !hid_submit_out(hid)) {
+ /* Successfully submitted next urb in queue */
spin_unlock_irqrestore(&usbhid->lock, flags);
return;
}
@@ -474,13 +476,9 @@ static void hid_ctrl(struct urb *urb)
else
usbhid->ctrltail = (usbhid->ctrltail + 1) & (HID_CONTROL_FIFO_SIZE - 1);

- if (usbhid->ctrlhead != usbhid->ctrltail) {
- if (hid_submit_ctrl(hid)) {
- clear_bit(HID_CTRL_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
- }
+ if (usbhid->ctrlhead != usbhid->ctrltail && !hid_submit_ctrl(hid)) {
+ /* Successfully submitted next urb in queue */
spin_unlock(&usbhid->lock);
- usb_autopm_put_interface_async(usbhid->intf);
return;
}

@@ -515,9 +513,23 @@ static void __usbhid_submit_report(struct hid_device *hid, struct hid_report *re
usbhid->out[usbhid->outhead].report = report;
usbhid->outhead = head;

+ /* Try to awake from autosuspend... */
+ if (usb_autopm_get_interface_async(usbhid->intf) < 0)
+ return;
+
+ /*
+ * But if still suspended, leave urb enqueued, don't submit.
+ * Submission will occur if/when resume() drains the queue.
+ */
+ if (test_bit(HID_REPORTED_IDLE, &usbhid->iofl))
+ return;
+
if (!test_and_set_bit(HID_OUT_RUNNING, &usbhid->iofl)) {
- if (hid_submit_out(hid))
+ if (hid_submit_out(hid)) {
clear_bit(HID_OUT_RUNNING, &usbhid->iofl);
+ usb_autopm_put_interface_async(usbhid->intf);
+ }
+ wake_up(&usbhid->wait);
} else {
/*
* the queue is known to run
@@ -549,9 +561,23 @@ static void __usbhid_submit_report(struct hid_device *hid, struct hid_report *re
usbhid->ctrl[usbhid->ctrlhead].dir = dir;
usbhid->ctrlhead = head;

+ /* Try to awake from autosuspend... */
+ if (usb_autopm_get_interface_async(usbhid->intf) < 0)
+ return;
+
+ /*
+ * If already suspended, leave urb enqueued, but don't submit.
+ * Submission will occur if/when resume() drains the queue.
+ */
+ if (test_bit(HID_REPORTED_IDLE, &usbhid->iofl))
+ return;
+
if (!test_and_set_bit(HID_CTRL_RUNNING, &usbhid->iofl)) {
- if (hid_submit_ctrl(hid))
+ if (hid_submit_ctrl(hid)) {
clear_bit(HID_CTRL_RUNNING, &usbhid->iofl);
+ usb_autopm_put_interface_async(usbhid->intf);
+ }
+ wake_up(&usbhid->wait);
} else {
/*
* the queue is known to run
--
1.7.2.5
 
Old 02-18-2012, 07:28 AM
Jonathan Nieder
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

(resending with newer address for Tom. Sorry for the noise, all)
Hi Steven,

Steven Chamberlain wrote:

> It may be only apcupsd users who experience this, but the process hangs
> due to a system call failing to return, and there were reports of a
> related error message in the kernel log (control queue full), which
> seems to have been a precursor to this hang.

Thanks. Odd --- the "control queue full" messages were supposed to be
addressed by v2.6.32.10~116 which was included in 2.6.32-10. Alas.

Are the same symptoms present in 2.6.32-41?

I realize it may be hard to test, but results from 3.3-rc1 or newer
or 3.2.y with the attached patch applied[1] would also be interesting.

Curious,
Jonathan

[1] see http://kernel-handbook.alioth.debian.org/ch-common-tasks.html
or the corresponding page in the debian-kernel-handbook package
From: Daniel Kurtz <djkurtz@chromium.org>
Date: Thu, 17 Nov 2011 19:23:49 +0800
Subject: HID: usbhid: hid-core: submit queued urbs before suspend

commit f0befcd64bc57e6a0b7a96c37c55f79e6b999af7 upstream.

If any userspace program has opened a keyboard device, the input core
de-activates the keyboard's LEDs upon suspend(). It does this by sending
individual EV_LED[LED_X]=0 events to the underlying device driver by
directly calling the driver's registered event() handler.

The usb-hid driver event() handler processes each request by immediately
attempting to submit a CTRL URB to turn off the LED. USB URB submission
is asynchronous. First the URB is added to the head of the ctrl queue.
Then, if the CTRL_RUNNING flag is false, the URB is submitted immediately
(and CTRL_RUNNING is set). If the CTRL_RUNNING flag was already true,
then the newly queued URB is submitted in the ctrl completion handler when
all previously submitted URBs have completed. When all queued URBs have
been submitted, the completion handler clears the CTRL_RUNNING flag.

In the 2-LED suspend case, at input suspend(), 2 LED event CTRL URBs get
queued, with only the first actually submitted. Soon after input
suspend() handler finishes, the usb-hid suspend() handler gets called.
Since this is NOT a PM_EVENT_AUTO suspend, the handler sets
REPORTED_IDLE, then waits for io to complete.

Unfortunately, this usually happens while the first LED request is
actually still being processed. Thus when the completion handler tries
to submit the second LED request it fails, since REPORTED_IDLE is
already set! This REPORTED_IDLE check failure causes the completion
handler to complete, however without clearing the CTRL_RUNNING flag.
This, in turn, means that the suspend() handler's wait_io() condition
is never satisfied, and instead it times out after 10 seconds, aborting
the original system suspend.

This patch changes the behavior to the following:
(1) allow completion handler to finish submitting all queued URBs, even if
REPORTED_IDLE is set. This guarantees that all URBs queued before the
hid-core suspend() call will be submitted before the system is
suspended.
(2) if REPORTED_IDLE is set and the URB queue is empty, queue, but
don't submit, new URB submission requests. These queued requests get
submitted when resume() flushes the URB queue. This is similar to the
existing behavior, however, any requests that arrive while the queue is
not yet empty will still get submitted before suspend.
(3) set the RUNNING flag when flushing the URB queue in resume().
This keeps URBs that were queued in (2) from colliding with any new
URBs that are being submitted during the resume process. The new URB
submission requests upon resume get properly queued behind the ones
being flushed instead of the current situation where they collide,
causing memory corruption and oopses.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>
Acked-by: Oliver Neukum <oneukum@suse.de>
Signed-off-by: Jiri Kosina <jkosina@suse.cz>
Signed-off-by: Jonathan Nieder <jrnieder@gmail.com>
---
drivers/hid/usbhid/hid-core.c | 176 +++++++++++++++++++++++-----------------
1 files changed, 101 insertions(+), 75 deletions(-)

diff --git a/drivers/hid/usbhid/hid-core.c b/drivers/hid/usbhid/hid-core.c
index b403fce..5d2e922 100644
--- a/drivers/hid/usbhid/hid-core.c
+++ b/drivers/hid/usbhid/hid-core.c
@@ -197,16 +197,24 @@ static int usbhid_restart_out_queue(struct usbhid_device *usbhid)
{
struct hid_device *hid = usb_get_intfdata(usbhid->intf);
int kicked;
+ int r;

if (!hid)
return 0;

if ((kicked = (usbhid->outhead != usbhid->outtail))) {
dbg("Kicking head %d tail %d", usbhid->outhead, usbhid->outtail);
+
+ r = usb_autopm_get_interface_async(usbhid->intf);
+ if (r < 0)
+ return r;
+ /* Asynchronously flush queue. */
+ set_bit(HID_OUT_RUNNING, &usbhid->iofl);
if (hid_submit_out(hid)) {
clear_bit(HID_OUT_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
+ usb_autopm_put_interface_async(usbhid->intf);
}
+ wake_up(&usbhid->wait);
}
return kicked;
}
@@ -215,6 +223,7 @@ static int usbhid_restart_ctrl_queue(struct usbhid_device *usbhid)
{
struct hid_device *hid = usb_get_intfdata(usbhid->intf);
int kicked;
+ int r;

WARN_ON(hid == NULL);
if (!hid)
@@ -222,10 +231,17 @@ static int usbhid_restart_ctrl_queue(struct usbhid_device *usbhid)

if ((kicked = (usbhid->ctrlhead != usbhid->ctrltail))) {
dbg("Kicking head %d tail %d", usbhid->ctrlhead, usbhid->ctrltail);
+
+ r = usb_autopm_get_interface_async(usbhid->intf);
+ if (r < 0)
+ return r;
+ /* Asynchronously flush queue. */
+ set_bit(HID_CTRL_RUNNING, &usbhid->iofl);
if (hid_submit_ctrl(hid)) {
clear_bit(HID_CTRL_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
+ usb_autopm_put_interface_async(usbhid->intf);
}
+ wake_up(&usbhid->wait);
}
return kicked;
}
@@ -304,30 +320,21 @@ static int hid_submit_out(struct hid_device *hid)
report = usbhid->out[usbhid->outtail].report;
raw_report = usbhid->out[usbhid->outtail].raw_report;

- r = usb_autopm_get_interface_async(usbhid->intf);
- if (r < 0)
- return -1;
+ usbhid->urbout->transfer_buffer_length = ((report->size - 1) >> 3) +
+ 1 + (report->id > 0);
+ usbhid->urbout->dev = hid_to_usb_dev(hid);
+ memcpy(usbhid->outbuf, raw_report,
+ usbhid->urbout->transfer_buffer_length);
+ kfree(raw_report);

- /*
- * if the device hasn't been woken, we leave the output
- * to resume()
- */
- if (!test_bit(HID_REPORTED_IDLE, &usbhid->iofl)) {
- usbhid->urbout->transfer_buffer_length = ((report->size - 1) >> 3) + 1 + (report->id > 0);
- usbhid->urbout->dev = hid_to_usb_dev(hid);
- memcpy(usbhid->outbuf, raw_report, usbhid->urbout->transfer_buffer_length);
- kfree(raw_report);
+ dbg_hid("submitting out urb
");

- dbg_hid("submitting out urb
");
-
- if (usb_submit_urb(usbhid->urbout, GFP_ATOMIC)) {
- hid_err(hid, "usb_submit_urb(out) failed
");
- usb_autopm_put_interface_async(usbhid->intf);
- return -1;
- }
- usbhid->last_out = jiffies;
+ r = usb_submit_urb(usbhid->urbout, GFP_ATOMIC);
+ if (r < 0) {
+ hid_err(hid, "usb_submit_urb(out) failed: %d
", r);
+ return r;
}
-
+ usbhid->last_out = jiffies;
return 0;
}

@@ -343,50 +350,48 @@ static int hid_submit_ctrl(struct hid_device *hid)
raw_report = usbhid->ctrl[usbhid->ctrltail].raw_report;
dir = usbhid->ctrl[usbhid->ctrltail].dir;

- r = usb_autopm_get_interface_async(usbhid->intf);
- if (r < 0)
- return -1;
- if (!test_bit(HID_REPORTED_IDLE, &usbhid->iofl)) {
- len = ((report->size - 1) >> 3) + 1 + (report->id > 0);
- if (dir == USB_DIR_OUT) {
- usbhid->urbctrl->pipe = usb_sndctrlpipe(hid_to_usb_dev(hid), 0);
- usbhid->urbctrl->transfer_buffer_length = len;
- memcpy(usbhid->ctrlbuf, raw_report, len);
- kfree(raw_report);
- } else {
- int maxpacket, padlen;
+ len = ((report->size - 1) >> 3) + 1 + (report->id > 0);
+ if (dir == USB_DIR_OUT) {
+ usbhid->urbctrl->pipe = usb_sndctrlpipe(hid_to_usb_dev(hid), 0);
+ usbhid->urbctrl->transfer_buffer_length = len;
+ memcpy(usbhid->ctrlbuf, raw_report, len);
+ kfree(raw_report);
+ } else {
+ int maxpacket, padlen;

- usbhid->urbctrl->pipe = usb_rcvctrlpipe(hid_to_usb_dev(hid), 0);
- maxpacket = usb_maxpacket(hid_to_usb_dev(hid), usbhid->urbctrl->pipe, 0);
- if (maxpacket > 0) {
- padlen = DIV_ROUND_UP(len, maxpacket);
- padlen *= maxpacket;
- if (padlen > usbhid->bufsize)
- padlen = usbhid->bufsize;
- } else
- padlen = 0;
- usbhid->urbctrl->transfer_buffer_length = padlen;
- }
- usbhid->urbctrl->dev = hid_to_usb_dev(hid);
+ usbhid->urbctrl->pipe = usb_rcvctrlpipe(hid_to_usb_dev(hid), 0);
+ maxpacket = usb_maxpacket(hid_to_usb_dev(hid),
+ usbhid->urbctrl->pipe, 0);
+ if (maxpacket > 0) {
+ padlen = DIV_ROUND_UP(len, maxpacket);
+ padlen *= maxpacket;
+ if (padlen > usbhid->bufsize)
+ padlen = usbhid->bufsize;
+ } else
+ padlen = 0;
+ usbhid->urbctrl->transfer_buffer_length = padlen;
+ }
+ usbhid->urbctrl->dev = hid_to_usb_dev(hid);

- usbhid->cr->bRequestType = USB_TYPE_CLASS | USB_RECIP_INTERFACE | dir;
- usbhid->cr->bRequest = (dir == USB_DIR_OUT) ? HID_REQ_SET_REPORT : HID_REQ_GET_REPORT;
- usbhid->cr->wValue = cpu_to_le16(((report->type + 1) << 8) | report->id);
- usbhid->cr->wIndex = cpu_to_le16(usbhid->ifnum);
- usbhid->cr->wLength = cpu_to_le16(len);
+ usbhid->cr->bRequestType = USB_TYPE_CLASS | USB_RECIP_INTERFACE | dir;
+ usbhid->cr->bRequest = (dir == USB_DIR_OUT) ? HID_REQ_SET_REPORT :
+ HID_REQ_GET_REPORT;
+ usbhid->cr->wValue = cpu_to_le16(((report->type + 1) << 8) |
+ report->id);
+ usbhid->cr->wIndex = cpu_to_le16(usbhid->ifnum);
+ usbhid->cr->wLength = cpu_to_le16(len);

- dbg_hid("submitting ctrl urb: %s wValue=0x%04x wIndex=0x%04x wLength=%u
",
- usbhid->cr->bRequest == HID_REQ_SET_REPORT ? "Set_Report" : "Get_Report",
- usbhid->cr->wValue, usbhid->cr->wIndex, usbhid->cr->wLength);
+ dbg_hid("submitting ctrl urb: %s wValue=0x%04x wIndex=0x%04x wLength=%u
",
+ usbhid->cr->bRequest == HID_REQ_SET_REPORT ? "Set_Report" :
+ "Get_Report",
+ usbhid->cr->wValue, usbhid->cr->wIndex, usbhid->cr->wLength);

- if (usb_submit_urb(usbhid->urbctrl, GFP_ATOMIC)) {
- usb_autopm_put_interface_async(usbhid->intf);
- hid_err(hid, "usb_submit_urb(ctrl) failed
");
- return -1;
- }
- usbhid->last_ctrl = jiffies;
+ r = usb_submit_urb(usbhid->urbctrl, GFP_ATOMIC);
+ if (r < 0) {
+ hid_err(hid, "usb_submit_urb(ctrl) failed: %d
", r);
+ return r;
}
-
+ usbhid->last_ctrl = jiffies;
return 0;
}

@@ -423,11 +428,8 @@ static void hid_irq_out(struct urb *urb)
else
usbhid->outtail = (usbhid->outtail + 1) & (HID_OUTPUT_FIFO_SIZE - 1);

- if (usbhid->outhead != usbhid->outtail) {
- if (hid_submit_out(hid)) {
- clear_bit(HID_OUT_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
- }
+ if (usbhid->outhead != usbhid->outtail && !hid_submit_out(hid)) {
+ /* Successfully submitted next urb in queue */
spin_unlock_irqrestore(&usbhid->lock, flags);
return;
}
@@ -474,13 +476,9 @@ static void hid_ctrl(struct urb *urb)
else
usbhid->ctrltail = (usbhid->ctrltail + 1) & (HID_CONTROL_FIFO_SIZE - 1);

- if (usbhid->ctrlhead != usbhid->ctrltail) {
- if (hid_submit_ctrl(hid)) {
- clear_bit(HID_CTRL_RUNNING, &usbhid->iofl);
- wake_up(&usbhid->wait);
- }
+ if (usbhid->ctrlhead != usbhid->ctrltail && !hid_submit_ctrl(hid)) {
+ /* Successfully submitted next urb in queue */
spin_unlock(&usbhid->lock);
- usb_autopm_put_interface_async(usbhid->intf);
return;
}

@@ -515,9 +513,23 @@ static void __usbhid_submit_report(struct hid_device *hid, struct hid_report *re
usbhid->out[usbhid->outhead].report = report;
usbhid->outhead = head;

+ /* Try to awake from autosuspend... */
+ if (usb_autopm_get_interface_async(usbhid->intf) < 0)
+ return;
+
+ /*
+ * But if still suspended, leave urb enqueued, don't submit.
+ * Submission will occur if/when resume() drains the queue.
+ */
+ if (test_bit(HID_REPORTED_IDLE, &usbhid->iofl))
+ return;
+
if (!test_and_set_bit(HID_OUT_RUNNING, &usbhid->iofl)) {
- if (hid_submit_out(hid))
+ if (hid_submit_out(hid)) {
clear_bit(HID_OUT_RUNNING, &usbhid->iofl);
+ usb_autopm_put_interface_async(usbhid->intf);
+ }
+ wake_up(&usbhid->wait);
} else {
/*
* the queue is known to run
@@ -549,9 +561,23 @@ static void __usbhid_submit_report(struct hid_device *hid, struct hid_report *re
usbhid->ctrl[usbhid->ctrlhead].dir = dir;
usbhid->ctrlhead = head;

+ /* Try to awake from autosuspend... */
+ if (usb_autopm_get_interface_async(usbhid->intf) < 0)
+ return;
+
+ /*
+ * If already suspended, leave urb enqueued, but don't submit.
+ * Submission will occur if/when resume() drains the queue.
+ */
+ if (test_bit(HID_REPORTED_IDLE, &usbhid->iofl))
+ return;
+
if (!test_and_set_bit(HID_CTRL_RUNNING, &usbhid->iofl)) {
- if (hid_submit_ctrl(hid))
+ if (hid_submit_ctrl(hid)) {
clear_bit(HID_CTRL_RUNNING, &usbhid->iofl);
+ usb_autopm_put_interface_async(usbhid->intf);
+ }
+ wake_up(&usbhid->wait);
} else {
/*
* the queue is known to run
--
1.7.2.5
 
Old 04-04-2012, 09:23 PM
Jonathan Nieder
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

Jonathan Nieder wrote:
> Steven Chamberlain wrote:

>> It may be only apcupsd users who experience this, but the process hangs
>> due to a system call failing to return, and there were reports of a
>> related error message in the kernel log (control queue full), which
>> seems to have been a precursor to this hang.
>
> Thanks. Odd --- the "control queue full" messages were supposed to be
> addressed by v2.6.32.10~116 which was included in 2.6.32-10. Alas.

Ping. Is nobody trying to use an APC UPS connected by USB any more?

What kernels work and don't work? Tom, Hugo: are you still interested
in pursuing this bug? If not, that's fine, but please do let us know
so we can plan accordingly.

In suspense,
Jonathan



--
To UNSUBSCRIBE, email to debian-kernel-REQUEST@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmaster@lists.debian.org
Archive: 20120404212301.GA18337@burratino">http://lists.debian.org/20120404212301.GA18337@burratino
 
Old 04-04-2012, 09:43 PM
Steven Chamberlain
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

found 409349 linux-2.6/2.6.32-41
thanks

On 04/04/12 22:23, Jonathan Nieder wrote:
> Ping. Is nobody trying to use an APC UPS connected by USB any more?

Yep! This week on 2.6.32-41 I noticed apcupsd hang after about a day,
followed by the 'control queue full' errors an hour later. That was
with the patches suggested in #631287 applied, just in case they made
any difference to this.

> What kernels work and don't work?

I already tagged affected versions in the BTS; the first report of this
was on 2.6.17 and I myself recall seeing it as far back as 2.6.26.


I hadn't been able to test the UPS on a 3.y kernel until this week.
Right now I have the UPS hooked up to a new server running 3.2.0-2-amd64
(Debian 3.2.12-1) to see if it recurs.

Then in a few weeks, I'll be taking the original hardware (on which the
issue was easily reproducible) out of production use, so I can try 3.y
kernels on that too. (Until now, I couldn't try 3.y kernels on that box
as it needs to run OpenVZ containers).

Regards,
--
Steven Chamberlain
steven@pyro.eu.org



--
To UNSUBSCRIBE, email to debian-kernel-REQUEST@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmaster@lists.debian.org
Archive: 4F7CC08E.5000406@pyro.eu.org">http://lists.debian.org/4F7CC08E.5000406@pyro.eu.org
 
Old 04-04-2012, 10:00 PM
Jonathan Nieder
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

unarchive 631287
reassign 631287 src:linux-2.6 2.6.32-35
found 631287 linux-2.6/2.6.32-34squeeze1
fixed 631287 linux-2.6/3.2.1-2
quit

Steven Chamberlain wrote:

> Yep! This week on 2.6.32-41 I noticed apcupsd hang after about a day,
> followed by the 'control queue full' errors an hour later.
[...]
> I hadn't been able to test the UPS on a 3.y kernel until this week.
> Right now I have the UPS hooked up to a new server running 3.2.0-2-amd64
> (Debian 3.2.12-1) to see if it recurs.
>
> Then in a few weeks, I'll be taking the original hardware (on which the
> issue was easily reproducible) out of production use, so I can try 3.y
> kernels on that too.

Perfect. Thanks much.

While I have your attention: does the patch series in #631287 seem to
prevent the BUG as advertised without any noticeable unpleasant
side-effects? How long have you been testing it?

Jonathan



--
To UNSUBSCRIBE, email to debian-kernel-REQUEST@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmaster@lists.debian.org
Archive: 20120404220007.GD17985@burratino">http://lists.debian.org/20120404220007.GD17985@burratino
 
Old 04-04-2012, 11:44 PM
Tom Wright
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

On Thursday 05 April 2012 00:39:32 you wrote:
> Tom Wright wrote:
> > I haven't seen this bug in quite a while, so maybe it's fixed in 3.X?
> > Best see what others say too I guess.
>
> Thanks for the update. How long have you been using the wheezy/sid
> kernel? Do you mind if I forward this information to the bug log?

Quite a while now - I run sid on the machine which has a UPS, so however long
it's been the standard kernel in that branch. A few months, at least. You're
welcome to send it on to the bug log too.
 
Old 04-05-2012, 12:18 AM
Jonathan Nieder
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

Tom Wright wrote:
> On Thursday 05 April 2012 00:39:32 you wrote:
>> Tom Wright wrote:

>>> I haven't seen this bug in quite a while, so maybe it's fixed in 3.X?
>>> Best see what others say too I guess.
>>
>> Thanks for the update. How long have you been using the wheezy/sid
>> kernel? Do you mind if I forward this information to the bug log?
>
> Quite a while now - I run sid on the machine which has a UPS, so however long
> it's been the standard kernel in that branch. A few months, at least. You're
> welcome to send it on to the bug log too.

Thanks much. Do you remember roughly when you last experienced this
bug?

(The last time I see in the bug log is in 2007 with 2.6.17 or so .
Others have experienced it with kernels as new as 2.6.32-41 so I'd be
especially interested if you remember the behavior with 2.6.33,
2.6.35, 2.6.38, etc. /var/log/dpkg.log* should have the upgrade
history of the kernel package if that helps jog your memory.)

Jonathan



--
To UNSUBSCRIBE, email to debian-kernel-REQUEST@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmaster@lists.debian.org
Archive: 20120405001841.GC19575@burratino">http://lists.debian.org/20120405001841.GC19575@burratino
 
Old 04-05-2012, 03:52 AM
hugo vanwoerkom
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

On Wed, Apr 4, 2012 at 7:18 PM, Jonathan Nieder <jrnieder@gmail.com> wrote:
> Tom Wright wrote:
>> On Thursday 05 April 2012 00:39:32 you wrote:
>>> Tom Wright wrote:
>
>>>> I haven't seen this bug in quite a while, so maybe it's fixed in 3.X?
>>>> Best see what others say too I guess.
>>>
>>> Thanks for the update. *How long have you been using the wheezy/sid
>>> kernel? *Do you mind if I forward this information to the bug log?
>>
>> Quite a while now - I run sid on the machine which has a UPS, so however long
>> it's been the standard kernel in that branch. *A few months, at least. *You're
>> welcome to send it on to the bug log too.
>
> Thanks much. *Do you remember roughly when you last experienced this
> bug?
>

Jan. 31 2011
But I have no records of what kernel I was running then :-(

Hugo


> (The last time I see in the bug log is in 2007 with 2.6.17 or so .
> Others have experienced it with kernels as new as 2.6.32-41 so I'd be
> especially interested if you remember the behavior with 2.6.33,
> 2.6.35, 2.6.38, etc. */var/log/dpkg.log* should have the upgrade
> history of the kernel package if that helps jog your memory.)
>
> Jonathan



--
To UNSUBSCRIBE, email to debian-kernel-REQUEST@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmaster@lists.debian.org
Archive: CAGe5QND1bgeXv2DUvEZ-JULC_Sg_CR8goTKMbxeMuoi-WwK21Q@mail.gmail.com">http://lists.debian.org/CAGe5QND1bgeXv2DUvEZ-JULC_Sg_CR8goTKMbxeMuoi-WwK21Q@mail.gmail.com
 
Old 04-05-2012, 04:27 AM
David Fries
 
Default Bug#409349: usbhid: control queue full; hung apcupsd task

On Sat, 22 Jan 2011 19:39:24 +0000 Steven Chamberlain wrote:
> Usually I see the stream of the "control queue full" errors first, but
> this time apcupsd hung very soon after boot:
> INFO: task apcupsd:21604 blocked for more than 120 seconds.
> [<ffffffffa01bdeb9>] ? ohci_urb_dequeue+0xd9/0xe9 [ohci_hcd]
> [<ffffffffa003f10c>] ? usb_kill_urb+0x9d/0xbb [usbcore]
> [<ffffffff8106681a>] ? autoremove_wake_function+0x0/0x2e
> [<ffffffffa0209feb>] ? usbhid_init_reports+0x8c/0xee
> [<ffffffffa020b396>] ? hiddev_ioctl+0x2bf/0x632 [usbhid]
> This was despite raising apcupsd's POLLTIME from 10 to 60 seconds.

My usbmon dump showed that requests were being made that the UPS
wasn't returning or failing, sounds like a task for a bus analyzer
and a read through the USB standard.

usbhid_init_report is called from usbhid_start and from hid.c "called
on probe to start the device", and as such wouldn't be called each
time apcupsd polls the UPS. So increasing the POLLTIME wouldn't have
helped. I don't know how many reports it is requesting, but the
timeout in usbhid_wait_io is 10 seconds, so 12 could add up to 120
seconds. Even so I would expect it to eventually timeout. Now if it
was sitting in ohci_urb_dequeue for 120 seconds that is a problem.

On Wed, Apr 04, 2012 at 10:43:42PM +0100, Steven Chamberlain wrote:
> found 409349 linux-2.6/2.6.32-41
> thanks
>
> On 04/04/12 22:23, Jonathan Nieder wrote:
> > Ping. Is nobody trying to use an APC UPS connected by USB any more?

I have three. I only had problems with one OHCI SiS rev 07 PCI
1039:7001 controller, and once I added the patch for "introduce
timeout for stuck ctrl/out URBs" I've not had the issue anymore.

> Yep! This week on 2.6.32-41 I noticed apcupsd hang after about a day,
> followed by the 'control queue full' errors an hour later. That was
> with the patches suggested in #631287 applied, just in case they made
> any difference to this.

My guess is the control queue message full problem just enlarges the
window of opportunity fro 'BUG during access to hiddev' bug report
#631287. I think it would help avoid crashing when it gets into this
situation, but from the patch titles I don't think it would help avoid
it.

The queue is 256 long, and with apcupsd querying every 10 seconds,
256*10/60=42 minutes once an entry gets blocked. With the timeout set
to 5 seconds in the "introduce timeout" patch and apcups polling every
10 seconds it no matter if every request failed to complete it
shouldn't be able to fill up. But that's only if apcupsd is only
submitting one control request every 10 seconds, but looking at my old
logs that isn't the case. For my UPS it seemed to only ignore a
transfer rarely, maybe there are some that are frequent enough to be a
problem, in which case the timeout patch wouldn't be able to keep up.
It would be nice to have a usbmon dump of it happening to see if that
is the case or not.

> > What kernels work and don't work?
>
> I already tagged affected versions in the BTS; the first report of this
> was on 2.6.17 and I myself recall seeing it as far back as 2.6.26.
>
>
> I hadn't been able to test the UPS on a 3.y kernel until this week.
> Right now I have the UPS hooked up to a new server running 3.2.0-2-amd64
> (Debian 3.2.12-1) to see if it recurs.

What UPS do you have that's the problem? Mine was,
BackUPS Pro 500
firmware 16.3.D USB FW:4

> Then in a few weeks, I'll be taking the original hardware (on which the
> issue was easily reproducible) out of production use, so I can try 3.y
> kernels on that too. (Until now, I couldn't try 3.y kernels on that box
> as it needs to run OpenVZ containers).

What kind of timeframe is easily reproducible? Can you run
information gathering patches on the box, if so I'll put something
together. Then again this has been going on for years, if you prefer
to wait a few weeks until it is not in production use that's fine.

Back when I was first debugging this I added some printk messages for
when the queue length increased. If you'll give them a try I'll look
them up and also printout that jiffies value as well.

--
David Fries <david@fries.net> PGP pub CB1EE8F0
http://fries.net/~david/



--
To UNSUBSCRIBE, email to debian-kernel-REQUEST@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmaster@lists.debian.org
Archive: 20120405042703.GE3011@spacedout.fries.net">http://lists.debian.org/20120405042703.GE3011@spacedout.fries.net
 

Thread Tools




All times are GMT. The time now is 07:38 AM.

VBulletin, Copyright ©2000 - 2014, Jelsoft Enterprises Ltd.
Content Relevant URLs by vBSEO ©2007, Crawlability, Inc.
Copyright 2007 - 2008, www.linux-archive.org