Re: problems with fasttrack xtend fxt009



On 09/11/11 09:49, Thomas Bechtold wrote:
i tried an older MM version (git snapshot from 20110608t111033) and with
that version, the modems sends responses even if the apn does not work.

Here are the logs with the older MM version (NM version is the same).
i started the same connection with "nmcli con up id ModemGSM". The modem works here. Can can not reproduce the provider failure.


Cheers,

Tom

######### MM-Log ###########
# pkill modem-manager && modem-manager --debug --log-level=DEBUG
modem-manager[24420]: <info> [1320922220.411168] [main.c:167] main(): ModemManager (version 0.5.999) starting... modem-manager[24420]: <info> [1320922220.639997] [mm-manager.c:154] found_plugin(): Loaded plugin 'Option' modem-manager[24420]: <info> [1320922220.640659] [mm-manager.c:154] found_plugin(): Loaded plugin 'X22X' modem-manager[24420]: <info> [1320922220.641238] [mm-manager.c:154] found_plugin(): Loaded plugin 'Ericsson MBM' modem-manager[24420]: <info> [1320922220.641816] [mm-manager.c:154] found_plugin(): Loaded plugin 'Sierra' modem-manager[24420]: <info> [1320922220.643231] [mm-manager.c:154] found_plugin(): Loaded plugin 'Linktop' modem-manager[24420]: <info> [1320922220.643552] [mm-manager.c:154] found_plugin(): Loaded plugin 'AnyData' modem-manager[24420]: <info> [1320922220.643789] [mm-manager.c:154] found_plugin(): Loaded plugin 'Longcheer' modem-manager[24420]: <info> [1320922220.644106] [mm-manager.c:154] found_plugin(): Loaded plugin 'Wavecom' modem-manager[24420]: <info> [1320922220.644339] [mm-manager.c:154] found_plugin(): Loaded plugin 'Novatel' modem-manager[24420]: <info> [1320922220.644557] [mm-manager.c:154] found_plugin(): Loaded plugin 'SimTech' modem-manager[24420]: <info> [1320922220.644777] [mm-manager.c:154] found_plugin(): Loaded plugin 'Nokia' modem-manager[24420]: <info> [1320922220.645207] [mm-manager.c:154] found_plugin(): Loaded plugin 'Samsung' modem-manager[24420]: <info> [1320922220.645458] [mm-manager.c:154] found_plugin(): Loaded plugin 'Gobi' modem-manager[24420]: <info> [1320922220.645683] [mm-manager.c:154] found_plugin(): Loaded plugin 'Huawei' modem-manager[24420]: <info> [1320922220.645900] [mm-manager.c:154] found_plugin(): Loaded plugin 'MotoC' modem-manager[24420]: <info> [1320922220.646116] [mm-manager.c:154] found_plugin(): Loaded plugin 'ZTE' modem-manager[24420]: <info> [1320922220.646982] [mm-manager.c:154] found_plugin(): Loaded plugin 'Option High-Speed' modem-manager[24420]: <info> [1320922220.647560] [mm-manager.c:154] found_plugin(): Loaded plugin 'Cinterion' modem-manager[24420]: <info> [1320922220.648146] [mm-manager.c:154] found_plugin(): Loaded plugin 'Generic' modem-manager[24420]: <info> [1320922220.648746] [mm-manager.c:206] load_plugins(): Successfully loaded 19 plugins modem-manager[24420]: <debug> [1320922220.659432] [mm-manager.c:1012] mm_manager_start(): Starting device scan... modem-manager[24420]: <debug> [1320922220.685973] [mm-manager.c:844] device_added(): (tty/ttyS0): port's parent platform driver is not whitelisted modem-manager[24420]: <debug> [1320922220.728696] [mm-manager.c:844] device_added(): (tty/ttyS2): port's parent platform driver is not whitelisted modem-manager[24420]: <debug> [1320922220.731369] [mm-manager.c:844] device_added(): (tty/ttyS4): port's parent platform driver is not whitelisted modem-manager[24420]: <debug> [1320922220.788052] [mm-manager.c:844] device_added(): (net/usb0): port's parent platform driver is not whitelisted modem-manager[24420]: <debug> [1320922220.790052] [mm-manager.c:1030] mm_manager_start(): Finished device scan... modem-manager[24420]: <info> [1320922220.790926] [mm-serial-port.c:760] mm_serial_port_open(): (ttyS1) opening serial port... modem-manager[24420]: <debug> [1320922220.793319] [mm-serial-port.c:822] mm_serial_port_open(): (ttyS1) device open count is 1 (open) modem-manager[24420]: <debug> [1320922220.794001] [mm-plugin-base.c:1021] try_open(): (ttyS1): probe requested by plugin 'Cinterion' modem-manager[24420]: <debug> [1320922220.903090] [mm-at-serial-port.c:298] debug_log(): (ttyS1): --> 'AT+GCAP<CR>' modem-manager[24420]: <debug> [1320922225.011100] [mm-at-serial-port.c:298] debug_log(): (ttyS1): --> 'AT+GCAP<CR>' modem-manager[24420]: <debug> [1320922229.008879] [mm-at-serial-port.c:298] debug_log(): (ttyS1): --> 'AT+GCAP<CR>' modem-manager[24420]: <debug> [1320922233.006625] [mm-serial-port.c:856] mm_serial_port_close(): (ttyS1) device open count is 0 (close) modem-manager[24420]: <info> [1320922233.007032] [mm-serial-port.c:871] mm_serial_port_close(): (ttyS1) closing serial port... modem-manager[24420]: <info> [1320922233.007587] [mm-serial-port.c:892] mm_serial_port_close(): (ttyS1) serial port closed modem-manager[24420]: <info> [1320922233.008942] [mm-serial-port.c:760] mm_serial_port_open(): (ttyS1) opening serial port... modem-manager[24420]: <debug> [1320922233.009824] [mm-serial-port.c:822] mm_serial_port_open(): (ttyS1) device open count is 1 (open) modem-manager[24420]: <debug> [1320922233.010663] [mm-qcdm-serial-port.c:194] debug_log(): (ttyS1): --> 00 78 f0 7e modem-manager[24420]: <debug> [1320922236.015239] [mm-qcdm-serial-port.c:194] debug_log(): (ttyS1): --> 00 78 f0 7e modem-manager[24420]: <debug> [1320922239.013710] [mm-serial-port.c:856] mm_serial_port_close(): (ttyS1) device open count is 0 (close) modem-manager[24420]: <info> [1320922239.014080] [mm-serial-port.c:871] mm_serial_port_close(): (ttyS1) closing serial port... modem-manager[24420]: <info> [1320922239.014535] [mm-serial-port.c:892] mm_serial_port_close(): (ttyS1) serial port closed modem-manager[24420]: <info> [1320922393.327969] [mm-serial-port.c:760] mm_serial_port_open(): (ttyACM0) opening serial port... modem-manager[24420]: <debug> [1320922393.332238] [mm-serial-port.c:822] mm_serial_port_open(): (ttyACM0) device open count is 1 (open) modem-manager[24420]: <debug> [1320922393.332910] [mm-plugin-base.c:1021] try_open(): (ttyACM0): probe requested by plugin 'Wavecom' modem-manager[24420]: <debug> [1320922393.437572] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GCAP<CR>' modem-manager[24420]: <debug> [1320922394.133493] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- 'AT+GCAP' modem-manager[24420]: <debug> [1320922394.135065] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR>' modem-manager[24420]: <debug> [1320922394.145907] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+GCAP: +CGSM, +FCLASS<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922394.147342] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMI<CR>' modem-manager[24420]: <debug> [1320922394.843058] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- 'AT+CGMI' modem-manager[24420]: <debug> [1320922394.844461] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR>' modem-manager[24420]: <debug> [1320922394.855503] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922394.857161] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMM<CR>' modem-manager[24420]: <debug> [1320922395.553007] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- 'AT+CGMM' modem-manager[24420]: <debug> [1320922395.554426] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR>' modem-manager[24420]: <debug> [1320922395.565207] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> MULTIBAND 900E 1800 <CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.566383] [mm-serial-port.c:856] mm_serial_port_close(): (ttyACM0) device open count is 0 (close) modem-manager[24420]: <info> [1320922395.566707] [mm-serial-port.c:871] mm_serial_port_close(): (ttyACM0) closing serial port... modem-manager[24420]: <info> [1320922395.584601] [mm-serial-port.c:892] mm_serial_port_close(): (ttyACM0) serial port closed modem-manager[24420]: <debug> [1320922395.635306] [mm-modem-base.c:207] mm_modem_base_add_port(): (ttyACM0) type primary claimed by /sys/devices/platform/at91_ohci/usb1/1-1 modem-manager[24420]: <info> [1320922395.637911] [mm-serial-port.c:760] mm_serial_port_open(): (ttyACM0) opening serial port... modem-manager[24420]: <debug> [1320922395.640081] [mm-serial-port.c:822] mm_serial_port_open(): (ttyACM0) device open count is 1 (open) modem-manager[24420]: <debug> [1320922395.641177] [mm-serial-port.c:822] mm_serial_port_open(): (ttyACM0) device open count is 2 (open) modem-manager[24420]: <debug> [1320922395.641982] [mm-serial-port.c:822] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) modem-manager[24420]: <info> [1320922395.643749] [mm-manager.c:599] do_grab_port(): (Wavecom): GSM modem /sys/devices/platform/at91_ohci/usb1/1-1 claimed port ttyACM0 modem-manager[24420]: <debug> [1320922395.644578] [mm-manager.c:352] add_modem(): Added modem /sys/devices/platform/at91_ohci/usb1/1-1 modem-manager[24420]: <debug> [1320922395.646429] [mm-manager.c:278] check_export_modem(): (tty/ttyACM0): outstanding support task prevents export of /sys/devices/platform/at91_ohci/usb1/1-1 modem-manager[24420]: <debug> [1320922395.650410] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATE0<CR>' modem-manager[24420]: <debug> [1320922395.653035] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- 'AT' modem-manager[24420]: <debug> [1320922395.655633] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- 'E0<CR>' modem-manager[24420]: <debug> [1320922395.665750] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.667275] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GMI<CR>' modem-manager[24420]: <debug> [1320922395.675797] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF>' modem-manager[24420]: <debug> [1320922395.685764] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.687606] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GMM<CR>' modem-manager[24420]: <debug> [1320922395.695948] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> MULTIBAND 900E 1800 ' modem-manager[24420]: <debug> [1320922395.697890] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.699304] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GMR<CR>' modem-manager[24420]: <debug> [1320922395.715144] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>R7.43.0.201003261552.FXT009 2139952 032610 15:52<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.716588] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMI<CR>' modem-manager[24420]: <debug> [1320922395.725803] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF>' modem-manager[24420]: <debug> [1320922395.727624] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.729043] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMM<CR>' modem-manager[24420]: <debug> [1320922395.745117] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> MULTIBAND 900E 1800 <CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.746541] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMR<CR>' modem-manager[24420]: <debug> [1320922395.755950] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>R7.43.0.201003261552.FXT009 2139952 032610 15:52<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.757651] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATI<CR>' modem-manager[24420]: <debug> [1320922395.775144] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF><CR><LF> MULTIBAND 900E 1800 <CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.776598] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATI1<CR>' modem-manager[24420]: <debug> [1320922395.786040] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.787642] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GSN<CR>' modem-manager[24420]: <debug> [1320922395.805085] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>353270040255830<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.806507] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGSN<CR>' modem-manager[24420]: <debug> [1320922395.835044] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>353270040255830<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.837177] [mm-modem-helpers.c:888] mm_create_device_identifier(): Device ID source '0000114f00001234WAVECOMWIRELESSCPUMULTIBAND900E1800353270040255830R7.43.0.201003261552.FXT009213995203261015:52MULTIBAND900E1800WAVECOMWIRELESSCPU' modem-manager[24420]: <debug> [1320922395.837816] [mm-modem-helpers.c:889] mm_create_device_identifier(): Device ID 'b330ba4f67afbd226ecd66a75e9ac66756ef3deb' modem-manager[24420]: <debug> [1320922395.838806] [mm-serial-port.c:856] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) modem-manager[24420]: <debug> [1320922395.839548] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATE0<CR>' modem-manager[24420]: <debug> [1320922395.855054] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.857175] [mm-serial-port.c:856] mm_serial_port_close(): (ttyACM0) device open count is 1 (close) modem-manager[24420]: <debug> [1320922395.857840] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CMEE=1<CR>' modem-manager[24420]: <debug> [1320922395.875042] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.876304] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CPIN?<CR>' modem-manager[24420]: <debug> [1320922395.895035] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CPIN: SIM PIN<CR><LF>' modem-manager[24420]: <debug> [1320922395.897934] [mm-serial-port.c:822] mm_serial_port_open(): (ttyACM0) device open count is 2 (open) modem-manager[24420]: <debug> [1320922395.898691] [mm-serial-port.c:856] mm_serial_port_close(): (ttyACM0) device open count is 1 (close) modem-manager[24420]: <debug> [1320922395.900241] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CRSM=176,12258,0,0,10<CR>' modem-manager[24420]: <debug> [1320922395.944891] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CRSM: 144,0,"98940232054910047404"<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922395.946226] [mm-serial-port.c:856] mm_serial_port_close(): (ttyACM0) device open count is 0 (close) modem-manager[24420]: <info> [1320922395.946845] [mm-serial-port.c:871] mm_serial_port_close(): (ttyACM0) closing serial port... modem-manager[24420]: <info> [1320922395.965030] [mm-serial-port.c:892] mm_serial_port_close(): (ttyACM0) serial port closed modem-manager[24420]: <debug> [1320922395.965969] [mm-generic-gsm.c:492] get_iccid_done(): SIM ID source '89492023509401404740' modem-manager[24420]: <debug> [1320922395.966530] [mm-generic-gsm.c:493] get_iccid_done(): SIM ID '71cdf6cacc17f1c4b14b36dca306266413bb2718' modem-manager[24420]: <debug> [1320922395.969139] [mm-manager.c:300] check_export_modem(): Exported modem /sys/devices/platform/at91_ohci/usb1/1-1 as /org/freedesktop/ModemManager/Modems/0 modem-manager[24420]: <debug> [1320922395.970274] [mm-manager.c:313] check_export_modem(): (/org/freedesktop/ModemManager/Modems/0): VID 0x114F PID 0x1234 (usb) modem-manager[24420]: <debug> [1320922395.970831] [mm-manager.c:314] check_export_modem(): (/org/freedesktop/ModemManager/Modems/0): data port is ttyACM0 modem-manager[24420]: <info> [1320922418.212473] [mm-serial-port.c:760] mm_serial_port_open(): (ttyACM0) opening serial port... modem-manager[24420]: <debug> [1320922418.214878] [mm-serial-port.c:822] mm_serial_port_open(): (ttyACM0) device open count is 1 (open) modem-manager[24420]: <debug> [1320922418.216218] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CPIN="0000"<CR>' modem-manager[24420]: <debug> [1320922420.073095] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.074217] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CPIN?<CR>' modem-manager[24420]: <debug> [1320922420.112915] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CPIN: READY<CR><LF>' modem-manager[24420]: <info> [1320922420.113652] [mm-modem-base.c:351] mm_modem_base_set_unlock_required(): Modem /org/freedesktop/ModemManager/Modems/0: unlock no longer required modem-manager[24420]: <info> [1320922420.114315] [mm-modem-base.c:390] mm_modem_base_set_unlock_retries(): Modem /org/freedesktop/ModemManager/Modems/0: # unlock retries is 0 modem-manager[24420]: <debug> [1320922420.117961] [mm-serial-port.c:856] mm_serial_port_close(): (ttyACM0) device open count is 0 (close) modem-manager[24420]: <info> [1320922420.118293] [mm-serial-port.c:871] mm_serial_port_close(): (ttyACM0) closing serial port... modem-manager[24420]: <info> [1320922420.138629] [mm-serial-port.c:892] mm_serial_port_close(): (ttyACM0) serial port closed modem-manager[24420]: <info> [1320922420.151296] [mm-serial-port.c:760] mm_serial_port_open(): (ttyACM0) opening serial port... modem-manager[24420]: <debug> [1320922420.152983] [mm-serial-port.c:822] mm_serial_port_open(): (ttyACM0) device open count is 1 (open) modem-manager[24420]: <info> [1320922420.154825] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling) modem-manager[24420]: <debug> [1320922420.264168] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATZ E0 V1<CR>' modem-manager[24420]: <debug> [1320922420.392761] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.393895] [mm-modem-wavecom-gsm.c:1111] do_enable_power_up_done(): [1/5] Getting current functionality status... modem-manager[24420]: <debug> [1320922420.394558] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATE0<CR>' modem-manager[24420]: <debug> [1320922420.412765] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.413756] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CMEE=1<CR>' modem-manager[24420]: <debug> [1320922420.432759] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.433747] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATX4 &C1<CR>' modem-manager[24420]: <debug> [1320922420.452739] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.453728] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CFUN?<CR>' modem-manager[24420]: <debug> [1320922420.472746] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CFUN: 1<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.473548] [mm-modem-wavecom-gsm.c:1079] get_current_functionality_status_cb(): [2/5] Getting supported MS classes... modem-manager[24420]: <debug> [1320922420.474204] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGCLASS=?<CR>' modem-manager[24420]: <debug> [1320922420.483470] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGCLASS: ("CG","CC","B")<CR><LF>' modem-manager[24420]: <debug> [1320922420.485361] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.486225] [mm-modem-wavecom-gsm.c:1015] get_supported_ms_classes_cb(): Modem supports Class B mobile station modem-manager[24420]: <debug> [1320922420.486495] [mm-modem-wavecom-gsm.c:1020] get_supported_ms_classes_cb(): Modem supports Class CG mobile station modem-manager[24420]: <debug> [1320922420.486717] [mm-modem-wavecom-gsm.c:1025] get_supported_ms_classes_cb(): Modem supports Class CC mobile station modem-manager[24420]: <debug> [1320922420.486918] [mm-modem-wavecom-gsm.c:1042] get_supported_ms_classes_cb(): [3/5] Getting current MS class... modem-manager[24420]: <debug> [1320922420.487525] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGCLASS?<CR>' modem-manager[24420]: <debug> [1320922420.502728] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGCLASS: "B"<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.503575] [mm-modem-wavecom-gsm.c:953] get_current_ms_class_cb(): Modem configured as a Class B mobile station modem-manager[24420]: <debug> [1320922420.503842] [mm-modem-wavecom-gsm.c:978] get_current_ms_class_cb(): [4/5] Ensuring highest MS class... modem-manager[24420]: <debug> [1320922420.504070] [mm-modem-wavecom-gsm.c:917] set_highest_ms_class(): No need to change mobile station class modem-manager[24420]: <debug> [1320922420.504306] [mm-modem-wavecom-gsm.c:872] set_highest_ms_class_cb(): [5/5] All done modem-manager[24420]: <debug> [1320922420.505540] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+IFC=2,2<CR>' modem-manager[24420]: <debug> [1320922420.522708] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.523713] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CNMI=2,1,2,1,0<CR>' modem-manager[24420]: <debug> [1320922420.552676] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CMS ERROR: 515<CR><LF>'
modem-manager[24420]: Invalid error code: 515
modem-manager[24420]: <debug> [1320922420.553778] [mm-serial-parsers.c:412] mm_serial_parser_v1_parse(): Got failure code 100: Unknown error modem-manager[24420]: <debug> [1320922420.554416] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CPMS="ME","ME","ME"<CR>' modem-manager[24420]: <debug> [1320922420.572690] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CMS ERROR: 515<CR><LF>'
modem-manager[24420]: Invalid error code: 515
modem-manager[24420]: <debug> [1320922420.573680] [mm-serial-parsers.c:412] mm_serial_parser_v1_parse(): Got failure code 100: Unknown error modem-manager[24420]: <debug> [1320922420.574275] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND=?<CR>' modem-manager[24420]: <debug> [1320922420.592761] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CIND: ("battchg",(0-5)),("signal",(0-5)),("service",(0-1)),("message",(0-1)),("call",(0-1)),("roam",(0-1)),("smsfull",(0-2))<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.594837] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CSCS=?<CR>' modem-manager[24420]: <debug> [1320922420.613322] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CSCS: ("GSM","PCCP437","CUSTOM","HEX")<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.615275] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CMER=3,0,0,1<CR>' modem-manager[24420]: <debug> [1320922420.632654] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.633668] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CSCS="GSM"<CR>' modem-manager[24420]: <debug> [1320922420.652645] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.653718] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CSCS?<CR>' modem-manager[24420]: <debug> [1320922420.663293] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CSCS: "GSM"<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <info> [1320922420.666143] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled) modem-manager[24420]: <debug> [1320922420.669362] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG=2<CR>' modem-manager[24420]: <debug> [1320922420.692640] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF><CR><LF>+CREG: 2<CR><LF>' modem-manager[24420]: <debug> [1320922420.693139] [mm-generic-gsm.c:2585] mm_generic_gsm_set_reg_status(): CS registration state changed: 2 modem-manager[24420]: <info> [1320922420.694649] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> searching) modem-manager[24420]: <debug> [1320922420.698761] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[24420]: <debug> [1320922420.712636] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,2<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.714025] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGREG=2<CR>' modem-manager[24420]: <debug> [1320922420.732607] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF><CR><LF>+CGREG: 0<CR><LF>' modem-manager[24420]: <debug> [1320922420.733903] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGREG?<CR>' modem-manager[24420]: <debug> [1320922420.748957] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGREG: 2,0<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922420.751657] [mm-generic-gsm.c:5146] simple_connect(): (ttyACM0): network_mode => 0 modem-manager[24420]: <debug> [1320922420.751994] [mm-generic-gsm.c:5146] simple_connect(): (ttyACM0): allowed_mode => 0 modem-manager[24420]: <debug> [1320922420.754311] [mm-generic-gsm.c:5146] simple_connect(): (ttyACM0): username => "vodafone" modem-manager[24420]: <debug> [1320922420.754897] [mm-generic-gsm.c:5146] simple_connect(): (ttyACM0): number => "*99#" modem-manager[24420]: <debug> [1320922420.755507] [mm-generic-gsm.c:5146] simple_connect(): (ttyACM0): pin => "0000" modem-manager[24420]: <debug> [1320922420.756093] [mm-generic-gsm.c:5146] simple_connect(): (ttyACM0): apn => "web.vodafone.de" modem-manager[24420]: <debug> [1320922420.756677] [mm-generic-gsm.c:5146] simple_connect(): (ttyACM0): password => "vodafone" modem-manager[24420]: <debug> [1320922420.757466] [mm-generic-gsm.c:5035] simple_state_machine(): (ttyACM0): simple connect state 0 modem-manager[24420]: <debug> [1320922420.758647] [mm-generic-gsm.c:5035] simple_state_machine(): (ttyACM0): simple connect state 2 modem-manager[24420]: <debug> [1320922420.759827] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[24420]: <debug> [1320922420.772547] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,2<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922422.002059] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[24420]: <debug> [1320922422.012950] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,2<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922423.011999] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[24420]: <debug> [1320922423.022411] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,2<CR><LF>' modem-manager[24420]: <debug> [1320922423.032419] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922424.011984] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[24420]: <debug> [1320922424.031816] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,2<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922424.281788] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 1,"013D","D4BF"<CR><LF><CR><LF>+CIEV: 3,1<CR><LF>' modem-manager[24420]: <debug> [1320922424.282598] [mm-generic-gsm.c:2585] mm_generic_gsm_set_reg_status(): CS registration state changed: 1 modem-manager[24420]: <info> [1320922424.285553] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (searching -> registered) modem-manager[24420]: <debug> [1320922424.286850] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+COPS=3,2;+COPS?<CR>' modem-manager[24420]: <debug> [1320922424.311713] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+COPS: 0,2,26202<CR><LF>' modem-manager[24420]: <debug> [1320922424.313339] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922424.314836] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+COPS=3,0;+COPS?<CR>' modem-manager[24420]: <debug> [1320922424.341805] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+COPS: 0,0,"Vodafone.de"<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922424.345119] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND?<CR>' modem-manager[24420]: <debug> [1320922424.361827] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CIND: 3,5,1,0,0,0,0<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922424.365352] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+WGPRS=9,2<CR>' modem-manager[24420]: <debug> [1320922424.381825] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+WGPRSIND: 1<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922425.011965] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[24420]: <debug> [1320922425.022410] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,1,"013D","D4BF"<CR><LF>' modem-manager[24420]: <debug> [1320922425.024280] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922425.025441] [mm-generic-gsm.c:5035] simple_state_machine(): (ttyACM0): simple connect state 4 modem-manager[24420]: <debug> [1320922425.026251] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGDCONT?<CR>' modem-manager[24420]: <debug> [1320922425.041835] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGDCONT: 1,"IP","web.vodafone.de",,0,0<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922425.043248] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGDCONT=?<CR>' modem-manager[24420]: <debug> [1320922425.061859] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGDCONT: (1-4),"IP",,,(0-1),(0-1)<CR><LF>+CGDCONT: (1-4),"PPP",,,0,0<CR><LF><CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922425.063429] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGDCONT=1,"IP","web.vodafone.de"<CR>' modem-manager[24420]: <debug> [1320922425.091678] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[24420]: <debug> [1320922425.093073] [mm-generic-gsm.c:5035] simple_state_machine(): (ttyACM0): simple connect state 5 modem-manager[24420]: <info> [1320922425.095743] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered -> connecting) modem-manager[24420]: <debug> [1320922425.096844] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATD*99***1#<CR>' modem-manager[24420]: <debug> [1320922425.122085] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>CONNECT 57600<CR><LF>~\255}#\192!}!}!} }<}!}$}%\220}"}&} } } } }%}&} } } } }'}"}(}"}#}$\192#\137U~' modem-manager[24420]: <debug> [1320922425.123365] [mm-port.c:181] mm_port_set_connected(): (ttyACM0): port now connected modem-manager[24420]: <info> [1320922425.125935] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting -> connected) modem-manager[24420]: <debug> [1320922425.126931] [mm-generic-gsm.c:5035] simple_state_machine(): (ttyACM0): simple connect state 6 modem-manager[24420]: <debug> [1320922425.345933] [mm-manager.c:828] device_added(): (net/ppp0): could not get port's parent device


