Bug 617989

Summary:	[usb-storage] Huawei E220 3G modem crashes accessing storage while PPP is active
Product:	[Fedora] Fedora	Reporter:	yunus <yunus.tji.nyan>
Component:	kernel	Assignee:	Pete Zaitcev <zaitcev>
Status:	CLOSED WORKSFORME	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	high	Docs Contact:
Priority:	low
Version:	13	CC:	anton, dcbw, dougsland, gansalmon, itamar, jonathan, kernel-maint, madhu.chinakonda, tomspur
Target Milestone:	---
Target Release:	---
Hardware:	x86_64
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2010-10-03 03:09:10 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description yunus 2010-07-25 13:17:06 UTC

Description of problem:
Huawei E220 connection become intermittent when I plug and unplug USB Flashdisk

Version-Release number of selected component (if applicable):
ModemManager-0.4-4.git20100720.fc13.x86_64


How reproducible:


Steps to Reproduce:
1. Making connection using NM applet
2. Plug in USB Flashdisk
3. Unplug USB Flashdisk
  
Actual results:
Connection become intermittent

Expected results:
It should be no problem when I plug in USB Flashdisk and unplug USB Flashdisk

Additional info:
I reboot the system to be able to make connection again.

Comment 1 yunus 2010-07-25 13:43:31 UTC

