GNOME.org
 

Re: NM 0.7.1 leaves open fd of /dev/tts/USB2 after disconnect

The patch still fails, here's the log:

NetworkManager: <info>  (tts/USB2): found serial port (udev:GSM
hal:GSM)
NetworkManager: <info>  (tts/USB2): new Modem device (driver: 'option')
NetworkManager: <info>  (tts/USB2): exported
as /org/freedesktop/Hal/devices/usb_device_19d2_31_1234567890ABCDEF_if3_serial_usb_0
NetworkManager: <info>  (tts/USB2): device state change: 1 -> 2
NetworkManager: <info>  (tts/USB2): deactivating device (reason: 2).
NetworkManager: <debug> [1246453670.008630] nm_serial_device_close():
Closing device 'tts/USB2'
NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion
`iface_idx >= 0' failed
NetworkManager: nm_system_device_flush_ip4_addresses_with_iface:
assertion `iface_idx >= 0' failed
NetworkManager: <debug> [1246453670.011935] nm_serial_device_close():
Closing device 'tts/USB2'
NetworkManager: <info>  (tts/USB2): device state change: 2 -> 3
NetworkManager: <debug> [1246453670.012225] nm_serial_device_close():
Closing device 'tts/USB2'
NetworkManager: <info>  Activation (tts/USB2) starting connection 'Omni
Connect'
NetworkManager: <info>  (tts/USB2): device state change: 3 -> 4
NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
Prepare) scheduled...
NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
Prepare) started...
NetworkManager: <debug> [1246453672.442231] nm_serial_device_open():
(tts/USB2) opening device...
NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
Prepare) complete.
NetworkManager: <debug> [1246453674.361167] nm_serial_debug(): Sending:
'ATZ E0 V1 X4 &C1 +FCLASS=0
'
NetworkManager: <debug> [1246453674.417314] nm_serial_debug(): Got: 'ATZ
E0 V1 X4 &C1 +FCLASS=0
'
NetworkManager: <debug> [1246453674.431308] nm_serial_debug(): Got: 'ATZ
E0 V1 X4 &C1 +FCLASS=0


ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (1)
NetworkManager: <debug> [1246453676.000074] nm_serial_debug(): Sending:
'ATZ E0 V1 &C1
'
NetworkManager: <debug> [1246453676.044164] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (2)
NetworkManager: <debug> [1246453677.001285] nm_serial_debug(): Sending:
'AT&F E0 V1 X4 &C1 +FCLASS=0
'
NetworkManager: <debug> [1246453677.069026] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (3)
NetworkManager: <debug> [1246453678.001124] nm_serial_debug(): Sending:
'AT&F E0 V1 &C1
'
NetworkManager: <debug> [1246453678.042355] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (4)
NetworkManager: <debug> [1246453679.001456] nm_serial_debug(): Sending:
'AT&F E0 V1
'
NetworkManager: <debug> [1246453679.034242] nm_serial_debug(): Got: '

OK

'
NetworkManager: <debug> [1246453679.034342] nm_serial_debug(): Sending:
'AT+CPIN?
'
NetworkManager: <debug> [1246453679.061754] nm_serial_debug(): Got: '

+CPIN: SIM PIN



OK

'
NetworkManager: <info>  (tts/USB2): GSM pin secret required
NetworkManager: <info>  (tts/USB2): device state change: 4 -> 6
NetworkManager: <debug> [1246453679.061948] nm_serial_device_close():
Closing device 'tts/USB2'
NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
Prepare) scheduled...
NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
Prepare) started...
NetworkManager: <info>  (tts/USB2): device state change: 6 -> 4
NetworkManager: <debug> [1246453679.077933] nm_serial_device_open():
(tts/USB2) opening device...
NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
Prepare) complete.
NetworkManager: <debug> [1246453679.181778] nm_serial_debug(): Sending:
'ATZ E0 V1 X4 &C1 +FCLASS=0
'
NetworkManager: <debug> [1246453679.250891] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (1)
NetworkManager: <debug> [1246453680.999813] nm_serial_debug(): Sending:
'ATZ E0 V1 &C1
'
NetworkManager: <debug> [1246453681.041843] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (2)
NetworkManager: <debug> [1246453682.001968] nm_serial_debug(): Sending:
'AT&F E0 V1 X4 &C1 +FCLASS=0
'
NetworkManager: <debug> [1246453682.070326] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (3)
NetworkManager: <debug> [1246453683.001413] nm_serial_debug(): Sending:
'AT&F E0 V1 &C1
'
NetworkManager: <debug> [1246453683.042892] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  init_done(): Trying alternate modem
initialization (4)
NetworkManager: <debug> [1246453684.001994] nm_serial_debug(): Sending:
'AT&F E0 V1
'
NetworkManager: <debug> [1246453684.034424] nm_serial_debug(): Got: '

