Bug 867710 - Activation of network connection failed
Summary: Activation of network connection failed
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 18
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-10-18 07:26 UTC by Mikhail
Modified: 2014-02-05 12:37 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-02-05 12:37:32 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
screenshot popup message (749.17 KB, image/png)
2012-10-18 07:26 UTC, Mikhail
no flags Details

Description Mikhail 2012-10-18 07:26:32 UTC
Created attachment 629209 [details]
screenshot popup message

Description of problem:
Can't up network connection through LTE modem instead pop's error "Activation of network connection failed"

$ lsusb
Bus 001 Device 002: ID 12d1:1506 Huawei Technologies Co., Ltd. E398 LTE/UMTS/GSM Modem/Networkcard
Bus 001 Device 003: ID 04f2:b1d8 Chicony Electronics Co., Ltd 
Bus 002 Device 003: ID 0502:3223 Acer, Inc. 
Bus 004 Device 002: ID 0cf3:3005 Atheros Communications, Inc. AR3011 Bluetooth
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub

$ dmesg
[ 4083.853607] usb 1-1: new high-speed USB device number 5 using ehci_hcd
[ 4083.971633] usb 1-1: New USB device found, idVendor=12d1, idProduct=1506
[ 4083.971644] usb 1-1: New USB device strings: Mfr=4, Product=3, SerialNumber=0
[ 4083.971651] usb 1-1: Product: HUAWEI Mobile
[ 4083.971657] usb 1-1: Manufacturer: Huawei Technologies
[ 4083.974650] option 1-1:1.0: GSM modem (1-port) converter detected
[ 4083.975111] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
[ 4083.975331] option 1-1:1.1: GSM modem (1-port) converter detected
[ 4083.975524] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
[ 4083.975714] option 1-1:1.2: GSM modem (1-port) converter detected
[ 4083.975901] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
[ 4083.977697] qmi_wwan 1-1:1.3: cdc-wdm0: USB WDM device
[ 4083.978134] qmi_wwan 1-1:1.3: wwan0: register 'qmi_wwan' at usb-0000:00:12.2-1, WWAN/QMI device, 00:a0:c6:00:00:00
[ 4083.981313] scsi7 : usb-storage 1-1:1.5
[ 4083.985311] scsi8 : usb-storage 1-1:1.6
[ 4084.983544] scsi 7:0:0:0: CD-ROM            HUAWEI   Mass Storage     2.31 PQ: 0 ANSI: 0
[ 4084.990844] scsi 8:0:0:0: Direct-Access     HUAWEI   SD Storage       2.31 PQ: 0 ANSI: 2
[ 4085.004584] sr0: scsi-1 drive
[ 4085.005013] sr 7:0:0:0: Attached scsi CD-ROM sr0
[ 4085.005242] sr 7:0:0:0: Attached scsi generic sg1 type 5
[ 4085.005712] sd 8:0:0:0: Attached scsi generic sg2 type 0
[ 4085.009039] sd 8:0:0:0: [sdb] Attached SCSI removable disk
[ 4088.108443] ISO 9660 Extensions: Microsoft Joliet Level 1
[ 4088.109962] ISOFS: changing to secondary root
[ 4088.111335] SELinux: initialized (dev sr0, type iso9660), uses genfs_contexts

Comment 1 Dan Winship 2012-10-19 11:28:02 UTC
please attach the /var/log/messages output from when you try to activate the connection