######### NM-Log ###########
# NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
NetworkManager[24377]: <info> NetworkManager (version 0.8.5.0) is starting... NetworkManager[24377]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
NetworkManager[24377]: <info> modem-manager is now available
NetworkManager[24377]: <info> monitoring kernel firmware directory '/lib/firmware'.
NetworkManager[24377]:    SCPlugin-Ifupdown: init!
NetworkManager[24377]:    SCPlugin-Ifupdown: update_system_hostname
NetworkManager[24377]: SCPluginIfupdown: guessed connection type (wlan0) = 802-3-ethernet NetworkManager[24377]: SCPlugin-Ifupdown: update_connection_setting_from_if_block: name:wlan0, type:802-3-ethernet, id:Ifupdown (wlan0), uuid: 5391eba4-6426-faca-338e-5828034ff9d1
NetworkManager[24377]:    SCPlugin-Ifupdown: addresses count: 1
NetworkManager[24377]: SCPlugin-Ifupdown: No dns-nameserver configured in /etc/network/interfaces NetworkManager[24377]: SCPlugin-Ifupdown: adding wlan0 to iface_connections NetworkManager[24377]: SCPlugin-Ifupdown: adding iface wlan0 to well_known_interfaces
NetworkManager[24377]:    SCPlugin-Ifupdown: autoconnect
NetworkManager[24377]:    SCPluginIfupdown: management mode: unmanaged
NetworkManager[24377]: SCPlugin-Ifupdown: devices added (path: /sys/devices/platform/at91_ohci/usb1/1-2/1-2:1.0/net/eth0, iface: eth0) NetworkManager[24377]: SCPlugin-Ifupdown: device added (path: /sys/devices/platform/at91_ohci/usb1/1-2/1-2:1.0/net/eth0, iface: eth0): no ifupdown configuration found. NetworkManager[24377]: SCPlugin-Ifupdown: devices added (path: /sys/devices/platform/at91_udc/gadget/net/usb0, iface: usb0) NetworkManager[24377]: SCPlugin-Ifupdown: device added (path: /sys/devices/platform/at91_udc/gadget/net/usb0, iface: usb0): no ifupdown configuration found. NetworkManager[24377]: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/lo, iface: lo) NetworkManager[24377]: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/lo, iface: lo): no ifupdown configuration found.
NetworkManager[24377]:    SCPlugin-Ifupdown: end _init.
NetworkManager[24377]: <info> Loaded plugin ifupdown: (C) 2008 Canonical Ltd. To report bugs please use the NetworkManager mailing list. NetworkManager[24377]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc. To report bugs please use the NetworkManager mailing list.
NetworkManager[24377]:    Ifupdown: get unmanaged devices count: 0
NetworkManager[24377]:    SCPlugin-Ifupdown: (810040) ... get_connections.
NetworkManager[24377]: SCPlugin-Ifupdown: (810040) ... get_connections (managed=false): return empty list.
NetworkManager[24377]:    keyfile: parsing ModemGSM ...
NetworkManager[24377]:    keyfile:     read connection 'ModemGSM'
NetworkManager[24377]:    keyfile: parsing Ethernet ...
NetworkManager[24377]:    keyfile:     read connection 'Ethernet'
NetworkManager[24377]:    keyfile: parsing UsbHost ...
NetworkManager[24377]:    keyfile:     read connection 'UsbHost'
NetworkManager[24377]:    Ifupdown: get unmanaged devices count: 0
NetworkManager[24377]: <info> WiFi enabled by radio killswitch; enabled by state file NetworkManager[24377]: <info> WWAN enabled by radio killswitch; enabled by state file NetworkManager[24377]: <info> WiMAX enabled by radio killswitch; enabled by state file
NetworkManager[24377]: <info> Networking is enabled by state file
NetworkManager[24377]: <error> [1320922177.710567] [nm-device-ethernet.c:765] real_update_permanent_hw_address(): (eth0): unable to read permanent MAC address (error 0)
NetworkManager[24377]: <info> (eth0): carrier is ON
NetworkManager[24377]: <info> (eth0): new Ethernet device (driver: 'MOSCHIP usb-ethernet driver' ifindex: 54) NetworkManager[24377]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0
NetworkManager[24377]: <info> (eth0): now managed
NetworkManager[24377]: <info> (eth0): device state change: 1 -> 2 (reason 41)
NetworkManager[24377]: <info> (eth0): preparing device.
NetworkManager[24377]: <info> Activation (eth0) starting connection 'Ethernet' NetworkManager[24377]: <info> (eth0): device stADDRCONF(NETDEV_UP): usb0: link is not ready
ate change: 2 -> 7 (reason 0)
NetworkManager[24377]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled. NetworkManager[24377]: <error> [1320922177.754330] [nm-device-ethernet.c:765] real_update_permanent_hw_address(): (usb0): unable to read permanent MAC address (error 0)
NetworkManager[24377]: <info> (usb0): carrier is OFF
NetworkManager[24377]: <info> (usb0): new Ethernet device (driver: 'at91_udc' ifindex: 4) NetworkManager[24377]: <info> (usb0): exported as /org/freedesktop/NetworkManager/Devices/1
NetworkManager[24377]: <info> (usb0): now managed
NetworkManager[24377]: <info> (usb0): device state change: 1 -> 2 (reason 2)
NetworkManager[24377]: <info> (usb0): bringing up device.
NetworkManager[24377]: <info> (usb0): preparing device.
NetworkManager[24377]: <info> (usb0): deactivating device (reason: 2).
/sbin/ifup: interface lo already configured
NetworkManager[24377]: <warn> bluez error getting default adapter: The name org.bluez was not provided by any .service files NetworkManager[24377]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started... NetworkManager[24377]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager[24377]: <info> dhclient started with pid 24379
NetworkManager[24377]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Internet Systems Consortium DHCP Client 4.1.1-P1
Copyright 2004-2010 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

