MASTER PPP connect fails if root is @console with pppd_timed_out() - (NetworkManager does not connect to Mobile Broadband anymore in Jaunty (Sierra AC880))

[Christof Länzlinger]

Official Workaround: close all root shells (e.g. sudo su)

Binary package hint: network-manager

Ubuntu: 9.04
network-manager: 0.7.1~rc4.1.cf199a964-0ubuntu2

I have recently installed Ubuntu 9.04 on my lenevo T61. I am using a mobile broadband card (Sierra Wirelss Aircard 880) to connect to the mobile broadband network.

In Ubuntu 8.04 it was working fine by using the NetworkManager. I only had to remove the APN setting in the Advanced Settings of the Connection to get it working. See also attachment nm-ppp-ubuntu8_10.log)

Now in Ubuntu 9.04 - in completely fresh installation - I cannot connect anymore to my mobile operator. (see attachment nm-ppp-ubuntu9_04-org.log)

First I guessed that the following warning was the reason for the problem:

---- log-extract start --------------------------------------------------------------------------
** (process:19537): WARNING **: Could not get secrets: Rejected send message, 7 matched rules; type="method_call", sender=":1.223" (uid=0 pid=19537 comm="/usr/sbin/pppd nodetach lock nodefaultroute debug ") interface="org.freedesktop.NetworkManager.PPP" member="NeedSecrets" error name="(unset)" requested_reply=0 destination="org.freedesktop.NetworkManager" (uid=0 pid=19390 comm="NetworkManager --no-daemon "))
Unable to obtain CHAP password for gprs on UMTS_CHAP_SRVR from plugin
---- log-extract end ---------------------------------------------------------------------------

Therefore I was trying to modify the dbus rules for the NetworkManager in the file /etc/dbus-1/system.d/NetworkManager.conf. I was removing the following section:

---- config start --------------------------------------------------------------------------------
 <deny send_destination="org.freedesktop.NetworkManager"
                      send_interface="org.freedesktop.NetworkManager.PPP"/>
---- config end ---------------------------------------------------------------------------------

This actually helped to get rid of the above mentioned warning. But still without success to connect to my mobile operator. In the log files I can now see that the connection is suddenly aborted in the IPCP negotiaten phase. Actually, no IPCP Response is received at all. (See attachment nm-ppp-ubuntu9_04.log). The same actually happend also without the above mentioned fix of the dbus rules.

My knowledge about the PPP Protocol is very limitted so I do not have any idea how to go on from this point. So any help is very much appreciated.

The log files were captured using the procedure described in the wiki for Network Manager, but with additional PPP debug information.

[Christof Länzlinger (laenzlinger)]

Attachmen 1: Successfull connection with Ubuntu 8.10 (Live-CD)

Debug procedure:

# become root
sudo su

# stop NM
/etc/init.d/NetworkManager stop

# start with serial log and tee it in a log file
NM_PPP_DEBUG=1 NetworkManager --no-daemon 2>&1 | tee /tmp/nm.log

[Christof Länzlinger (laenzlinger)]

Attachment 2: Unsuccessful connection with unmodified Ubuntu 9.04

Debug procedure:

# become root
sudo su

# stop NM
/etc/init.d/NetworkManager stop

# start with serial log and tee it in a log file
NM_PPP_DEBUG=1 NetworkManager --no-daemon 2>&1 | tee /tmp/nm.log

[Christof Länzlinger (laenzlinger)]

Attachment 2: Unsuccessful connection with modified Ubuntu 9.04

Removed the following section in /etc/dbus-1/system.d/NetworkManager.conf:

 <deny send_destination="org.freedesktop.NetworkManager"
                      send_interface="org.freedesktop.NetworkManager.PPP"/>

Debug procedure:

# become root
sudo su

# stop NM
/etc/init.d/NetworkManager stop

# start with serial log and tee it in a log file
NM_PPP_DEBUG=1 NetworkManager --no-daemon 2>&1 | tee /tmp/nm.log

[Alexander Sack (asac)]

this problem happens when your root user is @console; this is arguably a bug in consolekit; ensure that you have closed all root shells and then it will work without opening security gates by removing that line from your config.

[Alexander Sack (asac)]

an almost dupe (though its not the main NM package there) is bug 360818

[swoke (swoke)]

This workaround work for me.

[ichudov (igor-chudov)]

Thanks for a workaround, it works great. Thanks to Alexander and the rest for helping me to at least partially restore sanity.

But let's get real guys, this is not really a fix for the problem. It is kind of funny actually.

What is with this consolekit, it is so full of problems, and no one fixes them?

[Christof Länzlinger (laenzlinger)]