Comment 2 Mikhail 2012-10-19 12:25:08 UTC
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) starting connection 'Megafon RUS'
Oct 19 18:23:34 localhost NetworkManager[708]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> (ttyUSB0): device state change: prepare -> need-auth (reason 'none') [40 60 0]
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Oct 19 18:23:34 localhost modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> disconnecting)
Oct 19 18:23:34 localhost modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (disconnecting -> connected)
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> (ttyUSB0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Oct 19 18:23:34 localhost NetworkManager[708]: <info> disconnect failed: (32) The serial port is not open.
Oct 19 18:23:34 localhost dbus-daemon[583]: modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> disconnecting)
Oct 19 18:23:34 localhost dbus-daemon[583]: modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (disconnecting -> connected)
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0]
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0]
Oct 19 18:23:34 localhost NetworkManager[708]: <info> starting PPP connection
Oct 19 18:23:34 localhost NetworkManager[708]: <info> pppd started with pid 7140
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) started...
Oct 19 18:23:34 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Oct 19 18:23:34 localhost pppd[7140]: Plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so loaded.
Oct 19 18:23:34 localhost NetworkManager[708]: Plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so loaded.
Oct 19 18:23:34 localhost pppd[7140]: pppd 2.4.5 started by root, uid 0
Oct 19 18:23:34 localhost pppd[7140]: Removed stale lock on ttyUSB0 (pid 7020)
Oct 19 18:23:34 localhost NetworkManager[708]: Removed stale lock on ttyUSB0 (pid 7020)
Oct 19 18:23:34 localhost pppd[7140]: Using interface ppp0
Oct 19 18:23:34 localhost NetworkManager[708]: Using interface ppp0
Oct 19 18:23:34 localhost pppd[7140]: Connect: ppp0 <--> /dev/ttyUSB0
Oct 19 18:23:34 localhost NetworkManager[708]: Connect: ppp0 <--> /dev/ttyUSB0
Oct 19 18:23:34 localhost NetworkManager[708]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
Oct 19 18:23:55 localhost NetworkManager[708]: <warn> pppd timed out or didn't initialize our dbus module
Oct 19 18:23:55 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Oct 19 18:23:55 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) started...
Oct 19 18:23:55 localhost NetworkManager[708]: <info> (ttyUSB0): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
Oct 19 18:23:55 localhost NetworkManager[708]: <info> Marking connection 'Megafon RUS' invalid.
Oct 19 18:23:55 localhost pppd[7140]: Terminating on signal 15
Oct 19 18:23:55 localhost NetworkManager[708]: <warn> Activation (ttyUSB0) failed for connection 'Megafon RUS'
Oct 19 18:23:55 localhost NetworkManager[708]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) complete.
Oct 19 18:23:55 localhost NetworkManager[708]: <info> (ttyUSB0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Oct 19 18:23:55 localhost NetworkManager[708]: <info> (ttyUSB0): deactivating device (reason 'none') [0]
Oct 19 18:23:55 localhost modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> disconnecting)
Oct 19 18:23:55 localhost modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (disconnecting -> connected)
Oct 19 18:23:55 localhost NetworkManager[708]: Terminating on signal 15
Oct 19 18:23:55 localhost dbus-daemon[583]: modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (connected -> disconnecting)
Oct 19 18:23:55 localhost dbus-daemon[583]: modem-manager[765]: <info>  Modem /org/freedesktop/ModemManager/Modems/0: state changed (disconnecting -> connected)
Oct 19 18:23:57 localhost avahi-daemon[580]: Withdrawing workstation service for ppp0.

Comment 3 Jirka Klimes 2012-10-31 13:06:28 UTC
Please run NM with PP debugging as follows and attach the logs:

# systemctl mask NetworkManager.service
# systemctl stop NetworkManager.service

run NM with PPP debugging 
# 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.

Restore previous configuration
# systemctl unmask NetworkManager.service
# systemctl restart NetworkManager.service

