problems with fasttrack xtend fxt009



Hi,

i use latest git-snapshot from ModemManager with NM 0.8.4. I try to use a Fastttrack XTend FXT009.

I'm unable to get a working connection (see MM-Log).
After the connection, the modem does not answer to any AT-commands (see the end of MM-Log).

I tried to enable the modem with "nmcli con up id ModemGSM". See NM-Log for network-manager details.

The NetworkManager config for "ModemGSM" is:
# cat /etc/NetworkManager/system-connections/ModemGSM

[connection]
id=ModemGSM
uuid=baa2af1b-e21e-7bcf-f1ac-1a775c46ddc3
type=gsm
autoconnect=false

[ipv4]
method=auto

[gsm]
number=#99*
username=vodafone
password=vodafone
apn=web.vodafone.de
pin=0000

[serial]
baud=115200




Ideas how to solve the problem?

Cheers,

Tom



######### MM-Log ###########
# pkill modem-manager && modem-manager --debug --log-level=DEBUG
modem-manager[2800]: <info> [1320750454.293239] [main.c:167] main(): ModemManager (version 0.5.999) starting... modem-manager[2800]: <info> [1320750454.549302] [mm-manager.c:158] found_plugin(): Loaded plugin 'Option' modem-manager[2800]: <info> [1320750454.550114] [mm-manager.c:158] found_plugin(): Loaded plugin 'X22X' modem-manager[2800]: <info> [1320750454.550857] [mm-manager.c:158] found_plugin(): Loaded plugin 'Ericsson MBM' modem-manager[2800]: <info> [1320750454.574424] [mm-manager.c:158] found_plugin(): Loaded plugin 'Sierra' modem-manager[2800]: <info> [1320750454.574749] [mm-manager.c:158] found_plugin(): Loaded plugin 'Linktop' modem-manager[2800]: <info> [1320750454.575024] [mm-manager.c:158] found_plugin(): Loaded plugin 'AnyData' modem-manager[2800]: <info> [1320750454.575285] [mm-manager.c:158] found_plugin(): Loaded plugin 'Longcheer' modem-manager[2800]: <info> [1320750454.575547] [mm-manager.c:158] found_plugin(): Loaded plugin 'Wavecom' modem-manager[2800]: <info> [1320750454.575807] [mm-manager.c:158] found_plugin(): Loaded plugin 'Novatel' modem-manager[2800]: <info> [1320750454.576068] [mm-manager.c:158] found_plugin(): Loaded plugin 'SimTech' modem-manager[2800]: <info> [1320750454.576328] [mm-manager.c:158] found_plugin(): Loaded plugin 'Nokia' modem-manager[2800]: <info> [1320750454.576585] [mm-manager.c:158] found_plugin(): Loaded plugin 'Samsung' modem-manager[2800]: <info> [1320750454.576842] [mm-manager.c:158] found_plugin(): Loaded plugin 'Gobi' modem-manager[2800]: <info> [1320750454.577308] [mm-manager.c:158] found_plugin(): Loaded plugin 'Huawei' modem-manager[2800]: <info> [1320750454.578022] [mm-manager.c:158] found_plugin(): Loaded plugin 'MotoC' modem-manager[2800]: <info> [1320750454.578747] [mm-manager.c:158] found_plugin(): Loaded plugin 'ZTE' modem-manager[2800]: <info> [1320750454.579459] [mm-manager.c:158] found_plugin(): Loaded plugin 'Option High-Speed' modem-manager[2800]: <info> [1320750454.580178] [mm-manager.c:158] found_plugin(): Loaded plugin 'Cinterion' modem-manager[2800]: <info> [1320750454.580900] [mm-manager.c:158] found_plugin(): Loaded plugin 'Generic' modem-manager[2800]: <info> [1320750454.585689] [mm-manager.c:210] load_plugins(): Successfully loaded 19 plugins modem-manager[2800]: <debug> [1320750454.596035] [mm-manager.c:1030] mm_manager_start(): Starting device scan... modem-manager[2800]: <debug> [1320750454.672028] [mm-manager.c:848] device_added(): (tty/ttyS0): port's parent platform driver is not whitelisted modem-manager[2800]: <debug> [1320750454.720729] [mm-manager.c:848] device_added(): (tty/ttyS2): port's parent platform driver is not whitelisted modem-manager[2800]: <debug> [1320750454.723998] [mm-manager.c:848] device_added(): (tty/ttyS4): port's parent platform driver is not whitelisted modem-manager[2800]: <debug> [1320750454.789874] [mm-manager.c:848] device_added(): (net/usb0): port's parent platform driver is not whitelisted modem-manager[2800]: <debug> [1320750454.792532] [mm-manager.c:1048] mm_manager_start(): Finished device scan... modem-manager[2800]: <info> [1320750454.793574] [mm-serial-port.c:805] mm_serial_port_open(): (ttyACM0) opening serial port... modem-manager[2800]: <debug> [1320750454.796262] [mm-serial-port.c:874] mm_serial_port_open(): (ttyACM0) device open count is 1 (open) modem-manager[2800]: <debug> [1320750454.797095] [mm-plugin-base.c:1045] try_open(): (ttyACM0): probe requested by plugin 'Wavecom' modem-manager[2800]: <info> [1320750454.799453] [mm-serial-port.c:805] mm_serial_port_open(): (ttyS1) opening serial port... modem-manager[2800]: <debug> [1320750454.800870] [mm-serial-port.c:874] mm_serial_port_open(): (ttyS1) device open count is 1 (open) modem-manager[2800]: <debug> [1320750454.801855] [mm-plugin-base.c:1045] try_open(): (ttyS1): probe requested by plugin 'Cinterion' modem-manager[2800]: <debug> [1320750454.913371] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GCAP<CR>' modem-manager[2800]: <debug> [1320750454.914534] [mm-at-serial-port.c:298] debug_log(): (ttyS1): --> 'AT+GCAP<CR>' modem-manager[2800]: <debug> [1320750455.701495] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>ERROR<CR><LF>' modem-manager[2800]: <debug> [1320750455.702913] [mm-serial-parsers.c:410] mm_serial_parser_v1_parse(): Got failure code 100: Unknown error modem-manager[2800]: <debug> [1320750455.704925] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GCAP<CR>' modem-manager[2800]: <debug> [1320750456.501299] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+GCAP: +CGSM, +FCLASS<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750456.503317] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMI<CR>' modem-manager[2800]: <debug> [1320750457.301288] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750457.302884] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMM<CR>' modem-manager[2800]: <debug> [1320750458.101329] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> MULTIBAND 900E 1800 <CR><LF>' modem-manager[2800]: <debug> [1320750458.103032] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.104516] [mm-serial-port.c:908] mm_serial_port_close(): (ttyACM0) device open count is 0 (close) modem-manager[2800]: <info> [1320750458.104958] [mm-serial-port.c:923] mm_serial_port_close(): (ttyACM0) closing serial port... modem-manager[2800]: <info> [1320750458.123758] [mm-serial-port.c:944] mm_serial_port_close(): (ttyACM0) serial port closed modem-manager[2800]: <debug> [1320750458.183205] [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[2800]: <info> [1320750458.186787] [mm-serial-port.c:805] mm_serial_port_open(): (ttyACM0) opening serial port... modem-manager[2800]: <debug> [1320750458.189264] [mm-serial-port.c:874] mm_serial_port_open(): (ttyACM0) device open count is 1 (open) modem-manager[2800]: <debug> [1320750458.190582] [mm-serial-port.c:874] mm_serial_port_open(): (ttyACM0) device open count is 2 (open) modem-manager[2800]: <debug> [1320750458.191542] [mm-serial-port.c:874] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) modem-manager[2800]: <info> [1320750458.193328] [mm-manager.c:603] do_grab_port(): (Wavecom): GSM modem /sys/devices/platform/at91_ohci/usb1/1-1 claimed port ttyACM0 modem-manager[2800]: <debug> [1320750458.193944] [mm-manager.c:356] add_modem(): Added modem /sys/devices/platform/at91_ohci/usb1/1-1 modem-manager[2800]: <debug> [1320750458.194427] [mm-manager.c:282] check_export_modem(): (tty/ttyACM0): outstanding support task prevents export of /sys/devices/platform/at91_ohci/usb1/1-1 modem-manager[2800]: <debug> [1320750458.198731] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATE0<CR>' modem-manager[2800]: <debug> [1320750458.211416] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.213254] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GMI<CR>' modem-manager[2800]: <debug> [1320750458.221366] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF>' modem-manager[2800]: <debug> [1320750458.223308] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.225144] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GMM<CR>' modem-manager[2800]: <debug> [1320750458.241356] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> MULTIBAND 900E 1800 <CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.243135] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GMR<CR>' modem-manager[2800]: <debug> [1320750458.251384] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>R7.43.0.201003261552.FXT009 2139952 032610 15:52<CR><LF>' modem-manager[2800]: <debug> [1320750458.253349] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.255128] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMI<CR>' modem-manager[2800]: <debug> [1320750458.271357] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.273152] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMM<CR>' modem-manager[2800]: <debug> [1320750458.281337] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>' modem-manager[2800]: <debug> [1320750458.283306] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- ' MULTIBAND 900E 1800 <CR><LF>' modem-manager[2800]: <debug> [1320750458.285267] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.287049] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGMR<CR>' modem-manager[2800]: <debug> [1320750458.301364] [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[2800]: <debug> [1320750458.303154] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATI<CR>' modem-manager[2800]: <debug> [1320750458.311409] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF> WAVECOM WIRELESS CPU<CR><LF><CR><LF> MULTIBAND 900E 1800 ' modem-manager[2800]: <debug> [1320750458.313589] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.315423] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATI1<CR>' modem-manager[2800]: <debug> [1320750458.331321] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.333045] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+GSN<CR>' modem-manager[2800]: <debug> [1320750458.341358] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>353270040463475<CR><LF>' modem-manager[2800]: <debug> [1320750458.343320] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.345070] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGSN<CR>' modem-manager[2800]: <debug> [1320750458.361350] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>353270040463475<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.363964] [mm-modem-helpers.c:917] mm_create_device_identifier(): Device ID source '0000114f00001234WAVECOMWIRELESSCPUMULTIBAND900E1800353270040463475R7.43.0.201003261552.FXT009213995203261015:52MULTIBAND900E1800WAVECOMWIRELESSCPU' modem-manager[2800]: <debug> [1320750458.364727] [mm-modem-helpers.c:918] mm_create_device_identifier(): Device ID '91d241a8dfb846e81effccb4307874dccbd72558' modem-manager[2800]: <debug> [1320750458.365969] [mm-serial-port.c:908] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) modem-manager[2800]: <debug> [1320750458.366900] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATE0<CR>' modem-manager[2800]: <debug> [1320750458.381348] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.383945] [mm-serial-port.c:908] mm_serial_port_close(): (ttyACM0) device open count is 1 (close) modem-manager[2800]: <debug> [1320750458.384777] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CMEE=1<CR>' modem-manager[2800]: <debug> [1320750458.401380] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.402970] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CPIN?<CR>' modem-manager[2800]: <debug> [1320750458.421350] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CPIN: READY<CR><LF>' modem-manager[2800]: <debug> [1320750458.423123] [mm-serial-port.c:874] mm_serial_port_open(): (ttyACM0) device open count is 2 (open) modem-manager[2800]: <debug> [1320750458.424059] [mm-serial-port.c:908] mm_serial_port_close(): (ttyACM0) device open count is 1 (close) modem-manager[2800]: <debug> [1320750458.425146] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CRSM=176,12258,0,0,10<CR>' modem-manager[2800]: <debug> [1320750458.491348] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CRSM: 144,0,"98940232054910047404"<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750458.492929] [mm-serial-port.c:908] mm_serial_port_close(): (ttyACM0) device open count is 0 (close) modem-manager[2800]: <info> [1320750458.493699] [mm-serial-port.c:923] mm_serial_port_close(): (ttyACM0) closing serial port... modem-manager[2800]: <info> [1320750458.512271] [mm-serial-port.c:944] mm_serial_port_close(): (ttyACM0) serial port closed modem-manager[2800]: <debug> [1320750458.513465] [mm-generic-gsm.c:504] get_iccid_done(): SIM ID source '89492023509401404740' modem-manager[2800]: <debug> [1320750458.514170] [mm-generic-gsm.c:505] get_iccid_done(): SIM ID '71cdf6cacc17f1c4b14b36dca306266413bb2718' modem-manager[2800]: <debug> [1320750458.517382] [mm-manager.c:304] check_export_modem(): Exported modem /sys/devices/platform/at91_ohci/usb1/1-1 as /org/freedesktop/ModemManager/Modems/0 modem-manager[2800]: <debug> [1320750458.518783] [mm-manager.c:317] check_export_modem(): (/org/freedesktop/ModemManager/Modems/0): VID 0x114F PID 0x1234 (usb) modem-manager[2800]: <debug> [1320750458.854455] [mm-manager.c:318] check_export_modem(): (/org/freedesktop/ModemManager/Modems/0): data port is ttyACM0 modem-manager[2800]: <debug> [1320750459.011861] [mm-at-serial-port.c:298] debug_log(): (ttyS1): --> 'AT+GCAP<CR>' modem-manager[2800]: <debug> [1320750463.011807] [mm-at-serial-port.c:298] debug_log(): (ttyS1): --> 'AT+GCAP<CR>' modem-manager[2800]: <debug> [1320750467.011627] [mm-serial-port.c:908] mm_serial_port_close(): (ttyS1) device open count is 0 (close) modem-manager[2800]: <info> [1320750467.012076] [mm-serial-port.c:923] mm_serial_port_close(): (ttyS1) closing serial port... modem-manager[2800]: <info> [1320750467.012624] [mm-serial-port.c:944] mm_serial_port_close(): (ttyS1) serial port closed modem-manager[2800]: <info> [1320750467.014151] [mm-serial-port.c:805] mm_serial_port_open(): (ttyS1) opening serial port... modem-manager[2800]: <debug> [1320750467.015175] [mm-serial-port.c:874] mm_serial_port_open(): (ttyS1) device open count is 1 (open) modem-manager[2800]: <debug> [1320750467.016106] [mm-qcdm-serial-port.c:194] debug_log(): (ttyS1): --> 00 78 f0 7e modem-manager[2800]: <debug> [1320750470.021636] [mm-qcdm-serial-port.c:194] debug_log(): (ttyS1): --> 00 78 f0 7e modem-manager[2800]: <debug> [1320750473.021678] [mm-serial-port.c:908] mm_serial_port_close(): (ttyS1) device open count is 0 (close) modem-manager[2800]: <info> [1320750473.022126] [mm-serial-port.c:923] mm_serial_port_close(): (ttyS1) closing serial port... modem-manager[2800]: <info> [1320750473.022657] [mm-serial-port.c:944] mm_serial_port_close(): (ttyS1) serial port closed modem-manager[2800]: <info> [1320750473.309138] [mm-serial-port.c:805] mm_serial_port_open(): (ttyACM0) opening serial port... modem-manager[2800]: <debug> [1320750473.321421] [mm-serial-port.c:874] mm_serial_port_open(): (ttyACM0) device open count is 1 (open) modem-manager[2800]: <info> [1320750473.323613] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling) modem-manager[2800]: <debug> [1320750473.442614] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATZ E0 V1<CR>' modem-manager[2800]: <debug> [1320750473.541275] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.542865] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATZ E0 V1<CR>' modem-manager[2800]: <debug> [1320750473.641276] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.642992] [mm-modem-wavecom-gsm.c:1138] do_enable_power_up_check_needed(): Getting current functionality status... modem-manager[2800]: <debug> [1320750473.644236] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATE0<CR>' modem-manager[2800]: <debug> [1320750473.661311] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.662870] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CMEE=1<CR>' modem-manager[2800]: <debug> [1320750473.681325] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.682888] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATX4 &C1<CR>' modem-manager[2800]: <debug> [1320750473.701316] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.702857] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CFUN?<CR>' modem-manager[2800]: <debug> [1320750473.721963] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CFUN: 1<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.723286] [mm-modem-wavecom-gsm.c:1105] get_current_functionality_status_cb(): Already in full functionality status, skipping power-up command modem-manager[2800]: <debug> [1320750473.724437] [mm-generic-gsm.c:1811] enable_power_up_check_needed_done(): Power-up not needed, skipping... modem-manager[2800]: <debug> [1320750473.725212] [mm-modem-wavecom-gsm.c:1079] do_enable_power_up_done(): [1/4] Getting supported MS classes... modem-manager[2800]: <debug> [1320750473.726408] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGCLASS=?<CR>' modem-manager[2800]: <debug> [1320750473.741350] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGCLASS: ("CG","CC","B")<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.742737] [mm-modem-wavecom-gsm.c:1021] get_supported_ms_classes_cb(): Modem supports Class B mobile station modem-manager[2800]: <debug> [1320750473.743445] [mm-modem-wavecom-gsm.c:1026] get_supported_ms_classes_cb(): Modem supports Class CG mobile station modem-manager[2800]: <debug> [1320750473.744148] [mm-modem-wavecom-gsm.c:1031] get_supported_ms_classes_cb(): Modem supports Class CC mobile station modem-manager[2800]: <debug> [1320750473.744846] [mm-modem-wavecom-gsm.c:1048] get_supported_ms_classes_cb(): [2/4] Getting current MS class... modem-manager[2800]: <debug> [1320750473.746041] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGCLASS?<CR>' modem-manager[2800]: <debug> [1320750473.761327] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGCLASS: "B"<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.762686] [mm-modem-wavecom-gsm.c:959] get_current_ms_class_cb(): Modem configured as a Class B mobile station modem-manager[2800]: <debug> [1320750473.763388] [mm-modem-wavecom-gsm.c:984] get_current_ms_class_cb(): [3/4] Ensuring highest MS class... modem-manager[2800]: <debug> [1320750473.764100] [mm-modem-wavecom-gsm.c:923] set_highest_ms_class(): No need to change mobile station class modem-manager[2800]: <debug> [1320750473.764828] [mm-modem-wavecom-gsm.c:878] set_highest_ms_class_cb(): [4/4] All done modem-manager[2800]: <debug> [1320750473.766886] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+IFC=2,2<CR>' modem-manager[2800]: <debug> [1320750473.781361] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.782928] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CPMS="ME","ME","ME"<CR>' modem-manager[2800]: <debug> [1320750473.801344] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CPMS: 0,99,0,99,0,99<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.802985] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CNMI=2,1,2,1,0<CR>' modem-manager[2800]: <debug> [1320750473.821312] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.822857] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CUSD=1<CR>' modem-manager[2800]: <debug> [1320750473.841303] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.842874] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND=?<CR>' modem-manager[2800]: <debug> [1320750473.861428] [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[2800]: <debug> [1320750473.864324] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CSCS=?<CR>' modem-manager[2800]: <debug> [1320750473.881335] [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[2800]: <debug> [1320750473.883975] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CMER=3,0,0,1<CR>' modem-manager[2800]: <debug> [1320750473.902458] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.904022] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CSCS="GSM"<CR>' modem-manager[2800]: <debug> [1320750473.921316] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750473.922950] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CSCS?<CR>' modem-manager[2800]: <debug> [1320750473.931346] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CSCS: "GSM"<CR><LF>' modem-manager[2800]: <debug> [1320750473.933266] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <info> [1320750473.939758] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled) modem-manager[2800]: <debug> [1320750473.957502] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG=2<CR>' modem-manager[2800]: <debug> [1320750473.971404] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF><CR><LF>+CREG: 1,"013D","D4BF"<CR><LF>' modem-manager[2800]: <debug> [1320750473.972446] [mm-generic-gsm.c:2958] mm_generic_gsm_set_reg_status(): CS registration state changed: 1 modem-manager[2800]: <info> [1320750473.978076] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> registered) modem-manager[2800]: <debug> [1320750473.991092] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+COPS=3,2;+COPS?<CR>' modem-manager[2800]: <debug> [1320750474.011654] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+COPS: 0,2,26202<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.016995] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+COPS=3,0;+COPS?<CR>' modem-manager[2800]: <debug> [1320750474.041374] [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[2800]: <debug> [1320750474.045427] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND?<CR>' modem-manager[2800]: <debug> [1320750474.061325] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CIND: 3,4,1,0,0,0,0<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.065572] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+WGPRS=9,2<CR>' modem-manager[2800]: <debug> [1320750474.081329] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+WGPRSIND: 1<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.085280] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[2800]: <debug> [1320750474.093853] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,1,"013D","D4BF"<CR><LF>' modem-manager[2800]: <debug> [1320750474.095865] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.097689] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGREG=2<CR>' modem-manager[2800]: <debug> [1320750474.121317] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.123056] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGREG?<CR>' modem-manager[2800]: <debug> [1320750474.140192] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGREG: 2,0<CR><LF>' modem-manager[2800]: <debug> [1320750474.144179] [mm-generic-gsm.c:5601] simple_connect(): (ttyACM0): network_mode => 0 modem-manager[2800]: <debug> [1320750474.144976] [mm-generic-gsm.c:5601] simple_connect(): (ttyACM0): allowed_mode => 0 modem-manager[2800]: <debug> [1320750474.145718] [mm-generic-gsm.c:5601] simple_connect(): (ttyACM0): username => "vodafone" modem-manager[2800]: <debug> [1320750474.146447] [mm-generic-gsm.c:5601] simple_connect(): (ttyACM0): number => "#99*" modem-manager[2800]: <debug> [1320750474.147175] [mm-generic-gsm.c:5601] simple_connect(): (ttyACM0): pin => "0000" modem-manager[2800]: <debug> [1320750474.147909] [mm-generic-gsm.c:5601] simple_connect(): (ttyACM0): apn => "web.vodafone.de" modem-manager[2800]: <debug> [1320750474.148647] [mm-generic-gsm.c:5601] simple_connect(): (ttyACM0): password => "vodafone" modem-manager[2800]: <debug> [1320750474.149675] [mm-generic-gsm.c:5490] simple_state_machine(): (ttyACM0): simple connect state 0 modem-manager[2800]: <debug> [1320750474.150901] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.487781] [mm-generic-gsm.c:5490] simple_state_machine(): (ttyACM0): simple connect state 2 modem-manager[2800]: <debug> [1320750474.489251] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>' modem-manager[2800]: <debug> [1320750474.501349] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG: 2,1,"013D","D4BF"<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.503339] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGREG?<CR>' modem-manager[2800]: <debug> [1320750474.521323] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>+CGREG: 2,0<CR><LF><CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.523298] [mm-generic-gsm.c:5490] simple_state_machine(): (ttyACM0): simple connect state 4 modem-manager[2800]: <debug> [1320750474.524709] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGDCONT?<CR>' modem-manager[2800]: <debug> [1320750474.541353] [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[2800]: <debug> [1320750474.543417] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGDCONT=?<CR>' modem-manager[2800]: <debug> [1320750474.561388] [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[2800]: <debug> [1320750474.563666] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGDCONT=1,"IP","web.vodafone.de"<CR>' modem-manager[2800]: <debug> [1320750474.591319] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.593021] [mm-generic-gsm.c:5490] simple_state_machine(): (ttyACM0): simple connect state 5 modem-manager[2800]: <info> [1320750474.596337] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered -> connecting) modem-manager[2800]: <debug> [1320750474.597703] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'ATD#99****1#<CR>' modem-manager[2800]: <debug> [1320750474.631343] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>' modem-manager[2800]: <debug> [1320750474.632505] [mm-port.c:181] mm_port_set_connected(): (ttyACM0): port now connected modem-manager[2800]: <info> [1320750474.634257] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting -> connected) modem-manager[2800]: <debug> [1320750474.635082] [mm-generic-gsm.c:5490] simple_state_machine(): (ttyACM0): simple connect state 6 modem-manager[2800]: <debug> [1320750474.884395] [mm-manager.c:832] device_added(): (net/ppp0): could not get port's parent device modem-manager[2800]: <info> [1320750495.056056] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> disconnecting) modem-manager[2800]: <debug> [1320750496.082599] [mm-port.c:181] mm_port_set_connected(): (ttyACM0): port now disconnected modem-manager[2800]: <debug> [1320750496.083519] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CGACT=0,1<CR>' modem-manager[2800]: <info> [1320750496.691256] [mm-modem.c:742] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/0: state changed (disconnecting -> registered) modem-manager[2800]: <debug> [1320750504.021742] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND?<CR>' modem-manager[2800]: <debug> [1320750504.626068] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+WGPRS=9,2<CR>' modem-manager[2800]: <debug> [1320750534.042036] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND?<CR>' modem-manager[2800]: <debug> [1320750534.646299] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+WGPRS=9,2<CR>' modem-manager[2800]: <debug> [1320750564.041759] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND?<CR>' modem-manager[2800]: <debug> [1320750564.646972] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+WGPRS=9,2<CR>' modem-manager[2800]: <debug> [1320750594.041765] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND?<CR>' modem-manager[2800]: <debug> [1320750594.642180] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+WGPRS=9,2<CR>' modem-manager[2800]: <debug> [1320750624.041747] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+CIND?<CR>' modem-manager[2800]: <debug> [1320750624.638711] [mm-at-serial-port.c:298] debug_log(): (ttyACM0): --> 'AT+WGPRS=9,2<CR>'
####################################