OK

'
NetworkManager: <debug> [1246453684.034527] nm_serial_debug(): Sending:
'AT+CPIN?
'
NetworkManager: <debug> [1246453684.062055] nm_serial_debug(): Got: '

+CPIN: SIM PIN



OK

'
NetworkManager: <debug> [1246453684.062182] nm_serial_debug(): Sending:
'AT+CPIN="0000"
'
NetworkManager: <debug> [1246453684.198993] nm_serial_debug(): Got: '

OK

'
NetworkManager: <debug> [1246453684.199097] nm_serial_debug(): Sending:
'AT&F E0 V1
'
NetworkManager: <debug> [1246453684.231210] nm_serial_debug(): Got: '

OK

'
NetworkManager: <info>  (tts/USB2): powering up...
NetworkManager: <debug> [1246453684.231316] nm_serial_debug(): Sending:
'AT+CFUN=1
'
NetworkManager: <debug> [1246453684.262353] nm_serial_debug(): Got: '

OK

'
NetworkManager: <debug> [1246453684.262450] nm_serial_debug(): Sending:
'AT+CGMM
'
NetworkManager: <debug> [1246453684.289984] nm_serial_debug(): Got: '

MF633



OK

'
NetworkManager: <debug> [1246453684.290102] nm_serial_debug(): Sending:
'AT+CREG?
'
NetworkManager: <debug> [1246453684.317616] nm_serial_debug(): Got: '

+CREG: 0,2



OK

'
NetworkManager: <info>  Searching for a network...
NetworkManager: <debug> [1246453686.000483] nm_serial_debug(): Sending:
'AT+CREG?
'
NetworkManager: <debug> [1246453686.039123] nm_serial_debug(): Got: '

+CREG: 0,2



OK

'
NetworkManager: <info>  Searching for a network...
NetworkManager: <debug> [1246453687.001240] nm_serial_debug(): Sending:
'AT+CREG?
'
NetworkManager: <debug> [1246453687.020624] nm_serial_debug(): Got: '

+ZDONR: "Not Found"



+ZPASR: "No Service"



+ZDONR: "OMT",246,1,"CS_ONLY","ROAM_OFF"



+ZPASR: "UMTS"

'
NetworkManager: <debug> [1246453687.031617] nm_serial_debug(): Got: '

+ZDONR: "Not Found"



+ZPASR: "No Service"



+ZDONR: "OMT",246,1,"CS_ONLY","ROAM_OFF"



+ZPASR: "UMTS"



+CREG: 0,1



OK

'
NetworkManager: <info>  Registered on Home network
NetworkManager: <debug> [1246453687.031784] nm_serial_debug(): Sending:
'AT+COPS?
'
NetworkManager: <debug> [1246453687.073513] nm_serial_debug(): Got: '

+COPS: 0,1,"OMT",2



OK

'
NetworkManager: <info>  Associated with network: +COPS: 0,1,"OMT",2
NetworkManager: <debug> [1246453687.073643] nm_serial_debug(): Sending:
'ATDT*99#
'
NetworkManager: <debug> [1246453687.093549] nm_serial_debug(): Got: '

+ZDONR: "OMT",246,1,"CS_ONLY","ROAM_OFF"



+ZPASR: "UMTS"

'
NetworkManager: <debug> [1246453687.103749] nm_serial_debug(): Got: '

+ZDONR: "OMT",246,1,"CS_ONLY","ROAM_OFF"



+ZPASR: "UMTS"