Comment 4 Mikhail 2013-01-10 09:29:14 UTC
# NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
NetworkManager[14075]: <info> NetworkManager (version 0.9.7.0-12.git20121004.fc18) is starting...
NetworkManager[14075]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
NetworkManager[14075]: <info> WEXT support is enabled
NetworkManager[14075]: <info> VPN: loaded org.freedesktop.NetworkManager.pptp
NetworkManager[14075]: <info> VPN: loaded org.freedesktop.NetworkManager.vpnc
NetworkManager[14075]: <info> VPN: loaded org.freedesktop.NetworkManager.openvpn
NetworkManager[14075]: <info> VPN: loaded org.freedesktop.NetworkManager.openconnect
NetworkManager[14075]:    ifcfg-rh: Acquired D-Bus service com.redhat.ifcfgrh1
NetworkManager[14075]: <info> Loaded plugin ifcfg-rh: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
NetworkManager[14075]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
NetworkManager[14075]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-em1 ... 
NetworkManager[14075]: <warn> failed to allocate link cache: (-10) Operation not supported
NetworkManager[14075]:    ifcfg-rh:     read connection 'System em1'
NetworkManager[14075]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-lo ... 
NetworkManager[14075]:    keyfile: parsing Megafon RUS ... 
NetworkManager[14075]:    keyfile:     read connection 'Megafon RUS'
NetworkManager[14075]:    keyfile: parsing Megafon RUS-962e3944-5545-471b-ac5d-19514a5659c3 ... 
NetworkManager[14075]:    keyfile:     read connection 'Megafon RUS'
NetworkManager[14075]: <info> modem-manager is now available
NetworkManager[14075]: <info> monitoring kernel firmware directory '/lib/firmware'.
NetworkManager[14075]: <info> WiFi enabled by radio killswitch; enabled by state file
NetworkManager[14075]: <info> WWAN enabled by radio killswitch; enabled by state file
NetworkManager[14075]: <info> WiMAX enabled by radio killswitch; enabled by state file
NetworkManager[14075]: <info> Networking is enabled by state file
NetworkManager[14075]: <warn> failed to allocate link cache: (-10) Operation not supported
NetworkManager[14075]: <info> (em1): carrier is OFF
NetworkManager[14075]: <info> (em1): new Ethernet device (driver: 'e1000e' ifindex: 2)
NetworkManager[14075]: <info> (em1): exported as /org/freedesktop/NetworkManager/Devices/0
NetworkManager[14075]: <info> (em1): now managed
NetworkManager[14075]: <info> (em1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[14075]: <info> (em1): bringing up device.
NetworkManager[14075]: <info> (em1): preparing device.
NetworkManager[14075]: <info> (em1): deactivating device (reason 'managed') [2]
NetworkManager[14075]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[14075]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[14075]: <warn> (ttyUSB0): failed to look up interface index
NetworkManager[14075]: <info> (ttyUSB0): new GSM/UMTS device (driver: 'option1' ifindex: 0)
NetworkManager[14075]: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/1
NetworkManager[14075]: <info> (ttyUSB0): now managed
NetworkManager[14075]: <info> (ttyUSB0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[14075]: <info> (ttyUSB0): deactivating device (reason 'managed') [2]
NetworkManager[14075]: <info> WWAN now enabled by management service
NetworkManager[14075]: <info> (ttyUSB0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
NetworkManager[14075]: <info> (em1): carrier now ON (device state 20)
NetworkManager[14075]: <info> (em1): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
NetworkManager[14075]: <info> Auto-activating connection 'System em1'.
NetworkManager[14075]: <info> Activation (em1) starting connection 'System em1'
NetworkManager[14075]: <info> (em1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[14075]: <info> Activation (em1) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14075]: <info> Activation (em1) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14075]: <info> Activation (em1) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[14075]: <info> Activation (em1) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14075]: <info> Activation (em1) Stage 2 of 5 (Device Configure) starting...
NetworkManager[14075]: <info> (em1): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[14075]: <info> Activation (em1) Stage 2 of 5 (Device Configure) successful.
NetworkManager[14075]: <info> Activation (em1) Stage 2 of 5 (Device Configure) complete.
NetworkManager[14075]: <info> Activation (em1) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[14075]: <info> Activation (em1) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[14075]: <info> (em1): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[14075]: <info> Activation (em1) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager[14075]: <info> dhclient started with pid 14100
NetworkManager[14075]: <info> Activation (em1) Stage 3 of 5 (IP Configure Start) complete.
Internet Systems Consortium DHCP Client 4.2.4-P2
Copyright 2004-2012 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

/var/lib/dhclient/dhclient-057ee901-1b8e-45aa-adc5-fabb812eb68f-em1.lease line 5: no option named wpad in space dhcp
  option wpad "http://proxy-new.afbank.ru:80/wpad.dat"
          ^
/var/lib/dhclient/dhclient-057ee901-1b8e-45aa-adc5-fabb812eb68f-em1.lease line 21: no option named wpad in space dhcp
  option wpad "http://proxy-new.afbank.ru:80/wpad.dat"
          ^
NetworkManager[14075]: <info> (em1): DHCPv4 state changed nbi -> preinit
Listening on LPF/em1/00:1c:c0:4b:df:83
Sending on   LPF/em1/00:1c:c0:4b:df:83
Sending on   Socket/fallback
DHCPREQUEST on em1 to 255.255.255.255 port 67 (xid=0x1eeaae47)
DHCPACK from 10.10.1.251 (xid=0x1eeaae47)
NetworkManager[14075]: <info> (em1): DHCPv4 state changed preinit -> reboot
NetworkManager[14075]: <info>   address 10.10.0.113
NetworkManager[14075]: <info>   prefix 23 (255.255.254.0)
NetworkManager[14075]: <info>   gateway 10.10.1.254
NetworkManager[14075]: <info>   nameserver '10.10.4.2'
NetworkManager[14075]: <info>   nameserver '10.10.4.3'
NetworkManager[14075]: <info>   domain name 'afbank.ru'
NetworkManager[14075]: <info> Activation (em1) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
NetworkManager[14075]: <info> Activation (em1) Stage 5 of 5 (IPv4 Commit) started...
bound to 10.10.0.113 -- renewal in 38292 seconds.
NetworkManager[14075]: <info> (em1): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
NetworkManager[14075]: <info> Activation (em1) Stage 5 of 5 (IPv4 Commit) complete.
NetworkManager[14075]: <info> (em1): device state change: secondaries -> activated (reason 'none') [90 100 0]
NetworkManager[14075]: <info> Policy set 'System em1' (em1) as default for IPv4 routing and DNS.
NetworkManager[14075]: <info> Activation (em1) successful, device activated.
NetworkManager[14075]: <info> (em1): device state change: activated -> disconnected (reason 'user-requested') [100 30 39]
NetworkManager[14075]: <info> (em1): deactivating device (reason 'user-requested') [39]
NetworkManager[14075]: <info> (em1): canceled DHCP transaction, DHCP client pid 14100
NetworkManager[14075]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.
NetworkManager[14075]: <info> Activation (ttyUSB0) starting connection 'Megafon RUS'
NetworkManager[14075]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[14075]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[14075]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[14075]: <info> starting PPP connection
NetworkManager[14075]: <info> pppd started with pid 14277
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) started...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Plugin /usr/lib/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 14034)
using channel 10
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 0x67dd9ae3> <pcomp> <accomp>]
NetworkManager[14075]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x67dd9ae3> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x67dd9ae3> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x67dd9ae3> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x67dd9ae3> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x67dd9ae3> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x67dd9ae3> <pcomp> <accomp>]
NetworkManager[14075]: <warn> pppd timed out or didn't initialize our dbus module
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Terminating on signal 15
** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) started...
NetworkManager[14075]: <info> (ttyUSB0): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
sent [LCP TermReq id=0x2 "User request"]
NetworkManager[14075]: <warn> Activation (ttyUSB0) failed for connection 'Megafon RUS'
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) complete.
NetworkManager[14075]: <info> (ttyUSB0): device state change: failed -> disconnected (reason 'none') [120 30 0]
NetworkManager[14075]: <info> (ttyUSB0): deactivating device (reason 'none') [0]
NetworkManager[14075]: <info> Activation (ttyUSB0) starting connection 'Megafon RUS'
NetworkManager[14075]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[14075]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[14075]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[14075]: <info> starting PPP connection
NetworkManager[14075]: <info> pppd started with pid 14316
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) started...
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Plugin /usr/lib/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 14277)
using channel 11
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 0x83b45175> <pcomp> <accomp>]
NetworkManager[14075]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x83b45175> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x83b45175> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x83b45175> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x83b45175> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x83b45175> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x83b45175> <pcomp> <accomp>]
NetworkManager[14075]: <warn> pppd timed out or didn't initialize our dbus module
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Terminating on signal 15
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) started...
** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
NetworkManager[14075]: <info> (ttyUSB0): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
sent [LCP TermReq id=0x2 "User request"]
NetworkManager[14075]: <warn> Activation (ttyUSB0) failed for connection 'Megafon RUS'
NetworkManager[14075]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) complete.
NetworkManager[14075]: <info> (ttyUSB0): device state change: failed -> disconnected (reason 'none') [120 30 0]
NetworkManager[14075]: <info> (ttyUSB0): deactivating device (reason 'none') [0]