Thanks a lot for your help. The the warning "Could not get secrets" seems to be related to starting the NetworkManager in a root shell. But still I have the problem with connecting to the mobile operator with NetworkManager.

After CHAP authentication the connection is not established. See the following log extract:

------- log extract start --------------------------------------------------------------------------------------------------
CHAP authentication succeeded
sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
NetworkManager: <info> (ttyUSB2): device state change: 6 -> 7
rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Modem hangup
Connection terminated.
------- log extract end --------------------------------------------------------------------------------------------------

I do not get IPCP Responses when using NetworkManager.

When using the pppd from wvdial, the connection succeeds.

[Alexander Sack (asac)]

Christof, please don't misuse bugs to raise new issues. open new bugs. Anyway, you might need to add some random username/password in your broadband ppp connection editor ... also ensure that there is the right APN configured.

[Alexander Sack (asac)]

ok, please backup your /etc/dbus-1/system.d/NetworkManager.conf file somewhere and replace it with the file attached here. then restart your system and stress test NetworkManager for a while (using, reconfiguring, reconnecting and stuff). Try to connect with and without a root shell open. Let me know if there are other regressions for maybe unrelated use-cases.

[Alexander Sack (asac)]

remember to put the original file back in place after testing ... otherwise you won't get automatically updated dbus rules from the package in future.

[ichudov (igor-chudov)]

Alexander, When I look at your attachment, all I see is a number "512"?

It is not really a conf file?

[Alexander Sack (asac)]

> It is not really a conf file?

yes, seems launchpad tried to be smart and declared this as text/html ... i changed the mimetype so now you can better see it ;).

[Christof Länzlinger (laenzlinger)]

Alexander, thank you very much for taking your time to look into my issues. I did not intent to misuse this bug to raise new issues. Unfortunately it seems that with my initial bug report I have faced two different unrelated issues. I'll definitely try out what you suggested and in case I still don't succeed in connecting to my mobile operator I'll raise a new issue as you suggested.

[ichudov (igor-chudov)]

Alexander, I tried the changed file http://launchpadlibrarian.net/26395942/NetworkManager.conf

This file did not help.

Here's grep -i ppp /var/log/auth.log:

