Modem suddenly disconnecting?
Karoline Haus
karolinehaus at yahoo.de
Mon Dec 9 07:53:49 PST 2013
Actually I have now managed to get debugging logs from modemmanager:
** Message: ModemManager (version 0.4) starting...
** Message: Loaded plugin Gobi
** Message: Loaded plugin Nokia
** Message: Loaded plugin Ericsson MBM
** Message: Loaded plugin Sierra
** Message: Loaded plugin Option High-Speed
** Message: Loaded plugin SimTech
** Message: Loaded plugin Huawei
** Message: Loaded plugin Generic
** Message: Loaded plugin Novatel
** Message: Loaded plugin ZTE
** Message: Loaded plugin Longcheer
** Message: Loaded plugin AnyData
** Message: Loaded plugin Option
** Message: Loaded plugin MotoC
** (modem-manager.exec:10057): DEBUG: (tty/ttyS1): port's parent platform driver is not whitelisted
** (modem-manager.exec:10057): DEBUG: (tty/ttyS2): port's parent platform driver is not whitelisted
** (modem-manager.exec:10057): DEBUG: (tty/ttyS3): port's parent platform driver is not whitelisted
** (modem-manager.exec:10057): DEBUG: (tty/ttyS0): could not get port's parent device
** (modem-manager.exec:10057): DEBUG: (net/sit0): could not get port's parent device
** (modem-manager.exec:10057): DEBUG: (net/tun120280): could not get port's parent device
** (modem-manager.exec:10057): DEBUG: (net/tun120285): could not get port's parent device
** (modem-manager.exec:10057): DEBUG: (net/tun120291): could not get port's parent device
** Message: (ttyUSB0) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386603996.308210> (ttyUSB0) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: (ttyUSB0): probe requested by plugin 'Gobi'
** Message: (ttyUSB1) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386603996.308363> (ttyUSB1) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: (ttyUSB1): probe requested by plugin 'Gobi'
** (modem-manager.exec:10057): DEBUG: <1386603996.408713> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386603997.209745> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386603998.11047> (ttyUSB1): <-- 'AT+GCAP<CR><CR><LF>ERROR<CR><LF>'
** (modem-manager.exec:10057): DEBUG: Got failure code 100: Unknown error
** (modem-manager.exec:10057): DEBUG: <1386603998.11265> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386603998.812368> (ttyUSB1): <-- 'AT+GCAP<CR><CR><LF>ERROR<CR><LF>'
** (modem-manager.exec:10057): DEBUG: Got failure code 100: Unknown error
** (modem-manager.exec:10057): DEBUG: <1386603998.812518> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386603999.613695> (ttyUSB1): <-- 'AT+GCAP<CR><CR><LF>ERROR<CR><LF>'
** (modem-manager.exec:10057): DEBUG: Got failure code 100: Unknown error
** (modem-manager.exec:10057): DEBUG: <1386603999.613873> (ttyUSB1): --> 'ATI<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604000.14469> (ttyUSB1): <-- 'ATI<CR><CR><LF>Manufacturer: Qualcomm Incorporated<CR><LF>Model: HP un2420 Mobile Broadband Module<CR><LF>Revision: D1025-STUTABGD-3574 1 [Apr 07 2009 19:00:00]<CR><LF>SVN: 02<CR><LF>IMEI: 359881029347184<CR><LF>+GCAP: +CGSM,+DS,+ES<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604000.14616> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** Message: (ttyUSB1) type primary claimed by /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** Message: (ttyUSB1) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604000.16686> (ttyUSB1) device open count is 1 (open)
** Message: (Gobi): GSM modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 claimed port ttyUSB1
** (modem-manager.exec:10057): DEBUG: Added modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: <1386604000.16960> (ttyUSB1): --> 'AT+CPIN?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604000.26836> (ttyUSB1): <-- 'AT+CPIN?'
** (modem-manager.exec:10057): DEBUG: <1386604000.27256> (ttyUSB1): <-- '<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604000.27891> (ttyUSB1): <-- '<CR><LF>+CPIN: SIM PIN<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604000.28033> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: <1386604000.367700> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604004.370269> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604008.369513> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** Message: (ttyUSB0) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604008.409215> (ttyUSB0) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: <1386604008.409363> (ttyUSB0): --> 00 78 f0 7e
** (modem-manager.exec:10057): DEBUG: <1386604011.369944> (ttyUSB0): --> 00 78 f0 7e
** (modem-manager.exec:10057): DEBUG: <1386604011.415448> (ttyUSB0): <-- 00 41 70 72 20 20 37 20 32 30 30 39 31 38 3a 35 32 3a 31 33 41 70 72 20 30 37 20 32 30 30 39 31 39 3a 30 30 3a 30 30 53 54 55 54 41 42 47 44 00 00 0c 00 00 00 01 b2 df f9 7e
** (modem-manager.exec:10057): DEBUG: <1386604011.415611> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): ignoring port unsupported by physical modem's plugin
** (modem-manager.exec:10057): DEBUG: Exported modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 as /org/freedesktop/ModemManager/Modems/0
** (modem-manager.exec:10057): DEBUG: (/org/freedesktop/ModemManager/Modems/0): data port is ttyUSB1
** Message: (ttyUSB1) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604055.726163> (ttyUSB1) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: <1386604055.726290> (ttyUSB1): --> 'AT+CPIN="1902"<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604055.742711> (ttyUSB1): <-- 'AT+CPIN="1902"<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604055.850823> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604055.850971> (ttyUSB1): --> 'AT+CPIN?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604055.860813> (ttyUSB1): <-- 'AT+CPI'
** (modem-manager.exec:10057): DEBUG: <1386604055.861483> (ttyUSB1): <-- 'N'
** (modem-manager.exec:10057): DEBUG: <1386604055.862481> (ttyUSB1): <-- '?'
** (modem-manager.exec:10057): DEBUG: <1386604055.863268> (ttyUSB1): <-- '<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604055.864477> (ttyUSB1): <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
** Message: Modem /org/freedesktop/ModemManager/Modems/0: unlock no longer required
** (modem-manager.exec:10057): DEBUG: <1386604055.864849> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** Message: (ttyUSB1) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604055.867052> (ttyUSB1) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: <1386604055.867134> Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
** (modem-manager.exec:10057): DEBUG: <1386604055.967450> (ttyUSB1): --> 'ATZ E0 V1<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604055.978477> (ttyUSB1): <-- 'ATZ E0 V1'
** (modem-manager.exec:10057): DEBUG: <1386604055.978611> (ttyUSB1): <-- '<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604055.996782> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604055.996885> (ttyUSB1): --> 'ATE0<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.2504> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.2589> (ttyUSB1): --> 'AT+CMEE=1<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.13531> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.13609> (ttyUSB1): --> 'ATX4 &C1<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.23510> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.23598> (ttyUSB1): --> 'AT+CFUN=1<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.34563> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.34743> (ttyUSB1): --> 'AT+IFC=1,1<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.46692> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.46811> (ttyUSB1): --> 'AT+GMI<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.57923> (ttyUSB1): <-- '<CR><LF>Qualcomm Incorporated<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.58048> (ttyUSB1): --> 'AT+GMM<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.68151> (ttyUSB1): <-- '<CR><LF>HP un2420 Mobile Broadband Module<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.68288> (ttyUSB1): --> 'AT+GMR<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.75978> (ttyUSB1): <-- '<CR><LF>D1025-STUTABGD-3574 1 [Apr 07 2009 19:00:00]<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.76082> (ttyUSB1): --> 'AT+CGMI<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.87585> (ttyUSB1): <-- '<CR><LF>Qualcomm Incorporated<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.87699> (ttyUSB1): --> 'AT+CGMM<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.111224> (ttyUSB1): <-- '<CR><LF>HP un2420 Mobile Broadband Module<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.111339> (ttyUSB1): --> 'AT+CGMR<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.120106> (ttyUSB1): <-- '<CR><LF>D1025-STUTABGD-3574 1 [Apr 07 2009 19:00:00]<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.120221> (ttyUSB1): --> 'AT+CSCS=?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.131202> (ttyUSB1): <-- '<CR><LF>+CSCS: ("IRA","GSM","UCS2")<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.131428> (ttyUSB1): --> 'AT+CSCS="UCS2"<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.151066> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.151171> (ttyUSB1): --> 'AT+CSCS?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.161071> (ttyUSB1): <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.161228> Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
Here the modem has been unlocked, the PIN has been sent, and the modem is now enabled.
Now some AT commands follow, and then you can see that the modem suddenly disconnects.
** (modem-manager.exec:10057): DEBUG: <1386604056.161485> (ttyUSB1): --> 'AT+CREG=2<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.172414> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.172504> (ttyUSB1): --> 'AT+CREG?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.182373> (ttyUSB1): <-- '<CR><LF>+CREG: 2,0<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.182502> (ttyUSB1): --> 'AT+CGREG=2<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.194591> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604056.194677> (ttyUSB1): --> 'AT+CGREG?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604056.205682> (ttyUSB1): <-- '<CR><LF>+CGREG: 2,0<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604059.985766> (ttyUSB1) device open count is 0 (close)
BOOM, here the device is being closed. I guess the AT commands must have caused this? Any ideas?
** Message: (ttyUSB1) closing serial device...
** (modem-manager.exec:10057): DEBUG: <1386604059.990265> Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> disabled)
** (modem-manager.exec:10057): DEBUG: Removed modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** Message: (ttyUSB0) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604061.829359> (ttyUSB0) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: (ttyUSB0): probe requested by plugin 'Gobi'
** (modem-manager.exec:10057): DEBUG: <1386604061.929710> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604065.873876> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** (modem-manager.exec:10057): CRITICAL **: mm_serial_port_close: assertion `priv->open_count > 0' failed
** Message: (ttyUSB0) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604066.180543> (ttyUSB0) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: (ttyUSB0): probe requested by plugin 'Gobi'
** Message: (ttyUSB1) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604066.180694> (ttyUSB1) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: (ttyUSB1): probe requested by plugin 'Gobi'
** (modem-manager.exec:10057): DEBUG: <1386604066.281043> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604068.83331> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604068.884476> (ttyUSB1): <-- 'AT+GCAP<CR><CR><LF>ERROR<CR><LF>'
** (modem-manager.exec:10057): DEBUG: Got failure code 100: Unknown error
** (modem-manager.exec:10057): DEBUG: <1386604068.884706> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604069.685969> (ttyUSB1): <-- 'AT+GCAP<CR><CR><LF>ERROR<CR><LF>'
** (modem-manager.exec:10057): DEBUG: Got failure code 100: Unknown error
** (modem-manager.exec:10057): DEBUG: <1386604069.686161> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604070.487166> (ttyUSB1): <-- 'AT+GCAP<CR><CR><LF>ERROR<CR><LF>'
** (modem-manager.exec:10057): DEBUG: Got failure code 100: Unknown error
** (modem-manager.exec:10057): DEBUG: <1386604070.487394> (ttyUSB1): --> 'ATI<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604070.888096> (ttyUSB1): <-- 'ATI<CR><CR><LF>Manufacturer: Qualcomm Incorporated<CR><LF>Model: HP un2420 Mobile Broadband Module<CR><LF>Revision: D1025-STUTABGD-3574 1 [Apr 07 2009 19:00:00]<CR><LF>SVN: 02<CR><LF>IMEI: 359881029347184<CR><LF>+GCAP: +CGSM,+DS,+ES<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604070.888281> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** Message: (ttyUSB1) type primary claimed by /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** Message: (ttyUSB1) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604070.889671> (ttyUSB1) device open count is 1 (open)
** Message: (Gobi): GSM modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 claimed port ttyUSB1
** (modem-manager.exec:10057): DEBUG: Added modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: <1386604070.889938> (ttyUSB1): --> 'AT+CPIN?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604070.899768> (ttyUSB1): <-- 'AT+CPIN?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604070.900311> (ttyUSB1): <-- '<CR><LF>+CME ERROR: SIM busy<CR><LF>'
** (modem-manager.exec:10057): DEBUG: Got failure code 14: SIM busy
** (modem-manager.exec:10057): DEBUG: <1386604071.367163> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604073.367737> (ttyUSB1): --> 'AT+CPIN?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604073.377724> (ttyUSB1): <-- 'AT+CPIN?<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604073.378516> (ttyUSB1): <-- '<CR><LF>+CPIN: SIM PIN<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager.exec:10057): DEBUG: <1386604073.378681> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2
** (modem-manager.exec:10057): DEBUG: <1386604075.368644> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager.exec:10057): DEBUG: <1386604079.370094> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** Message: (ttyUSB0) opening serial device...
** (modem-manager.exec:10057): DEBUG: <1386604079.410074> (ttyUSB0) device open count is 1 (open)
** (modem-manager.exec:10057): DEBUG: <1386604079.410184> (ttyUSB0): --> 00 78 f0 7e
** (modem-manager.exec:10057): DEBUG: <1386604082.369506> (ttyUSB0): --> 00 78 f0 7e
** (modem-manager.exec:10057): DEBUG: <1386604082.413770> (ttyUSB0): <-- 00 41 70 72 20 20 37 20 32 30 30 39 31 38 3a 35 32 3a 31 33 41 70 72 20 30 37 20 32 30 30 39 31 39 3a 30 30 3a 30 30 53 54 55 54 41 42 47 44 00 00 0c 00 00 00 01 b2 df f9 7e
** (modem-manager.exec:10057): DEBUG: <1386604082.413876> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** (modem-manager.exec:10057): DEBUG: (tty/ttyUSB0): ignoring port unsupported by physical modem's plugin
** (modem-manager.exec:10057): DEBUG: Exported modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 as /org/freedesktop/ModemManager/Modems/1
** (modem-manager.exec:10057): DEBUG: (/org/freedesktop/ModemManager/Modems/1): data port is ttyUSB1
Karoline Haus <karolinehaus at yahoo.de> schrieb am 16:28 Montag, 9.Dezember 2013:
Hi Aleksander,
No, I cannot update modemmanager to a newer version for now. My system is restricted with what packages I can load/install.
What I can see here from the logs, it looks like after NetworkManager has enabled WWAN support, the driver does a reset and then reports "firmware changed". See below. Anyone ever seen this?
Unfortunately I cannot get any debugging from modemmanager, because when I kill the process as explained in your Wiki, then automatically a new process modemmanger is started without me being able to start it manually with --debugging enabled.
Thanks for any further advice.
Karoline
Dec 09 16:18:13 [modem-manager] (ttyUSB1) opening serial device...
Dec 09 16:18:13 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: unlock no longer required
Dec 09 16:18:13 [modem-manager] (ttyUSB1) closing serial device...
Dec 09 16:18:13 [modem-manager] (ttyUSB1) opening serial device...
Dec 09 16:18:13 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
Dec 09 16:18:13 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
Dec 09 16:18:13 [NetworkManager] <info> WWAN now enabled by management service
Dec 09 16:18:17 [kernel] [
351.895517] usb 1-1.2: reset high-speed USB device number 4 using ehci_hcd
Dec 09 16:18:17 [kernel] [ 351.981628] usb 1-1.2: device firmware changed
Dec 09 16:18:17 [modem-manager] (ttyUSB1) closing serial device...
Dec 09 16:18:17 [kernel] [ 351.982068] usb 1-1.2: USB disconnect, device number 4
Dec 09 16:18:17 [kernel] [ 351.982279] qcserial ttyUSB0: Qualcomm USB modem converter now disconnected from ttyUSB0
Dec 09 16:18:17 [kernel] [ 351.982310] qcserial 1-1.2:1.1: device disconnected
Dec 09 16:18:17 [kernel] [ 351.982494] qcserial ttyUSB1: Qualcomm USB modem converter now disconnected from ttyUSB1
Dec 09 16:18:17 [kernel] [ 351.982513] qcserial 1-1.2:1.2: device disconnected
Dec 09 16:18:17 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> disabled)
Dec 09 16:18:17 [NetworkManager] <info> (ttyUSB1): now unmanaged
Dec 09 16:18:17
[NetworkManager] <info> (ttyUSB1): device state change: 3 -> 1 (reason 36)
Dec 09 16:18:17 [NetworkManager] <info> (ttyUSB1): cleaning up...
Dec 09 16:18:17 [NetworkManager] <info> (ttyUSB1): taking down device.
Aleksander Morgado <aleksander at lanedo.com> schrieb am 12:41 Montag, 9.Dezember 2013:
Hey Karoline,
> Hi I'm using modemmanager-0.4 and I've got a problem trying to use my
> integrated HP broadband modem.
>
> Here the
logs and a description of the problem:
>
> ModemManager and NetworkManager detect my modem OK.
>
> Dec 06 10:43:09 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:43:09 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:43:12 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:43:12 [NetworkManager] <warn> (ttyUSB1): failed to look up
> interface index
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): new GSM device
> (driver: 'qcserial' ifindex: -1)
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): exported as
> /org/freedesktop/NetworkManager/Devices/2
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): now managed
> Dec
06 10:43:12 [NetworkManager] <info> (ttyUSB1): device state change:
> 1 -> 2 (reason 2)
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): deactivating device
> (reason: 2).
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): device state change:
> 2 -> 3 (reason 0)
> Dec 06 10:43:54 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:43:54 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: unlock no longer required
> Dec 06 10:43:54 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:43:54 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:43:54 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
> Dec 06 10:43:54 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
> Dec 06 10:43:54 [NetworkManager] <info> WWAN now enabled by management
> service
>
> At this point I have programmatically enabled and unlocked the modem by
> sending sendPin() and enable() to the modem via DBUS.
> But then, suddenly I get a disconnect from the USB modem. I don't
> understand why this happens, and I don't do anything programmatically
> here other than requesting modem information (manufacturer, network
> registration).
>
> Dec 06 10:43:58 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:43:58 [kernel] [ 90.892492] usb 1-1.2: USB
disconnect,
> device number 4
> Dec 06 10:43:58 [kernel] [ 90.892658] qcserial ttyUSB0: Qualcomm USB
> modem converter now disconnected from ttyUSB0
> Dec 06 10:43:58 [kernel] [ 90.892676] qcserial 1-1.2:1.1: device
> disconnected
> Dec 06 10:43:58 [kernel] [ 90.892807] qcserial ttyUSB1: Qualcomm USB
> modem converter now disconnected from ttyUSB1
> Dec 06 10:43:58 [kernel] [ 90.892819] qcserial 1-1.2:1.2: device
> disconnected
> Dec 06 10:43:58 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> disabled)
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): now unmanaged
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): device
state change:
> 3 -> 1 (reason 36)
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): cleaning up...
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): taking down device.
>
> At this point the modem is down and disappeared from ModemManager.
> Then it shows up again as a new USB device.
>
> Dec 06 10:43:59 [kernel] [ 91.323911] usb 1-1.2: new high-speed USB
> device number 8 using ehci_hcd
> Dec 06 10:43:59 [kernel] [ 91.412677] usb 1-1.2: config 1 has an
> invalid interface number: 1 but max is 0
> Dec 06 10:43:59 [kernel] [ 91.412683] usb 1-1.2: config 1 has no
> interface number 0
> Dec 06 10:43:59 [kernel] [ 91.414620] usb 1-1.2: New USB
device found,
> idVendor=03f0, idProduct=241d
> Dec 06 10:43:59 [kernel] [ 91.414626] usb 1-1.2: New USB device
> strings: Mfr=3, Product=2, SerialNumber=0
> Dec 06 10:43:59 [kernel] [ 91.414630] usb 1-1.2: Product: HP un2420
> Mobile Broadband Module
> Dec 06 10:43:59 [kernel] [ 91.414634] usb 1-1.2: Manufacturer:
> Qualcomm Incorporated
> Dec 06 10:43:59 [kernel] [ 91.416325] qcserial 1-1.2:1.1: Qualcomm USB
> modem converter detected
> Dec 06 10:43:59 [kernel] [ 91.416443] usb 1-1.2: Qualcomm USB modem
> converter now attached to ttyUSB0
> Dec 06 10:44:00 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:44:04 [modem-manager] (ttyUSB0) closing serial
device...
> Dec 06 10:44:04 [kernel] [ 96.254729] usb 1-1.2: USB disconnect,
> device number 8
> Dec 06 10:44:04 [kernel] [ 96.254856] qcserial ttyUSB0: Qualcomm USB
> modem converter now disconnected from ttyUSB0
> Dec 06 10:44:04 [kernel] [ 96.254873] qcserial 1-1.2:1.1: device
> disconnected
> Dec 06 10:44:04 [modem-manager] mm_serial_port_close: assertion
> `priv->open_count > 0' failed
> Dec 06 10:44:04 [kernel] [ 96.431980] usb 1-1.2: new high-speed USB
> device number 9 using ehci_hcd
> Dec 06 10:44:04 [kernel] [ 96.529939] usb 1-1.2: New USB device found,
> idVendor=03f0, idProduct=251d
> Dec 06 10:44:04 [kernel] [ 96.529945] usb 1-1.2: New USB device
> strings: Mfr=4, Product=3, SerialNumber=0
> Dec 06 10:44:04 [kernel] [ 96.529949] usb 1-1.2: Product: HP un2420
> Mobile Broadband Module
> Dec 06 10:44:04 [kernel] [ 96.529953] usb 1-1.2: Manufacturer:
> Qualcomm Incorporated
> Dec 06 10:44:04 [kernel] [ 96.534212] qcserial 1-1.2:1.1: Qualcomm USB
> modem converter detected
> Dec 06 10:44:04 [kernel] [ 96.534294] usb 1-1.2: Qualcomm USB modem
> converter now attached to ttyUSB0
> Dec 06 10:44:04 [kernel] [ 96.535342] qcserial 1-1.2:1.2: Qualcomm USB
> modem converter detected
> Dec 06 10:44:04 [kernel] [ 96.535419] usb 1-1.2: Qualcomm USB modem
> converter now attached to ttyUSB1
>
> Here ModemManager then detects a new device (the same modem!!) and
> registeres as a new modem device under a different DBUS path than
> previously (even though still the same device).
>
> Dec 06 10:44:04 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:44:04 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:44:08 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:44:08 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:44:08 [modem-manager] (Gobi): GSM modem
> /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 claimed port ttyUSB1
> Dec 06 10:44:08 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:44:17 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:44:17 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:44:20 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:44:20 [NetworkManager] <warn> (ttyUSB1): failed to look up
> interface index
> Dec 06 10:44:20 [NetworkManager] <info> WWAN now disabled by management
> service
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): new GSM device
> (driver: 'qcserial' ifindex: -1)
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): exported as
> /org/freedesktop/NetworkManager/Devices/3
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): now managed
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): device state change:
> 1 -> 2 (reason 2)
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): deactivating device
> (reason: 2).
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): device state change:
> 2 -> 3 (reason 0)
>
> Anyone got any idea why this happens and how I can further debug the
> problem?
>
0.4 is a really really old version. Aren't you able to upgrade it to
something newer, like 0.6.x at least? Of course 1.0.x with libqmi
support would be much better anyway, as I see it's a Gobi device.
Anyway, there's little we can do without debug logs from ModemManager.
You can probably follow the instructions here, but I'm not sure whether
they apply to MM 0.4:
https://wiki.gnome.org/Projects/NetworkManager/Debugging
If you're really into trying MM 1.0, use these ones:
http://www.freedesktop.org/wiki/Software/ModemManager/Debugging/
--
Aleksander
_______________________________________________
ModemManager-devel mailing list
ModemManager-devel at lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
_______________________________________________
ModemManager-devel mailing list
ModemManager-devel at lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/modemmanager-devel/attachments/20131209/ddf2a9a9/attachment-0001.html>
More information about the ModemManager-devel
mailing list