Comment 5 Mikhail 2013-02-01 08:33:11 UTC
[root@telecon_16 ~]# systemctl mask NetworkManager.service
ln -s '/dev/null' '/etc/systemd/system/NetworkManager.service'
[root@telecon_16 ~]# systemctl stop NetworkManager.service
[root@telecon_16 ~]# NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
NetworkManager[14408]: <info> NetworkManager (version 0.9.7.0-12.git20121004.fc18) is starting...
NetworkManager[14408]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
NetworkManager[14408]: <info> WEXT support is enabled
NetworkManager[14408]: <info> VPN: loaded org.freedesktop.NetworkManager.pptp
NetworkManager[14408]: <info> VPN: loaded org.freedesktop.NetworkManager.vpnc
NetworkManager[14408]: <info> VPN: loaded org.freedesktop.NetworkManager.openvpn
NetworkManager[14408]: <info> VPN: loaded org.freedesktop.NetworkManager.openconnect
NetworkManager[14408]:    ifcfg-rh: Acquired D-Bus service com.redhat.ifcfgrh1
NetworkManager[14408]: <info> Loaded plugin ifcfg-rh: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
NetworkManager[14408]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
NetworkManager[14408]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-em1 ... 
NetworkManager[14408]: <warn> failed to allocate link cache: (-10) Operation not supported
NetworkManager[14408]:    ifcfg-rh:     read connection 'System em1'
NetworkManager[14408]:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-lo ... 
NetworkManager[14408]:    keyfile: parsing Megafon RUS ... 
NetworkManager[14408]:    keyfile:     read connection 'Megafon RUS'
NetworkManager[14408]:    keyfile: parsing Megafon RUS-962e3944-5545-471b-ac5d-19514a5659c3 ... 
NetworkManager[14408]:    keyfile:     read connection 'Megafon RUS'
NetworkManager[14408]: <info> modem-manager is now available
NetworkManager[14408]: <info> monitoring kernel firmware directory '/lib/firmware'.
NetworkManager[14408]: <info> WiFi enabled by radio killswitch; enabled by state file
NetworkManager[14408]: <info> WWAN enabled by radio killswitch; enabled by state file
NetworkManager[14408]: <info> WiMAX enabled by radio killswitch; enabled by state file
NetworkManager[14408]: <info> Networking is enabled by state file
NetworkManager[14408]: <warn> failed to allocate link cache: (-10) Operation not supported
NetworkManager[14408]: <info> (em1): carrier is ON
NetworkManager[14408]: <info> (em1): new Ethernet device (driver: 'e1000e' ifindex: 2)
NetworkManager[14408]: <info> (em1): exported as /org/freedesktop/NetworkManager/Devices/0
NetworkManager[14408]: <info> (em1): now managed
NetworkManager[14408]: <info> (em1): device state change: unmanaged -> unavailable (reason 'connection-assumed') [10 20 41]
NetworkManager[14408]: <info> (em1): preparing device.
NetworkManager[14408]: <info> Activation (em1) starting connection 'System em1'
NetworkManager[14408]: <info> (em1): device state change: unavailable -> ip-config (reason 'none') [20 70 0]
NetworkManager[14408]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[14408]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[14408]: <warn> (ttyUSB0): failed to look up interface index
NetworkManager[14408]: <info> (ttyUSB0): new GSM/UMTS device (driver: 'option1' ifindex: 0)
NetworkManager[14408]: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/1
NetworkManager[14408]: <info> (ttyUSB0): now managed
NetworkManager[14408]: <info> (ttyUSB0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[14408]: <info> (ttyUSB0): deactivating device (reason 'managed') [2]
NetworkManager[14408]: <warn> (em1) firewall zone add/change failed: (32) ZONE_ALREADY_SET
NetworkManager[14408]: <info> Activation (em1) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[14408]: <info> WWAN now enabled by management service
NetworkManager[14408]: <info> (ttyUSB0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
NetworkManager[14408]: <info> Activation (em1) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[14408]: <info> Activation (em1) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager[14408]: <info> dhclient started with pid 14424
NetworkManager[14408]: <info> Activation (em1) Stage 3 of 5 (IP Configure Start) complete.
Internet Systems Consortium DHCP Client 4.2.5
Copyright 2004-2013 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

/var/lib/dhclient/dhclient-057ee901-1b8e-45aa-adc5-fabb812eb68f-em1.lease line 5: no option named wpad in space dhcp
  option wpad "http://proxy-new.afbank.ru:80/wpad.dat"
          ^
/var/lib/dhclient/dhclient-057ee901-1b8e-45aa-adc5-fabb812eb68f-em1.lease line 21: no option named wpad in space dhcp
  option wpad "http://proxy-new.afbank.ru:80/wpad.dat"
          ^
NetworkManager[14408]: <info> (em1): DHCPv4 state changed nbi -> preinit
Listening on LPF/em1/00:1c:c0:4b:df:83
Sending on   LPF/em1/00:1c:c0:4b:df:83
Sending on   Socket/fallback
DHCPREQUEST on em1 to 255.255.255.255 port 67 (xid=0xeb1600e)
DHCPACK from 10.10.1.251 (xid=0xeb1600e)
bound to 10.10.0.113 -- renewal in 32583 seconds.
NetworkManager[14408]: <info> (em1): DHCPv4 state changed preinit -> reboot
NetworkManager[14408]: <info>   address 10.10.0.113
NetworkManager[14408]: <info>   prefix 23 (255.255.254.0)
NetworkManager[14408]: <info>   gateway 10.10.1.254
NetworkManager[14408]: <info>   nameserver '10.10.4.2'
NetworkManager[14408]: <info>   nameserver '10.10.4.3'
NetworkManager[14408]: <info>   domain name 'afbank.ru'
NetworkManager[14408]: <info> Activation (em1) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
NetworkManager[14408]: <info> Activation (em1) Stage 5 of 5 (IPv4 Commit) started...
NetworkManager[14408]: <info> (em1): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
NetworkManager[14408]: <info> Activation (em1) Stage 5 of 5 (IPv4 Commit) complete.
NetworkManager[14408]: <info> (em1): device state change: secondaries -> activated (reason 'none') [90 100 0]
NetworkManager[14408]: <info> Policy set 'System em1' (em1) as default for IPv4 routing and DNS.
NetworkManager[14408]: <info> Activation (em1) successful, device activated.
NetworkManager[14408]: <info> (em1): device state change: activated -> disconnected (reason 'user-requested') [100 30 39]
NetworkManager[14408]: <info> (em1): deactivating device (reason 'user-requested') [39]
NetworkManager[14408]: <info> (em1): canceled DHCP transaction, DHCP client pid 14424
NetworkManager[14408]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.
NetworkManager[14408]: <info> Activation (ttyUSB0) starting connection 'Megafon RUS'
NetworkManager[14408]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[14408]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[14408]: <info> starting PPP connection
NetworkManager[14408]: <info> pppd started with pid 14613
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) started...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Plugin /usr/lib/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 14134)
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 0x91a91879> <pcomp> <accomp>]
NetworkManager[14408]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x91a91879> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x91a91879> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x91a91879> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x91a91879> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x91a91879> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x91a91879> <pcomp> <accomp>]
NetworkManager[14408]: <warn> pppd timed out or didn't initialize our dbus module
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
Terminating on signal 15
** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
sent [LCP TermReq id=0x2 "User request"]
NetworkManager[14408]: <warn> Activation (ttyUSB0) failed for connection 'Megafon RUS'
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) complete.
NetworkManager[14408]: <info> (ttyUSB0): device state change: failed -> disconnected (reason 'none') [120 30 0]
NetworkManager[14408]: <info> (ttyUSB0): deactivating device (reason 'none') [0]
NetworkManager[14408]: <info> Activation (ttyUSB0) starting connection 'Megafon RUS'
NetworkManager[14408]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: prepare -> need-auth (reason 'none') [40 60 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14408]: <info> disconnect failed: (32) The serial port is not open.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[14408]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[14408]: <info> starting PPP connection
NetworkManager[14408]: <info> pppd started with pid 14646
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) started...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Plugin /usr/lib/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 14613)
using channel 6
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 0xb8b0c677> <pcomp> <accomp>]
NetworkManager[14408]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb8b0c677> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb8b0c677> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb8b0c677> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb8b0c677> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb8b0c677> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb8b0c677> <pcomp> <accomp>]
NetworkManager[14408]: <warn> pppd timed out or didn't initialize our dbus module
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Terminating on signal 15
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) started...
** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
NetworkManager[14408]: <info> (ttyUSB0): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
sent [LCP TermReq id=0x2 "User request"]
NetworkManager[14408]: <warn> Activation (ttyUSB0) failed for connection 'Megafon RUS'
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv4 Configure Timeout) complete.
NetworkManager[14408]: <info> (ttyUSB0): device state change: failed -> disconnected (reason 'none') [120 30 0]
NetworkManager[14408]: <info> (ttyUSB0): deactivating device (reason 'none') [0]
Modem hangup
** Message: nm-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Connection terminated.
NetworkManager[14408]: <info> (ttyUSB0): now unmanaged
NetworkManager[14408]: <info> (ttyUSB0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
NetworkManager[14408]: <info> (ttyUSB0): cleaning up...
NetworkManager[14408]: <info> (ttyUSB0): taking down device.
NetworkManager[14408]: <warn> (ttyUSB0): failed to look up interface index
NetworkManager[14408]: <info> WWAN now disabled by management service
NetworkManager[14408]: <info> (ttyUSB0): new GSM/UMTS device (driver: 'option1' ifindex: 0)
NetworkManager[14408]: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/2
NetworkManager[14408]: <info> (ttyUSB0): now managed
NetworkManager[14408]: <info> (ttyUSB0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[14408]: <info> (ttyUSB0): deactivating device (reason 'managed') [2]
NetworkManager[14408]: <info> (ttyUSB0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) starting connection 'Megafon RUS'
NetworkManager[14408]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: prepare -> need-auth (reason 'none') [40 60 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[14408]: <info> WWAN now enabled by management service
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[14408]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[14408]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[14408]: <info> starting PPP connection
NetworkManager[14408]: <info> pppd started with pid 14778
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) started...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Plugin /usr/lib/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 14646)
using channel 8
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 0xd9808664> <pcomp> <accomp>]
rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x2c8d13d> <pcomp> <accomp>]
sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x2c8d13d> <pcomp> <accomp>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xd9808664> <pcomp> <accomp>]
sent [LCP EchoReq id=0x0 magic=0xd9808664]
** Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate'
rcvd [LCP DiscReq id=0x1 magic=0x2c8d13d]
rcvd [CHAP Challenge id=0x1 <78214b341a688230d69b80c1d86177e2>, name = "UMTS_CHAP_SRVR"]
** Message: nm-ppp-plugin: (get_credentials): passwd-hook, requesting credentials...
** Message: nm-ppp-plugin: (get_credentials): got credentials from NetworkManager
NetworkManager[14408]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
sent [CHAP Response id=0x1 <feb7f51731b413927c476ff56c2806a1>, name = "gdata"]
rcvd [LCP EchoRep id=0x0 magic=0x2c8d13d d9 80 86 64]
rcvd [CHAP Success id=0x1 ""]
CHAP authentication succeeded
CHAP authentication succeeded
** Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
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>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
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
rcvd [IPCP ConfNak id=0x1]
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [IPCP ConfNak id=0x2]
sent [IPCP ConfReq id=0x3 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [IPCP ConfReq id=0x0]
sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
rcvd [IPCP ConfRej id=0x3 <compress VJ 0f 01>]
sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [IPCP ConfReq id=0x1]
sent [IPCP ConfAck id=0x1]
rcvd [IPCP ConfNak id=0x4 <addr 10.251.234.61> <ms-dns1 10.163.182.9> <ms-dns2 10.163.182.10>]
sent [IPCP ConfReq id=0x5 <addr 10.251.234.61> <ms-dns1 10.163.182.9> <ms-dns2 10.163.182.10>]
rcvd [IPCP ConfAck id=0x5 <addr 10.251.234.61> <ms-dns1 10.163.182.9> <ms-dns2 10.163.182.10>]
Could not determine remote IP address: defaulting to 10.64.64.64
local  IP address 10.251.234.61
remote IP address 10.64.64.64
primary   DNS address 10.163.182.9
secondary DNS address 10.163.182.10
** Message: nm-ppp-plugin: (nm_phasechange): status 9 / phase 'running'
** Message: nm-ppp-plugin: (nm_ip_up): ip-up event
** Message: nm-ppp-plugin: (nm_ip_up): sending Ip4Config to NetworkManager...
NetworkManager[14408]: <info> PPP manager(IP Config Get) reply received.
Script /etc/ppp/ip-up started (pid 14783)
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 5 of 5 (IPv4 Commit) started...
Script /etc/ppp/ip-up finished (pid 14783), status = 0x0
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
NetworkManager[14408]: <info> (ttyUSB0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
NetworkManager[14408]: <info> Activation (ttyUSB0) Stage 5 of 5 (IPv4 Commit) complete.
NetworkManager[14408]: <info> (ttyUSB0): device state change: secondaries -> activated (reason 'none') [90 100 0]
NetworkManager[14408]: <info> Policy set 'Megafon RUS' (ppp0) as default for IPv4 routing and DNS.
NetworkManager[14408]: <info> Activation (ttyUSB0) successful, device activated.
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::b97c:8af5:f7e1:ae5a>]
IPV6CP: timeout sending Config-Requests

Comment 6 Fedora End Of Life 2013-12-21 09:08:43 UTC
This message is a reminder that Fedora 18 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 18. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '18'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 18's end of life.

Thank you for reporting this issue and we are sorry that we may not be 
able to fix it before Fedora 18 is 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  change the 'version' to a later Fedora 
version prior to Fedora 18's end of life.

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.

Comment 7 Fedora End Of Life 2014-02-05 12:37:34 UTC
Fedora 18 changed to end-of-life (EOL) status on 2014-01-14. Fedora 18 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.