CONNECT

'
NetworkManager: <info>  Connected, Woo!
NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
Configure) scheduled...
NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
Configure) starting...
NetworkManager: <info>  (tts/USB2): device state change: 4 -> 5
NetworkManager: <info>  Starting pppd connection
NetworkManager: <debug> [1246453687.112618] nm_ppp_manager_start():
Command line: /usr/sbin/pppd nodetach lock nodefaultroute debug tts/USB2
noipdefault noauth refuse-eap refuse-pap refuse-chap refuse-mschap
refuse-mschap-v2 usepeerdns lcp-echo-failure 0 lcp-echo-interval 0
ipparam /org/freedesktop/NetworkManager/PPP/0
plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded.
using channel 25
Using interface ppp0
Connect: ppp0 <--> /dev/tts/USB2
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xfeceee0> <pcomp>
<accomp>]
rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic
0x21edf0d> <pcomp> <accomp>]
No auth is possible
sent [LCP ConfRej id=0x0 <auth chap MD5>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xfeceee0> <pcomp>
<accomp>]
NetworkManager: <debug> [1246453687.157776] nm_ppp_manager_start(): ppp
started with pid 22807
NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
Configure) complete.
rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x21edf0d> <pcomp>
<accomp>]
sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x21edf0d> <pcomp>
<accomp>]
sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1
0.0.0.0> <ms-dns3 0.0.0.0>]
NetworkManager: <info>  (tts/USB2): device state change: 5 -> 6
Terminating on signal 15
sent [LCP TermReq id=0x2 "User request"]
NetworkManager: <debug> [1246453687.165349] nm_serial_device_close():
Closing device 'tts/USB2'
rcvd [LCP DiscReq id=0x2 magic=0x21edf0d]
rcvd [LCP ProtRej id=0x3 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03
2f]
rcvd [LCP TermAck id=0x2]
Connection terminated.
NetworkManager: <debug> [1246453689.001565] ensure_killed(): waiting for
ppp pid 22807 to exit
NetworkManager: <debug> [1246453689.001705] ensure_killed(): ppp pid
22807 cleaned up




