Hi,

I have a Huawei E620 3G usb stick.
After some debugging to find out why it didn't want to connect, I found out the following.

When connection with NetworkManager, it sends the correct PIN code:
modem-manager[5728]: <info> [1296952772.346647] [mm-serial-port.c:702] mm_serial_port_open(): (ttyUSB0) opening serial port...
modem-manager[5728]: <debug> [1296952772.349365] [mm-serial-port.c:764] mm_serial_port_open(): (ttyUSB0) device open count is 1 (open)
modem-manager[5728]: <debug> [1296952772.349644] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CPIN="1111"<CR>'
modem-manager[5728]: <debug> [1296952772.444560] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952772.444750] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CPIN?<CR>'
modem-manager[5728]: <debug> [1296952772.464425] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
modem-manager[5728]: <info> [1296952772.464723] [mm-modem-base.c:299] mm_modem_base_set_unlock_required(): Modem /org/freedesktop/ModemManager/Modems/3: unlock no longer required
modem-manager[5728]: <info> [1296952772.464991] [mm-modem-base.c:338] mm_modem_base_set_unlock_retries(): Modem /org/freedesktop/ModemManager/Modems/3: # unlock retries is 0
modem-manager[5728]: <debug> [1296952772.465645] [mm-serial-port.c:798] mm_serial_port_close(): (ttyUSB0) device open count is 0 (close)
modem-manager[5728]: <info> [1296952772.465867] [mm-serial-port.c:811] mm_serial_port_close(): (ttyUSB0) closing serial port...
modem-manager[5728]: <info> [1296952772.467261] [mm-serial-port.c:834] mm_serial_port_close(): (ttyUSB0) serial port closed
modem-manager[5728]: <info> [1296952772.468592] [mm-serial-port.c:702] mm_serial_port_open(): (ttyUSB0) opening serial port...
modem-manager[5728]: <debug> [1296952772.471366] [mm-serial-port.c:764] mm_serial_port_open(): (ttyUSB0) device open count is 1 (open)
modem-manager[5728]: <info> [1296952772.471606] [mm-modem.c:761] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/3: state changed (disabled -> enabling)
modem-manager[5728]: <debug> [1296952772.573247] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'ATZ E0 V1<CR>'
modem-manager[5728]: <debug> [1296952772.604424] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952772.604639] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'ATE0<CR>'
modem-manager[5728]: <debug> [1296952772.614445] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952772.614639] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CMEE=1<CR>'
modem-manager[5728]: <debug> [1296952772.634432] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952772.634764] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'ATX4 &C1<CR>'
modem-manager[5728]: <debug> [1296952772.654462] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952772.654610] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CFUN=1<CR>'
modem-manager[5728]: <debug> [1296952774.474464] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952774.474628] [mm-serial-port.c:764] mm_serial_port_open(): (ttyUSB0) device open count is 2 (open)
modem-manager[5728]: <debug> [1296952774.474734] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+IFC=1,1<CR>'
modem-manager[5728]: <debug> [1296952774.494418] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952774.494556] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CIND=?<CR>'
modem-manager[5728]: <debug> [1296952774.564452] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>ERROR<CR><LF>'
modem-manager[5728]: <debug> [1296952774.564565] [mm-serial-parsers.c:340] mm_serial_parser_v1_parse(): Got failure code 100: Unknown error
modem-manager[5728]: <debug> [1296952774.564660] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CRSM=176,12258,0,0,10<CR>'
modem-manager[5728]: <debug> [1296952775.034453] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CRSM: 144,0,"982300120080533028F3"<CR><LF><CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952775.034618] [mm-serial-port.c:798] mm_serial_port_close(): (ttyUSB0) device open count is 1 (close)

As you can see it sends the PIN correctly, but it can't connect.

Feb 6 01:49:22 laptop-jl modem-manager[5728]: <debug> [1296953362.317720] [mm-generic-gsm.c:4250] simple_state_machine(): (ttyUSB0): simple connect state 0
Feb 6 01:49:22 laptop-jl modem-manager[5728]: <debug> [1296953362.317913] [mm-generic-gsm.c:4250] simple_state_machine(): (ttyUSB0): simple connect state 2
Feb 6 01:49:22 laptop-jl modem-manager[5728]: <debug> [1296953362.324422] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CGREG: 2,2,00,0<CR><LF><CR><LF>OK<CR><LF>'
Feb 6 01:49:22 laptop-jl modem-manager[5728]: <debug> [1296953362.324669] [mm-generic-gsm.c:2352] mm_generic_gsm_set_reg_status(): PS registration state changed: 2
Feb 6 01:49:22 laptop-jl modem-manager[5728]: <debug> [1296953362.324934] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CREG?<CR>'
Feb 6 01:49:22 laptop-jl modem-manager[5728]: <debug> [1296953362.344640] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CREG: 2,2,00,0<CR><LF><CR><LF>OK<CR><LF>'
Feb 6 01:49:23 laptop-jl modem-manager[5728]: <debug> [1296953363.765634] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CREG?<CR>'
Feb 6 01:49:23 laptop-jl modem-manager[5728]: <debug> [1296953363.784424] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CREG: 2,2,00,0<CR><LF><CR><LF>OK<CR><LF>'
Feb 6 01:49:25 laptop-jl modem-manager[5728]: <debug> [1296953365.766741] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CREG?<CR>'
Feb 6 01:49:28 laptop-jl modem-manager[5728]: <debug> [1296953368.991789] [mm-serial-port.c:798] mm_serial_port_close(): (ttyUSB0) device open count is 0 (close)
Feb 6 01:49:28 laptop-jl modem-manager[5728]: <info> [1296953368.991859] [mm-serial-port.c:811] mm_serial_port_close(): (ttyUSB0) closing serial port...
Feb 6 01:49:28 laptop-jl modem-manager[5728]: <info> [1296953368.991932] [mm-serial-port.c:834] mm_serial_port_close(): (ttyUSB0) serial port closed

