Bug 196872

Summary: kernel floods dmesg
Product: [Fedora] Fedora Reporter: Nuno Carvalho <nmrrsc>
Component: kernelAssignee: Pete Zaitcev <zaitcev>
Status: CLOSED UPSTREAM QA Contact: Brian Brock <bbrock>
Severity: medium Docs Contact:
Priority: medium    
Version: 5CC: davej, wtogami
Target Milestone: ---   
Target Release: ---   
Hardware: i686   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2006-10-17 16:00:40 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Output of lspci, lsusb and /var/log/messages
none
usbmon output
none
usbmon output
none
usbmon output - USB Serial device -> OK
none
Enlarge input buffer upon hitting a bubble
none
usbmon after patch none

Description Nuno Carvalho 2006-06-27 13:54:05 UTC
Created attachment 131602 [details]
Output of lspci, lsusb and /var/log/messages

Comment 1 Nuno Carvalho 2006-06-27 13:54:05 UTC
Description of problem:
After the kernel update to version 2.6.17-1.2139smp, the kernel logs a warning
to dmesg with this message "drivers/usb/input/hid-core.c: input irq status -75
received". The kernel logs this message 7626 times per minute.

Jun 27 14:47:20 hxa-w004 last message repeated 7626 times
Jun 27 14:48:21 hxa-w004 last message repeated 7627 times

This doesn't happen in the previous version kernel-smp-2.6.16-1.2133_FC5,
neither in the non smp version of kernel-2.6.17-1.2139_FC5. I have an usb
keyboard attatched.

Version-Release number of selected component (if applicable):
kernel-smp-2.6.17-1.2139_FC5
CPU : Intel(R) Pentium(R) 4 CPU 3.00GHz

How reproducible: 100%

Steps to Reproduce:
1. Start the computer.
2. Wait until system is ready.
3. Kernel starts to flood dmesg
  
Actual results:


Expected results:
No flooding of dmesg

Additional info:

Comment 2 Nuno Carvalho 2006-07-06 14:38:08 UTC
This problem is also present in kernel 2.6.17-1.2145_FC5smp that was released
yesterday. Haven't tested with the non-smp version. Thanks to this bug I have
logs files with 50 Mb.

Comment 3 Pete Zaitcev 2006-07-08 00:05:12 UTC
Since the problem appears to be a race, it would be really awesome if
you captured me usbmon traces from both. This is because the HID code
is not terribly transparent, so it's hard for me to guess what exactly
the problem may be. Instructions for usbmon come with kernel-doc and
should end at this path:
 /usr/share/doc/kernel-doc-2.6.16/Documentation/usb/usbmon.txt

Thanks for the excellent report with precise kernel versions, I'm starting
on the diffing now.


Comment 4 Nuno Carvalho 2006-07-18 15:23:02 UTC
Created attachment 132605 [details]
usbmon output

Comment 5 Nuno Carvalho 2006-07-18 15:24:27 UTC
Hi Pete,

Done the usbmon logging. Started usbmon, pressed keys for a while and then
killed 'cat'. Hope this help you finding it. This "pattern" is also present in
the newest kernel 2.6.17-1.2157_FC5smp.

Comment 6 Pete Zaitcev 2006-07-25 19:20:05 UTC
The trace only started after the situation developed. I need one which
shows how we got into it. The easiest way is to unplug and plug back
the keyboard or mouse. You mentioned keyboard, but 5-byte reports are
requested from a mouse. Perhaps something is wrong with the mouse port.

Comment 7 Pete Zaitcev 2006-07-25 20:40:15 UTC
One important quiestion: can you test patches, or do not need prebuilt kernels?

Comment 8 Nuno Carvalho 2006-07-27 09:42:27 UTC
Definitely it's an usb problem, tested removing the mouse several times and the
race continued. But when I unpluged the keyboard the race stopped as you
probably can see on the output of usbmon. Then I pluged back the keyboard, it
was fine for a while then entered on the race again.

I'm using the prebuilt kernel, but can test patches.

Comment 9 Nuno Carvalho 2006-07-27 09:48:29 UTC
Created attachment 133137 [details]
usbmon output

Comment 10 Nuno Carvalho 2006-07-28 11:11:22 UTC
Also tested with a PS/2 keyboard and had no problem. Tried with an USB Serial
device, also worked with no problems (new attachment). But when I connect the
usb keyboard it will enter on that race condition (on previous attachment).

