Network-manager "Looks like pppd didn't initialize our dbus module" with Huawei E160G (E220) on amd64 Intrepid

[Tristan S]

Binary package hint: network-manager

Using Huawei E160G on Intrepid amd64, network manager fails to connect to UK network "three" (3) with following syslog entries:

Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) starting connection '3'
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Dec 7 18:53:08 ts-laptop-u NetworkManager: <debug> [1228675988.578562] nm_serial_device_open(): (ttyUSB0) opening device...
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> (ttyUSB0): powering up...
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Registered on Home network
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Associated with network: +COPS: 0,2,"23420",2
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Connected, Woo!
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Starting pppd connection
Dec 7 18:53:08 ts-laptop-u NetworkManager: <debug> [1228675988.892082] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock user three ttyUSB0 noipdefault usepeerdns ipparam /org/freedesktop/NetworkManager/PPP/0 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
Dec 7 18:53:08 ts-laptop-u NetworkManager: <debug> [1228675988.907285] nm_ppp_manager_start(): ppp started with pid 6101
Dec 7 18:53:08 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
Dec 7 18:53:09 ts-laptop-u NetworkManager: <info> (ttyUSB0): device state change: 5 -> 6
Dec 7 18:53:09 ts-laptop-u NetworkManager: <info> (ttyUSB0): device state change: 6 -> 7
Dec 7 18:53:23 ts-laptop-u NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module
Dec 7 18:53:23 ts-laptop-u NetworkManager: <info> (ttyUSB0): device state change: 7 -> 9
Dec 7 18:53:23 ts-laptop-u NetworkManager: <debug> [1228676003.913691] nm_serial_device_close(): Closing device 'ttyUSB0'
Dec 7 18:53:23 ts-laptop-u NetworkManager: <info> Marking connection '3' invalid.
Dec 7 18:53:23 ts-laptop-u NetworkManager: <info> Activation (ttyUSB0) failed.
Dec 7 18:53:23 ts-laptop-u NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3
Dec 7 18:53:23 ts-laptop-u NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0).
Dec 7 18:53:23 ts-laptop-u NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
Dec 7 18:53:23 ts-laptop-u NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
Dec 7 18:53:25 ts-laptop-u NetworkManager: <debug> [1228676005.913480] ensure_killed(): waiting for ppp pid 6101 to exit
Dec 7 18:53:25 ts-laptop-u NetworkManager: <debug> [1228676005.913691] ensure_killed(): ppp pid 6101 cleaned up

Not believed to be related to 271446 because using 0.7~~svn20081018t105859-0ubuntu1.8.10.1

Note also, not using a PIN on this device.

[Anonio Fiol (antonio-fiol-es)]

I got the same error on different hardware (Novatel Merlin UMTS modem). Posted logs as follow-up to bug#248630, which was open to deal with the specifics of that pcmcia card.

[Geert-Jan (geert-jan-hut)]

I have not been able to use my new Huawei E620 umts USB stick (lspci info: "12d1:1001 Huawei Technologies Co., Ltd. E620 USB Modem") with the same error many times. I have tried it on three machines, two of them ran AMD64 Intrepid, the other one is an Asus eeepc with an up to date i386 Intrepid installation. With this eeepc I have created the log attached below.

What I see is either the message as shown above, or a message that just states 'pppd: connection terminated'

In the attached log you can see that I tried to connect two times, the first time I was just disconnected, the second time a password dialog box appeared multiple times (after which I was also disconnected) but not before getting the same message as the same bug reporters.

On two of the three machines I have also tried to use the hardware in Windows, and there it works as expected. I also tried to use the linux vodafone drivers from betavine, and these give the similar errors as NetworkManager.

[Tristan S (tristanstevens)]

I get this much less often now as long as I plug the USB Modem in before boot time. This seems to have fixed it for 99% of the time. Occasionally when disconnected (due to signal or handover) it will not re-connect because of this, however in this instance I tend to get away with unplugging and re-plugging in.

[Geert-Jan (geert-jan-hut)]

Tristan, thanks for your comment. I finally got around trying your solution to have the modem inserted at boot time, but for me this didn't solve the problem. I can do anything with the modem (including sending SMS messages), but I cannot get a connection.

[Chris1976 (chsenger)]

I have the same problem like posted above with an Huawei E180 (Identified as E220).