Then we use wvdial magic:
--> WvDial: Internet dialer version 1.61
--> Cannot set information for serial port.
--> Initializing modem.
--> Sending: ATZ
OK
--> Sending: ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
OK
--> Sending: AT+CPIN=1111
AT+CPIN=1111
OK
--> Modem initialized.

And guess what, it connects without issues:

modem-manager[5728]: <info> [1296952925.235386] [mm-serial-port.c:702] mm_serial_port_open(): (ttyUSB0) opening serial port...
modem-manager[5728]: <debug> [1296952925.237993] [mm-serial-port.c:764] mm_serial_port_open(): (ttyUSB0) device open count is 1 (open)
modem-manager[5728]: <info> [1296952925.238210] [mm-modem.c:761] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/5: state changed (disabled -> enabling)
modem-manager[5728]: <debug> [1296952925.339739] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'ATZ E0 V1<CR>'
modem-manager[5728]: <debug> [1296952925.350835] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- 'ATZ E0 V'
modem-manager[5728]: <debug> [1296952925.354414] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '1<CR>'
modem-manager[5728]: <debug> [1296952925.364423] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952925.364628] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'ATE0<CR>'
modem-manager[5728]: <debug> [1296952925.374417] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952925.374623] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CMEE=1<CR>'
modem-manager[5728]: <debug> [1296952925.394418] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952925.394611] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'ATX4 &C1<CR>'
modem-manager[5728]: <debug> [1296952925.414409] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952925.414637] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CFUN=1<CR>'
modem-manager[5728]: <debug> [1296952925.434526] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952774.474628] [mm-serial-port.c:764] mm_serial_port_open(): (ttyUSB0) device open count is 2 (open)
modem-manager[5728]: <debug> [1296952774.474734] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+IFC=1,1<CR>'
modem-manager[5728]: <debug> [1296952774.494418] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952774.494556] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CIND=?<CR>'
modem-manager[5728]: <debug> [1296952774.564452] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>ERROR<CR><LF>'
modem-manager[5728]: <debug> [1296952774.564565] [mm-serial-parsers.c:340] mm_serial_parser_v1_parse(): Got failure code 100: Unknown error
modem-manager[5728]: <debug> [1296952774.564660] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CRSM=176,12258,0,0,10<CR>'
modem-manager[5728]: <debug> [1296952775.034453] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CRSM: 144,0,"982300120080533028F3"<CR><LF><CR><LF>OK<CR><LF>'
modem-manager[5728]: <debug> [1296952775.034618] [mm-serial-port.c:798] mm_serial_port_close(): (ttyUSB0) device open count is 1 (close)

Feb  6 01:51:38 laptop-jl modem-manager[5728]: <debug> [1296953498.217473] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
Feb  6 01:51:38 laptop-jl modem-manager[5728]: <debug> [1296953498.219319] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CSQ<CR>'
Feb  6 01:51:38 laptop-jl modem-manager[5728]: <debug> [1296953498.234437] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CSQ: 13,99<CR><LF><CR><LF>OK<CR><LF>'
Feb  6 01:51:38 laptop-jl modem-manager[5728]: <debug> [1296953498.234680] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): --> 'AT+CREG?<CR>'
Feb  6 01:51:38 laptop-jl modem-manager[5728]: <debug> [1296953498.254442] [mm-at-serial-port.c:298] debug_log(): (ttyUSB0): <-- '<CR><LF>+CREG: 2,1,57C,B076<CR><LF><CR><LF>OK<CR><LF>'
Feb  6 01:51:38 laptop-jl modem-manager[5728]: <debug> [1296953498.254561] [mm-generic-gsm.c:2352] mm_generic_gsm_set_reg_status(): CS registration state changed: 1
Feb  6 01:51:38 laptop-jl modem-manager[5728]: <info> [1296953498.254829] [mm-modem.c:761] mm_modem_set_state(): Modem /org/freedesktop/ModemManager/Modems/7: state changed (enabled -> registered)


So it seems like something goes wrong when sending the PIN code.

It would be nice to get this bug fixed!


Oh yea, i'm using Ubuntu Natty with the following NetworkManager version:
0.8.3+git.20101219t181118.e919218-0ubuntu1