<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=us-ascii">
<meta name="Generator" content="Microsoft Word 14 (filtered medium)">
<style><!--
/* Font Definitions */
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:blue;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:purple;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri","sans-serif";
color:windowtext;}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri","sans-serif";}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
</head>
<body lang="EN-US" link="blue" vlink="purple">
<div class="WordSection1">
<p class="MsoNormal">I have been investigating a problem where bcmxcp_usb fails to recover from a USB cable unplug-plug sequence. So far, I have been trying to characterize the conditions which cause the failure. Before I start trying to debug this, I thought
I would ask if this is a known problem and if someone has a solution.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">The configuration is a Westmere platform running Debian 6 with a 2.6.39 kernel with NUT 2.6.4 with a Powerware 5115 UPS connected via USB 1.1. We have many systems that are identically configured and all have this problem.
<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">The reaction of bcmxcp_usb seems to depend on how long the USB cable is unplugged.
<o:p></o:p></p>
<p class="MsoNormal">If the cable is unplugged for only 5 seconds, then communication to the UPS recovers but there are periodic RECONNECT USB DEVICE messages in the syslog.<o:p></o:p></p>
<p class="MsoNormal">If the cable is unplugged for more than 25 seconds, then bcmxcp_usb exits (sometimes) and my software restarts it and then communication to the UPS recovers.<o:p></o:p></p>
<p class="MsoNormal">However, in many cases bcmxcp_usb neither recovers communication to the UPS nor exits. These are easy to reproduce, particularly if the USB cable unplug-plug sequence is repeated more than once. In these cases, there is often nothing
in the syslog from bcmxcp_usb, however the driver does not respond to a PING. In these cases I can kill the bcmxcp_usb process and restart it and then communication to the UPS recovers.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">In all cases, I notice that when the USB cable is plugged back in the kernel assigns it a new USB device number. I suspect that this might have something to do with the failures.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">I believe that these failures are new behavior. These systems have been in production for over 3 years and the USB cable unplug-plug sequence has worked in the past. However, many things have changed recently so I am not willing to say
that this is new bcmxcp_usb behavior (it could be new kernel driver behavior or new libusb behavior).<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Thanks,<o:p></o:p></p>
<p class="MsoNormal">Rich<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">The following is an example syslog that shows the reaction to a 5-second cable pull.<o:p></o:p></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:50:56.616960+00:00 (none) kernel: [ 1157.122391] usb 4-2: USB disconnect, device number 3<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:50:56.818756+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:50:56.818766+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:50:58.819548+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:50:58.819556+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:00.821146+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:00.821154+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:02.821666+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:02.821673+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:03.554410+00:00 (none) kernel: [ 1164.058615] usb 4-2: new low speed USB device number 4 using uhci_hcd<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:04.822084+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:04.822091+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:06.822307+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:06.822315+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:08.822796+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:08.822804+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:10.823378+00:00 (none) bcmxcp_usb[4678]: Warning: excessive comm failures, limiting error reporting<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:10.823385+00:00 (none) bcmxcp_usb[4678]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:10.823389+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:12.824128+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:51:12.826415+00:00 (none) bcmxcp_usb[4678]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:52:47.267635+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:53:21.491630+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:55:33.923723+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:56:47.331749+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T06:57:19.923746+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:01:09.603900+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:02:43.427937+00:00 (none) bcmxcp_usb[4678]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">The following is an example syslog that shows the reaction to a 25-second cable pull.<o:p></o:p></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:15.584954+00:00 (none) kernel: [ 4416.204455] usb 4-2: USB disconnect, device number 4<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:15.952872+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:15.952879+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:17.954857+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:17.954865+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:19.956861+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:19.956869+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:21.957451+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:21.957459+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:23.958350+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:23.958357+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:25.958454+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:25.958461+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:27.959023+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:27.959030+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:29.959933+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:29.959940+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:31.961017+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:31.961024+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:33.963028+00:00 (none) bcmxcp_usb[5083]: Warning: excessive comm failures, limiting error reporting<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:33.963037+00:00 (none) bcmxcp_usb[5083]: Communications with UPS lost: Error executing command<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:33.963041+00:00 (none) bcmxcp_usb[5083]: Short read from UPS<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:35.964370+00:00 (none) bcmxcp_usb[5083]: RECONNECT USB DEVICE<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:35.964378+00:00 (none) bcmxcp_usb[5083]: Fatal error: unusable configuration<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:35.964382+00:00 (none) bcmxcp_usb[5083]: CLOSING<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:45:42.882509+00:00 (none) kernel: [ 4443.501394] usb 4-2: new low speed USB device number 5 using uhci_hcd<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:47:00.885780+00:00 (none) JHELPER[4682]: upsdrvctl start<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-family:"Courier New"">2012-09-06T07:47:04.422380+00:00 (none) bcmxcp_usb[5127]: Startup successful<o:p></o:p></span></p>
</div>
</body>
</html>