Re: Persistent 3G connection fails, not sure why

[Dan Williams <dcbw redhat com>]

On Mon, 2011-10-17 at 09:49 -0400, David Pfeffer wrote:
> I maintain a persistent 3G connection on a remote device using network
> manager. However, every so often, the link fails and then does not
> restart itself. I managed to identify an occurrence of this in my
> syslog, but honestly I'm not really sure what I'm looking at. It seems
> that the machine thinks the device has been unplugged, but there's no
> corresponding log entry for it actually being unplugged.

ALmost seems like the modem crashed and reset itself.  What kind of
modem is this and what model?

Dan

> Would someone mind looking at the below syslog snip and guiding me in
> the right direction?
> 
>         Oct 13 22:25:26 tracker pppd[1091]: LCP terminated by peer
>         Oct 13 22:25:26 tracker pppd[1091]: Connect time 206.7 minutes.
>         Oct 13 22:25:26 tracker pppd[1091]: Sent 203306 bytes, received 182777 bytes.
>         Oct 13 22:25:26 tracker pppd[1091]: Modem hangup
>         Oct 13 22:25:26 tracker pppd[1091]: Connection terminated.
>         Oct 13 22:25:26 tracker NetworkManager[333]: <info> (ttyUSB1): device state change: 8 -> 9 (reason 13)
>         Oct 13 22:25:26 tracker NetworkManager[333]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
>         Oct 13 22:25:26 tracker NetworkManager[333]: <warn> Activation (ttyUSB1) failed.
>         Oct 13 22:25:26 tracker modem-manager[337]: <info>  (ttyUSB1) closing serial port...
>         Oct 13 22:25:26 tracker NetworkManager[333]: <info> (ttyUSB1): device state change: 9 -> 3 (reason 0)
>         Oct 13 22:25:26 tracker NetworkManager[333]: <info> (ttyUSB1): deactivating device (reason: 0).
>         Oct 13 22:25:26 tracker kernel: [12441.840088] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
>         Oct 13 22:25:26 tracker kernel: [12441.846744] ata1.00: BMDMA stat 0x66
>         Oct 13 22:25:26 tracker kernel: [12441.850446] ata1.00: failed command: WRITE DMA
>         Oct 13 22:25:26 tracker kernel: [12441.855020] ata1.00: cmd ca/00:02:c4:fb:5b/00:00:00:00:00/e0 tag 0 dma 1024 out
>         Oct 13 22:25:26 tracker kernel: [12441.855024]          res 51/84:00:c4:fb:5b/00:00:00:00:00/e0 Emask 0x30 (host bus error)
>         Oct 13 22:25:26 tracker kernel: [12441.870623] ata1.00: status: { DRDY ERR }
>         Oct 13 22:25:26 tracker kernel: [12441.874708] ata1.00: error: { ICRC ABRT }
>         Oct 13 22:25:26 tracker kernel: [12441.878820] ata1: soft resetting link
>         Oct 13 22:25:26 tracker modem-manager[337]: <info>  (ttyUSB1) serial port closed
>         Oct 13 22:25:26 tracker modem-manager[337]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> disconnecting)
>         Oct 13 22:25:26 tracker modem-manager[337]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (disconnecting -> connected)
>         Oct 13 22:25:26 tracker NetworkManager[333]: <warn> could not read ppp stats: No such device
>         Oct 13 22:25:26 tracker pppd[1091]: Exit.
>         Oct 13 22:25:26 tracker NetworkManager[333]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
>         Oct 13 22:25:26 tracker NetworkManager[333]:    SCPlugin-Ifupdown: devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
>         Oct 13 22:25:26 tracker NetworkManager[333]: <info> disconnect failed: (32) The serial port is not open.
>         Oct 13 22:25:27 tracker kernel: [12442.048218] ata1.00: configured for UDMA/100
>         Oct 13 22:25:27 tracker kernel: [12442.048241] ata1: EH complete
>         Oct 13 22:25:27 tracker kernel: [12442.050941] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
>         Oct 13 22:25:27 tracker kernel: [12442.057483] ata1.00: BMDMA stat 0x66
>         Oct 13 22:25:27 tracker kernel: [12442.061153] ata1.00: failed command: WRITE DMA
>         Oct 13 22:25:27 tracker kernel: [12442.065696] ata1.00: cmd ca/00:02:c4:fb:5b/00:00:00:00:00/e0 tag 0 dma 1024 out
>         Oct 13 22:25:27 tracker kernel: [12442.065699]          res 51/84:00:c4:fb:5b/00:00:00:00:00/e0 Emask 0x30 (host bus error)
>         Oct 13 22:25:27 tracker kernel: [12442.081273] ata1.00: status: { DRDY ERR }
>         Oct 13 22:25:27 tracker kernel: [12442.085366] ata1.00: error: { ICRC ABRT }
>         Oct 13 22:25:27 tracker kernel: [12442.089488] ata1: soft resetting link
>         Oct 13 22:25:27 tracker kernel: [12442.260206] ata1.00: configured for UDMA/100
>         Oct 13 22:25:27 tracker kernel: [12442.260226] ata1: EH complete
>         Oct 13 22:25:27 tracker kernel: [12442.268296] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
>         Oct 13 22:25:27 tracker kernel: [12442.274829] ata1.00: BMDMA stat 0x66
>         Oct 13 22:25:27 tracker kernel: [12442.278480] ata1.00: failed command: WRITE DMA
>         Oct 13 22:25:27 tracker kernel: [12442.283022] ata1.00: cmd ca/00:02:c4:fb:5b/00:00:00:00:00/e0 tag 0 dma 1024 out
>         Oct 13 22:25:27 tracker kernel: [12442.283026]          res 51/84:00:c4:fb:5b/00:00:00:00:00/e0 Emask 0x30 (host bus error)
>         Oct 13 22:25:27 tracker kernel: [12442.298605] ata1.00: status: { DRDY ERR }
>         Oct 13 22:25:27 tracker kernel: [12442.302693] ata1.00: error: { ICRC ABRT }
>         Oct 13 22:25:27 tracker kernel: [12442.306763] ata1: soft resetting link
>         Oct 13 22:25:27 tracker kernel: [12442.476225] ata1.00: configured for UDMA/100
>         Oct 13 22:25:27 tracker kernel: [12442.476248] ata1: EH complete
>         Oct 13 22:25:29 tracker NetworkManager[333]: <info> Activation (ttyUSB1) starting connection 'cdma'
>         Oct 13 22:25:29 tracker NetworkManager[333]: <info> (ttyUSB1): device state change: 3 -> 4 (reason 0)
>         Oct 13 22:25:29 tracker NetworkManager[333]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
>         Oct 13 22:25:29 tracker NetworkManager[333]: <info> Activation (ttyUSB1) Stage 1 of 5 (Device Prepare) scheduled...
>         Oct 13 22:25:29 tracker NetworkManager[333]: <info> Activation (ttyUSB1) Stage 1 of 5 (Device Prepare) started...
>         Oct 13 22:25:29 tracker NetworkManager[333]: <info> Activation (ttyUSB1) Stage 1 of 5 (Device Prepare) complete.
>         Oct 13 22:25:30 tracker modem-manager[337]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> registered)
>         Oct 13 22:25:30 tracker modem-manager[337]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered -> connecting)
>         Oct 13 22:25:30 tracker modem-manager[337]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting -> registered)
>         Oct 13 22:25:30 tracker NetworkManager[333]: <warn> CDMA connection failed: (32) Sending command failed: device is not enabled
>         Oct 13 22:25:30 tracker NetworkManager[333]: <info> (ttyUSB1): device state change: 4 -> 9 (reason 0)
>         Oct 13 22:25:30 tracker NetworkManager[333]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
>         Oct 13 22:25:30 tracker NetworkManager[333]: <info> Marking connection 'cdma' invalid.
>         Oct 13 22:25:30 tracker NetworkManager[333]: <warn> Activation (ttyUSB1) failed.
>         Oct 13 22:25:30 tracker NetworkManager[333]: <info> (ttyUSB1): device state change: 9 -> 3 (reason 0)
>         Oct 13 22:25:30 tracker NetworkManager[333]: <info> (ttyUSB1): deactivating device (reason: 0).
>         Oct 13 22:25:30 tracker NetworkManager[333]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
> 
> I posted this question on askubuntu.com with little result:
> http://askubuntu.com/questions/66470/persistant-3g-connection-w-network-manager-fails
> _______________________________________________
> networkmanager-list mailing list
> networkmanager-list gnome org
> http://mail.gnome.org/mailman/listinfo/networkmanager-list