[SOLVED] USB CDMA modem always disconnects after 50 minutes

[pepalogik]

Hi,

I am running Linux Mint 17 Xfce 64bit. I use Vertex VW110L USB CDMA modem for connecting to the Internet. The modem is correctly recognized and it is easy to set up and establish the connection with the connection manager. The problem is that it always disconnects 50 minutes after connecting. dmesg says nothing on it. In the file ~/.xsession-errors, the following message appears several times:
** (nm-applet:1784): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation
The same message, however, appears also immediately after connecting.

More details: 50 minutes after connecting, the connection is lost and this is accompanied by HDD activity. Then a message appears, telling me that the computer is not connected to network, and the network icon in the panel changes accordingly.

This is definitely not a hardware problem, as the modem works fine with Windows and it also worked in Linux Mint 15, though with a somewhat similar problem. (In LM 15, it always disconnected when no data had been transfered for some time. However, if the connection was in use, it stayed connected - even for many hours. Another bug was that reconnecting after the connection loss didn't work - workaround was to disable networking, enable networking and then reconnect. In LM 17, reconnecting works seamlessly.)

Any suggestions?

[PatH57]

Hi,

the message is not really important it's just a notification from the applet.

let's try to get some more info and enabling debug:

Get Debug Logs

Important: please do not pack (tar, zip, etc.) or compress the log files before uploading to launchpad. Just attach them as they are produced - this makes it easier for developers and triagers.


# stop NetworkManager ( >= karmic - aka upstart)

Code: Select all

sudo stop network-manager

# restart modemmanager with --debug and put output in /tmp/modem.log.txt

Code: Select all

sudo killall modem-manager; sudo modem-manager --debug 2>&1 | tee /tmp/modem.log.txt

# enable PPP debugging too:

Code: Select all

export NM_PPP_DEBUG=1

# start networkmanager and put log in /tmp/nm.log.txt

Code: Select all

sudo NetworkManager --no-daemon 2>&1 | tee /tmp/nm.log.txt

[pepalogik]

Hi PatH57,

thank you for your reply, but I have a few problems or questions:

1. modem-manager does not exist.
2. I assumed I should disconnect before performing the commands. Right?
3. After performing your commands, the connection that I use is not present in the network menu (that appears after clicking on the network indicator). How do I connect then?
4. My LM installation is in Czech, so I should probably add "LC_ALL=C" somewhere, but I do not know where.
5. By mentioning "uploading to launchpad", do you mean that I should file a bug report on https://bugs.launchpad.net/linuxmint?

[PatH57]

Hi,


my bad I assumed it was a modem in fact it is a usb 3G type of modem?

Code: Select all

lspci

Code: Select all

lsusb

Just checked with mine (integrated card). It cuts every 30 minute (also power management is disabled) and guess what the "cut" is issued by the network provider not the card.

[pepalogik]

Yes, I think it is 3G.

Code: Select all

jenda@NovyKomp ~ $ lspci
00:00.0 RAM memory: NVIDIA Corporation C51 Host Bridge (rev a2)
00:00.1 RAM memory: NVIDIA Corporation C51 Memory Controller 0 (rev a2)
00:00.2 RAM memory: NVIDIA Corporation C51 Memory Controller 1 (rev a2)
00:00.3 RAM memory: NVIDIA Corporation C51 Memory Controller 5 (rev a2)
00:00.4 RAM memory: NVIDIA Corporation C51 Memory Controller 4 (rev a2)
00:00.5 RAM memory: NVIDIA Corporation C51 Host Bridge (rev a2)
00:00.6 RAM memory: NVIDIA Corporation C51 Memory Controller 3 (rev a2)
00:00.7 RAM memory: NVIDIA Corporation C51 Memory Controller 2 (rev a2)
00:05.0 VGA compatible controller: NVIDIA Corporation C51PV [GeForce 6150] (rev a2)
00:09.0 RAM memory: NVIDIA Corporation MCP51 Host Bridge (rev a2)
00:0a.0 ISA bridge: NVIDIA Corporation MCP51 LPC Bridge (rev a3)
00:0a.1 SMBus: NVIDIA Corporation MCP51 SMBus (rev a3)
00:0a.2 RAM memory: NVIDIA Corporation MCP51 Memory Controller 0 (rev a3)
00:0b.0 USB controller: NVIDIA Corporation MCP51 USB Controller (rev a3)
00:0b.1 USB controller: NVIDIA Corporation MCP51 USB Controller (rev a3)
00:0d.0 IDE interface: NVIDIA Corporation MCP51 IDE (rev a1)
00:0e.0 IDE interface: NVIDIA Corporation MCP51 Serial ATA Controller (rev a1)
00:0f.0 IDE interface: NVIDIA Corporation MCP51 Serial ATA Controller (rev a1)
00:10.0 PCI bridge: NVIDIA Corporation MCP51 PCI Bridge (rev a2)
00:10.1 Audio device: NVIDIA Corporation MCP51 High Definition Audio (rev a2)
00:14.0 Bridge: NVIDIA Corporation MCP51 Ethernet Controller (rev a3)
00:18.0 Host bridge: Advanced Micro Devices, Inc. [AMD] K8 [Athlon64/Opteron] HyperTransport Technology Configuration
00:18.1 Host bridge: Advanced Micro Devices, Inc. [AMD] K8 [Athlon64/Opteron] Address Map
00:18.2 Host bridge: Advanced Micro Devices, Inc. [AMD] K8 [Athlon64/Opteron] DRAM Controller
00:18.3 Host bridge: Advanced Micro Devices, Inc. [AMD] K8 [Athlon64/Opteron] Miscellaneous Control
01:05.0 FireWire (IEEE 1394): Texas Instruments TSB43AB22A IEEE-1394a-2000 Controller (PHY/Link) [iOHCI-Lynx]

Code: Select all

jenda@NovyKomp ~ $ lsusb
Bus 001 Device 004: ID 1058:1110 Western Digital Technologies, Inc. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 003: ID 046d:c050 Logitech, Inc. RX 250 Optical Mouse
Bus 002 Device 002: ID 1fe7:0100 Vertex Wireless Co., Ltd. 
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub

Vertex is it.

[PatH57]

ok,

we are getting somewhere

Code: Select all

nmcli nm

Code: Select all

nmcli con

also does it disconnect while you are using it? as I said some carriers do reset the connection after a fixed amount of time.

[pepalogik]

Code: Select all

jenda@NovyKomp ~ $ LC_ALL=C nmcli nm

** (process:5539): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:5539): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
RUNNING         STATE           WIFI-HARDWARE   WIFI       WWAN-HARDWARE   WWAN      
running         connected       enabled         enabled    enabled         enabled   

