Attachment 928496 Details for Bug 1130782 – NetworkManager log while manually activating the connection

NetworkManager log while manually activating the connection

activation.log (text/plain), 14.55 KB, created by David Juran on 2014-08-19 19:37:21 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: David Juran

Created: 2014-08-19 19:37:21 UTC

Size: 14.55 KB

patch

obsolete

>-- Logs begin at Mon 2014-07-28 19:34:49 CEST. --
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) started...
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) complete.
>Aug 19 21:26:22 localhost.localdomain ModemManager[539]: <info>  Simple connect started...
>Aug 19 21:26:22 localhost.localdomain ModemManager[539]: <info>  Simple connect state (1/8): Unlock check
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: prepare -> need-auth (reason 'none') [40 60 0]
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <warn> No agents were available for this request.
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: need-auth -> failed (reason 'no-secrets') [60 120 7]
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <warn> Activation (cdc-wdm0) failed for connection 'bredband'
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: failed -> disconnected (reason 'none') [120 30 0]
>Aug 19 21:26:22 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): deactivating device (reason 'none') [0]
>Aug 19 21:28:38 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) starting connection 'bredband'
>Aug 19 21:28:38 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
>Aug 19 21:28:38 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) scheduled...
>Aug 19 21:28:38 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) started...
>Aug 19 21:28:38 localhost.localdomain ModemManager[539]: <info>  Simple connect started...
>Aug 19 21:28:38 localhost.localdomain ModemManager[539]: <info>  Simple connect state (1/8): Unlock check
>Aug 19 21:28:38 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) complete.
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Simple connect state (2/8): Wait to get fully initialized
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (locked -> initializing)
>Aug 19 21:28:40 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0) modem state changed, 'locked' --> 'initializing' (reason: unknown)
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  (ttyUSB2): port attributes not fully set
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  couldn't load Supported Bands: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2''
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  couldn't load Power State: 'Unhandled power state: 'unknown' (255)'
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  couldn't load SIM identifier: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2''
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  couldn't load IMSI: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2''
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned''
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  couldn't load current allowed/preferred modes: 'Loading current modes is not supported by this device'
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  couldn't load current Bands: 'QMI operation failed: Cannot send message: QMI service 'nas' version '1.1' required, got version '1.0''
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (initializing -> disabled)
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Simple connect state (3/8): Enable
>Aug 19 21:28:40 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0) modem state changed, 'initializing' --> 'disabled' (reason: unknown)
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (disabled -> enabling)
>Aug 19 21:28:40 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0) modem state changed, 'disabled' --> 'enabling' (reason: user-requested)
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <warn>  (ttyUSB2): port attributes not fully set
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: Couldn't reload current power state: Unhandled power state: 'unknown' (255)
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP Registration state changed (unknown -> idle)
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (enabling -> enabled)
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Simple connect state (4/8): Wait to get fully enabled
>Aug 19 21:28:40 localhost.localdomain ModemManager[539]: <info>  Simple connect state (5/8): Register
>Aug 19 21:28:40 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0) modem state changed, 'enabling' --> 'enabled' (reason: user-requested)
>Aug 19 21:28:40 localhost.localdomain NetworkManager[533]: <info> WWAN now enabled by management service
>Aug 19 21:28:41 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP Registration state changed (idle -> registering)
>Aug 19 21:28:41 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP location updated (MCC: '240', MNC: '8', Location area code: '0', Cell ID: '0')
>Aug 19 21:28:41 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP Registration state changed (registering -> home)
>Aug 19 21:28:41 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (enabled -> registered)
>Aug 19 21:28:41 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0) modem state changed, 'enabled' --> 'registered' (reason: unknown)
>Aug 19 21:28:41 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: access technology changed (unknown -> umts)
>Aug 19 21:28:41 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: signal quality updated (68)
>Aug 19 21:28:43 localhost.localdomain ModemManager[539]: <info>  Simple connect state (6/8): Bearer
>Aug 19 21:28:43 localhost.localdomain ModemManager[539]: <info>  Simple connect state (7/8): Connect
>Aug 19 21:28:43 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (registered -> connecting)
>Aug 19 21:28:44 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0) modem state changed, 'registered' --> 'connecting' (reason: user-requested)
>Aug 19 21:28:44 localhost.localdomain ModemManager[539]: [/dev/cdc-wdm0] Allocating new client ID...
>Aug 19 21:28:44 localhost.localdomain ModemManager[539]: [/dev/cdc-wdm0] Registered 'wds' (version 1.5) client with ID '1'
>Aug 19 21:28:46 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (connecting -> connected)
>Aug 19 21:28:46 localhost.localdomain ModemManager[539]: <info>  Simple connect state (8/8): All done
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0) modem state changed, 'connecting' --> 'connected' (reason: user-requested)
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) scheduled...
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) starting...
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: prepare -> config (reason 'none') [40 50 0]
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): bringing up device.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) successful.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 3 of 5 (IP Configure Start) scheduled.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) complete.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 3 of 5 (IP Configure Start) started...
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: config -> ip-config (reason 'none') [50 70 0]
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (Mokkula) Beginning DHCPv4 transaction (timeout in 45 seconds)
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> dhclient started with pid 2186
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 3 of 5 (IP Configure Start) complete.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 4 of 5 (IPv6 Configure Timeout) started...
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: Internet Systems Consortium DHCP Client 4.2.6
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: Copyright 2004-2014 Internet Systems Consortium.
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: All rights reserved.
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: For info, please visit https://www.isc.org/software/dhcp/
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: 
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (Mokkula): DHCPv4 state changed nbi -> preinit
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: Listening on LPF/Mokkula/7a:73:73:75:50:73
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: Sending on   LPF/Mokkula/7a:73:73:75:50:73
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: Sending on   Socket/fallback
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: DHCPDISCOVER on Mokkula to 255.255.255.255 port 67 interval 5 (xid=0xc373847)
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: DHCPREQUEST on Mokkula to 255.255.255.255 port 67 (xid=0xc373847)
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: DHCPOFFER from 94.234.184.33
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: DHCPACK from 94.234.184.33 (xid=0xc373847)
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: Internet Systems Consortium DHCP Client 4.2.6
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: Copyright 2004-2014 Internet Systems Consortium.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: All rights reserved.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: For info, please visit https://www.isc.org/software/dhcp/
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: Listening on LPF/Mokkula/7a:73:73:75:50:73
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: Sending on   LPF/Mokkula/7a:73:73:75:50:73
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: Sending on   Socket/fallback
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: DHCPDISCOVER on Mokkula to 255.255.255.255 port 67 interval 5 (xid=0xc373847)
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: DHCPREQUEST on Mokkula to 255.255.255.255 port 67 (xid=0xc373847)
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: DHCPOFFER from 94.234.184.33
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: DHCPACK from 94.234.184.33 (xid=0xc373847)
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (Mokkula): DHCPv4 state changed preinit -> bound
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info>   address 94.234.184.47
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info>   plen 27 (255.255.255.224)
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info>   gateway 94.234.184.33
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info>   server identifier 94.234.184.33
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info>   lease time 7200
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info>   nameserver '195.54.122.221'
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info>   nameserver '195.54.122.211'
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
>Aug 19 21:28:46 localhost.localdomain dhclient[2186]: bound to 94.234.184.47 -- renewal in 3055 seconds.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 5 of 5 (IPv4 Commit) started...
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) Stage 5 of 5 (IPv4 Commit) complete.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> (cdc-wdm0): device state change: secondaries -> activated (reason 'none') [90 100 0]
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: bound to 94.234.184.47 -- renewal in 3055 seconds.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Policy set 'bredband' (Mokkula) as default for IPv4 routing and DNS.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Policy set 'bredband' (Mokkula) as default for IPv6 routing and DNS.
>Aug 19 21:28:46 localhost.localdomain NetworkManager[533]: <info> Activation (cdc-wdm0) successful, device activated.
>Aug 19 21:29:11 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: signal quality updated (68)
>Aug 19 21:29:25 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: signal quality updated (78)
>Aug 19 21:29:40 localhost.localdomain ModemManager[539]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: signal quality updated (78)

Actions: View

Attachments on bug 1130782: 927516 | 928492 | 928496 | 928497 | 928498 | 929977