network manager ppp timeout

Bug #393094 reported by Wolf Rogner
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
network-manager (Ubuntu)
Won't Fix
Low
Unassigned
Nominated for Karmic by Gabriel

Bug Description

NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module

I cannot connect via usb UMTS modem.

Here's the log (Machine: MSI X320, Ubuntu 9.04, Linux 2.6.28.13-generic #44-Ubuntu SMP)
---------------------------
Jun 28 11:29:53 xb NetworkManager: <info> Activation (ttyUSB0) starting connection 'Yesss'
Jun 28 11:29:53 xb NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4
Jun 28 11:29:53 xb NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Jun 28 11:29:53 xb NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Jun 28 11:29:53 xb NetworkManager: <debug> [1246181393.723285] nm_serial_device_open(): (ttyUSB0) opening device...
Jun 28 11:29:53 xb NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Jun 28 11:29:53 xb NetworkManager: <info> (ttyUSB0): GSM pin secret required
Jun 28 11:29:53 xb NetworkManager: <info> (ttyUSB0): device state change: 4 -> 6
Jun 28 11:29:53 xb NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Jun 28 11:29:53 xb NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Jun 28 11:29:53 xb NetworkManager: <info> (ttyUSB0): device state change: 6 -> 4
Jun 28 11:29:53 xb NetworkManager: <debug> [1246181393.929608] nm_serial_device_open(): (ttyUSB0) opening device...
Jun 28 11:29:53 xb NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Jun 28 11:29:54 xb NetworkManager: <info> (ttyUSB0): powering up...
Jun 28 11:29:56 xb NetworkManager: <info> Searching for a network...
Jun 28 11:30:01 xb last message repeated 5 times
Jun 28 11:30:02 xb NetworkManager: <info> Registered on Roaming network
Jun 28 11:30:02 xb NetworkManager: <info> Associated with network: +COPS: 0,2,"23205",2
Jun 28 11:30:02 xb NetworkManager: <info> Connected, Woo!
Jun 28 11:30:02 xb NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
Jun 28 11:30:02 xb NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
Jun 28 11:30:02 xb NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5
Jun 28 11:30:02 xb NetworkManager: <info> Starting pppd connection
Jun 28 11:30:02 xb NetworkManager: <debug> [1246181402.327197] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/0 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
Jun 28 11:30:02 xb NetworkManager: <debug> [1246181402.347065] nm_ppp_manager_start(): ppp started with pid 3306
Jun 28 11:30:02 xb NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
Jun 28 11:30:02 xb pppd[3306]: Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded.
Jun 28 11:30:02 xb pppd[3306]: pppd 2.4.5 started by root, uid 0
Jun 28 11:30:02 xb pppd[3306]: Using interface ppp0
Jun 28 11:30:02 xb pppd[3306]: Connect: ppp0 <--> /dev/ttyUSB0
Jun 28 11:30:02 xb pppd[3306]: Unable to obtain CHAP password for xb on UMTS_CHAP_SRVR from plugin
Jun 28 11:30:02 xb pppd[3306]: No CHAP secret found for authenticating us to UMTS_CHAP_SRVR
Jun 28 11:30:02 xb pppd[3306]: CHAP authentication succeeded
Jun 28 11:30:02 xb pppd[3306]: CHAP authentication succeeded
Jun 28 11:30:02 xb kernel: [ 137.660149] PPP BSD Compression module registered
Jun 28 11:30:02 xb kernel: [ 137.717957] PPP Deflate Compression module registered
Jun 28 11:30:06 xb pppd[3306]: Could not determine remote IP address: defaulting to 10.64.64.64
Jun 28 11:30:06 xb pppd[3306]: Cannot determine ethernet address for proxy ARP
Jun 28 11:30:06 xb pppd[3306]: local IP address 10.113.214.1
Jun 28 11:30:06 xb pppd[3306]: remote IP address 10.64.64.64
Jun 28 11:30:06 xb pppd[3306]: primary DNS address 81.3.216.100
Jun 28 11:30:06 xb pppd[3306]: secondary DNS address 194.24.128.100
Jun 28 11:30:18 xb NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module
Jun 28 11:30:18 xb NetworkManager: <info> (ttyUSB0): device state change: 5 -> 9
Jun 28 11:30:18 xb pppd[3306]: Terminating on signal 15
Jun 28 11:30:18 xb NetworkManager: <debug> [1246181418.011641] nm_serial_device_close(): Closing device 'ttyUSB0'
Jun 28 11:30:18 xb pppd[3306]: Connect time 0.2 minutes.
Jun 28 11:30:18 xb pppd[3306]: Sent 0 bytes, received 0 bytes.
Jun 28 11:30:18 xb NetworkManager: <info> Marking connection 'Yesss' invalid.
Jun 28 11:30:18 xb NetworkManager: <info> Activation (ttyUSB0) failed.
Jun 28 11:30:18 xb NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3
Jun 28 11:30:18 xb NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0).
Jun 28 11:30:18 xb NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
Jun 28 11:30:18 xb NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
Jun 28 11:30:18 xb pppd[3306]: Connection terminated.
Jun 28 11:30:18 xb pppd[3306]: Exit.
Jun 28 11:30:20 xb NetworkManager: <debug> [1246181420.002615] ensure_killed(): waiting for ppp pid 3306 to exit
Jun 28 11:30:20 xb NetworkManager: <debug> [1246181420.002969] ensure_killed(): ppp pid 3306 cleaned up
---------------------------