(I do not quite understand that - there is no Wi-Fi device in my computer.)

Code: Select all

jenda@NovyKomp ~ $ LC_ALL=C nmcli con

** (process:5540): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:5540): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
NAME                      UUID                                   TYPE              TIMESTAMP-REAL                    
Připojení U:fon           80165cfc-68f8-4a4b-9b87-9db8f6bfc6b0   cdma              Mon Aug  4 14:32:56 2014          
Drátové připojení 1       a4512410-523d-439c-a20b-8aa0c2f08f7c   802-3-ethernet    Mon Aug  4 13:10:17 2014          

(Just a small explanation: připojení = connection, U:fon = name of the provider, drátové = wired.)

also does it disconnect while you are using it? as I said some carriers do reset the connection after a fixed amount of time.

As I have written, it disconnects always 50 minutes after connecting, even during a download (that's why it is so annoying). It has nothing to do with the provider - when using this modem with Windows or Linux Mint 15, it stays connected (at least if the connection is in use). Service outages do happen occasionally (roughly once a month), but not every 50 minutes.

[PatH57]

just had to get a clear picture.
Let's take a look at the usb messages, it could be that power management quicks out the stick

Code: Select all

dmesg | grep -i usb

[pepalogik]

Code: Select all

jenda@NovyKomp ~ $ dmesg | grep -i usb
[    0.137819] ACPI: bus type USB registered
[    0.137848] usbcore: registered new interface driver usbfs
[    0.137860] usbcore: registered new interface driver hub
[    0.137897] usbcore: registered new device driver usb
[    1.076331] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    1.076563] ehci-pci 0000:00:0b.1: new USB bus registered, assigned bus number 1
[    1.088024] ehci-pci 0000:00:0b.1: USB 2.0 started, EHCI 1.00
[    1.088114] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    1.088118] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.088121] usb usb1: Product: EHCI Host Controller
[    1.088124] usb usb1: Manufacturer: Linux 3.13.0-24-generic ehci_hcd
[    1.088126] usb usb1: SerialNumber: 0000:00:0b.1
[    1.088280] hub 1-0:1.0: USB hub found
[    1.088546] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    1.088709] ohci-pci 0000:00:0b.0: new USB bus registered, assigned bus number 2
[    1.146055] usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
[    1.146059] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.146062] usb usb2: Product: OHCI PCI host controller
[    1.146065] usb usb2: Manufacturer: Linux 3.13.0-24-generic ohci_hcd
[    1.146067] usb usb2: SerialNumber: 0000:00:0b.0
[    1.146207] hub 2-0:1.0: USB hub found
[    1.146471] uhci_hcd: USB Universal Host Controller Interface driver
[    1.716041] usb 1-4: new high-speed USB device number 4 using ehci-pci
[    1.849055] usb 1-4: New USB device found, idVendor=1058, idProduct=1110
[    1.849062] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    1.849066] usb 1-4: Product: My Book 1110
[    1.849068] usb 1-4: Manufacturer: Western Digital
[    1.849071] usb 1-4: SerialNumber: 574341565934383834383938
[    1.853965] usb-storage 1-4:1.0: USB Mass Storage device detected
[    1.854387] scsi6 : usb-storage 1-4:1.0
[    1.854484] usbcore: registered new interface driver usb-storage
[    2.280026] usb 2-2: new full-speed USB device number 2 using ohci-pci
[    2.492076] usb 2-2: New USB device found, idVendor=1fe7, idProduct=0100
[    2.492083] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.492087] usb 2-2: Product: Vertex Wireless Multi-Function Device
[    2.492090] usb 2-2: Manufacturer: Vertex Wireless Co., Ltd.
[    2.808034] usb 2-3: new low-speed USB device number 3 using ohci-pci
[    3.022076] usb 2-3: New USB device found, idVendor=046d, idProduct=c050
[    3.022082] usb 2-3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    3.022086] usb 2-3: Product: USB-PS/2 Optical Mouse
[    3.022089] usb 2-3: Manufacturer: Logitech
[    3.041712] usbcore: registered new interface driver usbhid
[    3.041718] usbhid: USB HID core driver
[    3.045186] input: Logitech USB-PS/2 Optical Mouse as /devices/pci0000:00/0000:00:0b.0/usb2/2-3/2-3:1.0/input/input3
[    3.046479] hid-generic 0003:046D:C050.0001: input,hidraw0: USB HID v1.10 Mouse [Logitech USB-PS/2 Optical Mouse] on usb-0000:00:0b.0-3/input0
[   20.211255] cdc_acm 2-2:1.0: ttyACM0: USB ACM device
[   20.216307] usbcore: registered new interface driver cdc_acm
[   20.216313] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters

