| Summary: | NetworkManager: <warn> pppd timed out or didn't initialize our dbus module | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Jon Thomas <jthomas> | ||||||||||
| Component: | NetworkManager | Assignee: | Dan Williams <dcbw> | ||||||||||
| Status: | CLOSED WONTFIX | QA Contact: | Fedora Extras Quality Assurance <extras-qa> | ||||||||||
| Severity: | medium | Docs Contact: | |||||||||||
| Priority: | unspecified | ||||||||||||
| Version: | 14 | CC: | dcbw, jim, jklimes, rona.dinihari | ||||||||||
| Target Milestone: | --- | ||||||||||||
| Target Release: | --- | ||||||||||||
| Hardware: | Unspecified | ||||||||||||
| OS: | Unspecified | ||||||||||||
| Whiteboard: | |||||||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||||||
| Doc Text: | Story Points: | --- | |||||||||||
| Clone Of: | Environment: | ||||||||||||
| Last Closed: | 2012-08-16 12:59:53 UTC | Type: | --- | ||||||||||
| Regression: | --- | Mount Type: | --- | ||||||||||
| Documentation: | --- | CRM: | |||||||||||
| Verified Versions: | Category: | --- | |||||||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||||||
| Attachments: |
|
||||||||||||
If you do the following: serivce NetworkManager stop NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon and then try to reproduce the problem, you'll get a lot of good debugging info from the PPP process that we can use to debug the issue. I seem to have the same problem. When I follow Dan William's instructions I get: NetworkManager[3202]: <info> (ttyUSB0): new CDMA device (driver: 'option1' ifindex: -1) NetworkManager[3202]: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/3 NetworkManager[3202]: <info> (ttyUSB0): now managed NetworkManager[3202]: <info> (ttyUSB0): device state change: 1 -> 2 (reason 2) NetworkManager[3202]: <info> (ttyUSB0): deactivating device (reason: 2). NetworkManager[3202]: <info> (ttyUSB0): device state change: 2 -> 3 (reason 0) NetworkManager[3202]: <info> Activation (ttyUSB0) starting connection 'O2 connection 2' NetworkManager[3202]: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0) NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... NetworkManager[3202]: <info> (ttyUSB0): device state change: 4 -> 6 (reason 0) NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... NetworkManager[3202]: <info> (ttyUSB0): device state change: 6 -> 4 (reason 0) NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. NetworkManager[3202]: <info> WWAN now enabled by radio killswitch NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled... NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting... NetworkManager[3202]: <info> (ttyUSB0): device state change: 4 -> 5 (reason 0) NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful. NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled. NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete. NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started... NetworkManager[3202]: <info> (ttyUSB0): device state change: 5 -> 7 (reason 0) NetworkManager[3202]: <info> starting PPP connection NetworkManager[3202]: <info> pppd started with pid 3404 NetworkManager[3202]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete. Plugin /usr/lib64/pppd/2.4.5/nm-pppd-plugin.so loaded. ** Message: nm-ppp-plugin: (plugin_init): initializing ** Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection' Removed stale lock on ttyUSB0 (pid 2715) using channel 5 Using interface ppp0 Connect: ppp0 <--> /dev/ttyUSB0 ** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish' sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x7ad4ae9b> <pcomp> <accomp>] rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x8ac7a68b> <pcomp> <accomp>] sent [LCP ConfAck id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x8ac7a68b> <pcomp> <accomp>] rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x7ad4ae9b> <pcomp> <accomp>] ** Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate' rcvd [CHAP Challenge id=0x1 <40e967eafe208b806a7a0d92a5db6b0b85836d3b6f760e8c808d9b40446eb591>, name = ""] ** Message: nm-ppp-plugin: (get_credentials): passwd-hook, requesting credentials... ** Message: nm-ppp-plugin: (get_credentials): got credentials from NetworkManager sent [CHAP Response id=0x1 <6f1b34caa449cf88ea613d696f309264>, name = "601006873@ETCZ"] NetworkManager[3202]: <warn> pppd timed out or didn't initialize our dbus module NetworkManager[3202]: <info> (ttyUSB0): device state change: 7 -> 9 (reason 5) Terminating on signal 15 ** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate' ** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish' sent [LCP TermReq id=0x2 "User request"] NetworkManager[3202]: <info> Marking connection 'O2 connection 2' invalid. NetworkManager[3202]: <warn> Activation (ttyUSB0) failed. NetworkManager[3202]: <info> (ttyUSB0): device state change: 9 -> 3 (reason 0) NetworkManager[3202]: <info> (ttyUSB0): deactivating device (reason: 0). rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x9577b187> <pcomp> <accomp>] rcvd [LCP TermAck id=0x2] ** Message: nm-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect' Connection terminated. ** Message: nm-ppp-plugin: (nm_phasechange): status 1 / phase 'dead' ** Message: nm-ppp-plugin: (nm_exit_notify): cleaning up fyi, NetworkManager-0.8.2 seemed to fix the problem for me. I'm using Fedora 16 and tried so many things. I rarely have connection with my USB CDMA modem using any provider. I am using wvdial for now. (In reply to comment #4) > I'm using Fedora 16 and tried so many things. I rarely have connection with > my USB CDMA modem using any provider. I am using wvdial for now. You may experience diffrent problem. Anyway, would you mind following steps at https://live.gnome.org/NetworkManager/Debugging#NM_3G_08_09 to get logs? Created attachment 594326 [details]
Test result in Arch Linux
Created attachment 594327 [details]
Test result in Arch Linux
Created attachment 594328 [details]
Test result in Arch Linux
(In reply to comment #5) > (In reply to comment #4) > > I'm using Fedora 16 and tried so many things. I rarely have connection with > > my USB CDMA modem using any provider. I am using wvdial for now. > > You may experience diffrent problem. > Anyway, would you mind following steps at > https://live.gnome.org/NetworkManager/Debugging#NM_3G_08_09 to get logs? Sorry, I am using Arch Linux now, but what I experience in Fedora 16 and Arch Linux with NetworkManager and USB CDMA are the same. I have attached the logs from Arch Linux. I won't be able to test further if there are any updates, unless you accept tests in a hosted environment such as under VirtualBox. I do hope I can go back to using Fedora. My decission over distros are not entirely in relation with the bug. This message is a notice that Fedora 14 is now at end of life. Fedora has stopped maintaining and issuing updates for Fedora 14. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At this time, all open bugs with a Fedora 'version' of '14' have been closed as WONTFIX. (Please note: Our normal process is to give advanced warning of this occurring, but we forgot to do that. A thousand apologies.) Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, feel free to reopen this bug and simply change the 'version' to a later Fedora version. Bug Reporter: Thank you for reporting this issue and we are sorry that we were unable to fix it before Fedora 14 reached end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged to click on "Clone This Bug" (top right of this page) and open it against that version of Fedora. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. The process we are following is described here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping |
Created attachment 478307 [details] messages pppd/netowork manager fails to connect with USB 305/308 Feb 11 07:01:59 basin pppd[2534]: pppd 2.4.5 started by root, uid 0 Feb 11 07:01:59 basin pppd[2534]: Using interface ppp0 Feb 11 07:01:59 basin pppd[2534]: Connect: ppp0 <--> /dev/ttyUSB2 Feb 11 07:02:20 basin NetworkManager[1446]: <warn> pppd timed out or didn't initialize our dbus module Feb 11 07:02:20 basin NetworkManager[1446]: <info> (ttyUSB2): device state change: 7 -> 9 (reason 5) Feb 11 07:02:20 basin pppd[2534]: Terminating on signal 15 This seems to be intermittent. If I boot with the device connected, it will always fail. If I then disconnect the device, wait, and reattach, it usually succeeds (but not always). Attached is messages with a failure followed by a success.