On Wed, 2009-07-01 at 07:48 -0400, Dan Williams wrote:
> On Wed, 2009-07-01 at 11:29 +0300, Valmantas Palikša wrote:
> > On Tue, 2009-06-30 at 17:51 -0400, Dan Williams wrote: 
> > > On Wed, 2009-06-24 at 22:26 +0300, Valmantas Palikša wrote:
> > > > Done some digging and found out that NM opens the device twice. This
> > > > very often leads to kernel panics here if the device connects multiple
> > > > times or is pluged/unpluged when the descriptor is left open. Probably
> > > > some bug in the kernel somewhere.. 
> > > 
> > > Yes, it is, and I think 2.6.31 should fix that, but I had thought that
> > > 2d93148ab6988cad872e65d694c95e8944e1b626 in 2.6.30 would have done so.
> > > 
> > > So you've got two issues here, the first is that NM is finding two
> > > ports, not one.  I'd expect NM 0.7.1 to do OK here, see my recent post
> > > on the ZTE thing a bit earlier today.  There may be a (already fixed)
> > > bug with HAL 'info.bus' handling that you can test by dropping that fdi
> > > file into the right place.
> > > 
> > 
> > NM applet shows 2 ports:
> > 
> > NetworkManager: <info>  (tts/USB2): found serial port (udev:GSM
> > hal:GSM)
> > NetworkManager: <info>  (tts/USB2): new Modem device (driver: 'option')
> > NetworkManager: <info>  (tts/USB2): exported
> > as /org/freedesktop/Hal/devices/usb_device_19d2_31_1234567890ABCDEF_if3_serial_usb_0
> > NetworkManager: <info>  (tts/USB0): ignoring due to lack of mobile
> > broadband capabilties
> > NetworkManager: <info>  (tts/USB2): device state change: 1 -> 2
> > NetworkManager: <info>  (tts/USB2): deactivating device (reason: 2).
> > NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion
> > `iface_idx >= 0' failed
> > NetworkManager: nm_system_device_flush_ip4_addresses_with_iface:
> > assertion `iface_idx >= 0' failed
> > NetworkManager: <info>  (tts/USB2): device state change: 2 -> 3
> > NetworkManager: <info>  (tts/USB1): found serial port (udev:GSM  hal:)
> > NetworkManager: <info>  (tts/USB1): deferring until all ports found
> > NetworkManager: <info>  Re-checking deferred serial ports
> > NetworkManager: <info>  (tts/USB1): new Modem device (driver: 'option')
> > NetworkManager: <info>  (tts/USB1): exported
> > as /org/freedesktop/Hal/devices/usb_device_19d2_31_1234567890ABCDEF_if1_serial_usb_0
> > NetworkManager: <info>  (tts/USB1): device state change: 1 -> 2
> > NetworkManager: <info>  (tts/USB1): deactivating device (reason: 2).
> > NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion
> > `iface_idx >= 0' failed
> > NetworkManager: nm_system_device_flush_ip4_addresses_with_iface:
> > assertion `iface_idx >= 0' failed
> > NetworkManager: <info>  (tts/USB1): device state change: 2 -> 3
> > 
> > Got it fixed by using this udev rule:
> > ACTION!="add|change", GOTO="nm_modem_probe_end"
> > SUBSYSTEM!="tty", GOTO="nm_modem_probe_end"
> > 
> > ENV{NM_MODEM_USB_INTERFACE_NUMBER}=="01", ENV{ID_VENDOR_ID}=="19d2",
> > ENV{ID_MODEL_ID}=="0031", ENV{ID_NM_MODEM_GSM}="0"
> > 
> > LABEL="nm_modem_probe_end"
> > 
> > EDIT:
> > dropped the deprecated keys fdi file and it seems it now detects 1 port
> > correctly.
> > 
> > 
> > 
> > > But yes, NM appears to re-open the port.  We should be closing it when
> > > requesting secrets since it may be a long time before secrets come back.
> > > Can you try they attached patch and let me know if it fixes the issue?
> > > 
> > 
> > Hmm, something's wrong with the patch, can't connect at all:
> 
> Try the attached patch as a replacement for what you've already got, the
> fd wasn't correctly initialized to -1.
> 
> Next, can you run NM with
> 
> NM_PPP_DEBUG=1 NM_SERIAL_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
> 
> (ie, add NM_PPP_DEBUG=1 to what you've already got)
> 
> Thanks,
> Dan
> 
> 
> > NetworkManager: <info>  (tts/USB2): found serial port (udev:GSM
> > hal:GSM)
> > NetworkManager: <info>  (tts/USB2): new Modem device (driver: 'option')
> > NetworkManager: <info>  (tts/USB2): exported
> > as /org/freedesktop/Hal/devices/usb_device_19d2_31_1234567890ABCDEF_if3_serial_usb_0
> > NetworkManager: <info>  (tts/USB0): ignoring due to lack of mobile
> > broadband capabilties
> > NetworkManager: <info>  (tts/USB2): device state change: 1 -> 2
> > NetworkManager: <info>  (tts/USB2): deactivating device (reason: 2).
> > NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion
> > `iface_idx >= 0' failed
> > NetworkManager: nm_system_device_flush_ip4_addresses_with_iface:
> > assertion `iface_idx >= 0' failed
> > NetworkManager: <info>  (tts/USB2): device state change: 2 -> 3
> > NetworkManager: <info>  Activation (tts/USB2) starting connection 'Omni
> > Connect'
> > NetworkManager: <info>  (tts/USB2): device state change: 3 -> 4
> > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > Prepare) scheduled...
> > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > Prepare) started...
> > NetworkManager: <debug> [1246435879.217633] nm_serial_device_open():
> > (tts/USB2) bug: device already open
> > NetworkManager: <debug> [1246435879.217670] nm_serial_device_open():
> > (tts/USB2) opening device...
> > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > Prepare) complete.
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (1)
> > NetworkManager: <info>  (tts/USB1): ignoring due to lack of mobile
> > broadband capabilties
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (2)
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (3)
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (4)
> > NetworkManager: <info>  (tts/USB2): GSM pin secret required
> > NetworkManager: <info>  (tts/USB2): device state change: 4 -> 6
> > NetworkManager: <debug> [1246435887.061857] nm_serial_device_close():
> > Closing device 'tts/USB2'
> > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > Prepare) scheduled...
> > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > Prepare) started...
> > NetworkManager: <info>  (tts/USB2): device state change: 6 -> 4
> > NetworkManager: <debug> [1246435887.066475] nm_serial_device_open():
> > (tts/USB2) bug: device already open
> > NetworkManager: <debug> [1246435887.066503] nm_serial_device_open():
> > (tts/USB2) opening device...
> > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > Prepare) complete.
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (1)
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (2)
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (3)
> > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > initialization (4)
> > NetworkManager: <info>  (tts/USB2): powering up...
> > NetworkManager: <info>  Searching for a network...
> > NetworkManager: <info>  Searching for a network...
> > NetworkManager: <info>  Registered on Home network
> > NetworkManager: <info>  Associated with network: +COPS: 0,1,"OMT",2
> > NetworkManager: <info>  Connected, Woo!
> > NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
> > Configure) scheduled...
> > NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
> > Configure) starting...
> > NetworkManager: <info>  (tts/USB2): device state change: 4 -> 5
> > NetworkManager: <info>  Starting pppd connection
> > NetworkManager: <debug> [1246435894.109089] nm_ppp_manager_start():
> > Command line: /usr/sbin/pppd nodetach lock nodefaultroute tts/USB2
> > noipdefault noauth refuse-eap refuse-pap refuse-chap refuse-mschap
> > refuse-mschap-v2 usepeerdns lcp-echo-failure 0 lcp-echo-interval 0
> > ipparam /org/freedesktop/NetworkManager/PPP/0
> > plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
> > Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded.
> > NetworkManager: <debug> [1246435894.125042] nm_ppp_manager_start(): ppp
> > started with pid 2143
> > Using interface ppp0
> > Connect: ppp0 <--> /dev/tts/USB2
> > NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
> > Configure) complete.
> > NetworkManager: <info>  (tts/USB2): device state change: 5 -> 6
> > Terminating on signal 15
> > NetworkManager: <debug> [1246435894.159214] nm_serial_device_close():
> > Closing device 'tts/USB2'
> > Connection terminated.
> > NetworkManager: <debug> [1246435896.000993] ensure_killed(): waiting for
> > ppp pid 2143 to exit
> > NetworkManager: <debug> [1246435896.001139] ensure_killed(): ppp pid
> > 2143 cleaned up
> > 
> > 
> > > Dan
> > > 
> > > > Kernel: 2.6.30
> > > > NM: 0.7.1
> > > > Modem: ZTE MF633 (0x19d2 0x0031)
> > > > 
> > > > My temporary patch:
> > > > 
> > > > --- nm-gsm-device.old.c	2009-04-13 01:29:59.000000000 +0300
> > > > +++ nm-gsm-device.c	2009-06-24 22:17:58.039782740 +0300
> > > > @@ -823,6 +823,11 @@
> > > >  
> > > >  	setting = NM_SETTING_SERIAL (gsm_device_get_setting (NM_GSM_DEVICE
> > > > (device), NM_TYPE_SETTING_SERIAL));
> > > >  
> > > > + 	if(NM_GSM_DEVICE_GET_PRIVATE (device)->init_ok) {
> > > > + 		nm_warning("BUG: Closing previous connection");
> > > > + 		nm_serial_device_close (serial_device);
> > > > + 	}
> > > > +
> > > >  	if (!nm_serial_device_open (serial_device, setting)) {
> > > >  		*reason = NM_DEVICE_STATE_REASON_CONFIG_FAILED;
> > > >  		return NM_ACT_STAGE_RETURN_FAILURE;
> > > > 
> > > > Also the log:
> > > > 
> > > > NetworkManager: <info>  (tts/USB2): device state change: 2 -> 3
> > > > NetworkManager: <info>  (tts/USB1): found serial port (udev:GSM  hal:)
> > > > NetworkManager: <info>  (tts/USB1): deferring until all ports found
> > > > NetworkManager: <info>  Activation (tts/USB2) starting connection 'Omni
> > > > Connect'
> > > > NetworkManager: <info>  (tts/USB2): device state change: 3 -> 4
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > > > Prepare) scheduled...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > > > Prepare) started...
> > > > NetworkManager: <WARN>  real_act_stage1_prepare(): Stage1 0xf64010 0
> > > > NetworkManager: <debug> [1245870737.912363] nm_serial_device_open():
> > > > (tts/USB2) opening device...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > > > Prepare) complete.
> > > > NetworkManager: <info>  Re-checking deferred serial ports
> > > > NetworkManager: <info>  (tts/USB1): new Modem device (driver: 'option')
> > > > NetworkManager: <info>  (tts/USB1): exported
> > > > as /org/freedesktop/Hal/devices/usb_device_19d2_31_1234567890ABCDEF_if1_serial_usb_0
> > > > NetworkManager: <debug> [1245870738.017629] nm_serial_debug(): Sending:
> > > > 'ATZ E0 V1 X4 &C1 +FCLASS=0
> > > > '
> > > > NetworkManager: <debug> [1245870738.075007] nm_serial_debug(): Got: 'ATZ
> > > > E0 V1 X4 &C1 +FCLASS=0'
> > > > NetworkManager: <debug> [1245870738.086523] nm_serial_debug(): Got: 'ATZ
> > > > E0 V1 X4 &C1 +FCLASS=0
> > > > 
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (1)
> > > > NetworkManager: <debug> [1245870739.001616] nm_serial_debug(): Sending:
> > > > 'ATZ E0 V1 &C1
> > > > '
> > > > NetworkManager: <debug> [1245870739.046540] nm_serial_debug(): Got: '
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (2)
> > > > NetworkManager: <debug> [1245870740.001537] nm_serial_debug(): Sending:
> > > > 'AT&F E0 V1 X4 &C1 +FCLASS=0
> > > > '
> > > > NetworkManager: <debug> [1245870740.073194] nm_serial_debug(): Got: '
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (3)
> > > > NetworkManager: <debug> [1245870741.001280] nm_serial_debug(): Sending:
> > > > 'AT&F E0 V1 &C1
> > > > '
> > > > NetworkManager: <debug> [1245870741.043247] nm_serial_debug(): Got: '
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (4)
> > > > NetworkManager: <info>  (tts/USB1): device state change: 1 -> 2
> > > > NetworkManager: <info>  (tts/USB1): deactivating device (reason: 2).
> > > > NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion
> > > > `iface_idx >= 0' failed
> > > > NetworkManager: nm_system_device_flush_ip4_addresses_with_iface:
> > > > assertion `iface_idx >= 0' failed
> > > > NetworkManager: <debug> [1245870742.008830] nm_serial_debug(): Sending:
> > > > 'AT&F E0 V1
> > > > '
> > > > NetworkManager: <info>  (tts/USB1): device state change: 2 -> 3
> > > > NetworkManager: <debug> [1245870742.043197] nm_serial_debug(): Got: '
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <debug> [1245870742.043300] nm_serial_debug(): Sending:
> > > > 'AT+CPIN?
> > > > '
> > > > NetworkManager: <debug> [1245870742.073198] nm_serial_debug(): Got: '
> > > > 
> > > > +CPIN: SIM PIN
> > > > 
> > > > 
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <info>  (tts/USB2): GSM pin secret required
> > > > NetworkManager: <info>  (tts/USB2): device state change: 4 -> 6
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > > > Prepare) scheduled...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > > > Prepare) started...
> > > > NetworkManager: <info>  (tts/USB2): device state change: 6 -> 4
> > > > NetworkManager: <WARN>  real_act_stage1_prepare(): Stage1 0xf64010 1
> > > > NetworkManager: <WARN>  real_act_stage1_prepare(): BUG: Closing previous
> > > > connection
> > > > NetworkManager: <debug> [1245870742.083547] nm_serial_device_close():
> > > > Closing device 'tts/USB2'
> > > > NetworkManager: <debug> [1245870742.085062] nm_serial_device_open():
> > > > (tts/USB2) opening device...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 1 of 5 (Device
> > > > Prepare) complete.
> > > > NetworkManager: <debug> [1245870742.189500] nm_serial_debug(): Sending:
> > > > 'ATZ E0 V1 X4 &C1 +FCLASS=0
> > > > '
> > > > NetworkManager: <debug> [1245870742.263205] nm_serial_debug(): Got: '
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (1)
> > > > NetworkManager: <debug> [1245870744.000128] nm_serial_debug(): Sending:
> > > > 'ATZ E0 V1 &C1
> > > > '
> > > > NetworkManager: <debug> [1245870744.043202] nm_serial_debug(): Got: '
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (2)
> > > > NetworkManager: <debug> [1245870745.001327] nm_serial_debug(): Sending:
> > > > 'AT&F E0 V1 X4 &C1 +FCLASS=0
> > > > '
> > > > NetworkManager: <debug> [1245870745.073348] nm_serial_debug(): Got: '
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (3)
> > > > NetworkManager: <debug> [1245870746.001424] nm_serial_debug(): Sending:
> > > > 'AT&F E0 V1 &C1
> > > > '
> > > > NetworkManager: <debug> [1245870746.046530] nm_serial_debug(): Got: '
> > > > 
> > > > ERROR
> > > > 
> > > > '
> > > > NetworkManager: <WARN>  init_done(): Trying alternate modem
> > > > initialization (4)
> > > > NetworkManager: <debug> [1245870747.001170] nm_serial_debug(): Sending:
> > > > 'AT&F E0 V1
> > > > '
> > > > NetworkManager: <debug> [1245870747.036539] nm_serial_debug(): Got: '
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <debug> [1245870747.036647] nm_serial_debug(): Sending:
> > > > 'AT+CPIN?
> > > > '
> > > > NetworkManager: <debug> [1245870747.066536] nm_serial_debug(): Got: '
> > > > 
> > > > +CPIN: SIM PIN
> > > > 
> > > > 
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <debug> [1245870747.066661] nm_serial_debug(): Sending:
> > > > 'AT+CPIN="6486"
> > > > '
> > > > NetworkManager: <debug> [1245870747.206678] nm_serial_debug(): Got: '
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <debug> [1245870747.206787] nm_serial_debug(): Sending:
> > > > 'AT&F E0 V1
> > > > '
> > > > NetworkManager: <debug> [1245870747.239868] nm_serial_debug(): Got: '
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <info>  (tts/USB2): powering up...
> > > > NetworkManager: <debug> [1245870747.239981] nm_serial_debug(): Sending:
> > > > 'AT+CFUN=1
> > > > '
> > > > NetworkManager: <debug> [1245870747.273203] nm_serial_debug(): Got: '
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <debug> [1245870747.273295] nm_serial_debug(): Sending:
> > > > 'AT+CGMM
> > > > '
> > > > NetworkManager: <debug> [1245870747.303212] nm_serial_debug(): Got: '
> > > > 
> > > > MF633
> > > > 
> > > > 
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <debug> [1245870747.303328] nm_serial_debug(): Sending:
> > > > 'AT+CREG?
> > > > '
> > > > NetworkManager: <debug> [1245870747.333206] nm_serial_debug(): Got: '
> > > > 
> > > > +CREG: 0,2
> > > > 
> > > > 
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <info>  Searching for a network...
> > > > NetworkManager: <debug> [1245870749.000070] nm_serial_debug(): Sending:
> > > > 'AT+CREG?
> > > > '
> > > > NetworkManager: <debug> [1245870749.083204] nm_serial_debug(): Got: '
> > > > 
> > > > +CREG: 0,2
> > > > 
> > > > 
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <info>  Searching for a network...
> > > > NetworkManager: <debug> [1245870750.001634] nm_serial_debug(): Sending:
> > > > 'AT+CREG?
> > > > '
> > > > NetworkManager: <debug> [1245870750.023357] nm_serial_debug(): Got: '
> > > > 
> > > > +ZDONR: "OMT",246,1,"CS_ONLY","ROAM_OFF"
> > > > 
> > > > 
> > > > 
> > > > +ZPASR: "UMTS"
> > > > 
> > > > '
> > > > NetworkManager: <debug> [1245870750.036873] nm_serial_debug(): Got: '
> > > > 
> > > > +ZDONR: "OMT",246,1,"CS_ONLY","ROAM_OFF"
> > > > 
> > > > 
> > > > 
> > > > +ZPASR: "UMTS"
> > > > 
> > > > 
> > > > 
> > > > +CREG: 0,1
> > > > 
> > > > 
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <info>  Registered on Home network
> > > > NetworkManager: <debug> [1245870750.037021] nm_serial_debug(): Sending:
> > > > 'AT+COPS?
> > > > '
> > > > NetworkManager: <debug> [1245870750.066538] nm_serial_debug(): Got: '
> > > > 
> > > > +COPS: 0,1,"OMT",2
> > > > 
> > > > 
> > > > 
> > > > OK
> > > > 
> > > > '
> > > > NetworkManager: <info>  Associated with network: +COPS: 0,1,"OMT",2
> > > > NetworkManager: <debug> [1245870750.066685] nm_serial_debug(): Sending:
> > > > 'ATDT*99#
> > > > '
> > > > NetworkManager: <debug> [1245870750.096538] nm_serial_debug(): Got: '
> > > > 
> > > > CONNECT
> > > > 
> > > > '
> > > > NetworkManager: <info>  Connected, Woo!
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
> > > > Configure) scheduled...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
> > > > Configure) starting...
> > > > NetworkManager: <info>  (tts/USB2): device state change: 4 -> 5
> > > > NetworkManager: <info>  Starting pppd connection
> > > > NetworkManager: <debug> [1245870750.106860] nm_ppp_manager_start():
> > > > Command line: /usr/sbin/pppd nodetach lock nodefaultroute tts/USB2
> > > > noipdefault noauth refuse-eap refuse-pap refuse-chap refuse-mschap
> > > > refuse-mschap-v2 usepeerdns lcp-echo-failure 0 lcp-echo-interval 0
> > > > ipparam /org/freedesktop/NetworkManager/PPP/0
> > > > plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
> > > > Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded.
> > > > NetworkManager: <debug> [1245870750.121755] nm_ppp_manager_start(): ppp
> > > > started with pid 27105
> > > > Using interface ppp0
> > > > Connect: ppp0 <--> /dev/tts/USB2
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 2 of 5 (Device
> > > > Configure) complete.
> > > > NetworkManager: <info>  (tts/USB2): device state change: 5 -> 6
> > > > NetworkManager: <info>  (tts/USB2): device state change: 6 -> 7
> > > > Could not determine remote IP address: defaulting to 10.64.64.64
> > > > Cannot determine ethernet address for proxy ARP
> > > > local  IP address 10.123.21.99
> > > > remote IP address 10.64.64.64
> > > > primary   DNS address 10.11.12.13
> > > > secondary DNS address 10.11.12.14
> > > > NetworkManager: <info>  PPP manager(IP Config Get) reply received.
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 4 of 5 (IP Configure
> > > > Get) scheduled...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 4 of 5 (IP Configure
> > > > Get) started...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 5 of 5 (IP Configure
> > > > Commit) scheduled...
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 4 of 5 (IP Configure
> > > > Get) complete.
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 5 of 5 (IP Configure
> > > > Commit) started...
> > > > NetworkManager: <info>  (tts/USB2): device state change: 7 -> 8
> > > > NetworkManager: <info>  Policy set 'Omni Connect' (ppp0) as default for
> > > > routing and DNS.
> > > > NetworkManager: <info>  Activation (tts/USB2) successful, device
> > > > activated.
> > > > NetworkManager: <info>  Activation (tts/USB2) Stage 5 of 5 (IP Configure
> > > > Commit) complete.
> > > > 
> > > > 
> > > > 
> > > > 
> > > > _______________________________________________
> > > > NetworkManager-list mailing list
> > > > NetworkManager-list gnome org
> > > > http://mail.gnome.org/mailman/listinfo/networkmanager-list
> > 
> > _______________________________________________
> > NetworkManager-list mailing list
> > NetworkManager-list gnome org
> > http://mail.gnome.org/mailman/listinfo/networkmanager-list
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]