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