It works fine on all my other machines.

Revision history for this message
Wolf Rogner (war-rsb) wrote :
Download full text (10.0 KiB)

This is how it works on my main machine (not flawless because disconnect does not work):
---------------------
Jun 28 12:20:55 wb kernel: [13850.192111] usb 2-3: new high speed USB device using ehci_hcd and address 6
Jun 28 12:20:55 wb kernel: [13850.336128] usb 2-3: configuration #1 chosen from 1 choice
Jun 28 12:20:55 wb kernel: [13850.338593] usb-storage: probe of 2-3:1.0 failed with error -5
Jun 28 12:20:55 wb kernel: [13850.338969] usb-storage: probe of 2-3:1.1 failed with error -5
Jun 28 12:20:55 wb kernel: [13850.340580] usb-storage: probe of 2-3:1.2 failed with error -1
Jun 28 12:20:55 wb kernel: [13850.342759] usb-storage: probe of 2-3:1.3 failed with error -1
Jun 28 12:20:55 wb kernel: [13850.662531] usbcore: registered new interface driver usbserial
Jun 28 12:20:55 wb kernel: [13850.662559] USB Serial support registered for generic
Jun 28 12:20:55 wb kernel: [13850.662678] usbcore: registered new interface driver usbserial_generic
Jun 28 12:20:55 wb kernel: [13850.662683] usbserial: USB Serial Driver core
Jun 28 12:20:55 wb kernel: [13850.675874] USB Serial support registered for GSM modem (1-port)
Jun 28 12:20:55 wb kernel: [13850.675977] option 2-3:1.0: GSM modem (1-port) converter detected
Jun 28 12:20:55 wb kernel: [13850.676873] usb 2-3: GSM modem (1-port) converter now attached to ttyUSB0
Jun 28 12:20:55 wb kernel: [13850.676897] option 2-3:1.1: GSM modem (1-port) converter detected
Jun 28 12:20:55 wb kernel: [13850.676990] usb 2-3: GSM modem (1-port) converter now attached to ttyUSB1
Jun 28 12:20:55 wb kernel: [13850.677042] usbcore: registered new interface driver option
Jun 28 12:20:55 wb kernel: [13850.677046] option: v0.7.2:USB Driver for GSM modems
Jun 28 12:20:56 wb NetworkManager: <info> (ttyUSB1): ignoring due to lack of mobile broadband capabilties
Jun 28 12:20:56 wb nm-system-settings: SCPlugin-Ifupdown: device added (udi: /org/freedesktop/Hal/devices/usb_device_12d1_1003_noserial_if0_serial_usb_0, iface: (null)): iface not found
Jun 28 12:20:56 wb NetworkManager: <info> (ttyUSB0): found serial port (udev:GSM hal:GSM)
Jun 28 12:20:56 wb NetworkManager: <info> (ttyUSB0): new Modem device (driver: 'option')
Jun 28 12:20:56 wb NetworkManager: <info> (ttyUSB0): exported as /org/freedesktop/Hal/devices/usb_device_12d1_1003_noserial_if0_serial_usb_0
Jun 28 12:21:01 wb NetworkManager: <info> (ttyUSB0): device state change: 1 -> 2
Jun 28 12:21:01 wb NetworkManager: <info> (ttyUSB0): deactivating device (reason: 2).
Jun 28 12:21:01 wb NetworkManager: <info> Policy set 'rsb' (wlan0) as default for routing and DNS.
Jun 28 12:21:01 wb NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
Jun 28 12:21:01 wb NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
Jun 28 12:21:01 wb NetworkManager: <info> (ttyUSB0): device state change: 2 -> 3
Jun 28 12:21:01 wb NetworkManager: <info> Activation (ttyUSB0) starting connection 'Yesss'
Jun 28 12:21:01 wb NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4
Jun 28 12:21:01 wb NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Jun ...

Revision history for this message
Nicola Ferralis (feranick) wrote :

Thank you for taking the time to report this bug and helping to make Ubuntu better. This bug did not have a package associated with it, which is important for ensuring that it gets looked at by the proper developers. You can learn more about finding the right package at https://wiki.ubuntu.com/Bugs/FindRightPackage. I have classified this bug as a bug in network-manager.

When reporting bugs in the future please use apport, either via the appropriate application's "Help -> Report a Problem" menu or using 'ubuntu-bug' and the name of the package affected. You can learn more about this functionality at https://wiki.ubuntu.com/ReportingBugs.

