Modem suddenly disconnecting?
Dan Williams
dcbw at redhat.com
Mon Dec 9 08:46:45 PST 2013
On Mon, 2013-12-09 at 15:53 +0000, Karoline Haus wrote:
> Actually I have now managed to get debugging logs from modemmanager:
One thing I see is that the firmware you're using is dated [Apr 07 2009
19:00:00], which is a very very early version of the Gobi 2k firmware; I
just helped another user debug a problem last week that was magically
fixed by updating the firmware to a version from 2010. If at all
possible, it would be a great test to get updated firmware for the
module.
For example, you may be able to extract the firmware from the drivers
at:
http://h20565.www2.hp.com/portal/site/hpsc/template.PAGE/public/psi/swdDetails/?cc=us&lang=en&sp4ts.oid=4095879&swItem=ob_95197_1&ac.admitted=1386607259068.876444892.492883150
Dan
>
> ** 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/
>
>
>
> _______________________________________________
> ModemManager-devel mailing list
> ModemManager-devel at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
More information about the ModemManager-devel
mailing list