<div dir="ltr"><div>Hi Aleksandar and Dan,</div><div><br></div><div>I'm looking into an issue with MM (built with udev) occasionally failing to find the net port when doing the initial probing of a MBIM modem.  Have you seen something similar before?</div><div><br></div><div>Thanks,</div><div>Ben</div><div><br></div><div>###</div><div><br></div><div><br></div><div>2017-08-17T20:04:35.062308-07:00 INFO kernel: [ 4903.471298] usb 1-3: new high-speed USB device number 14 using xhci-hcd</div><div>2017-08-17T20:04:35.082205-07:00 INFO kernel: [ 4903.495755] usb 1-3: New USB device found, idVendor=12d1, idProduct=15bb</div><div>2017-08-17T20:04:35.082235-07:00 INFO kernel: [ 4903.495768] usb 1-3: New USB device strings: Mfr=6, Product=5, SerialNumber=0</div><div>2017-08-17T20:04:35.082242-07:00 INFO kernel: [ 4903.495776] usb 1-3: Product: HUAWEI Mobile Broadband Module</div><div>2017-08-17T20:04:35.082247-07:00 INFO kernel: [ 4903.495783] usb 1-3: Manufacturer: Huawei Technologies Co., Ltd.</div><div>2017-08-17T20:04:35.092179-07:00 INFO kernel: [ 4903.503156] usb 1-3: MAC-Address: xx:xx:xx:xx:xx:xx</div><div>2017-08-17T20:04:35.092208-07:00 INFO kernel: [ 4903.503542] cdc_ncm 1-3:2.0 usb0: register 'cdc_ncm' at usb-xhci-hcd.0.auto-3, CDC NCM, xx:xx:xx:xx:xx:xx</div><div>2017-08-17T20:04:35.102279-07:00 INFO kernel: [ 4903.516219] cdc_ncm 1-3:2.0 usb0: unregister 'cdc_ncm' usb-xhci-hcd.0.auto-3, CDC NCM</div><div><br></div><div># Switching from USB configuration 2 (NCM) -> USB configuration 3 (MBIM) ...  net/usb0 is removed and then net/wwan0 is added</div><div><br></div><div>2017-08-17T20:04:35.162402-07:00 INFO kernel: [ 4903.573001] cdc_mbim 1-3:3.0: cdc-wdm0: USB WDM device</div><div>2017-08-17T20:04:35.162432-07:00 INFO kernel: [ 4903.574327] cdc_mbim 1-3:3.0 wwan0: register 'cdc_mbim' at usb-xhci-hcd.0.auto-3, CDC MBIM, xx:xx:xx:xx:xx:xx</div><div>2017-08-17T20:04:35.191646-07:00 DEBUG ModemManager[26503]: <debug> (usbmisc/cdc-wdm0): adding device at sysfs path: /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3/1-3:3.0/usbmisc/cdc-wdm0</div><div><br></div><div># cdc-wdm is considered the first port of /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3</div><div><br></div><div>2017-08-17T20:04:35.192518-07:00 DEBUG ModemManager[26503]: <debug> (usbmisc/cdc-wdm0): first port in device /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3</div><div>2017-08-17T20:04:35.192628-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2: new support task for device: /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3</div><div>2017-08-17T20:04:35.192895-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2: port grabbed: cdc-wdm0</div><div>2017-08-17T20:04:35.192916-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: new support task for port</div><div>2017-08-17T20:04:35.192930-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager) task 2,cdc-wdm0: deferred until min wait time elapsed</div><div><br></div><div># This device removal looks suspicious ... I'm guessing it's related to net/usb0 </div><div><br></div><div>2017-08-17T20:04:35.193998-07:00 DEBUG ModemManager[26503]: <debug> Removing device '/sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3'</div><div>2017-08-17T20:04:35.196198-07:00 DEBUG ModemManager[26503]: <debug> (net/wwan0): adding device at sysfs path: /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3/1-3:3.0/net/wwan0</div><div><br></div><div># wwan0 should be considered as an additional port of the same device, but considered the first port..  perhaps related to the device removal above</div><div><br></div><div>2017-08-17T20:04:35.197025-07:00 DEBUG ModemManager[26503]: <debug> (net/wwan0): first port in device /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3</div><div><br></div><div># The following error also looks kind of weird </div><div><br></div><div>2017-08-17T20:04:35.197660-07:00 INFO ModemManager[26503]: <info>  Couldn't check support for device '/sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3': Device support check task already available for device '/sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3'</div><div><br></div><div>2017-08-17T20:04:35.199626-07:00 DEBUG ModemManager[26503]: <debug> (net/usb0): adding device at sysfs path: /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3/1-3:2.0/net/usb0</div><div>2017-08-17T20:04:35.200104-07:00 DEBUG ModemManager[26503]: <debug> (net/usb0): first port in device /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3</div><div>2017-08-17T20:04:35.200446-07:00 DEBUG ModemManager[26503]: <debug> (net/usb0) could not get vendor/product id</div><div>2017-08-17T20:04:35.200540-07:00 DEBUG ModemManager[26503]: <debug> (net/usb0) could not get vendor/product id</div><div>2017-08-17T20:04:35.200912-07:00 INFO ModemManager[26503]: <info>  Couldn't check support for device '/sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3': Device support check task already available for device '/sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3'</div><div>2017-08-17T20:04:36.694918-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2: min wait time elapsed</div><div>2017-08-17T20:04:36.694963-07:00 DEBUG ModemManager[26503]: <debug> (Novatel LTE) [cdc-wdm0] filtered by subsystem</div><div>2017-08-17T20:04:36.694993-07:00 DEBUG ModemManager[26503]: <debug> (Telit) [cdc-wdm0] filtered by vendor/product IDs</div><div>2017-08-17T20:04:36.695019-07:00 DEBUG ModemManager[26503]: <debug> (Samsung) [cdc-wdm0] filtered by subsystem</div><div>2017-08-17T20:04:36.695045-07:00 DEBUG ModemManager[26503]: <debug> (ZTE) [cdc-wdm0] filtered by vendor/product IDs</div><div>2017-08-17T20:04:36.695069-07:00 DEBUG ModemManager[26503]: <debug> (Longcheer) [cdc-wdm0] filtered by subsystem</div><div>2017-08-17T20:04:36.695094-07:00 DEBUG ModemManager[26503]: <debug> (Altair LTE) [cdc-wdm0] filtered by subsystem</div><div>2017-08-17T20:04:36.695128-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: found '2' plugins to try</div><div>2017-08-17T20:04:36.695151-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: will try with plugin 'Huawei'</div><div>2017-08-17T20:04:36.695174-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: will try with plugin 'Generic'</div><div>2017-08-17T20:04:36.695216-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager) task 2,cdc-wdm0: started</div><div>2017-08-17T20:04:36.695867-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: checking with plugin 'Huawei'</div><div>2017-08-17T20:04:36.696037-07:00 DEBUG ModemManager[26503]: <debug> (Huawei) [cdc-wdm0] probe required: 'mbim'</div><div>2017-08-17T20:04:36.696086-07:00 DEBUG ModemManager[26503]: <debug> (usbmisc/cdc-wdm0) launching port probing: 'mbim'</div><div>2017-08-17T20:04:36.696142-07:00 DEBUG ModemManager[26503]: <debug> (usbmisc/cdc-wdm0) probing MBIM...</div><div>2017-08-17T20:04:36.697733-07:00 DEBUG ModemManager[26503]: opening device...</div><div>2017-08-17T20:04:36.698239-07:00 DEBUG ModemManager[26503]: cannot connect to proxy: Could not connect: Connection refused</div><div>2017-08-17T20:04:36.698275-07:00 DEBUG ModemManager[26503]: spawning new mbim-proxy (try 1)...</div><div>2017-08-17T20:04:36.807686-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Read max control message size from descriptors file: 1024</div><div>2017-08-17T20:04:36.808578-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Sent message...#012<<<<<< RAW:#012<<<<<<   length = 88#012<<<<<<   data   = 03:00:00:00:58:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:01:00:00:00:28:00:00:00:0C:00:00:00:1A:00:00:00:1E:00:00:00:2F:00:64:00:65:00:76:00:2F:00:63:00:64:00:63:00:2D:00:77:00:64:00:6D:00:30:00:00:00</div><div>2017-08-17T20:04:36.809129-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Sent message (translated)...#012<<<<<< Header:#012<<<<<<   length      = 88#012<<<<<<   type        = command (0x00000003)#012<<<<<<   transaction = 1#012<<<<<< Fragment header:#012<<<<<<   total   = 1#012<<<<<<   current = 0#012<<<<<< Contents:#012<<<<<<   service = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b)#012<<<<<<   cid     = 'configuration' (0x00000001)#012<<<<<<   type    = 'set' (0x00000001)</div><div>2017-08-17T20:04:37.027805-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Received message...#012>>>>>> RAW:#012>>>>>>   length = 48#012>>>>>>   data   = 03:00:00:80:30:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:00:00:00:00:00:00:00:00</div><div>2017-08-17T20:04:37.027952-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Received message (translated)...#012>>>>>> Header:#012>>>>>>   length      = 48#012>>>>>>   type        = command-done (0x80000003)#012>>>>>>   transaction = 1#012>>>>>> Fragment header:#012>>>>>>   total   = 1#012>>>>>>   current = 0#012>>>>>> Contents:#012>>>>>>   status error = 'None' (0x00000000)#012>>>>>>   service      = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b)#012>>>>>>   cid          = 'configuration' (0x00000001)</div><div>2017-08-17T20:04:37.028108-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Sent message...#012<<<<<< RAW:#012<<<<<<   length = 16#012<<<<<<   data   = 01:00:00:00:10:00:00:00:02:00:00:00:00:04:00:00</div><div>2017-08-17T20:04:37.028178-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Sent message (translated)...#012<<<<<< Header:#012<<<<<<   length      = 16#012<<<<<<   type        = open (0x00000001)#012<<<<<<   transaction = 2#012<<<<<< Contents:#012<<<<<<   max_control_transfer = 1024</div><div>2017-08-17T20:04:37.029093-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Received message...#012>>>>>> RAW:#012>>>>>>   length = 16#012>>>>>>   data   = 01:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00</div><div>2017-08-17T20:04:37.029324-07:00 DEBUG ModemManager[26503]: <debug> (usbmisc/cdc-wdm0) port is MBIM-capable</div><div>2017-08-17T20:04:37.029426-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Sent message...#012<<<<<< RAW:#012<<<<<<   length = 12#012<<<<<<   data   = 02:00:00:00:0C:00:00:00:03:00:00:00</div><div>2017-08-17T20:04:37.029492-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Sent message (translated)...#012<<<<<< Header:#012<<<<<<   length      = 12#012<<<<<<   type        = close (0x00000002)#012<<<<<<   transaction = 3</div><div>2017-08-17T20:04:37.030365-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] Received message...#012>>>>>> RAW:#012>>>>>>   length = 16#012>>>>>>   data   = 02:00:00:80:10:00:00:00:03:00:00:00:00:00:00:00</div><div>2017-08-17T20:04:37.030483-07:00 DEBUG ModemManager[26503]: [/dev/cdc-wdm0] channel destroyed</div><div>2017-08-17T20:04:37.030891-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: found best plugin for port (Huawei)</div><div>2017-08-17T20:04:37.030961-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: finished in '1.838009' seconds</div><div>2017-08-17T20:04:37.031016-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2,cdc-wdm0: found best plugin: Huawei</div><div>2017-08-17T20:04:37.031066-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2: no more ports to probe</div><div>2017-08-17T20:04:37.031115-07:00 DEBUG ModemManager[26503]: <debug> [plugin manager] task 2: finished in '1.838466' seconds</div><div>2017-08-17T20:04:37.031244-07:00 INFO ModemManager[26503]: <info>  [device /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3] creating modem with plugin 'Huawei' and '1' ports</div><div>2017-08-17T20:04:37.031338-07:00 DEBUG ModemManager[26503]: <debug> MBIM-powered Huawei modem found...</div><div>2017-08-17T20:04:37.037442-07:00 DEBUG ModemManager[26503]: <debug> (usbmisc/cdc-wdm0) Port will have AT flags 'none'</div><div>2017-08-17T20:04:37.037618-07:00 DEBUG ModemManager[26503]: <debug> (cdc-wdm0) type 'mbim' claimed by /sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3</div><div>2017-08-17T20:04:37.037892-07:00 DEBUG ModemManager[26503]: <debug> Modem (Huawei) '/sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3' completely disposed</div><div><br></div><div># Seems like wwan0 wasn't probed along with cdc-wdm0, so no net port was found</div><div><br></div><div>2017-08-17T20:04:37.037971-07:00 WARNING ModemManager[26503]: <warn>  Couldn't create modem for device '/sys/devices/soc0/70090000.usb/xhci-hcd.0.auto/usb1/1-3': Failed to find a net port in the MBIM modem</div><div><br></div></div>