Re: modem-manager fails to reconnect
On Fri, 2010-09-24 at 20:14 -0300, José Queiroz wrote: Hi, I've noticed a strange behavior with my 3g dongle (Onda MSA405 HS / 19d2:0037). When I plug it, it connects with ease. After some time, if I disconnect it and try to reconnect, it fails, and I have to unplug/plug again the device or restart modem-manager process to get the connection back. That's interesting, and something we should probably handle. We should detect NO CARRIER on secondary ports and then tell NetworkManager that we've terminated the connection so that it disconnects PPP. I've turned on loggin on modem-manager, and I saw that when it states that the connection transitioned from connected - disconnecting and from disconnecting - registered, I can reconnect it. But sometimes, it transitions from connected - disconnecting and then disconnecting - connect. When this happens, I cannot reconnect unless unplug or restart modem-manager. Should fix that too. What's happening here is that ModemManager tries to disconnect the port by breaking into the serial stream, but clearly that's not working. Since that wasn't successful (it didn't get a response) it reverts to the previous state (which is connected). We'd need to put some more debugging in to detect where exactly it fails and try to figure out what to do about that. Dan This sometimes happens in the first reconnection, sometimes it takes some reconnections to happen, but sooner or later will happen. I'm using: Kubuntu Lucid 10.04, NetworkManager 0.8.1+git.20100810t184654.ab580f4-0ubuntu3~nmt3~lucid modem-manager 0.4+git.20100922t210758.618dc06-0ubuntu1~nmt1~lucid I also saw that in a normal disconnect, ttyUSB2 (data port) and ttyUSB1 send a NO CARRIER message; when the disconnection fails, only ttyUSB1 says NO CARRIER. This is a piece of modem-manager debug. I can consistently reproduce the symptom, if needed. ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): network_mode = 8 ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): username = tim ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): number = *99# ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): apn = www.tim.com.br ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): allowed_mode = 4 ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): password = tim ** (modem-manager:11224): DEBUG: 1285364689.581451 (ttyUSB2): simple connect state 0 ** (modem-manager:11224): DEBUG: 1285364689.581492 (ttyUSB2): simple connect state 2 ** (modem-manager:11224): DEBUG: 1285364689.581541 (ttyUSB2): -- 'AT+CREG?CR' ** (modem-manager:11224): DEBUG: 1285364689.591677 (ttyUSB2): -- 'CRLF+CREG: 1,1CRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364689.591776 (ttyUSB2): simple connect state 4 ** (modem-manager:11224): DEBUG: 1285364689.591821 (ttyUSB2): -- 'AT+CGDCONT?CR' ** (modem-manager:11224): DEBUG: 1285364689.613745 (ttyUSB2): -- 'CRLF+CGDCONT: 1,IP,www.tim.com.br,0.0.0.0,0,0CRLF+CGDCONT: 2,IP,www.tim.com.br,0.0.0.0,0,0CRLF+CGDCONT: 3,IP,bandalarga.claro.com.br,0.0.0.0,0,0CRLF+CGDCONT: 4,IP,tim.br,0.0.0.0,0,0CRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364689.613907 (ttyUSB2): simple connect state 5 ** (modem-manager:11224): DEBUG: 1285364689.613961 Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered - connecting) ** (modem-manager:11224): DEBUG: 1285364689.614001 (ttyUSB2): -- 'ATD*99***1#CR' ** (modem-manager:11224): DEBUG: 1285364689.634906 (ttyUSB2): -- 'CRLFCONNECT 115200CRLF' ** (modem-manager:11224): DEBUG: 1285364689.635012 (ttyUSB2): port now connected ** (modem-manager:11224): DEBUG: 1285364689.635055 Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting - connected) ** (modem-manager:11224): DEBUG: 1285364689.635098 (ttyUSB2): simple connect state 6 ** (modem-manager:11224): DEBUG: (net/ppp0): could not get port's parent device ** (modem-manager:11224): DEBUG: 1285364691.463726 (ttyUSB1): -- 'CRLF+ZPASR: HSDPACRLF' ** (modem-manager:11224): DEBUG: 1285364701.3719 (ttyUSB1): -- 'AT +CSQCR' ** (modem-manager:11224): DEBUG: 1285364701.13901 (ttyUSB1): -- 'CRLF+CSQ: 16,99CRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364701.14020 (ttyUSB1): -- 'AT +ZPAS?CR' ** (modem-manager:11224): DEBUG: 1285364701.34469 (ttyUSB1): -- 'CRLF+ZPAS: HSDPA,CS_PSCRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364708.9169 Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected - disconnecting) ** (modem-manager:11224): DEBUG: 1285364708.9302 (ttyUSB1): -- 'AT +CGACT=0,1CR' ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): network_mode = 8 ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): username = tim ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): number = *99# ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): apn = www.tim.com.br ** (modem-manager:11224): DEBUG:
modem-manager fails to reconnect
Hi, I've noticed a strange behavior with my 3g dongle (Onda MSA405 HS / 19d2:0037). When I plug it, it connects with ease. After some time, if I disconnect it and try to reconnect, it fails, and I have to unplug/plug again the device or restart modem-manager process to get the connection back. I've turned on loggin on modem-manager, and I saw that when it states that the connection transitioned from connected - disconnecting and from disconnecting - registered, I can reconnect it. But sometimes, it transitions from connected - disconnecting and then disconnecting - connect. When this happens, I cannot reconnect unless unplug or restart modem-manager. This sometimes happens in the first reconnection, sometimes it takes some reconnections to happen, but sooner or later will happen. I'm using: Kubuntu Lucid 10.04, NetworkManager 0.8.1+git.20100810t184654.ab580f4-0ubuntu3~nmt3~lucid modem-manager 0.4+git.20100922t210758.618dc06-0ubuntu1~nmt1~lucid I also saw that in a normal disconnect, ttyUSB2 (data port) and ttyUSB1 send a NO CARRIER message; when the disconnection fails, only ttyUSB1 says NO CARRIER. This is a piece of modem-manager debug. I can consistently reproduce the symptom, if needed. ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): network_mode = 8 ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): username = tim ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): number = *99# ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): apn = www.tim.com.br ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): allowed_mode = 4 ** (modem-manager:11224): DEBUG: 1285364689.581337 (ttyUSB2): password = tim ** (modem-manager:11224): DEBUG: 1285364689.581451 (ttyUSB2): simple connect state 0 ** (modem-manager:11224): DEBUG: 1285364689.581492 (ttyUSB2): simple connect state 2 ** (modem-manager:11224): DEBUG: 1285364689.581541 (ttyUSB2): -- 'AT+CREG?CR' ** (modem-manager:11224): DEBUG: 1285364689.591677 (ttyUSB2): -- 'CRLF+CREG: 1,1CRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364689.591776 (ttyUSB2): simple connect state 4 ** (modem-manager:11224): DEBUG: 1285364689.591821 (ttyUSB2): -- 'AT+CGDCONT?CR' ** (modem-manager:11224): DEBUG: 1285364689.613745 (ttyUSB2): -- 'CRLF+CGDCONT: 1,IP,www.tim.com.br,0.0.0.0,0,0CRLF+CGDCONT: 2,IP,www.tim.com.br,0.0.0.0,0,0CRLF+CGDCONT: 3,IP, bandalarga.claro.com.br,0.0.0.0,0,0CRLF+CGDCONT: 4,IP,tim.br ,0.0.0.0,0,0CRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364689.613907 (ttyUSB2): simple connect state 5 ** (modem-manager:11224): DEBUG: 1285364689.613961 Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered - connecting) ** (modem-manager:11224): DEBUG: 1285364689.614001 (ttyUSB2): -- 'ATD*99***1#CR' ** (modem-manager:11224): DEBUG: 1285364689.634906 (ttyUSB2): -- 'CRLFCONNECT 115200CRLF' ** (modem-manager:11224): DEBUG: 1285364689.635012 (ttyUSB2): port now connected ** (modem-manager:11224): DEBUG: 1285364689.635055 Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting - connected) ** (modem-manager:11224): DEBUG: 1285364689.635098 (ttyUSB2): simple connect state 6 ** (modem-manager:11224): DEBUG: (net/ppp0): could not get port's parent device ** (modem-manager:11224): DEBUG: 1285364691.463726 (ttyUSB1): -- 'CRLF+ZPASR: HSDPACRLF' ** (modem-manager:11224): DEBUG: 1285364701.3719 (ttyUSB1): -- 'AT+CSQCR' ** (modem-manager:11224): DEBUG: 1285364701.13901 (ttyUSB1): -- 'CRLF+CSQ: 16,99CRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364701.14020 (ttyUSB1): -- 'AT+ZPAS?CR' ** (modem-manager:11224): DEBUG: 1285364701.34469 (ttyUSB1): -- 'CRLF+ZPAS: HSDPA,CS_PSCRLFCRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364708.9169 Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected - disconnecting) ** (modem-manager:11224): DEBUG: 1285364708.9302 (ttyUSB1): -- 'AT+CGACT=0,1CR' ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): network_mode = 8 ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): username = tim ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): number = *99# ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): apn = www.tim.com.br ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): allowed_mode = 4 ** (modem-manager:11224): DEBUG: 1285364708.42966 (ttyUSB2): password = tim ** (modem-manager:11224): DEBUG: 1285364708.43083 (ttyUSB2): simple connect state 0 ** (modem-manager:11224): DEBUG: 1285364708.43126 (ttyUSB2): simple connect state 2 ** (modem-manager:11224): DEBUG: 1285364710.903746 (ttyUSB2): -- 'CRLF+ZPASR: UMTSCRLF' ** (modem-manager:11224): DEBUG: 1285364710.903941 (ttyUSB1): -- 'CRLF+ZPASR: UMTSCRLF' ** (modem-manager:11224): DEBUG: 1285364710.925500 (ttyUSB1): -- 'CRLFOKCRLF' ** (modem-manager:11224): DEBUG: 1285364710.927614 (ttyUSB2): -- 'CRLFNO CARRIERCRLF' ** (modem-manager:11224): DEBUG: Got failure code 3: No carrier ** (modem-manager:11224): DEBUG: 1285364710.927688 (ttyUSB1): --