Hope that it helps.

Comment 11 Nuno Carvalho 2006-07-28 11:12:21 UTC
Created attachment 133229 [details]
usbmon output - USB Serial device -> OK

Comment 12 Pete Zaitcev 2006-07-28 19:53:30 UTC
Very well, please build a baseline kernel and let me know what release you
are using precisely, so I can build a patch. Either Fedora or stock 2.6.18-rcX
will work. This seems like a problem which would happen with any of them.

The trace looks like this:

ee1dc0c0 1215524745 C Ii:005:01 0 8 = 00000000 00000000
ee1dc0c0 1215524765 S Ii:005:01 -115 8 <
f6a4a140 1225050124 C Ci:005:00 -2 0
f6a4a140 1225050130 S Ci:005:00 s a1 01 0102 0001 0002 8 <
f6a4a2c0 1225050386 S Ii:005:02 -115 5 <
f6a4a2c0 1225059128 C Ii:005:02 -75 5 = 00000f00 00

So, the very first submission to the mouse ends with the bubble
and there's no reset involved.


Comment 13 Pete Zaitcev 2006-07-30 00:33:47 UTC
Created attachment 133285 [details]
Enlarge input buffer upon hitting a bubble

I wanted to do something like this for a long time, but there was no good
test case.

Comment 14 Pete Zaitcev 2006-07-30 00:37:01 UTC
The above is a patch against 2.6.18-rc1, but I think that area did not change
since 2.6.16 when hid_io_error() appeared, so the patch ought to be good
for all recent Fedora releases too. Please test and let me know if it helps.


Comment 15 Nuno Carvalho 2006-08-18 09:51:45 UTC
Hi Pete,

I was on vacation, couldn't reply sonner ;).

Tested the patch with on kernel-smp-2.6.17-1.2174_FC5, the keyboard acts funny
with this patch. Almost the time I have to press a key twice to be displayed.
That are the chenages that I see, became worst with the patch. In terms of
logging, a new message came up on dmesg, about 20 times per minute : 

Aug 18 10:38:11 hxa-w004 kernel: usb 2-2: reset low speed USB device using
uhci_hcd and address 2

Also have the log of usbmon that will go has attatchment. Started the logging
with the keyboard plugged, pressed some keys (had to press twice most the times,
and sometimes it filled the screen with this key, maybe a race), unplugged the
keyboard. Plugged it back in, waited a while and pressed again some keys.

Comment 16 Nuno Carvalho 2006-08-18 09:53:32 UTC
Created attachment 134428 [details]
usbmon after patch

Comment 17 Pete Zaitcev 2006-09-16 00:17:11 UTC
I can see now that it was a bad idea. Obviously, when I grab everything that
keyboard has in one go, I get a few events. The idea was that by polling
fast enough we'd get only relevant events. But the broken mouse pushes so
many of them that keys end in the tail of the URB buffer.


Comment 18 Dave Jones 2006-10-16 18:39:22 UTC
A new kernel update has been released (Version: 2.6.18-1.2200.fc5)
based upon a new upstream kernel release.

Please retest against this new kernel, as a large number of patches
go into each upstream release, possibly including changes that
may address this problem.

This bug has been placed in NEEDINFO state.
Due to the large volume of inactive bugs in bugzilla, if this bug is
still in this state in two weeks time, it will be closed.

Should this bug still be relevant after this period, the reporter
can reopen the bug at any time. Any other users on the Cc: list
of this bug can request that the bug be reopened by adding a
comment to the bug.

In the last few updates, some users upgrading from FC4->FC5
have reported that installing a kernel update has left their
systems unbootable. If you have been affected by this problem
please check you only have one version of device-mapper & lvm2
installed.  See bug 207474 for further details.

If this bug is a problem preventing you from installing the
release this version is filed against, please see bug 169613.

If this bug has been fixed, but you are now experiencing a different
problem, please file a separate bug for the new problem.

Thank you.

Comment 19 Nuno Carvalho 2006-10-17 08:49:31 UTC
It seems that this new kernel (Version: 2.6.18-1.2200.fc5) solves the problem,
no more flooding in dmesg.

Comment 20 Pete Zaitcev 2006-10-17 16:00:40 UTC
OK, I'll close for now.