<div dir="ltr"><div><div><div><div>2014-03-11 18:01 GMT+08:00 Bjørn Mork <<a href="mailto:bjorn@mork.no">bjorn@mork.no</a>>: > Bjørn Mork <<a href="mailto:bjorn@mork.no">bjorn@mork.no</a>> writes: >> szlin <<a href="mailto:lin.sunze@gmail.com">lin.sunze@gmail.com</a>> writes: >> >>>>> #qmicli -d /dev/cdc-wdm0 --get-service-version-info >>>>> [ 79.644073] qmi_wwan 1-1:1.8: nonzero urb status received: -EPIPE >>>>> [10 Mar 2014, 20:22:03] -Warning ** Error reading from istream: Error >>>>> reading from file descriptor: Input/output error >>>>> >>>>> error: couldn't get service version info: Transaction timed out >>>> >>>> Hmm, wonder if that isn't a symptom of a firmware crash maybe? >>> >>> After seeing error message, the system is frozen without any kernel >>> panic/oops msg. >>> (ping is available but other service such like ssh is unavailable) >> >> OK, that sounds like we end up in a busy loop somewhere. Are you testing >> this on a single core system? >> >>> I'll keep trace on communication protocol between module and qmi_wwan. >> >> I'll try to figure out how we can end up looping at this point. It does >> look like it is related to the status endpoint handling, so it is >> probably in the cdc-wdm driver somewhere. We have changed that driver >> somewhat for v3.13, but I don't think any of the changes would fix a bug >> like this. It would still be useful to know if you can recreate the >> problem on v3.13.2 or later, if that is something you easily can do. > > Hmm, looking at the code involved I don't think we have ever changed the > behaviour for EPIPE here. We're reading from the control endpoint, so > there isn't really much we can do about it... According to > > <a href="https://www.mail-archive.com/linux-usb-devel@lists.sourceforge.net/msg36748.html">https://www.mail-archive.com/linux-usb-devel@lists.sourceforge.net/msg36748.html</a> > > the cause is either a transmission error or that the device didn't > understand the command. We never change the command - it' the same read > URB all the time - so I don't see how the device could suddenly not > understand it. Unless something scribbles on the memory, in which case > you are in bigger trouble. > > So I guess we are looking at a transmission error of some sort. > > We should of course deal with that without hanging anything. The output > from qmicli shows that the read terminates with EIO as expected in this > case. The question is where it goes wrong from there. I don't really > know. It looks like we might end up never reading from the device > again, unless we receive another notification, but that should really be > fine in a sense. The device or controller has failed and we don't know > how to get it into a workable state again. But where does it hang? > > I have no other ideas than trying to sprinkle a few debug printk's all > around cdc-wdm.c. At least enable the debug output that's already > there. If you have dynamic debugging, you can do: > > mount -t debugfs none /sys/kernel/debug > echo 'file cdc-wdm.c +fp' > /sys/kernel/debug/dynamic_debug/control > > You should then see at least one "zero length - clearing WDM_READ" > debug message after the error. But since your system fails at this > point, you might want to add more debug messages around the in callback > and read functions first. > I did some experiments according to your suggestion. *First time*: I type "qmicli -d /dev/cdc-wdm0 --nas-get-system-info" I got the following message. </div>drivers/net/usb/usbnet.c:596 [usbnet]unlink_urbs - "unlink urb err, %d\012" drivers/net/usb/usbnet.c:639 [usbnet]usbnet_terminate_urbs - "waited for %d urb completions\012" drivers/net/usb/usbnet.c:518 [usbnet]intr_complete - "intr shutdown, code %d\012" drivers/net/usb/usbnet.c:525 [usbnet]intr_complete - "intr status %d\012" drivers/net/usb/usbnet.c:1325 [usbnet]usbnet_probe - "blacklisted by %s\012" drivers/net/usb/usbnet.c:215 [usbnet]init_status - "status ep%din, %d bytes period %d\012" drivers/net/usb/usbnet.c:730 [usbnet]usbnet_open - "can't open; %d\012" drivers/net/usb/usbnet.c:171 [usbnet]usbnet_get_ethernet_addr - "bad MAC string %d fetch, %d\012" drivers/net/usb/usbnet.c:544 [usbnet]usbnet_pause_rx - "paused rx queue enabled\012" drivers/net/usb/usbnet.c:315 [usbnet]usbnet_defer_kevent - "kevent %d scheduled\012" drivers/net/usb/usbnet.c:332 [usbnet]rx_submit - "no rx skb\012" drivers/net/usb/usbnet.c:362 [usbnet]rx_submit - "device gone\012" drivers/net/usb/usbnet.c:370 [usbnet]rx_submit - "rx submit, %d\012" drivers/net/usb/usbnet.c:377 [usbnet]rx_submit - "rx: stopped\012" drivers/net/usb/usbnet.c:979 [usbnet]kevent - "kevent done, flags = 0x%lx\012" drivers/net/usb/usbnet.c:438 [usbnet]rx_complete - "rx length %d\012" drivers/net/usb/usbnet.c:456 [usbnet]rx_complete - "rx shutdown, code %d\012" drivers/net/usb/usbnet.c:470 [usbnet]rx_complete - "rx throttle %d\012" drivers/net/usb/usbnet.c:486 [usbnet]rx_complete - "rx status %d\012" drivers/net/usb/usbnet.c:500 [usbnet]rx_complete - "no read resubmitted\012" drivers/net/usb/usbnet.c:1069 [usbnet]usbnet_start_xmit - "can't tx_fixup skb\012" drivers/net/usb/usbnet.c:1080 [usbnet]usbnet_start_xmit - "no urb\012" drivers/net/usb/usbnet.c:1128 [usbnet]usbnet_start_xmit - "Delaying transmission for resumption\012" drivers/net/usb/usbnet.c:1142 [usbnet]usbnet_start_xmit - "tx: submit urb err %d\012" drivers/net/usb/usbnet.c:1153 [usbnet]usbnet_start_xmit - "drop, code %d\012" drivers/net/usb/usbnet.c:1162 [usbnet]usbnet_start_xmit - "> tx, len %d, type 0x%x\012" drivers/net/usb/usbnet.c:1017 [usbnet]tx_complete - "tx throttle %d\012" drivers/net/usb/usbnet.c:1023 [usbnet]tx_complete - "tx err %d\012" drivers/net/usb/usbnet.c:239 [usbnet]usbnet_skb_return - "< rx, len %zu, type 0x%x\012" drivers/net/usb/usbnet.c:248 [usbnet]usbnet_skb_return - "netif_rx status %d\012" drivers/net/usb/usbnet.c:411 [usbnet]rx_process - "drop\012" drivers/net/usb/usbnet.c:1193 [usbnet]usbnet_bh - "bogus skb state %d\012" drivers/net/usb/usbnet.c:1227 [usbnet]usbnet_bh - "rxqlen %d --> %d\012" drivers/net/usb/usbnet.c:563 [usbnet]usbnet_resume_rx - "paused rx queue disabled, %d skbs requeued\012" drivers/usb/class/cdc-wdm.c:938 [cdc_wdm]wdm_suspend - "wdm%d_suspend\012" drivers/usb/class/cdc-wdm.c:424 [cdc_wdm]wdm_write - "Tx URB has been submitted index=%d" drivers/usb/class/cdc-wdm.c:928 [cdc_wdm]wdm_disconnect - "%s: %d open files - postponing cleanup\012" drivers/usb/class/cdc-wdm.c:637 [cdc_wdm]wdm_release - "wdm_release: cleanup" drivers/usb/class/cdc-wdm.c:642 [cdc_wdm]wdm_release - "cdc_wdm %s: device gone - cleaning up\012" drivers/usb/class/cdc-wdm.c:836 [cdc_wdm]wdm_probe - "Finding maximum buffer length: %d" drivers/usb/class/cdc-wdm.c:178 [cdc_wdm]wdm_in_callback - "nonzero urb status received: -ENOENT" drivers/usb/class/cdc-wdm.c:182 [cdc_wdm]wdm_in_callback - "nonzero urb status received: -ECONNRESET" drivers/usb/class/cdc-wdm.c:186 [cdc_wdm]wdm_in_callback - "nonzero urb status received: -ESHUTDOWN" drivers/usb/class/cdc-wdm.c:247 [cdc_wdm]wdm_int_callback - "NOTIFY_RESPONSE_AVAILABLE received: index %d len %d" drivers/usb/class/cdc-wdm.c:254 [cdc_wdm]wdm_int_callback - "NOTIFY_NETWORK_CONNECTION %s network" drivers/usb/class/cdc-wdm.c:271 [cdc_wdm]wdm_int_callback - "%s: usb_submit_urb %d" drivers/usb/class/cdc-wdm.c:988 [cdc_wdm]wdm_resume - "wdm%d_resume\012" drivers/net/usb/qmi_wwan.c:183 [qmi_wwan]qmi_wwan_manage_power - "%s() pmcount=%d, on=%d\012" drivers/net/usb/qmi_wwan.c:85 [qmi_wwan]qmi_wwan_bind - "guessing \042control\042 => %s, \042data\042 => this\012" drivers/net/usb/qmi_wwan.c:99 [qmi_wwan]qmi_wwan_bind - "extra CDC header\012" drivers/net/usb/qmi_wwan.c:103 [qmi_wwan]qmi_wwan_bind - "CDC header len %u\012" drivers/net/usb/qmi_wwan.c:109 [qmi_wwan]qmi_wwan_bind - "extra CDC union\012" drivers/net/usb/qmi_wwan.c:113 [qmi_wwan]qmi_wwan_bind - "CDC union len %u\012" drivers/net/usb/qmi_wwan.c:120 [qmi_wwan]qmi_wwan_bind - "extra CDC ether\012" drivers/net/usb/qmi_wwan.c:124 [qmi_wwan]qmi_wwan_bind - "CDC ether len %u\012" *Second time*: Type the same command again, the system is frozen! I also added some debug messages into read function, the result shows it is frozen when I got the read buffer. </div></div> </div>I just got another sierra module - MC7304, which product id is the same as the MC7354. Maybe I could do some experiments to clarify this issue. <div><div><div> > > Bjørn ></div> </div></div></div>