Listening on LPF/eth0/00:13:3b:00:0e:66
Sending on   LPF/eth0/00:13:3b:00:0e:66
Sending on   Socket/fallback
NetworkManager[24377]: <info> (eth0): DHCPv4 state changed nbi -> preinit
DHCPREQUEST on eth0 to 255.255.255.255 port 67
DHCPACK from 192.168.12.1
bound to 192.168.12.42 -- renewal in 1713100 seconds.
NetworkManager[24377]: <info> (eth0): DHCPv4 state changed preinit -> reboot
NetworkManager[24377]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Get) scheduled... NetworkManager[24377]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Get) started...
NetworkManager[24377]: <info>   address 192.168.12.42
NetworkManager[24377]: <info>   prefix 24 (255.255.255.0)
NetworkManager[24377]: <info>   gateway 192.168.12.4
NetworkManager[24377]: <info>   nameserver '192.168.12.1'
NetworkManager[24377]: <info>   nameserver '192.168.12.3'
NetworkManager[24377]: <info>   domain name 'BLUBBLUB'
NetworkManager[24377]: <info>   wins '192.168.12.1'
NetworkManager[24377]: <info> Scheduling stage 5
NetworkManager[24377]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
NetworkManager[24377]: <info> Done scheduling stage 5
NetworkManager[24377]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Get) complete. NetworkManager[24377]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
NetworkManager[24377]: <info> (eth0): device state change: 7 -> 8 (reason 0)
NetworkManager[24377]: <info> Policy set 'Ethernet' (eth0) as default for IPv4 routing and DNS. NetworkManager[24377]: <info> Activation (eth0) successful, device activated. NetworkManager[24377]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
NetworkManager[24377]: <info> the modem manager disappeared
NetworkManager[24377]: <info> trying to start the modem manager...
NetworkManager[24377]: <info> modem-manager is now available
usb 1-1: new full speed USB device using at91_ohci and address 38
usb 1-1: New USB device found, idVendor=114f, idProduct=1234
usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 1-1: Product: WAVECOM MODEM
usb 1-1: Manufacturer: WAVECOM
usb 1-1: SerialNumber: BH1150069108100
cdc_acm 1-1:1.0: ttyACM0: USB ACM device
NetworkManager[24377]: <warn> (ttyACM0): failed to look up interface index
NetworkManager[24377]: <info> (ttyACM0): new GSM device (driver: 'cdc_acm' ifindex: -1) NetworkManager[24377]: <info> (ttyACM0): exported as /org/freedesktop/NetworkManager/Devices/2
NetworkManager[24377]: <info> (ttyACM0): now managed
NetworkManager[24377]: <info> (ttyACM0): device state change: 1 -> 2 (reason 2)
NetworkManager[24377]: <info> (ttyACM0): deactivating device (reason: 2).
NetworkManager[24377]: <info> (ttyACM0): device state change: 2 -> 3 (reason 0) NetworkManager[24377]: <info> Activation (ttyACM0) starting connection 'ModemGSM' NetworkManager[24377]: <info> (ttyACM0): device state change: 3 -> 4 (reason 0) NetworkManager[24377]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) scheduled... NetworkManager[24377]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) started... NetworkManager[24377]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[24377]: <warn> GSM modem enable failed: (32) SIM PIN required
NetworkManager[24377]: <info> WWAN now enabled by management service
NetworkManager[24377]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) scheduled... NetworkManager[24377]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) starting... NetworkManager[24377]: <info> (ttyACM0): device state change: 4 -> 5 (reason 0) NetworkManager[24377]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) successful. NetworkManager[24377]: <info> Activation (ttyACM0) Stage 3 of 5 (IP Configure Start) scheduled. NetworkManager[24377]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) complete. NetworkManager[24377]: <info> Activation (ttyACM0) Stage 3 of 5 (IP Configure Start) started... NetworkManager[24377]: <info> (ttyACM0): device state change: 5 -> 7 (reason 0)
NetworkManager[24377]: <info> starting PPP connection
NetworkManager[24377]: <info> pppd started with pid 24444
NetworkManager[24377]: <info> Activation (ttyACM0) Stage 3 of 5 (IP Configure Start) complete.
Plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so loaded.
** Message: nm-ppp-plugin: (plugin_init): initializing
** Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
using channel 50
Using interface ppp0
Connect: ppp0 <--> /dev/ttyACM0
** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9a5bf6d3> <pcomp> <accomp>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x9a5bf6d3> <pcomp> <accomp>]
NetworkManager[24377]: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0) NetworkManager[24377]: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found. rcvd [LCP ConfReq id=0x1 <mru 1500> <asyncmap 0x0> <magic 0x0> <pcomp> <accomp> <auth pap>] sent [LCP ConfAck id=0x1 <mru 1500> <asyncmap 0x0> <magic 0x0> <pcomp> <accomp> <auth pap>]
** Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate'
** Message: nm-ppp-plugin: (get_credentials): passwd-hook, requesting credentials... ** Message: nm-ppp-plugin: (get_credentials): got credentials from NetworkManager
sent [PAP AuthReq id=0x1 user="vodafone" password=<hidden>]
sent [PAP AuthReq id=0x2 user="vodafone" password=<hidden>]
rcvd [PAP AuthAck id=0x2 "Welcome!"]
Remote message: Welcome!
PAP authentication succeeded
** Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [IPCP ConfReq id=0x1 <addr 192.168.111.111>]
sent [IPCP ConfAck id=0x1 <addr 192.168.111.111>]
rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] rcvd [IPCP ConfNak id=0x2 <addr 109.45.13.31> <ms-dns1 139.7.30.126> <ms-dns2 139.7.30.125>] sent [IPCP ConfReq id=0x3 <addr 109.45.13.31> <ms-dns1 139.7.30.126> <ms-dns2 139.7.30.125>] rcvd [IPCP ConfAck id=0x3 <addr 109.45.13.31> <ms-dns1 139.7.30.126> <ms-dns2 139.7.30.125>]
local  IP address 109.45.13.31
remote IP address 192.168.111.111
primary   DNS address 139.7.30.126
secondary DNS address 139.7.30.125
** Message: nm-ppp-plugin: (nm_phasechange): status 9 / phase 'running'
** Message: nm-ppp-plugin: (nm_ip_up): ip-up event
** Message: nm-ppp-plugin: (nm_ip_up): sending Ip4Config to NetworkManager...
NetworkManager[24377]: <info> PPP manager(IP Config Get) reply received.
NetworkManager[24377]: <info> Activation (ttyACM0) Stage 4 of 5 (IP4 Configure Get) scheduled...
Script /etc/ppp/ip-up started (pid 24447)
NetworkManager[24377]: <info> Activation (ttyACM0) Stage 4 of 5 (IP4 Configure Get) started...
NetworkManager[24377]: <info> Scheduling stage 5
NetworkManager[24377]: <info> Activation (ttyACM0) Stage 5 of 5 (IP Configure Commit) scheduled...
NetworkManager[24377]: <info> Done scheduling stage 5
NetworkManager[24377]: <info> Activation (ttyACM0) Stage 4 of 5 (IP4 Configure Get) complete. NetworkManager[24377]: <info> Activation (ttyACM0) Stage 5 of 5 (IP Configure Commit) started...
Script /etc/ppp/ip-up finished (pid 24447), status = 0x0
NetworkManager[24377]: <info> Policy set 'Ethernet' (eth0) as default for IPv4 routing and DNS. NetworkManager[24377]: <info> (ttyACM0): device state change: 7 -> 8 (reason 0) NetworkManager[24377]: <info> Activation (ttyACM0) successful, device activated. NetworkManager[24377]: <info> Activation (ttyACM0) Stage 5 of 5 (IP Configure Commit) complete.

[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]