[root@localhost tj]# service NetworkManager stop
Stopping NetworkManager daemon:                            [  OK  ]
[root@localhost tj]# killall -TERM modem-manager
[root@localhost tj]# gdb /usr/sbin/modem-manager
GNU gdb (GDB) Fedora (7.1-30.fc13)
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/modem-manager...(no debugging symbols found)...done.
Missing separate debuginfos, use: debuginfo-install ModemManager-0.4-4.git20100720.fc13.x86_64
(gdb) run --debug
Starting program: /usr/sbin/modem-manager --debug
[Thread debugging using libthread_db enabled]
** Message: ModemManager (version 0.4-4.git20100720.fc13) starting...
** Message: Loaded plugin AnyData
** Message: Loaded plugin Ericsson MBM
** Message: Loaded plugin Generic
** Message: Loaded plugin Longcheer
** Message: Loaded plugin Nokia
** Message: Loaded plugin Option
** Message: Loaded plugin SimTech
** Message: Loaded plugin ZTE
** Message: Loaded plugin Gobi
** Message: Loaded plugin MotoC
** Message: Loaded plugin Option High-Speed
** Message: Loaded plugin Sierra
** Message: Loaded plugin Novatel
** Message: Loaded plugin Huawei
** (modem-manager:2657): DEBUG: (tty/ttyS1): port's parent platform driver is not whitelisted
** (modem-manager:2657): DEBUG: (tty/ttyS2): port's parent platform driver is not whitelisted
** (modem-manager:2657): DEBUG: (tty/ttyS3): port's parent platform driver is not whitelisted
** (modem-manager:2657): DEBUG: (tty/ttyS0): could not get port's parent device
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB1) deferring support check
** Message: (ttyUSB0) opening serial device...
** (modem-manager:2657): DEBUG: <1280064478.194820> (ttyUSB0) device open count is 1 (open)
** (modem-manager:2657): DEBUG: (ttyUSB0): probe requested by plugin 'Huawei'
** (modem-manager:2657): DEBUG: <1280064478.295888> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: <1280064479.97225> (ttyUSB0): <-- 'AT+GCAP<CR><CR><LF>+GCAP: +CGSM,+DS,+ES<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064479.97410> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** Message: (ttyUSB0) type primary claimed by /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** Message: (ttyUSB0) opening serial device...
** (modem-manager:2657): DEBUG: <1280064479.106832> (ttyUSB0) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064479.106912> (ttyUSB0) device open count is 2 (open)
** Message: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 claimed port ttyUSB0
** (modem-manager:2657): DEBUG: Added modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: (tty/ttyUSB1): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064479.107482> (ttyUSB0): --> 'AT+CPIN?<CR>'
** (modem-manager:2657): DEBUG: <1280064479.117731> (ttyUSB0): <-- 'AT+CPIN?'
** (modem-manager:2657): DEBUG: <1280064479.117873> (ttyUSB0): <-- '<CR>'
** (modem-manager:2657): DEBUG: <1280064479.118979> (ttyUSB0): <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064479.119101> (ttyUSB0) device open count is 1 (close)
** (modem-manager:2657): DEBUG: (tty/ttyUSB1): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064479.119270> (ttyUSB0): --> 'ATE0<CR>'
** (modem-manager:2657): DEBUG: <1280064479.124950> (ttyUSB0): <-- 'ATE0<CR>'
** (modem-manager:2657): DEBUG: <1280064479.126026> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064479.126156> (ttyUSB0): --> 'AT+CGSN<CR>'
** (modem-manager:2657): DEBUG: <1280064479.137982> (ttyUSB0): <-- '<CR><LF>358192013098036<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064479.138176> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** (modem-manager:2657): DEBUG: (ttyUSB1): re-checking support...
** Message: (ttyUSB1) opening serial device...
** (modem-manager:2657): DEBUG: <1280064481.194963> (ttyUSB1) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064488.81019> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** Message: (ttyUSB1) type ignored claimed by /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** Message: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 claimed port ttyUSB1
** (modem-manager:2657): DEBUG: Exported modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 as /org/freedesktop/ModemManager/Modems/0
** (modem-manager:2657): DEBUG: (/org/freedesktop/ModemManager/Modems/0): data port is ttyUSB0
** Message: (ttyUSB0) opening serial device...
** (modem-manager:2657): DEBUG: <1280064488.150933> (ttyUSB0) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064488.151034> Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
** (modem-manager:2657): DEBUG: <1280064488.252080> (ttyUSB0): --> 'ATZ E0 V1<CR>'
** (modem-manager:2657): DEBUG: <1280064488.285111> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.285389> (ttyUSB0): --> 'ATE0<CR>'
** (modem-manager:2657): DEBUG: <1280064488.292030> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.292149> (ttyUSB0): --> 'AT+CMEE=1<CR>'
** (modem-manager:2657): DEBUG: <1280064488.308018> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.308164> (ttyUSB0): --> 'ATX4 &C1<CR>'
** (modem-manager:2657): DEBUG: <1280064488.319012> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.319122> (ttyUSB0): --> 'AT+CFUN=1<CR>'
** (modem-manager:2657): DEBUG: <1280064488.336638> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.336850> (ttyUSB0): --> 'AT+IFC=1,1<CR>'
** (modem-manager:2657): DEBUG: <1280064488.352095> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.352299> (ttyUSB0): --> 'AT+GMI<CR>'
** (modem-manager:2657): DEBUG: <1280064488.362013> (ttyUSB0): <-- '<CR><LF>huawei<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.362161> (ttyUSB0): --> 'AT+GMM<CR>'
** (modem-manager:2657): DEBUG: <1280064488.372011> (ttyUSB0): <-- '<CR><LF>E220<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.372146> (ttyUSB0): --> 'AT+GMR<CR>'
** (modem-manager:2657): DEBUG: <1280064488.381001> (ttyUSB0): <-- '<CR><LF>11.116.05.00.00<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.381105> (ttyUSB0): --> 'AT+CGMI<CR>'
** (modem-manager:2657): DEBUG: <1280064488.392015> (ttyUSB0): <-- '<CR><LF>huawei<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.392179> (ttyUSB0): --> 'AT+CGMM<CR>'
** (modem-manager:2657): DEBUG: <1280064488.403015> (ttyUSB0): <-- '<CR><LF>E220<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.403160> (ttyUSB0): --> 'AT+CGMR<CR>'
** (modem-manager:2657): DEBUG: <1280064488.416005> (ttyUSB0): <-- '<CR><LF>11.116.05.00.00<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.416124> (ttyUSB0): --> 'AT^SYSCFG?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.432063> (ttyUSB0): <-- '<CR><LF>^SYSCFG:14,2,3FFFFFFF,1,2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.432326> (ttyUSB0): --> 'AT+CSCS=?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.445048> (ttyUSB0): <-- '<CR><LF>+CSCS: ("IRA","GSM","UCS2")<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.445353> (ttyUSB0): --> 'AT+CSCS="UCS2"<CR>'
** (modem-manager:2657): DEBUG: <1280064488.463975> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.464110> (ttyUSB0): --> 'AT+CSCS?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.475046> (ttyUSB0): <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.475290> Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
** (modem-manager:2657): DEBUG: <1280064488.475532> (ttyUSB0): --> 'AT+CREG=2<CR>'
** (modem-manager:2657): DEBUG: <1280064488.489983> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.490350> (ttyUSB0): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064488.499038> (ttyUSB0): <-- '<CR><LF>+CSQ: 7,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.499340> (ttyUSB0): --> 'AT+CREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.510035> (ttyUSB0): <-- '<CR><LF>+CREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: CS registration state changed: 1
** (modem-manager:2657): DEBUG: <1280064488.510253> Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> registered)
** (modem-manager:2657): DEBUG: <1280064488.510364> (ttyUSB0): --> 'AT+CGREG=2<CR>'
** (modem-manager:2657): DEBUG: <1280064488.526038> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.526263> (ttyUSB0): --> 'AT+COPS=3,2;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.549096> (ttyUSB0): <-- '<CR><LF>+COPS: 0,2,"51010",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.549453> (ttyUSB0): --> 'AT+COPS=3,0;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.611395> (ttyUSB0): network_mode => 8
** (modem-manager:2657): DEBUG: <1280064488.611395> (ttyUSB0): allowed_mode => 4
** (modem-manager:2657): DEBUG: <1280064488.611395> (ttyUSB0): number => "*99#"
** (modem-manager:2657): DEBUG: <1280064488.611395> (ttyUSB0): apn => "internet"
** (modem-manager:2657): DEBUG: <1280064488.611558> (ttyUSB0): simple connect state 0
** (modem-manager:2657): DEBUG: <1280064488.611636> (ttyUSB0): simple connect state 2
** (modem-manager:2657): DEBUG: <1280064488.668014> (ttyUSB0): <-- '<CR><LF>+COPS: 0,0,"IND TELKOMSEL",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.668340> (ttyUSB0): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064488.677979> (ttyUSB0): <-- '<CR><LF>+CSQ: 7,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.678129> (ttyUSB0): --> 'AT^SYSINFO<CR>'
** (modem-manager:2657): DEBUG: <1280064488.691968> (ttyUSB0): <-- '<CR><LF>^SYSINFO:2,3,0,5,1,0,4<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.692318> (ttyUSB0): --> 'AT+CGREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.705151> (ttyUSB0): <-- '<CR><LF>+CGREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: PS registration state changed: 1
** (modem-manager:2657): DEBUG: <1280064488.705408> (ttyUSB0): --> 'AT+CREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.717983> (ttyUSB0): <-- '<CR><LF>+CREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.718142> (ttyUSB0): simple connect state 4
** (modem-manager:2657): DEBUG: <1280064488.718197> (ttyUSB0): --> 'AT+COPS=3,2;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.740018> (ttyUSB0): <-- '<CR><LF>+COPS: 0,2,"51010",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.740190> (ttyUSB0): --> 'AT+COPS=3,0;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.763099> (ttyUSB0): <-- '<CR><LF>+COPS: 0,0,"IND TELKOMSEL",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.763328> (ttyUSB0): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064488.773030> (ttyUSB0): <-- '<CR><LF>+CSQ: 7,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.773208> (ttyUSB0): --> 'AT^SYSINFO<CR>'
** (modem-manager:2657): DEBUG: <1280064488.788216> (ttyUSB0): <-- '<CR><LF>^SYSINFO:2,3,0,5,1,0,4<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.788399> (ttyUSB0): --> 'AT+CGDCONT?<CR>'
** (modem-manager:2657): DEBUG: <1280064488.807076> (ttyUSB0): <-- '<CR><LF>+CGDCONT: 1,"IP","internet","0.0.0.0",0,0<CR><LF>+CGDCONT: 2,"IP","telkomsel","0.0.0.0",0,0<CR><LF>+CGDCONT: 3,"IP","internet","0.0.0.0",0,0<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.807313> (ttyUSB0): simple connect state 5
** (modem-manager:2657): DEBUG: <1280064488.807406> Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered -> connecting)
** (modem-manager:2657): DEBUG: <1280064488.807487> (ttyUSB0): --> 'ATD*99***1#<CR>'
** (modem-manager:2657): DEBUG: <1280064488.825109> (ttyUSB0): <-- '<CR><LF>CONNECT 7200000<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064488.825283> (ttyUSB0): port now connected
** (modem-manager:2657): DEBUG: <1280064488.825360> Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting -> connected)
** (modem-manager:2657): DEBUG: <1280064488.825438> (ttyUSB0): simple connect state 6
** (modem-manager:2657): DEBUG: (net/ppp0): could not get port's parent device
** (modem-manager:2657): DEBUG: <1280064495.387705> Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> disabled)
** (modem-manager:2657): DEBUG: Removed modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064495.387914> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** (modem-manager:2657): DEBUG: <1280064495.387967> (ttyUSB0): port now disconnected
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB0) deferring support check
** Message: (ttyUSB1) opening serial device...
** (modem-manager:2657): DEBUG: <1280064496.31114> (ttyUSB1) device open count is 1 (open)
** (modem-manager:2657): DEBUG: (ttyUSB1): probe requested by plugin 'Huawei'
** (modem-manager:2657): DEBUG: <1280064496.31306> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...