[PatH57]

seems in newer kernels usb autosuspend is enabled
so try this

Code: Select all

sudo echo "options usbcore autosuspend=-1" > /etc/modprobe.d/disable-usb-autosuspend.conf

[pepalogik]

Done, rebooted, no effect. (Btw. the command is invalid - bash: /etc/modprobe.d/disable-usb-autosuspend.conf: Permission denied - but this was easy to solve by first entering su and then the echo... I have checked that the target file was created and contains what it should.)

The modem is actually not powered off - its LED keeps on blinking blue, which means "ready". Just the connection (I assume PPP) is aborted.

[PatH57]

well my account is part of sudoer in linux so didn't catch the error.
it blinks that fine but the usb part on the unit may go to sleep or disconnect (have seen this a lot with usb drives suddenly not being mounted after x amount of time)
I keep digging on wwan connection and see what I can find.

could you try the nmcli commands when it drops the connection?

[pepalogik]

Thank you, take your time. I am at work now and was just posting my yesterday's findings. I will try the nmcli commands in the evening when I am at home.

Regarding the sudo... command: I am not a Linux expert but I guess the redirection part is not performed within sudo, hence the error. (My account is sudoer as well.)

[PatH57]

also check the dmesg usb info when it happens.
Concerning the su vs sudo there is no simple answer
http://askubuntu.com/questions/376199/s ... ch-is-used