affects: ubuntu → network-manager (Ubuntu)
Revision history for this message
Pedro Villavicencio (pedro) wrote :

Thanks for taking the time to report this bug and helping to make Ubuntu better. Could you please open a terminal and execute: apport-collect 393094 ? It will attach the necessary information to this report. Also you can submit more information for it by looking to https://wiki.ubuntu.com/DebuggingNetworkManager , Thanks in advance.

Changed in network-manager (Ubuntu):
status: New → Incomplete
importance: Undecided → Low
Revision history for this message
Gabriel (galvarez-mdp) wrote :

with the network manager form

http://ppa.launchpad.net/network-manager/trunk/ubuntu karmic main

works fine

the alternative to conect is configure the conection with pppoeconf

Revision history for this message
Gabriel (galvarez-mdp) wrote : apport-collect data

Architecture: amd64
CRDA: Error: [Errno 2] No such file or directory
DistroRelease: Ubuntu 9.10
IfupdownConfig: Error: [Errno 13] Permission denied: '/etc/network/interfaces'
IpRoute:
 200.63.148.91 dev ppp0 proto kernel scope link src 201.254.74.85
 192.168.1.0/24 dev eth0 proto kernel scope link src 192.168.1.2 metric 1
 169.254.0.0/16 dev eth0 scope link metric 1000
 default dev ppp0 scope link
NonfreeKernelModules: nvidia
Package: network-manager 0.8~a~git.20091013t193206.679d548-0ubuntu1
PackageArchitecture: amd64
ProcEnviron:
 SHELL=/bin/bash
 PATH=(custom, user)
 LANG=es_AR.UTF-8
ProcVersionSignature: Ubuntu 2.6.31-19.56-generic
RfKill:

Uname: Linux 2.6.31-19-generic x86_64
UserGroups: adm admin audio cdrom dialout dip fax fuse lpadmin netdev plugdev sambashare tape video
WpaSupplicantLog:

Changed in network-manager (Ubuntu):
status: Incomplete → Confirmed
Revision history for this message
Gabriel (galvarez-mdp) wrote : Dependencies.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : Gconf.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : IpAddr.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : IwConfig.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : NetDevice.eth0.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : NetDevice.eth1.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : NetDevice.lo.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : NetDevice.ppp0.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : PciNetwork.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : WifiSyslog.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : XsessionErrors.txt
Revision history for this message
Gabriel (galvarez-mdp) wrote : nm-system-settings.conf.txt
tags: added: apport-collected
Revision history for this message
Gabriel (galvarez-mdp) wrote :

with ubuntu 9.04 works fine also

Revision history for this message
Bryan Quigley (bryanquigley) wrote :

Thank you for taking the time to report this bug and helping to make Ubuntu better. We are sorry that we do not always have the capacity to look at all reported bugs in a timely manner. There have been many changes in Ubuntu since that time you reported the bug and your problem may have been fixed with some of the updates.

Is this still an issue for anyone in 12.04/14.04 or newer?

Changed in network-manager (Ubuntu):
status: Confirmed → Incomplete
Revision history for this message
Wolf Rogner (war-rsb) wrote :

I just read the syslog excerpt above.

I recently had a similar issue in 15.10 and want to share my experience:

The symptoms: Timeouts and connection termination after some minutes. I used openconnect vpn connector.

After several experiments I figured the source of the problem being that my home network is a class A network (10.x.x.x) and the destination network is a class A network (10.x.x.x) as well.

Keep alive packets follow the routing table and in my case, this included the default route pointing to my router.
The router tunnels the vpn connection but does not route it which means that keep alives will not reach the remote endpoint and the connection runs into timeouts.

I found no solution to this issue other than using an alternative network connection (using mobile modem which issues a different home IP address 172.16.x.x). Now the connection is stable and keep alives are forwarded correctly.

Note: Even static routes do not help as the endpoint of the vpn tunnel has rolling IP addresses.

Why do I believe there is a connection?

see:
Jun 28 11:30:06 xb pppd[3306]: Cannot determine ethernet address for proxy ARP
Jun 28 11:30:06 xb pppd[3306]: local IP address 10.113.214.1 <========================
Jun 28 11:30:06 xb pppd[3306]: remote IP address 10.64.64.64 <========================

I hope this helps

Revision history for this message
Bryan Quigley (bryanquigley) wrote :

Thanks for sharing! If that is the underlying issue, I'm not sure there is anything we can do to fix it in Ubuntu...

Revision history for this message
Wolf Rogner (war-rsb) wrote :

I could verify this situation with a Windows client. I doubt there is anything that can be done. If two networks share the same IP range with two different default gateways and different dns name spaces, not even static routes can solve this.

Thanks for your efforts though.

Revision history for this message
Bryan Quigley (bryanquigley) wrote :

@war-rsb
Thanks for your analysis! I'm going to go ahead and close the case since there is no way to fix this.

Changed in network-manager (Ubuntu):
status: Incomplete → Won't Fix
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.