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

[Valmantas Palikša <walmis gmail com>]

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.. 

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.