[pepalogik]

Nothing interesting in dmesg - the log sent yesterday was generated after several disconnects already.

[pepalogik]

I was curious about the meaning of the connection time stamp, so I ran "nmcli con" many times while the connection was active. I have found that it updates every five minutes (I added current time to make it clearer), here is a sample:

Code: Select all

jenda@NovyKomp ~ $ LC_ALL=C date; LC_ALL=C nmcli con
Tue Aug  5 23:40:17 CEST 2014

** (process:4885): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:4885): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
NAME                      UUID                                   TYPE              TIMESTAMP-REAL                    
Připojení U:fon           80165cfc-68f8-4a4b-9b87-9db8f6bfc6b0   cdma              Tue Aug  5 23:35:40 2014          
Drátové připojení 1       a4512410-523d-439c-a20b-8aa0c2f08f7c   802-3-ethernet    Mon Aug  4 13:10:17 2014          
jenda@NovyKomp ~ $ LC_ALL=C date; LC_ALL=C nmcli con
Tue Aug  5 23:41:24 CEST 2014

** (process:4889): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:4889): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
NAME                      UUID                                   TYPE              TIMESTAMP-REAL                    
Připojení U:fon           80165cfc-68f8-4a4b-9b87-9db8f6bfc6b0   cdma              Tue Aug  5 23:40:40 2014          
Drátové připojení 1       a4512410-523d-439c-a20b-8aa0c2f08f7c   802-3-ethernet    Mon Aug  4 13:10:17 2014          

And here is a sample from the time it disconnected:

Code: Select all

jenda@NovyKomp ~ $ LC_ALL=C date; LC_ALL=C nmcli con
Tue Aug  5 23:57:17 CEST 2014

** (process:5391): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:5391): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
NAME                      UUID                                   TYPE              TIMESTAMP-REAL                    
Připojení U:fon           80165cfc-68f8-4a4b-9b87-9db8f6bfc6b0   cdma              Tue Aug  5 23:55:40 2014          
Drátové připojení 1       a4512410-523d-439c-a20b-8aa0c2f08f7c   802-3-ethernet    Mon Aug  4 13:10:17 2014          
jenda@NovyKomp ~ $ LC_ALL=C date; LC_ALL=C nmcli con
Tue Aug  5 23:57:21 CEST 2014

** (process:5433): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:5433): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
NAME                      UUID                                   TYPE              TIMESTAMP-REAL                    
Připojení U:fon           80165cfc-68f8-4a4b-9b87-9db8f6bfc6b0   cdma              Tue Aug  5 23:57:20 2014          
Drátové připojení 1       a4512410-523d-439c-a20b-8aa0c2f08f7c   802-3-ethernet    Mon Aug  4 13:10:17 2014          

23:57:20 is presumably the disconnection time. This time stamp remained until I connected again.

In the "nmcli nm", state changed from connected to disconnected, but I did not run this command repeatedly about the disconnection time. Should I?

Code: Select all

jenda@NovyKomp ~ $ LC_ALL=C date; LC_ALL=C nmcli nm
Tue Aug  5 23:16:59 CEST 2014

** (process:4207): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:4207): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
RUNNING         STATE           WIFI-HARDWARE   WIFI       WWAN-HARDWARE   WWAN      
running         connected       enabled         enabled    enabled         enabled   

Code: Select all

jenda@NovyKomp ~ $ LC_ALL=C date; LC_ALL=C nmcli nm 
Tue Aug  5 23:58:05 CEST 2014

