Bug 506531
| Summary: | NetworkManager rejects to make internet connection (using Huawei E220 USB Modem) | ||
|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | yunus <yunus.tji.nyan> |
| Component: | NetworkManager | Assignee: | Dan Williams <dcbw> |
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Fedora Extras Quality Assurance <extras-qa> |
| Severity: | medium | Docs Contact: | |
| Priority: | low | ||
| Version: | rawhide | CC: | danw, dcbw, sven, tscherf, yunus.tji.nyan |
| Target Milestone: | --- | ||
| Target Release: | --- | ||
| Hardware: | All | ||
| OS: | Linux | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2009-11-06 06:30:08 UTC | Type: | --- |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
|
Description
yunus
2009-06-17 16:34:35 UTC
/var/log/messages reported below messages when NetworkManager failed to make connection : .... <snip> Jun 17 23:35:20 localhost NetworkManager: <info> Activation (ttyUSB0) starting connection 'apn-internet' Jun 17 23:35:20 localhost NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 Jun 17 23:35:20 localhost NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... Jun 17 23:35:20 localhost NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... Jun 17 23:35:20 localhost NetworkManager: <WARN> nm_serial_device_open(): (ttyUSB0) cannot open device (errno 13) Jun 17 23:35:20 localhost NetworkManager: <info> (ttyUSB0): device state change: 4 -> 9 Jun 17 23:35:20 localhost NetworkManager: <info> Marking connection 'apn-internet' invalid. Jun 17 23:35:20 localhost NetworkManager: <info> Activation (ttyUSB0) failed. Jun 17 23:35:20 localhost NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. Jun 17 23:35:20 localhost NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3 Jun 17 23:35:20 localhost NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0). Jun 17 23:35:20 localhost NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed Jun 17 23:35:20 localhost NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed Same issue here with a HUAWEI E870 ExpressCard when you get "errno 13" think, what's the output of: ls -al /dev/ttyUSB0 ? errno 13 is EACCES, which means that NM was denied access to the port. Do you have SELinux running in enforcing mode? Can you run NM with "--no-daemon" from a terminal and reproduce the failure, or does it only fail when run as a system service? I always have SElinux running in enforcing mode. I don't think I got "errno 13" (I will try to make sure once I have a chance). Last time I tried I ran NM with "--no-daemon". It was also did not work. Currently I have no access to my original rawhide laptop due to HDD failure. I intend to reproduce the bug using rawhide Live CD. Unfortunately, I still cannot run the Live CD until now due to X problem (the issue I have almost a month). Once I succeed in running the rawhide LiveCD, I will let you know the information you inquired above. [liveuser@localhost ~]$ rpm -qa | grep Manager
ModemManager-0.2-3.20090826.fc12.x86_64
NetworkManager-0.7.995-3.git20090813.fc12.x86_64
NetworkManager-gnome-0.7.995-3.git20090813.fc12.x86_64
NetworkManager-glib-0.7.995-3.git20090813.fc12.x86_64
Please ignore my previous comment about "errno 13" (sorry for that)
I failed to reproduce the "errno 13"
{===/var/log/messages===
Sep 5 16:19:38 localhost dbus-daemon: Rejected send message, 2 matched rules; type="error", sender=":1.8" (uid=0 pid=1285 comm="NetworkManager) interface="(u
nset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.37" (uid=0 pid=3215 comm="/usr/sbin/pppd))
Sep 5 16:19:38 localhost dbus-daemon: Rejected send message, 2 matched rules; type="error", sender=":1.8" (uid=0 pid=1285 comm="NetworkManager) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.37" (uid=0 pid=3215 comm="/usr/sbin/pppd))
Sep 5 16:19:38 localhost dbus-daemon: Rejected send message, 2 matched rules; type="error", sender=":1.8" (uid=0 pid=1285 comm="NetworkManager) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.37" (uid=0 pid=3215 comm="/usr/sbin/pppd))
Sep 5 16:19:38 localhost pppd[3215]: Connection terminated.
Sep 5 16:19:38 localhost dbus-daemon: Rejected send message, 2 matched rules; type="error", sender=":1.8" (uid=0 pid=1285 comm="NetworkManager) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.37" (uid=0 pid=3215 comm="/usr/sbin/pppd))
Sep 5 16:19:38 localhost pppd[3215]: Exit.
===/var/log/messages===}
Please see below for output of NM with "--no-daemon" from terminal. It failed also. I saw the nm-applet icon kept spinning "aroud the two green ball" ==output from termial== [liveuser@localhost ~]$ su -c 'NM_SERIAL_DEBUG=1 /usr/sbin/NetworkManager --no-daemon' NetworkManager: <info> starting... NetworkManager: <info> modem-manager is now available NetworkManager: Loaded plugin ifcfg-rh: (c) 2007 - 2008 Red Hat, Inc. To report bugs please use the NetworkManager mailing list. NetworkManager: <info> Found radio killswitch rfkill3 (at /sys/devices/pci0000:00/0000:00:1c.0/0000:02:00.0/ieee80211/phy0/rfkill3) (driver <unknown>) NetworkManager: <info> Found radio killswitch rfkill0 (at /sys/devices/platform/acer-wmi/rfkill/rfkill0) (driver acer-wmi) NetworkManager: <info> Wireless now disabled by radio killswitch NetworkManager: ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-lo ... NetworkManager: <info> (wlan0): driver supports SSID scans (scan_capa 0x01). NetworkManager: <info> (wlan0): new 802.11 WiFi device (driver: 'iwl3945') NetworkManager: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/0 NetworkManager: <info> (wlan0): now managed NetworkManager: <info> (wlan0): device state change: 1 -> 2 (reason 2) NetworkManager: <info> (wlan0): bringing up device. NetworkManager: <info> (wlan0): deactivating device (reason: 2). NetworkManager: <info> (eth0): new Ethernet device (driver: 'tg3') NetworkManager: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/1 NetworkManager: <info> (eth0): now managed NetworkManager: <info> (eth0): device state change: 1 -> 2 (reason 2) NetworkManager: <info> (eth0): bringing up device. NetworkManager: <info> (eth0): preparing device. NetworkManager: <info> (eth0): deactivating device (reason: 2). NetworkManager: Added default wired connection 'Auto eth0' for /sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/eth0 -- Error received: File exists -- Original message: type=0x14 length=56 flags=<REQUEST,ACK,ATOMIC> sequence-nr=1252183890 pid=4197741 NetworkManager: <info> (ttyUSB0): new GSM device (driver: 'option1') NetworkManager: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/2 NetworkManager: <info> (ttyUSB0): now managed NetworkManager: <info> (ttyUSB0): device state change: 1 -> 2 (reason 2) NetworkManager: <info> (ttyUSB0): deactivating device (reason: 2). NetworkManager: flush_routes: assertion `iface_idx >= 0' failed NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed NetworkManager: <WARN> default_adapter_cb(): bluez error getting default adapter: The name org.bluez was not provided by any .service files NetworkManager: <info> (ttyUSB0): device state change: 2 -> 3 (reason 0) NetworkManager: <info> Activation (ttyUSB0) starting connection 'Telkomsel' NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0) NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled... NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting... NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5 (reason 0) NetworkManager: <info> Starting pppd connection NetworkManager: <debug> [1252183936.155176] 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/lib64/pppd/2.4.4/nm-pppd-plugin.so NetworkManager: <debug> [1252183936.158648] nm_ppp_manager_start(): ppp started with pid 3445 NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete. Plugin /usr/lib64/pppd/2.4.4/nm-pppd-plugin.so loaded. Using interface ppp0 Connect: ppp0 <--> /dev/ttyUSB0 NetworkManager: <info> (ttyUSB0): device state change: 5 -> 6 (reason 0) CHAP authentication succeeded CHAP authentication succeeded NetworkManager: <info> (ttyUSB0): device state change: 6 -> 7 (reason 0) Could not determine remote IP address: defaulting to 10.64.64.64 local IP address 114.124.110.109 remote IP address 10.64.64.64 primary DNS address 10.11.12.13 secondary DNS address 10.11.12.14 NetworkManager: <info> PPP manager(IP Config Get) reply received. NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) scheduled... NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) started... NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) complete. I should confirm that it works for below version NetworkManager-glib-0.7.996-1.git20090826.fc12.x86_64 NetworkManager-0.7.996-1.git20090826.fc12.x86_64 NetworkManager-gnome-0.7.996-1.git20090826.fc12.x86_64 FYI, I have SElinux disabled from comment #5 to comment #8 in order to reach X. I have a similar issue with a sierra modem: # lsusb: Bus 003 Device 002: ID 1199:6804 Sierra Wireless, Inc. MC8755 Device # tail /var/log/messages Oct 20 09:09:22 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete. Oct 20 09:09:22 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started... Oct 20 09:09:22 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete. Oct 20 09:09:22 tiffy pppd[3807]: Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded. Oct 20 09:09:22 tiffy pppd[3807]: pppd 2.4.4 started by root, uid 0 Oct 20 09:09:22 tiffy pppd[3807]: Using interface ppp0 Oct 20 09:09:22 tiffy pppd[3807]: Connect: ppp0 <--> /dev/ttyUSB0 Oct 20 09:09:22 tiffy NetworkManager: Tried to set deprecated property gsm/puk Oct 20 09:09:22 tiffy pppd[3807]: CHAP authentication succeeded Oct 20 09:09:22 tiffy pppd[3807]: CHAP authentication succeeded Oct 20 09:09:42 tiffy NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module Oct 20 09:09:42 tiffy NetworkManager: <info> (ttyUSB0): device state change: 7 -> 9 (reason 14) Oct 20 09:09:42 tiffy pppd[3807]: Terminating on signal 15 Oct 20 09:09:42 tiffy NetworkManager: <info> Marking connection 'Vodafone-Germany' invalid. Oct 20 09:09:42 tiffy NetworkManager: Tried to set deprecated property gsm/puk Oct 20 09:09:42 tiffy NetworkManager: <info> Activation (ttyUSB0) failed. Oct 20 09:09:42 tiffy NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3 (reason 0) Oct 20 09:09:42 tiffy NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0). Oct 20 09:09:42 tiffy NetworkManager: flush_routes: assertion `iface_idx >= 0' failed Oct 20 09:09:42 tiffy NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed Oct 20 09:09:42 tiffy pppd[3807]: Connection terminated. Oct 20 09:09:42 tiffy dbus: Rejected send message, 2 matched rules; type="error", sender=":1.66" (uid=0 pid=3795 comm="NetworkManager) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.68" (uid=0 pid=3807 comm="/usr/sbin/pppd)) Oct 20 09:09:42 tiffy dbus: Rejected send message, 2 matched rules; type="error", sender=":1.66" (uid=0 pid=3795 comm="NetworkManager) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.68" (uid=0 pid=3807 comm="/usr/sbin/pppd)) Oct 20 09:09:42 tiffy dbus: Rejected send message, 2 matched rules; type="error", sender=":1.66" (uid=0 pid=3795 comm="NetworkManager) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply=0 destination=":1.68" (uid=0 pid=3807 comm="/usr/sbin/pppd)) Oct 20 09:09:43 tiffy modem-manager: (ttyUSB0) closing serial device... Oct 20 09:09:43 tiffy pppd[3807]: Exit. Oct 20 09:09:54 tiffy NetworkManager: <info> Activation (ttyUSB0) starting connection 'Vodafone-Germany' Oct 20 09:09:54 tiffy NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0) Oct 20 09:09:54 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... Oct 20 09:09:54 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... Oct 20 09:09:54 tiffy NetworkManager: <info> (ttyUSB0): device state change: 4 -> 6 (reason 0) Oct 20 09:09:54 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. Oct 20 09:09:54 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... Oct 20 09:09:54 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... Oct 20 09:09:54 tiffy NetworkManager: <info> (ttyUSB0): device state change: 6 -> 4 (reason 0) Oct 20 09:09:54 tiffy NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. Oct 20 09:09:54 tiffy modem-manager: (ttyUSB0) opening serial device... Oct 20 09:09:55 tiffy NetworkManager: <WARN> stage1_prepare_done(): GSM modem connection failed: Sending command failed: device is connected Oct 20 09:09:55 tiffy NetworkManager: <info> (ttyUSB0): device state change: 4 -> 9 (reason 1) Oct 20 09:09:55 tiffy NetworkManager: <info> Marking connection 'Vodafone-Germany' invalid. Oct 20 09:09:55 tiffy NetworkManager: Tried to set deprecated property gsm/puk Oct 20 09:09:55 tiffy NetworkManager: <info> Activation (ttyUSB0) failed. Oct 20 09:09:55 tiffy NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3 (reason 0) Oct 20 09:09:55 tiffy NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0). Oct 20 09:09:55 tiffy NetworkManager: flush_routes: assertion `iface_idx >= 0' failed Oct 20 09:09:55 tiffy NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed Oct 20 09:09:55 tiffy modem-manager: (ttyUSB0) closing serial device... disabling/enabling the card with the rfkill switch "sometimes" fixes the problems, but most of the time I get a kernel oops when using the rfkill switch, see BZ #529743 for this. yunus, please try: https://admin.fedoraproject.org/updates/F11/FEDORA-2009-10696 that has a number of fixes for various modems include Huawei. Please re-open if it doesn't fix the problem! |