"pppd_timed_out(): Looks like pppd didn't initialize our dbus module" is the only thing I can see in the syslog.

I had it fixed until by installing the latest DBUS package. But that helped exactly until the next reboot.
The problem also occures on my PC with an clean install from the latest Intrepid Desktop CD.
Problem might be Networkmanager-independent since I am unable to connect with Gnome-PPP as
well. If needed I can provide logfiles (this will take a little since I cannot go online due to the problem)

[Jim Kirkpatrick (jim-kirkpatrick)]

I get this occasionally too. However, for me this usually happens when the connection I'm using just stops working. Network Manager (NM) thinks it's fine, but it's not so I disconnect and try to reconnect. At this point, the connection process takes twice as long and the NM applet spins for a bit then just reverts back to a 'disconnected' state. Looking in the syslog usually shows the above "pppd_timed_out(): Looks like pppd didn't initialize our dbus module" issue.

I have a Huawei E169 modem that is usually plugged in at startup.

However, I've found a script that enables me to reconnect after I run it:

----- restart_usb.sh ------
#!/bin/bash

sudo modprobe -r uhci_hcd
sudo modprobe uhci_hcd

echo "Waiting kernel to detect modem device"

#Wait till the kernel recognizes our E220
while [ ! -c /dev/ttyUSB1 ]; do
sleep 1
done
--- EOF ---

I am not a linux guru leet haxor, but it looks like the above simply dumps the USB subsystem and then adds it back in again, forcing freshness and joy onto your system.

I hope it's of help to people here or gives some insight into the source of the error/bug.

[João Neves (jneves)]

Same problem with a Huawei E180. My handmade PPP configuration simply works, Network Manager connects, then disconnects:

Apr 25 00:24:13 home pppd[17936]: Using interface ppp0
Apr 25 00:24:13 home pppd[17936]: Connect: ppp0 <--> /dev/ttyUSB2
Apr 25 00:24:13 home pppd[17936]: Unable to obtain CHAP password for home.silvaneves.org on UMTS_CHAP_SRVR from plugin
Apr 25 00:24:13 home pppd[17936]: No CHAP secret found for authenticating us to UMTS_CHAP_SRVR
Apr 25 00:24:13 home pppd[17936]: CHAP authentication succeeded
Apr 25 00:24:13 home pppd[17936]: CHAP authentication succeeded
Apr 25 00:24:17 home pppd[17936]: Could not determine remote IP address: defaulting to 10.64.64.64
Apr 25 00:24:17 home pppd[17936]: Cannot determine ethernet address for proxy ARP
Apr 25 00:24:17 home pppd[17936]: local IP address 78.130.14.96
Apr 25 00:24:17 home pppd[17936]: remote IP address 10.64.64.64
Apr 25 00:24:17 home pppd[17936]: primary DNS address 62.169.67.172
Apr 25 00:24:17 home pppd[17936]: secondary DNS address 62.169.67.171
Apr 25 00:24:29 home NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module
Apr 25 00:24:29 home NetworkManager: <info> (ttyUSB2): device state change: 5 -> 9
Apr 25 00:24:29 home pppd[17936]: Terminating on signal 15
Apr 25 00:24:29 home pppd[17936]: Connect time 0.2 minutes.
Apr 25 00:24:29 home pppd[17936]: Sent 0 bytes, received 131 bytes.

BTW, the pin is entered correctly by NM. I've checked everything that Alexander Sack asked to check in bugs 358048 and 271446.

Any suggestions?

[João Neves (jneves)]

My NM now connects. I've noticed the following in /var/log/auth.log:

Apr 25 01:43:41 home dbus-daemon: Rejected send message, 1 matched rules; type="method_call", sender=":1.42" (uid=1000 pid=6083 comm="/usr/lib/indicator-applet/indicator-applet --oaf-a") interface="org.freedesktop.DBus.Properties" member="Get" error name="(unset)" requested_reply=0 destination=":1.56" (uid=0 pid=8443 comm="/usr/lib/NetworkManager/nm-dispatcher.action "))

My feeling is that some kind of resolution is failing with dbus, so I changed all deny to allow in /etc/dbus-1/system.d/nm-dispatcher.conf to check if that changed and now I can connect.

Anyone knows how the service to name resolution works in dbus so I can correctly correct my system?

[Alexander Sack (asac)]

dupe of bug 371291 ... see the "official workaround" in that bugs summary.

[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