** (process:5443): WARNING **: Could not create object for /org/freedesktop/NetworkManager/Settings/2: uid 1000 has no permission to perform this operation

** (process:5443): WARNING **: handle_property_changed: failed to update property 'available-connections' of object type NMDeviceModem.
RUNNING         STATE           WIFI-HARDWARE   WIFI       WWAN-HARDWARE   WWAN      
running         disconnected    enabled         enabled    enabled         enabled   

[PatH57]

sound like a problem with modem-manager
http://ubuntuforums.org/showthread.php?t=2218034

[pepalogik]

Thank you for your digging. The thread on Ubuntu Forums basically suggest the use of wvdial instead of the default connection manager. I have tried it, first it did not work, then it worked, and after 50 minutes, a surprising thing happened (it begins with the line "Connect time 50.6 minutes"):

Code: Select all

NovyKomp jenda # wvdial
--> WvDial: Internet dialer version 1.61
--> 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
--> Modem initialized.
--> Sending: ATDT#777
--> Waiting for carrier.
ATDT#777
CONNECT
--> Carrier detected.  Waiting for prompt.
~[7f]}#@!}!}!} }9}"}&} } } } }#}%B#}%}%}&}(}[1f]1}'}"}(}"wn~
--> PPP negotiation detected.
--> Starting pppd at Thu Aug  7 23:00:44 2014
--> Pid of pppd: 2354
--> Using interface ppp0
--> local  IP address 78.136.189.55
--> remote IP address 172.18.55.1
--> primary   DNS address 78.136.128.4
--> secondary DNS address 78.136.128.12
--> Connect time 50.6 minutes.
--> Disconnecting at Thu Aug  7 23:51:24 2014
--> The PPP daemon has died: A modem hung up the phone (exit code = 16)
--> man pppd explains pppd error codes in more detail.
--> Try again and look into /var/log/messages and the wvdial and pppd man pages for more information.
--> Auto Reconnect will be attempted in 5 seconds
--> Initializing modem.
--> Sending: ATZ
ATZ
OK
--> Sending: ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
OK
--> Modem initialized.
--> Initializing modem.
--> Sending: ATZ
ATZ
OK
--> Sending: ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
OK
--> Modem initialized.
--> Sending: ATDT#777
--> Waiting for carrier.
ATDT#777
CONNECT
~[7f]}#@!}!}!} }9}"}&} } } } }#}%B#}%}%}&}(}_C}'}"}(}"[08]e~
--> Carrier detected.  Waiting for prompt.
~[7f]}#@!}!}"} }9}"}&} } } } }#}%B#}%}%}&}(}&V}'}"}(}"wp~
--> PPP negotiation detected.
--> Starting pppd at Thu Aug  7 23:51:33 2014
--> Pid of pppd: 4490
--> Using interface ppp0
--> local  IP address 78.136.176.62
--> remote IP address 172.18.55.1
--> primary   DNS address 78.136.128.4
--> secondary DNS address 78.136.128.12

It looks like a modem problem - like if the modem always hung up after 50.6 minutes. But in the past, I performed continuous downloads lasting several hours with this modem, so it must be a software problem.

[PatH57]

Hi,

why 50 minutes?
try this one
http://ubuntuforums.org/showthread.php?t=1586753

[pepalogik]

Hi,

me too would like to know why 50 minutes. The referred thread describes a different problem. I have not tried the described modifications to file /etc/ppp/options as they seem to be completely unrelated and they apparently did not help the questioner. I have tried out Sakis3g, that helped the questioner, but it does not work for me and I have quickly recognized why. Quote from known problems section in sakis3g man: "Connecting with an operator using CDMA is not yet possible."

Do you have any other suggestions? I have two:

1. There are some debug options in /etc/ppp/options (debug and kdebug). Enabling them might be helpful (but it is not clear to me where the logs should appear).
2. There are also plenty of other options in /etc/ppp/options. I would like to see that file in Mint 15 and compare it with the current one. If you think this is reasonable, can you dig the old file somewhere?