May 6 13:58:07 potato dbus-daemon: Rejected send message, 1 matched rules; type="method_call", sender=":1.124" (uid=1000 pid=11447 comm="/usr/lib/indicator-applet/indicator-applet --oaf-a") interface="org.freedesktop.DBus.Properties" member="Get" error name="(unset)" requested_reply=0 destination=":1.133" (uid=0 pid=11796 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB"))
May 6 13:58:40 potato dbus-daemon: Rejected send message, 1 matched rules; type="method_call", sender=":1.124" (uid=1000 pid=11447 comm="/usr/lib/indicator-applet/indicator-applet --oaf-a") interface="org.freedesktop.DBus.Properties" member="Get" error name="(unset)" requested_reply=0 destination=":1.137" (uid=0 pid=12332 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB"))
May 6 13:58:40 potato dbus-daemon: Rejected send message, 11 matched rules; type="method_call", sender=":1.137" (uid=0 pid=12332 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB") interface="org.freedesktop.NetworkManager.PPP" member="SetState" error name="(unset)" requested_reply=0 destination="org.freedesktop.NetworkManager" (uid=0 pid=3771 comm="/usr/sbin/NetworkManager --pid-file /var/run/Netwo"))
May 6 13:58:40 potato dbus-daemon: Rejected send message, 11 matched rules; type="method_call", sender=":1.137" (uid=0 pid=12332 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB") interface="org.freedesktop.NetworkManager.PPP" member="SetState" error name="(unset)" requested_reply=0 destination="org.freedesktop.NetworkManager" (uid=0 pid=3771 comm="/usr/sbin/NetworkManager --pid-file /var/run/Netwo"))
May 6 13:58:40 potato dbus-daemon: Rejected send message, 11 matched rules; type="method_call", sender=":1.137" (uid=0 pid=12332 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB") interface="org.freedesktop.NetworkManager.PPP" member="SetState" error name="(unset)" requested_reply=0 destination="org.freedesktop.NetworkManager" (uid=0 pid=3771 comm="/usr/sbin/NetworkManager --pid-file /var/run/Netwo"))
May 6 13:58:40 potato dbus-daemon: Rejected send message, 11 matched rules; type="method_call", sender=":1.137" (uid=0 pid=12332 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB") interface="org.freedesktop.NetworkManager.PPP" member="SetState" error name="(unset)" requested_reply=0 destination="org.freedesktop.NetworkManager" (uid=0 pid=3771 comm="/usr/sbin/NetworkManager --pid-file /var/run/Netwo"))
May 6 13:58:40 potato dbus-daemon: Rejected send message, 11 matched rules; type="method_call", sender=":1.137" (uid=0 pid=12332 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB") interface="org.freedesktop.NetworkManager.PPP" member="SetState" error name="(unset)" requested_reply=0 destination="org.freedesktop.NetworkManager" (uid=0 pid=3771 comm="/usr/sbin/NetworkManager --pid-file /var/run/Netwo"))
May 6 13:58:40 potato dbus-daemon: Rejected send message, 11 matched rules; type="method_call", sender=":1.137" (uid=0 pid=12332 comm="/usr/sbin/pppd nodetach lock nodefaultroute ttyUSB") interface="...

[ncyclon (ncyclon)]

--------------------------------------------------------------------------------------------------------------------------------------
# cat /etc/dbus-1/system.d/NetworkManager.conf
<!DOCTYPE busconfig PUBLIC
 "-//freedesktop//DTD D-BUS Bus Configuration 1.0//EN"
 "http://www.freedesktop.org/standards/dbus/1.0/busconfig.dtd">
<busconfig>
        <policy user="root">
                <allow own="org.freedesktop.NetworkManager"/>
                <allow send_destination="org.freedesktop.NetworkManager"/>

                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.PPP"/>
        </policy>
        <policy user="haldaemon">
                <allow send_destination="org.freedesktop.NetworkManager"/>
                <allow send_interface="org.freedesktop.NetworkManager"/>
        </policy>
        <policy at_console="true">
  <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.DBus.Introspectable"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.DBus.Properties"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.AccessPoint"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.Connection.Active"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.Device.Cdma"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.Device.Wired"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.Device.Gsm"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.Device.Serial"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.Device.Wireless"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.Device"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.DHCP4Config"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.IP4Config"/>
                <allow send_destination="org.freedesktop.NetworkManager"
                       send_interface="org.freedesktop.NetworkManager.VPN.Connection"/>

        </policy>
        <policy context="default">
                <deny own="org.freedesktop.NetworkManager"/>...

[Alexander Sack (asac)]

ncyclon, thanks.

anyone else can confirm that the config file i posted here: https://bugs.edge.launchpad.net/ubuntu/+source/network-manager/+bug/371291/comments/10

fixes this for you?

[Peter Miller (pmiller-opensource)]

Adding these lines fixed it for me:

<policy group="dialout">
                <allow send_destination="org.freedesktop.NetworkManager"

send_interface="org.freedesktop.NetworkManager.PPP"/>
        </policy>

On Mon, 2009-05-11 at 18:27 +0000, ncyclon wrote:
> --------------------------------------------------------------------------------------------------------------------------------------
> # cat /etc/dbus-1/system.d/NetworkManager.conf
> <!DOCTYPE busconfig PUBLIC
> "-//freedesktop//DTD D-BUS Bus Configuration 1.0//EN"
> "http://www.freedesktop.org/standards/dbus/1.0/busconfig.dtd">
> <busconfig>
> <policy user="root">
> <allow own="org.freedesktop.NetworkManager"/>
> <allow send_destination="org.freedesktop.NetworkManager"/>
>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.PPP"/>
> </policy>
> <policy user="haldaemon">
> <allow send_destination="org.freedesktop.NetworkManager"/>
> <allow send_interface="org.freedesktop.NetworkManager"/>
> </policy>
> <policy at_console="true">
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.DBus.Introspectable"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.DBus.Properties"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.AccessPoint"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.Connection.Active"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.Device.Cdma"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.Device.Wired"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.Device.Gsm"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.Device.Serial"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.Device.Wireless"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.Device"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> send_interface="org.freedesktop.NetworkManager.DHCP4Config"/>
> <allow send_destination="org.freedesktop.NetworkManager"
> ...

[oombill (blefler)]

The config file posted did not work for me. (https://bugs.edge.launchpad.net/ubuntu/+source/network-manager/+bug/371291/comments/10). I am running Ubuntu 9.04 trying to connect to an AT&T DSL modem. However, I did restart Network Manager from a root shell.

[Mario Splivalo (mariosplivalo)]

The config file posted did not work for me too. Jaunty, 64bit, fresh install. But, the error message in my auth.log is a bit different. Here is what shows up after I get disconnected:

May 15 12:50:13 mike dbus-daemon: Rejected send message, 2 matched rules; type="error", sender=":1.8" (uid=0 pid=3277 comm="/usr/sbin/NetworkManager --pid-file /var/run/Netwo") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.42" (uid=0 pid=4859 comm="/usr/sbin/pppd nodetach lock nodefaultroute user 3"))
May 15 12:50:13 mike dbus-daemon: Rejected send message, 2 matched rules; type="error", sender=":1.8" (uid=0 pid=3277 comm="/usr/sbin/NetworkManager --pid-file /var/run/Netwo") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.42" (uid=0 pid=4859 comm="/usr/sbin/pppd nodetach lock nodefaultroute user 3"))

[roan (info-iroan)]

I'm using a Nokia N79 and NM complains about dbus.

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

Ncyclon's fix works for me. Thanks.

[Kurt Stephens (kurt-launchpad)]

Bug 374443 might be related.

[Kurt Stephens (kurt-launchpad)]

 ncylon's fix above fixes Bug 374443.

Thanks!

[Mario Splivalo (mariosplivalo)]

Kurt, roan, could you attach the output in /var/log/auth.log, while connecting?

[TomaszChmielewski (mangoo-wpkg)]

Unfortunately, I still can't use my GSM connection, with changes suggested in this bug report (371291).

See attached /var/log/syslog and /var/log/auth.log.

[TomaszChmielewski (mangoo-wpkg)]

/var/log/syslog when attempting to connect.

[Alexander Sack (asac)]

fixed in karmic. The feedback from my config file is too ambigous to roll this out. Not sure what was different in #16 to my file, so i think its not different.

[Rolf Leggewie (r0lf)]

I believe I am still seeing this bug in Karmic. I am not connecting via GSM but via PPPoE and that fails in Network Manager while it succeeds with pon/poff. I attach an excerpt from syslog (line 36 is key I think "Oct 20 06:27:22 X24 NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module"). Let me know if you need any other information.

Reopening

[Rolf Leggewie (r0lf)]

My Network Manager related configuration is attached to bug 432777

[Alexander Sack (asac)]

we think this is fixed in daily ppa: https://edge.launchpad.net/~network-manager/+archive/trunk

please try that.

[Rolf Leggewie (r0lf)]

Alexander, thank you for giving this a shot.

FWIW, 0.8~a~git.20091203t185502.9c37194-0ubuntu1~nmt1~karmic still cuts the connection from the USB UMTS stick right after it's been established.

Dec 7 18:17:06 X24 NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module

[Hardik Dalwadi (hardik-dalwadi)]

Hi,

I am getting this Bug in Lucid RC1.

[pescobar (pescobar)]

I am also getting this bug in xubuntu lucid x86_64. the workaround of closing every root shell worked for me.

[bag (gruening)]

Can confirm these bug in Ubuntu 10.4 32bit. I have no root-shell manually open.

[Arthur Țițeică (arthur-titeica)]

An year has passed...

[ChristianH (chansis)]

Hi,

can confirm this after upgrading from karmic to lucid on a thinkpad notebook. No root shell open. Trying to connect to klarmobil (German broadband cell provider, actually on the o2 net) with their umts-usb adapter through network-manager. The adapter is a 1c9e:f000 W14 stick.

usb_modeswitch seems to work fine, there is a PIN handshake working up to the GUI and back. Then pppd stops with a pppd_timed_out, same as Rolf's post above. Checking auth.log reveals the org.freedesktop.DBus.Error.UnknownMethod problem.

Fix: replaced the /etc/dbus-1/system.d/NetworkManager.conf with a fresh copy manually extracted from the nm deb package. Maybe re-installing through synaptic might work as well, did not check.Rebooted, and broadband connects right away :)

Maybe that works for others as well...

[Rolf Leggewie (r0lf)]

Christian, interesting. Did you diff the /etc/dbus-1/system.d/NetworkManager.conf file you had and the one from the Debian package?

[ChristianH (chansis)]

Good point Rolf, did not think of that. I did make a backup copy but don't have it any more. Sorry. My mistake.

[AIAMUZZ (muzafsh-113)]

My System : Aspire One ZG5
OS : Ubuntu 10.10 (Maverick)
3G Device : Gobi 2000 (inbuilt)

sorry i seem to have been hit with this bug

The first connection throws up an almost connected log. (Attached File : First 3G connection attempt)

whereas subsequent attempts to connect throws a very minimal log. (Attached File : Second 3G connection attempt)

And i am absolutely unable to connect to the internet.

Please help me fix this issue

thanks

[AIAMUZZ (muzafsh-113)]

a very minimal log on second and subsequent connection attempts !!!

[AIAMUZZ (muzafsh-113)]

not sure why on second/subsequent attempts the log is not as detailed as the first attempt at connecting after bootup

help most appreciated.

thanks

[JC Hulce (soaringsky)]

Thank you for taking the time to report this bug. Jaunty is EOL, so I am declining this task for Jaunty.

[Thomas Hood (jdthood)]

Does anyone still have this problem after upgrading to Ubuntu 12.04?

[Launchpad Janitor (janitor)]

[Expired for network-manager (Ubuntu) because there has been no activity for 60 days.]