** (modem-manager:2657): CRITICAL **: mm_serial_port_close: assertion `priv->open_count > 0' failed
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB1) deferring support check
** Message: (ttyUSB0) opening serial device...
** (modem-manager:2657): DEBUG: <1280064512.921301> (ttyUSB0) device open count is 1 (open)
** (modem-manager:2657): DEBUG: (ttyUSB0): probe requested by plugin 'Huawei'
** (modem-manager:2657): DEBUG: <1280064513.23380> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: <1280064513.824601> (ttyUSB0): <-- 'AT+GCAP<CR><CR><LF>+CME ERROR: SIM busy<CR><LF>'
** (modem-manager:2657): DEBUG: Got failure code 14: SIM busy
** (modem-manager:2657): DEBUG: <1280064513.824813> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: <1280064514.626013> (ttyUSB0): <-- 'AT+GCAP<CR><CR><LF>+CME ERROR: SIM busy<CR><LF>'
** (modem-manager:2657): DEBUG: Got failure code 14: SIM busy
** (modem-manager:2657): DEBUG: <1280064514.626229> (ttyUSB0): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: <1280064515.427317> (ttyUSB0): <-- 'AT+GCAP<CR><CR><LF>+CME ERROR: SIM busy<CR><LF>'
** (modem-manager:2657): DEBUG: Got failure code 14: SIM busy
** (modem-manager:2657): DEBUG: <1280064515.427539> (ttyUSB0): --> 'ATI<CR>'
** (modem-manager:2657): DEBUG: <1280064515.828159> (ttyUSB0): <-- 'ATI<CR><CR><LF>Manufacturer: huawei<CR><LF>Model: E220<CR><LF>Revision: 11.116.05.00.00<CR><LF>IMEI: 358192013098036<CR><LF>+GCAP: +CGSM,+DS,+ES<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064515.828333> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** Message: (ttyUSB0) type primary claimed by /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** Message: (ttyUSB0) opening serial device...
** (modem-manager:2657): DEBUG: <1280064515.838339> (ttyUSB0) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064515.838443> (ttyUSB0) device open count is 2 (open)
** Message: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 claimed port ttyUSB0
** (modem-manager:2657): DEBUG: Added modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: (tty/ttyUSB1): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064515.838951> (ttyUSB0): --> 'AT+CPIN?<CR>'
** (modem-manager:2657): DEBUG: <1280064515.849030> (ttyUSB0): <-- 'AT+CPIN'
** (modem-manager:2657): DEBUG: <1280064515.850972> (ttyUSB0): <-- '?<CR><CR><LF>+CME ERROR: SIM busy<CR><LF>'
** (modem-manager:2657): DEBUG: Got failure code 14: SIM busy
** (modem-manager:2657): DEBUG: <1280064515.851153> (ttyUSB0): --> 'ATE0<CR>'
** (modem-manager:2657): DEBUG: <1280064515.856732> (ttyUSB0): <-- 'ATE0'
** (modem-manager:2657): DEBUG: <1280064515.858311> (ttyUSB0): <-- '<CR><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064515.858433> (ttyUSB0): --> 'AT+CGSN<CR>'
** (modem-manager:2657): DEBUG: <1280064515.870988> (ttyUSB0): <-- '<CR><LF>358192013098036<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064515.871189> (ttyUSB0) device open count is 1 (close)
** (modem-manager:2657): DEBUG: (ttyUSB1): re-checking support...
** Message: (ttyUSB1) opening serial device...
** (modem-manager:2657): DEBUG: <1280064515.921367> (ttyUSB1) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064516.956037> (ttyUSB1): <-- '<CR><LF>^SIMST:1,0<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064516.958027> (ttyUSB1): <-- '<CR><LF>^SRVST:2<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064518.80932> (ttyUSB0): --> 'AT+CPIN?<CR>'
** (modem-manager:2657): DEBUG: <1280064518.92984> (ttyUSB0): <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064518.93143> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** (modem-manager:2657): DEBUG: (tty/ttyUSB1): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064523.80255> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** Message: (ttyUSB1) type ignored claimed by /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** Message: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 claimed port ttyUSB1
** (modem-manager:2657): DEBUG: Exported modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 as /org/freedesktop/ModemManager/Modems/1
** (modem-manager:2657): DEBUG: (/org/freedesktop/ModemManager/Modems/1): data port is ttyUSB0
** Message: (ttyUSB0) opening serial device...
** (modem-manager:2657): DEBUG: <1280064523.225413> (ttyUSB0) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064523.225503> Modem /org/freedesktop/ModemManager/Modems/1: state changed (disabled -> enabling)
** (modem-manager:2657): DEBUG: <1280064523.327420> (ttyUSB0): --> 'ATZ E0 V1<CR>'
** (modem-manager:2657): DEBUG: <1280064523.355017> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.355205> (ttyUSB0): --> 'ATE0<CR>'
** (modem-manager:2657): DEBUG: <1280064523.363015> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.363175> (ttyUSB0): --> 'AT+CMEE=1<CR>'
** (modem-manager:2657): DEBUG: <1280064523.376018> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.376168> (ttyUSB0): --> 'ATX4 &C1<CR>'
** (modem-manager:2657): DEBUG: <1280064523.401122> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.401398> (ttyUSB0): --> 'AT+CFUN=1<CR>'
** (modem-manager:2657): DEBUG: <1280064523.419985> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.420188> (ttyUSB0): --> 'AT+IFC=1,1<CR>'
** (modem-manager:2657): DEBUG: <1280064523.433963> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.434106> (ttyUSB0): --> 'AT+GMI<CR>'
** (modem-manager:2657): DEBUG: <1280064523.444056> (ttyUSB0): <-- '<CR><LF>huawei<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.444262> (ttyUSB0): --> 'AT+GMM<CR>'
** (modem-manager:2657): DEBUG: <1280064523.454981> (ttyUSB0): <-- '<CR><LF>E220<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.455144> (ttyUSB0): --> 'AT+GMR<CR>'
** (modem-manager:2657): DEBUG: <1280064523.463964> (ttyUSB0): <-- '<CR><LF>11.116.05.00.00<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.464099> (ttyUSB0): --> 'AT+CGMI<CR>'
** (modem-manager:2657): DEBUG: <1280064523.476961> (ttyUSB0): <-- '<CR><LF>huawei<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.477103> (ttyUSB0): --> 'AT+CGMM<CR>'
** (modem-manager:2657): DEBUG: <1280064523.488967> (ttyUSB0): <-- '<CR><LF>E220<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.489114> (ttyUSB0): --> 'AT+CGMR<CR>'
** (modem-manager:2657): DEBUG: <1280064523.502035> (ttyUSB0): <-- '<CR><LF>11.116.05.00.00<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.502229> (ttyUSB0): --> 'AT^SYSCFG?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.521026> (ttyUSB0): <-- '<CR><LF>^SYSCFG:14,2,3FFFFFFF,1,2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.521274> (ttyUSB0): --> 'AT+CSCS=?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.537991> (ttyUSB0): <-- '<CR><LF>+CSCS: ("IRA","GSM","UCS2")<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.538251> (ttyUSB0): --> 'AT+CSCS="UCS2"<CR>'
** (modem-manager:2657): DEBUG: <1280064523.556098> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.556327> (ttyUSB0): --> 'AT+CSCS?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.567948> (ttyUSB0): <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.568183> Modem /org/freedesktop/ModemManager/Modems/1: state changed (enabling -> enabled)
** (modem-manager:2657): DEBUG: <1280064523.568434> (ttyUSB0): --> 'AT+CREG=2<CR>'
** (modem-manager:2657): DEBUG: <1280064523.581253> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.581579> (ttyUSB0): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064523.591977> (ttyUSB0): <-- '<CR><LF>+CSQ: 8,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.592248> (ttyUSB0): --> 'AT+CREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.604996> (ttyUSB0): <-- '<CR><LF>+CREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: CS registration state changed: 1
** (modem-manager:2657): DEBUG: <1280064523.605250> Modem /org/freedesktop/ModemManager/Modems/1: state changed (enabled -> registered)
** (modem-manager:2657): DEBUG: <1280064523.605364> (ttyUSB0): --> 'AT+CGREG=2<CR>'
** (modem-manager:2657): DEBUG: <1280064523.618999> (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.619222> (ttyUSB0): --> 'AT+COPS=3,2;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.644007> (ttyUSB0): <-- '<CR><LF>+COPS: 0,2,"51010",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.644369> (ttyUSB0): --> 'AT+COPS=3,0;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.676096> (ttyUSB0): network_mode => 8
** (modem-manager:2657): DEBUG: <1280064523.676096> (ttyUSB0): allowed_mode => 4
** (modem-manager:2657): DEBUG: <1280064523.676096> (ttyUSB0): number => "*99#"
** (modem-manager:2657): DEBUG: <1280064523.676096> (ttyUSB0): apn => "internet"
** (modem-manager:2657): DEBUG: <1280064523.676262> (ttyUSB0): simple connect state 0
** (modem-manager:2657): DEBUG: <1280064523.676339> (ttyUSB0): simple connect state 2
** (modem-manager:2657): DEBUG: <1280064523.770083> (ttyUSB0): <-- '<CR><LF>+COPS: 0,0,"IND TELKOMSEL",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.770476> (ttyUSB0): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064523.779966> (ttyUSB0): <-- '<CR><LF>+CSQ: 8,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.780121> (ttyUSB0): --> 'AT^SYSINFO<CR>'
** (modem-manager:2657): DEBUG: <1280064523.793966> (ttyUSB0): <-- '<CR><LF>^SYSINFO:2,3,0,5,1,0,4<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.794252> (ttyUSB0): --> 'AT+CGREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.806993> (ttyUSB0): <-- '<CR><LF>+CGREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: PS registration state changed: 1
** (modem-manager:2657): DEBUG: <1280064523.807266> (ttyUSB0): --> 'AT+CREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.820081> (ttyUSB0): <-- '<CR><LF>+CREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.820341> (ttyUSB0): simple connect state 4
** (modem-manager:2657): DEBUG: <1280064523.820427> (ttyUSB0): --> 'AT+COPS=3,2;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.844000> (ttyUSB0): <-- '<CR><LF>+COPS: 0,2,"51010",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.844208> (ttyUSB0): --> 'AT+COPS=3,0;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.868970> (ttyUSB0): <-- '<CR><LF>+COPS: 0,0,"IND TELKOMSEL",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.869119> (ttyUSB0): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064523.878004> (ttyUSB0): <-- '<CR><LF>+CSQ: 8,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.878175> (ttyUSB0): --> 'AT^SYSINFO<CR>'
** (modem-manager:2657): DEBUG: <1280064523.892357> (ttyUSB0): <-- '<CR><LF>^SYSINFO:2,3,0,5,1,0,4<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.892584> (ttyUSB0): --> 'AT+CGDCONT?<CR>'
** (modem-manager:2657): DEBUG: <1280064523.907997> (ttyUSB0): <-- '<CR><LF>+CGDCONT: 1,"IP","internet","0.0.0.0",0,0<CR><LF>+CGDCONT: 2,"IP","telkomsel","0.0.0.0",0,0<CR><LF>+CGDCONT: 3,"IP","internet","0.0.0.0",0,0<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.908253> (ttyUSB0): simple connect state 5
** (modem-manager:2657): DEBUG: <1280064523.908348> Modem /org/freedesktop/ModemManager/Modems/1: state changed (registered -> connecting)
** (modem-manager:2657): DEBUG: <1280064523.908429> (ttyUSB0): --> 'ATD*99***1#<CR>'
** (modem-manager:2657): DEBUG: <1280064523.928976> (ttyUSB0): <-- '<CR><LF>CONNECT 7200000<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064523.929086> (ttyUSB0): port now connected
** (modem-manager:2657): DEBUG: <1280064523.929146> Modem /org/freedesktop/ModemManager/Modems/1: state changed (connecting -> connected)
** (modem-manager:2657): DEBUG: <1280064523.929198> (ttyUSB0): simple connect state 6
** (modem-manager:2657): DEBUG: (net/ppp0): could not get port's parent device
** (modem-manager:2657): DEBUG: <1280064539.23304> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** (modem-manager:2657): DEBUG: <1280064539.23386> (ttyUSB0): port now disconnected
** (modem-manager:2657): DEBUG: <1280064539.25183> Modem /org/freedesktop/ModemManager/Modems/1: state changed (connected -> disabled)
** (modem-manager:2657): DEBUG: Removed modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB0) deferring support check
** Message: (ttyUSB1) opening serial device...
** (modem-manager:2657): DEBUG: <1280064539.328609> (ttyUSB1) device open count is 1 (open)
** (modem-manager:2657): DEBUG: (ttyUSB1): probe requested by plugin 'Huawei'
** (modem-manager:2657): DEBUG: <1280064539.429597> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: <1280064540.231003> (ttyUSB1): <-- '<CR><LF>NO CARRIER<CR><LF>'
** (modem-manager:2657): DEBUG: Got failure code 3: No carrier
** (modem-manager:2657): DEBUG: <1280064540.231206> (ttyUSB1): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: <1280064541.32765> (ttyUSB1): <-- '<CR><LF>+GCAP: +CGSM,+DS,+ES<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064541.33001> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** Message: (ttyUSB1) type primary claimed by /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** Message: (ttyUSB1) opening serial device...
** (modem-manager:2657): DEBUG: <1280064541.42678> (ttyUSB1) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064541.42783> (ttyUSB1) device open count is 2 (open)
** Message: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 claimed port ttyUSB1
** (modem-manager:2657): DEBUG: Added modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064541.43419> (ttyUSB1): --> 'AT+CPIN?<CR>'
** (modem-manager:2657): DEBUG: <1280064541.57008> (ttyUSB1): <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064541.57200> (ttyUSB1) device open count is 1 (close)
** (modem-manager:2657): DEBUG: (tty/ttyUSB0): outstanding support task prevents export of /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064541.57357> (ttyUSB1): --> 'ATE0<CR>'
** (modem-manager:2657): DEBUG: <1280064541.65991> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064541.66114> (ttyUSB1): --> 'AT+CGSN<CR>'
** (modem-manager:2657): DEBUG: <1280064541.79039> (ttyUSB1): <-- '<CR><LF>358192013098036<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064541.79275> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** (modem-manager:2657): DEBUG: (ttyUSB0): re-checking support...
** Message: (ttyUSB0) opening serial device...
** (modem-manager:2657): DEBUG: <1280064542.324701> (ttyUSB0) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064549.78670> (ttyUSB0) device open count is 0 (close)
** Message: (ttyUSB0) closing serial device...
** Message: (ttyUSB0) type ignored claimed by /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** Message: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 claimed port ttyUSB0
** (modem-manager:2657): DEBUG: Exported modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1 as /org/freedesktop/ModemManager/Modems/2
** (modem-manager:2657): DEBUG: (/org/freedesktop/ModemManager/Modems/2): data port is ttyUSB1
** Message: (ttyUSB1) opening serial device...
** (modem-manager:2657): DEBUG: <1280064549.223706> (ttyUSB1) device open count is 1 (open)
** (modem-manager:2657): DEBUG: <1280064549.223808> Modem /org/freedesktop/ModemManager/Modems/2: state changed (disabled -> enabling)
** (modem-manager:2657): DEBUG: <1280064549.325801> (ttyUSB1): --> 'ATZ E0 V1<CR>'
** (modem-manager:2657): DEBUG: <1280064549.353842> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.354072> (ttyUSB1): --> 'ATE0<CR>'
** (modem-manager:2657): DEBUG: <1280064549.362256> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.362418> (ttyUSB1): --> 'AT+CMEE=1<CR>'
** (modem-manager:2657): DEBUG: <1280064549.376050> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.376212> (ttyUSB1): --> 'ATX4 &C1<CR>'
** (modem-manager:2657): DEBUG: <1280064549.388986> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.389148> (ttyUSB1): --> 'AT+CFUN=1<CR>'
** (modem-manager:2657): DEBUG: <1280064549.400961> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.401123> (ttyUSB1): --> 'AT+IFC=1,1<CR>'
** (modem-manager:2657): DEBUG: <1280064549.415961> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.416101> (ttyUSB1): --> 'AT+GMI<CR>'
** (modem-manager:2657): DEBUG: <1280064549.426296> (ttyUSB1): <-- '<CR><LF>huawei<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.426459> (ttyUSB1): --> 'AT+GMM<CR>'
** (modem-manager:2657): DEBUG: <1280064549.436982> (ttyUSB1): <-- '<CR><LF>E220<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.437123> (ttyUSB1): --> 'AT+GMR<CR>'
** (modem-manager:2657): DEBUG: <1280064549.448982> (ttyUSB1): <-- '<CR><LF>11.116.05.00.00<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.449148> (ttyUSB1): --> 'AT+CGMI<CR>'
** (modem-manager:2657): DEBUG: <1280064549.458967> (ttyUSB1): <-- '<CR><LF>huawei<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.459107> (ttyUSB1): --> 'AT+CGMM<CR>'
** (modem-manager:2657): DEBUG: <1280064549.469972> (ttyUSB1): <-- '<CR><LF>E220<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.470122> (ttyUSB1): --> 'AT+CGMR<CR>'
** (modem-manager:2657): DEBUG: <1280064549.480986> (ttyUSB1): <-- '<CR><LF>11.116.05.00.00<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.481164> (ttyUSB1): --> 'AT^SYSCFG?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.498054> (ttyUSB1): <-- '<CR><LF>^SYSCFG:14,2,3FFFFFFF,1,2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.498295> (ttyUSB1): --> 'AT+CSCS=?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.510981> (ttyUSB1): <-- '<CR><LF>+CSCS: ("IRA","GSM","UCS2")<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.511255> (ttyUSB1): --> 'AT+CSCS="UCS2"<CR>'
** (modem-manager:2657): DEBUG: <1280064549.529989> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.530150> (ttyUSB1): --> 'AT+CSCS?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.541983> (ttyUSB1): <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.542242> Modem /org/freedesktop/ModemManager/Modems/2: state changed (enabling -> enabled)
** (modem-manager:2657): DEBUG: <1280064549.542494> (ttyUSB1): --> 'AT+CREG=2<CR>'
** (modem-manager:2657): DEBUG: <1280064549.558630> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.558979> (ttyUSB1): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064549.568969> (ttyUSB1): <-- '<CR><LF>+CSQ: 8,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.569328> (ttyUSB1): --> 'AT+CREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.581985> (ttyUSB1): <-- '<CR><LF>+CREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: CS registration state changed: 1
** (modem-manager:2657): DEBUG: <1280064549.582208> Modem /org/freedesktop/ModemManager/Modems/2: state changed (enabled -> registered)
** (modem-manager:2657): DEBUG: <1280064549.582321> (ttyUSB1): --> 'AT+CGREG=2<CR>'
** (modem-manager:2657): DEBUG: <1280064549.598117> (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.598381> (ttyUSB1): --> 'AT+COPS=3,2;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.622996> (ttyUSB1): <-- '<CR><LF>+COPS: 0,2,"51010",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.623339> (ttyUSB1): --> 'AT+COPS=3,0;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.646977> (ttyUSB1): <-- '<CR><LF>+COPS: 0,0,"IND TELKOMSEL",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.647203> (ttyUSB1): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064549.657808> (ttyUSB1): <-- '<CR><LF>+CSQ: 8,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.657992> (ttyUSB1): --> 'AT^SYSINFO<CR>'
** (modem-manager:2657): DEBUG: <1280064549.670981> (ttyUSB1): <-- '<CR><LF>^SYSINFO:2,3,0,5,1,0,4<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.671304> (ttyUSB1): --> 'AT+CGREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.685014> (ttyUSB1): <-- '<CR><LF>+CGREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: PS registration state changed: 1
** (modem-manager:2657): DEBUG: <1280064549.685315> (ttyUSB1): --> 'AT+COPS=3,2;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.707032> (ttyUSB1): network_mode => 8
** (modem-manager:2657): DEBUG: <1280064549.707032> (ttyUSB1): allowed_mode => 4
** (modem-manager:2657): DEBUG: <1280064549.707032> (ttyUSB1): number => "*99#"
** (modem-manager:2657): DEBUG: <1280064549.707032> (ttyUSB1): apn => "internet"
** (modem-manager:2657): DEBUG: <1280064549.707208> (ttyUSB1): simple connect state 0
** (modem-manager:2657): DEBUG: <1280064549.707283> (ttyUSB1): simple connect state 2
** (modem-manager:2657): DEBUG: <1280064549.709989> (ttyUSB1): <-- '<CR><LF>+COPS: 0,2,"51010",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.710180> (ttyUSB1): --> 'AT+COPS=3,0;+COPS?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.736061> (ttyUSB1): <-- '<CR><LF>+COPS: 0,0,"IND TELKOMSEL",2<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.736269> (ttyUSB1): --> 'AT+CSQ<CR>'
** (modem-manager:2657): DEBUG: <1280064549.745960> (ttyUSB1): <-- '<CR><LF>+CSQ: 8,99<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.746147> (ttyUSB1): --> 'AT^SYSINFO<CR>'
** (modem-manager:2657): DEBUG: <1280064549.761331> (ttyUSB1): <-- '<CR><LF>^SYSINFO:2,3,0,5,1,0,4<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.761567> (ttyUSB1): --> 'AT+CREG?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.773985> (ttyUSB1): <-- '<CR><LF>+CREG: 2,1,1E83,3114045<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.774191> (ttyUSB1): simple connect state 4
** (modem-manager:2657): DEBUG: <1280064549.774279> (ttyUSB1): --> 'AT+CGDCONT?<CR>'
** (modem-manager:2657): DEBUG: <1280064549.788977> (ttyUSB1): <-- '<CR><LF>+CGDCONT: 1,"IP","internet","0.0.0.0",0,0<CR><LF>+CGDCONT: 2,"IP","telkomsel","0.0.0.0",0,0<CR><LF>+CGDCONT: 3,"IP","internet","0.0.0.0",0,0<CR><LF><CR><LF>OK<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.789176> (ttyUSB1): simple connect state 5
** (modem-manager:2657): DEBUG: <1280064549.789265> Modem /org/freedesktop/ModemManager/Modems/2: state changed (registered -> connecting)
** (modem-manager:2657): DEBUG: <1280064549.789345> (ttyUSB1): --> 'ATD*99***1#<CR>'
** (modem-manager:2657): DEBUG: <1280064549.806003> (ttyUSB1): <-- '<CR><LF>CONNECT 7200000<CR><LF>'
** (modem-manager:2657): DEBUG: <1280064549.806153> (ttyUSB1): port now connected
** (modem-manager:2657): DEBUG: <1280064549.806229> Modem /org/freedesktop/ModemManager/Modems/2: state changed (connecting -> connected)
** (modem-manager:2657): DEBUG: <1280064549.806304> (ttyUSB1): simple connect state 6
** (modem-manager:2657): DEBUG: (net/ppp0): could not get port's parent device
** (modem-manager:2657): DEBUG: <1280064551.385225> Modem /org/freedesktop/ModemManager/Modems/2: state changed (connected -> disabled)
** (modem-manager:2657): DEBUG: Removed modem /sys/devices/pci0000:00/0000:00:1d.2/usb4/4-1
** (modem-manager:2657): DEBUG: <1280064551.385452> (ttyUSB1) device open count is 0 (close)
** Message: (ttyUSB1) closing serial device...
** (modem-manager:2657): DEBUG: <1280064551.385521> (ttyUSB1): port now disconnected
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB0) deferring support check
** Message: (ttyUSB2) opening serial device...
** (modem-manager:2657): DEBUG: <1280064566.657019> (ttyUSB2) device open count is 1 (open)
** (modem-manager:2657): DEBUG: (ttyUSB2): probe requested by plugin 'Huawei'
** (modem-manager:2657): DEBUG: (ttyUSB0): re-checking support...
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB0) deferring support check
** (modem-manager:2657): DEBUG: (ttyUSB0): re-checking support...
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB0) deferring support check
** (modem-manager:2657): DEBUG: <1280064576.760363> (ttyUSB2): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: (ttyUSB0): re-checking support...
** (modem-manager:2657): DEBUG: (Huawei): (ttyUSB0) deferring support check
** (modem-manager:2657): DEBUG: <1280064580.168083> (ttyUSB2): --> 'AT+GCAP<CR>'
** (modem-manager:2657): DEBUG: <1280064582.72828> (ttyUSB2) device open count is 0 (close)
** Message: (ttyUSB2) closing serial device...
^C
Program received signal SIGINT, Interrupt.
0x000000349eed7da8 in poll () from /lib64/libc.so.6
(gdb) backtrace
#0  0x000000349eed7da8 in poll () from /lib64/libc.so.6
#1  0x00000034a063f849 in ?? () from /lib64/libglib-2.0.so.0
#2  0x00000034a063fff5 in g_main_loop_run () from /lib64/libglib-2.0.so.0
#3  0x000000000040b5a1 in main ()
(gdb)

Comment 2 yunus 2010-07-25 14:26:28 UTC

I do not know wether below messages showed by 'dmesg' related to this bug or not.

usb 4-1: new full speed USB device using uhci_hcd and address 9
usb 4-1: New USB device found, idVendor=12d1, idProduct=1003
usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 4-1: Product: HUAWEI Mobile
usb 4-1: Manufacturer: HUAWEI Technologies
scsi9 : usb-storage 4-1:1.0
usb 4-1: USB disconnect, address 9
usb 4-1: new full speed USB device using uhci_hcd and address 10
usb 4-1: New USB device found, idVendor=12d1, idProduct=1003
usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 4-1: Product: HUAWEI Mobile
usb 4-1: Manufacturer: HUAWEI Technologies
option 4-1:1.0: GSM modem (1-port) converter detected
usb 4-1: GSM modem (1-port) converter now attached to ttyUSB0
option 4-1:1.1: GSM modem (1-port) converter detected
usb 4-1: GSM modem (1-port) converter now attached to ttyUSB1
scsi12 : usb-storage 4-1:1.2
scsi 12:0:0:0: CD-ROM            HUAWEI   Mass Storage     2.31 PQ: 0 ANSI: 2
sr1: scsi-1 drive
sr 12:0:0:0: Attached scsi CD-ROM sr1
sr 12:0:0:0: Attached scsi generic sg2 type 5
sr1: CDROM (ioctl) error, command: Xpwrite, Read disk info 51 00 00 00 00 00 00 00 02 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 28 00 00 00 00 10 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 20 00 00 00 00 18 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
ISO 9660 Extensions: Microsoft Joliet Level 1
ISOFS: changing to secondary root
SELinux: initialized (dev sr1, type iso9660), uses genfs_contexts
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
[root@localhost tj]#

Comment 3 Thomas Spura 2010-07-25 14:33:53 UTC

(In reply to comment #0)
> Steps to Reproduce:
> 1. Making connection using NM applet
> 2. Plug in USB Flashdisk
> 3. Unplug USB Flashdisk
> 
> Actual results:
> Connection become intermittent
> 
> Expected results:
> It should be no problem when I plug in USB Flashdisk and unplug USB Flashdisk
> 
> Additional info:
> I reboot the system to be able to make connection again.    

Hmm, honestly I don't understand your bug report...

You have a connection and plug the flashdrive out -> connection crashes.

When you unplug the modem, isn't this expected?
No modem -> no connection...

Comment 4 yunus 2010-07-25 14:58:47 UTC

I do not know wether below messages showed by 'dmesg' related to this bug or not.

usb 4-1: new full speed USB device using uhci_hcd and address 9
usb 4-1: New USB device found, idVendor=12d1, idProduct=1003
usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 4-1: Product: HUAWEI Mobile
usb 4-1: Manufacturer: HUAWEI Technologies
scsi9 : usb-storage 4-1:1.0
usb 4-1: USB disconnect, address 9
usb 4-1: new full speed USB device using uhci_hcd and address 10
usb 4-1: New USB device found, idVendor=12d1, idProduct=1003
usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 4-1: Product: HUAWEI Mobile
usb 4-1: Manufacturer: HUAWEI Technologies
option 4-1:1.0: GSM modem (1-port) converter detected
usb 4-1: GSM modem (1-port) converter now attached to ttyUSB0
option 4-1:1.1: GSM modem (1-port) converter detected
usb 4-1: GSM modem (1-port) converter now attached to ttyUSB1
scsi12 : usb-storage 4-1:1.2
scsi 12:0:0:0: CD-ROM            HUAWEI   Mass Storage     2.31 PQ: 0 ANSI: 2
sr1: scsi-1 drive
sr 12:0:0:0: Attached scsi CD-ROM sr1
sr 12:0:0:0: Attached scsi generic sg2 type 5
sr1: CDROM (ioctl) error, command: Xpwrite, Read disk info 51 00 00 00 00 00 00 00 02 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 28 00 00 00 00 10 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 20 00 00 00 00 18 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
ISO 9660 Extensions: Microsoft Joliet Level 1
ISOFS: changing to secondary root
SELinux: initialized (dev sr1, type iso9660), uses genfs_contexts
sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
sr: Sense Key : Hardware Error [current] 
sr: Add. Sense: No additional sense information
[root@localhost tj]#

Comment 5 yunus 2010-07-25 15:04:50 UTC

(In reply to comment #3)
> (In reply to comment #0)
> > Steps to Reproduce:
> > 1. Making connection using NM applet
> > 2. Plug in USB Flashdisk
> > 3. Unplug USB Flashdisk
> > 
> > Actual results:
> > Connection become intermittent
> > 
> > Expected results:
> > It should be no problem when I plug in USB Flashdisk and unplug USB Flashdisk
> > 
> > Additional info:
> > I reboot the system to be able to make connection again.    
> 
> Hmm, honestly I don't understand your bug report...
> 
> You have a connection and plug the flashdrive out -> connection crashes.
> 
> When you unplug the modem, isn't this expected?
> No modem -> no connection...    

I meant the modem is still there (I don't unplug the modem). I plug another USB Flashdsik or USB HDD and unplug them (not the modem itself).

It is weird. Why pluggin and unpluging another USB Flashdisk and USB HDD do affect the modem.

Comment 6 Dan Williams 2010-07-28 04:16:43 UTC

So the problem does *not* occur if you do not plug in the other flash key?

Comment 7 yunus 2010-07-28 14:32:46 UTC

yes, it does not accur.

I observe that
   [0] Green Mobile Partner icon on desktop
   [1] plug in the other flask key
   [2] An flash key icon will appear on destop
   [3] click on the flash icon in order to access data on my flash key
   [4] Green Mobile Partner icon on desktop dissappear while perform [3]
   [5] Mobile Connection disconnects while perform [3]

As long as I don't perform [3], the mobile connection is still connected.

Comment 8 Dan Williams 2010-08-01 21:41:16 UTC

Ok; so it sounds like the modem is having problems with concurrent access of the USB storage function and the serial function.  While ModemManager should be handling the modem disconnect better (ie, not throwing CRITICAL errors like you mentioned before), this bug surely appears to be either a kernel bug (USB storage subsystem doing something it shouldn't be) or a modem firmware bug (the firmware incorrectly handles concurrent accesses of the modem and storage functions).

With that in mind, I'm going to move this to the kernel as perhaps there is something that the usb-storage subsystem could be doing to mitigate the issue.  But it appears that there's not much that ModemManager could do (or should do) to fix this issue since it's simply talking on the serial port.

Comment 9 Dan Williams 2010-08-01 21:44:26 UTC

(one thing to do might be to trace usb-storage calls and make sure that the USB stack isn't poking the Huawei stick in some housekeeping manner when it also accesses the other flash drive.  but the fact that just accessing another flash drive makes the E220 angry is enough to suspect a bug in the kernel here)