######### NM-Log ###########
NetworkManager[2740]: <info> Activation (ttyACM0) starting connection 'ModemGSM' NetworkManager[2740]: <info> (ttyACM0): device state change: 3 -> 4 (reason 0) NetworkManager[2740]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) scheduled... NetworkManager[2740]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) started... NetworkManager[2740]: <info> (ttyACM0): device state change: 4 -> 6 (reason 0) NetworkManager[2740]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) complete. NetworkManager[2740]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) scheduled... NetworkManager[2740]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) started... NetworkManager[2740]: <info> (ttyACM0): device state change: 6 -> 4 (reason 0) NetworkManager[2740]: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[2740]: <info> WWAN now enabled by management service
NetworkManager[2740]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) scheduled... NetworkManager[2740]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) starting... NetworkManager[2740]: <info> (ttyACM0): device state change: 4 -> 5 (reason 0) NetworkManager[2740]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) successful. NetworkManager[2740]: <info> Activation (ttyACM0) Stage 3 of 5 (IP Configure Start) scheduled. NetworkManager[2740]: <info> Activation (ttyACM0) Stage 2 of 5 (Device Configure) complete. NetworkManager[2740]: <info> Activation (ttyACM0) Stage 3 of 5 (IP Configure Start) started... NetworkManager[2740]: <info> (ttyACM0): device state change: 5 -> 7 (reason 0)
NetworkManager[2740]: <info> starting PPP connection
NetworkManager[2740]: <info> pppd started with pid 2810
NetworkManager[2740]: <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'
Removed stale lock on ttyACM0 (pid 2725)
using channel 14
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 0x9ecbebc0> <pcomp> <accomp>]
NetworkManager[2740]: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0) NetworkManager[2740]: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ecbebc0> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ecbebc0> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ecbebc0> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ecbebc0> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ecbebc0> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9ecbebc0> <pcomp> <accomp>]
NetworkManager[2740]: <warn> pppd timed out or didn't initialize our dbus module NetworkManager[2740]: <info> (ttyACM0): device state change: 7 -> 9 (reason 5)
NetworkManager[2740]: <info> Marking connection 'ModemGSM' invalid.
NetworkManager[2740]: <warn> Activation (ttyACM0) failed.
Terminating on signal 15
** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
sent [LCP TermReq id=0x2 "User request"]
NetworkManager[2740]: <info> (ttyACM0): device state change: 9 -> 3 (reason 0)
NetworkManager[2740]: <info> (ttyACM0): deactivating device (reason: 0).
NetworkManager[2740]: <info> Policy set 'Ethernet' (eth1) as default for IPv4 routing and DNS. NetworkManager[2740]: <info> Policy set 'Ethernet' (eth1) as default for IPv4 routing and DNS. NetworkManager[2740]: SCPlugin-Ifupdown: devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
####################################




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