Huawei E160E USB modem fails to connect with ModemManager-1.0.0 and NetworkManager-0.9.8.8

David Allen david.a58 at optusnet.com.au
Sun Nov 3 06:27:19 CET 2013


Hi,

I have a Huawei E160E USB modem that works with ModemManager-0.6.2.0 and 
NetworkManager-0.9.8.2
  but does not work with ModemManager-1.0.0 and NetworkManager-0.9.8.8. The
modem appears to be initialised but disconnects when a connection to my 
ISP is
attempted.
There is also a confirmatory report of this issue here. 
https://bugzilla.novell.com/show_bug.cgi?id=843537

I note that when this device works, a ppp0 interface is created, but 
when the
device does not work, a wwan0 interface is created.

Please find attached:
Debug logs- (Recorded on a Slackware 14.1-RC3 32bit installation)
  dump_working.txt and syslog_working.txt - Recorded with earlier versions
  dump_not_working.txt and syslog_not_working.txt - Recorded with later 
versions
Device details-
  modeminfo.txt - Excerpt from output of usb-devices
  mmcli_output.txt - Output from mmcli with ModemManager-1.0.0 installed
  qmicli1.txt - Output from 'qmicli -d /dev/cdc-wdm0 
--device-open-version-info --dms-get-ids -v'
                      with ModemManager-1.0.0 installed
  qmicli2.txt - Output from 'qmicli -d /dev/cdc-wdm0 --dms-get-ids -v'
                      with ModemManager-1.0.0 installed
                     (Perhaps the error without the 
'--device-open-version-info' option is relevant)
Screenshots-
  E160E_01.png and E160E_02.png - Showing results of querying this 
device with AT commands

Best regards.

David Allen




-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/modemmanager-devel/attachments/20131103/ccc475a1/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: E160E_01.png
Type: image/png
Size: 35946 bytes
Desc: not available
URL: <http://lists.freedesktop.org/archives/modemmanager-devel/attachments/20131103/ccc475a1/attachment-0002.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: E160E_02.png
Type: image/png
Size: 41046 bytes
Desc: not available
URL: <http://lists.freedesktop.org/archives/modemmanager-devel/attachments/20131103/ccc475a1/attachment-0003.png>
-------------- next part --------------
ModemManager[1169]: <info>  [1382529370.281031] [main.c:128] main(): ModemManager (version 1.0.0) starting...
ModemManager[1169]: <debug> [1382529370.291964] [main.c:61] bus_acquired_cb(): Bus acquired, creating manager...
ModemManager[1169]: <debug> [1382529370.306148] [mm-plugin-manager.c:788] load_plugins(): Looking for plugins in '/usr/lib/ModemManager'
ModemManager[1169]: <debug> [1382529370.308101] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Ericsson MBM'
ModemManager[1169]: <debug> [1382529370.309078] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Telit'
ModemManager[1169]: <debug> [1382529370.310005] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Novatel LTE'
ModemManager[1169]: <debug> [1382529370.310965] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Novatel'
ModemManager[1169]: <debug> [1382529370.311875] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Motorola'
ModemManager[1169]: <debug> [1382529370.312824] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Wavecom'
ModemManager[1169]: <debug> [1382529370.313732] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Generic'
ModemManager[1169]: <debug> [1382529370.314640] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Linktop'
ModemManager[1169]: <debug> [1382529370.315612] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Option High-Speed'
ModemManager[1169]: <debug> [1382529370.316546] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Cinterion'
ModemManager[1169]: <debug> [1382529370.317548] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Huawei'
ModemManager[1169]: <debug> [1382529370.318557] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Option'
ModemManager[1169]: <debug> [1382529370.319541] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'AnyDATA'
ModemManager[1169]: <debug> [1382529370.320564] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Gobi'
ModemManager[1169]: <debug> [1382529370.321578] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Samsung'
ModemManager[1169]: <debug> [1382529370.322590] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Nokia (Icera)'
ModemManager[1169]: <debug> [1382529370.323576] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'X22X'
ModemManager[1169]: <debug> [1382529370.324606] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Longcheer'
ModemManager[1169]: <debug> [1382529370.325608] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Iridium'
ModemManager[1169]: <debug> [1382529370.326713] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Altair LTE'
ModemManager[1169]: <debug> [1382529370.327809] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Pantech'
ModemManager[1169]: <debug> [1382529370.328843] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'ZTE'
ModemManager[1169]: <debug> [1382529370.329904] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Nokia'
ModemManager[1169]: <debug> [1382529370.330936] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'SimTech'
ModemManager[1169]: <debug> [1382529370.332077] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Via CBP7'
ModemManager[1169]: <debug> [1382529370.333344] [mm-plugin-manager.c:813] load_plugins(): Loaded plugin 'Sierra'
ModemManager[1169]: <debug> [1382529370.333655] [mm-plugin-manager.c:838] load_plugins(): Successfully loaded 26 plugins
ModemManager[1169]: <warn>  [1382529370.335253] [main.c:97] name_lost_cb(): Could not acquire the 'org.freedesktop.ModemManager1' service name
ModemManager[1169]: <info>  [1382529370.338808] [main.c:179] main(): ModemManager is shut down
NetworkManager[1173]: <info> NetworkManager (version 0.9.8.8) is starting...
NetworkManager[1173]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
NetworkManager[1173]: <info> WEXT support is enabled
NetworkManager[1173]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
NetworkManager[1173]:    keyfile: parsing Optus - Wireless Broadband ... 
NetworkManager[1173]:    keyfile:     read connection 'Optus - Wireless Broadband'
NetworkManager[1173]:    keyfile: parsing Wired connection 1 ... 
NetworkManager[1173]:    keyfile:     read connection 'Wired connection 1'
NetworkManager[1173]:    keyfile: parsing OPTUSA4680E8 ... 
NetworkManager[1173]:    keyfile:     read connection 'OPTUSA4680E8'
NetworkManager[1173]: <debug> [1382529370.660291] [nm-modem-manager.c:376] modem_manager_disappeared(): trying to start the modem manager...
NetworkManager[1173]: <debug> [1382529370.661148] [nm-modem-manager.c:280] poke_modem_cb(): Requesting to (re)launch modem-manager...
NetworkManager[1173]: <info> monitoring kernel firmware directory '/lib/firmware'.
NetworkManager[1173]: <debug> [1382529370.664708] [nm-firewall-manager.c:248] nm_firewall_manager_init(): firewall is not running
NetworkManager[1173]: <info> rfkill0: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0/ieee80211/phy0/rfkill0) (driver ath9k)
NetworkManager[1173]: <info> rfkill1: found WiFi radio killswitch (at /sys/devices/platform/acer-wmi/rfkill/rfkill1) (platform driver acer-wmi)
NetworkManager[1173]: <debug> [1382529370.674826] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill1 state now 1/0
NetworkManager[1173]: <debug> [1382529370.675523] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill0 state now 1/0
NetworkManager[1173]: <info> WiFi hardware radio set enabled
NetworkManager[1173]: <info> WiFi enabled by radio killswitch; enabled by state file
NetworkManager[1173]: <info> WWAN enabled by radio killswitch; enabled by state file
NetworkManager[1173]: <info> WiMAX enabled by radio killswitch; enabled by state file
NetworkManager[1173]: <info> Networking is enabled by state file
NetworkManager[1173]: <debug> [1382529370.758894] [nm-device-wifi.c:309] constructor(): (wlan0): kernel ifindex 3
NetworkManager[1173]: <info> (wlan0): using nl80211 for WiFi device control
NetworkManager[1173]: <info> (wlan0): driver supports Access Point (AP) mode
NetworkManager[1173]: <debug> [1382529370.762337] [nm-device-wifi.c:2930] update_initial_hw_address(): (wlan0): read initial MAC address C4:17:FE:AF:86:B1
NetworkManager[1173]: <debug> [1382529370.763254] [nm-manager.c:1726] manager_rfkill_update_one_type(): WiFi hw-enabled 1 sw-enabled 1
NetworkManager[1173]: <debug> [1382529370.763639] [nm-device-wifi.c:3576] set_enabled(): (wlan0): device now enabled
NetworkManager[1173]: <debug> [1382529370.763922] [nm-device-wifi.c:3582] set_enabled(): (enable): wlan0 blocked by UNMANAGED state
NetworkManager[1173]: <info> (wlan0): new 802.11 WiFi device (driver: 'ath9k' ifindex: 3)
NetworkManager[1173]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/0
NetworkManager[1173]: <debug> [1382529370.764657] [nm-device.c:5314] nm_device_set_managed(): (wlan0): now managed
NetworkManager[1173]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[1173]: <info> (wlan0): bringing up device.
NetworkManager[1173]: <info> (wlan0): preparing device.
NetworkManager[1173]: <info> (wlan0): deactivating device (reason 'managed') [2]
NetworkManager[1173]: <debug> [1382529370.810428] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/accept_ra' to '0'
NetworkManager[1173]: <debug> [1382529370.810631] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/use_tempaddr' to '0'
NetworkManager[1173]: <debug> [1382529370.810933] [nm-device-wifi.c:854] _set_hw_addr(): (wlan0): no MAC address change needed
NetworkManager[1173]: <debug> [1382529370.811832] [nm-system.c:1404] nm_system_iface_flush_routes(): (wlan0): flushing routes ifindex 3 family INET (2)
NetworkManager[1173]: <debug> [1382529370.813216] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[1173]: <debug> [1382529370.813491] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/32
NetworkManager[1173]: <debug> [1382529370.813715] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[1173]: <debug> [1382529370.813913] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.1/32
NetworkManager[1173]: <debug> [1382529370.814091] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.255.255.255/32
NetworkManager[1173]: <debug> [1382529370.815083] [nm-system.c:194] sync_addresses(): (wlan0): syncing addresses (family 2)
NetworkManager[1173]: <debug> [1382529370.815939] [nm-supplicant-manager.c:90] nm_supplicant_manager_iface_get(): (wlan0): creating new supplicant interface
NetworkManager[1173]: <debug> [1382529370.816882] [nm-supplicant-interface.c:1022] interface_add(): (wlan0): adding interface to supplicant
NetworkManager[1173]: <debug> [1382529370.817813] [nm-device-wifi.c:1381] is_available(): (wlan0): not available because supplicant interface not ready
NetworkManager[1173]: <debug> [1382529370.818939] [nm-device.c:5146] nm_device_state_changed(): (wlan0): device not yet available for transition to DISCONNECTED
NetworkManager[1173]: <debug> [1382529370.819582] [nm-manager.c:1381] system_create_virtual_devices(): creating virtual devices...
NetworkManager[1173]: <warn> failed to allocate link cache: (-10) Operation not supported
NetworkManager[1173]: <debug> [1382529370.823238] [nm-device-ethernet.c:1607] supports_ethtool_carrier_detect(): ethtool is supported
NetworkManager[1173]: <debug> [1382529370.823882] [nm-device-wired.c:313] constructor(): (eth0): kernel ifindex 2
NetworkManager[1173]: <info> (eth0): carrier is OFF
NetworkManager[1173]: <debug> [1382529370.825632] [nm-device-ethernet.c:260] constructor(): (eth0): kernel ifindex 2
NetworkManager[1173]: <debug> [1382529370.827605] [nm-device-ethernet.c:484] update_initial_hw_address(): (eth0): read initial MAC address 70:5A:B6:28:A1:9B
NetworkManager[1173]: <info> (eth0): new Ethernet device (driver: 'atl1c' ifindex: 2)
NetworkManager[1173]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/1
NetworkManager[1173]: <debug> [1382529370.829102] [nm-device.c:5314] nm_device_set_managed(): (eth0): now managed
NetworkManager[1173]: <info> (eth0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[1173]: <info> (eth0): bringing up device.
NetworkManager[1173]: <info> (eth0): preparing device.
NetworkManager[1173]: <info> (eth0): deactivating device (reason 'managed') [2]
NetworkManager[1173]: <debug> [1382529370.850955] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/accept_ra' to '0'
NetworkManager[1173]: <debug> [1382529370.851195] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/use_tempaddr' to '0'
NetworkManager[1173]: <debug> [1382529370.851415] [nm-device-ethernet.c:383] _set_hw_addr(): (eth0): no MAC address change needed
NetworkManager[1173]: <debug> [1382529370.852640] [nm-system.c:1404] nm_system_iface_flush_routes(): (eth0): flushing routes ifindex 2 family INET (2)
NetworkManager[1173]: <debug> [1382529370.853994] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[1173]: <debug> [1382529370.854241] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/32
NetworkManager[1173]: <debug> [1382529370.854449] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[1173]: <debug> [1382529370.854659] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.1/32
NetworkManager[1173]: <debug> [1382529370.854909] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.255.255.255/32
NetworkManager[1173]: <debug> [1382529370.856406] [nm-system.c:194] sync_addresses(): (eth0): syncing addresses (family 2)
NetworkManager[1173]: <debug> [1382529370.857190] [nm-device.c:5146] nm_device_state_changed(): (eth0): device not yet available for transition to DISCONNECTED
NetworkManager[1173]: <debug> [1382529370.857831] [nm-manager.c:1381] system_create_virtual_devices(): creating virtual devices...
NetworkManager[1173]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[1173]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[1173]: <debug> [1382529370.862981] [nm-manager.c:1381] system_create_virtual_devices(): creating virtual devices...
NetworkManager[1173]: <debug> [1382529370.863315] [main.c:611] main(): setting up local loopback
NetworkManager[1173]: <debug> [1382529370.865698] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[1173]: <debug> [1382529370.867092] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 2 flags 0x1003
NetworkManager[1173]: <debug> [1382529370.870872] [nm-supplicant-manager.c:182] get_capabilities_cb(): AP mode is supported
NetworkManager[1173]: <debug> [1382529370.871199] [nm-supplicant-manager.c:194] get_capabilities_cb(): EAP-FAST is supported
NetworkManager[1173]: <debug> [1382529370.877336] [nm-agent-manager.c:298] impl_agent_manager_register(): (:1.8/org.freedesktop.nm-applet/503) requesting permissions
NetworkManager[1173]: <warn> Couldn't get managed objects: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.bluez was not provided by any .service files
NetworkManager[1173]: <debug> [1382529370.896946] [nm-supplicant-interface.c:849] interface_add_done(): (wlan0): interface added to supplicant
NetworkManager[1173]: <info> (wlan0) supports 4 scan SSIDs
NetworkManager[1173]: <debug> [1382529370.928200] [nm-supplicant-interface.c:747] iface_check_netreply_cb(): Supplicant supports network credentials requests
NetworkManager[1173]: <info> (wlan0): supplicant interface state: starting -> ready
NetworkManager[1173]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
NetworkManager[1173]: <warn> Trying to remove a non-existant call id.
NetworkManager[1173]: <debug> [1382529370.933174] [nm-agent-manager.c:227] agent_register_permissions_done(): (:1.8/org.freedesktop.nm-applet/503) agent registered
NetworkManager[1173]: <info> (wlan0): supplicant interface state: ready -> disconnected
NetworkManager[1173]: <info> (wlan0) supports 4 scan SSIDs
NetworkManager[1173]: <debug> [1382529370.956614] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 1 flags 0x10049
NetworkManager[1173]: <debug> [1382529370.957062] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 2 flags 0x1003
NetworkManager[1173]: <debug> [1382529370.957318] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[1173]: <info> ModemManager available in the bus
NetworkManager[1173]: <debug> [1382529371.839047] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[1173]: <info> (wlan0): supplicant interface state: disconnected -> inactive
NetworkManager[1173]: <debug> [1382529395.87064] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[1173]: <debug> [1382529398.295594] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 7 flags 0x1002
NetworkManager[1173]: <debug> [1382529398.362326] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'add' subsys 'net' device 'wwan0'
NetworkManager[1173]: <debug> [1382529398.362782] [nm-udev-manager.c:477] net_add(): (wwan0): ignoring interface with devtype 'wwan'
NetworkManager[1173]: <debug> [1382529398.363158] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill1 state now 1/0
NetworkManager[1173]: <debug> [1382529398.363540] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill0 state now 1/0
NetworkManager[1173]: <warn> (cdc-wdm0): failed to look up interface index
NetworkManager[1173]: <debug> [1382529412.413379] [nm-device.c:410] device_get_driver_info(): SIOCETHTOOL ioctl() failed: cmd=ETHTOOL_GDRVINFO, iface=cdc-wdm0, errno=19
NetworkManager[1173]: <debug> [1382529412.413713] [NetworkManagerUtils.c:684] nm_utils_get_proc_sys_net_value(): (cdc-wdm0): error reading /proc/sys/net/ipv6/conf/cdc-wdm0/accept_ra: (4) Failed to open file '/proc/sys/net/ipv6/conf/cdc-wdm0/accept_ra': No such file or directory
NetworkManager[1173]: <debug> [1382529412.413898] [NetworkManagerUtils.c:684] nm_utils_get_proc_sys_net_value(): (cdc-wdm0): error reading /proc/sys/net/ipv6/conf/cdc-wdm0/use_tempaddr: (4) Failed to open file '/proc/sys/net/ipv6/conf/cdc-wdm0/use_tempaddr': No such file or directory
NetworkManager[1173]: <debug> [1382529412.414333] [nm-manager.c:1723] manager_rfkill_update_one_type(): WWAN hw-enabled 1 sw-enabled 1 daemon-enabled 0
NetworkManager[1173]: <info> (cdc-wdm0): new Broadband device (driver: 'qmi_wwan, option1' ifindex: 0)
NetworkManager[1173]: <info> (cdc-wdm0): exported as /org/freedesktop/NetworkManager/Devices/2
NetworkManager[1173]: <debug> [1382529412.414613] [nm-device.c:5314] nm_device_set_managed(): (cdc-wdm0): now managed
NetworkManager[1173]: <info> (cdc-wdm0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[1173]: <info> (cdc-wdm0): deactivating device (reason 'managed') [2]
NetworkManager[1173]: <debug> [1382529412.424869] [nm-device.c:5142] nm_device_state_changed(): (cdc-wdm0): device is available, will transition to DISCONNECTED
NetworkManager[1173]: <debug> [1382529412.424986] [nm-device.c:5253] nm_device_queue_state(): (cdc-wdm0): queued state change to disconnected (id 81)
NetworkManager[1173]: <debug> [1382529412.425245] [nm-manager.c:1381] system_create_virtual_devices(): creating virtual devices...
NetworkManager[1173]: <debug> [1382529412.426500] [nm-device.c:5211] queued_set_state(): (cdc-wdm0): running queued state change to disconnected (id 81)
NetworkManager[1173]: <info> (cdc-wdm0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
NetworkManager[1173]: <debug> [1382529428.80090] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[1173]: <info> Activation (cdc-wdm0) starting connection 'Optus - Wireless Broadband'
NetworkManager[1173]: <info> (cdc-wdm0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[1173]: <info> NetworkManager state is now CONNECTING
NetworkManager[1173]: <debug> [1382529431.65262] [nm-manager.c:4088] policy_activating_device_changed(): ActivatingConnection now Optus - Wireless Broadband
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[1173]: <info> (cdc-wdm0) modem state changed, 'disabled' --> 'enabling' (reason: user-requested)
NetworkManager[1173]: <info> (cdc-wdm0) modem state changed, 'enabling' --> 'registered' (reason: user-requested)
NetworkManager[1173]: <info> WWAN now enabled by management service
NetworkManager[1173]: <debug> [1382529431.514841] [nm-manager.c:1723] manager_rfkill_update_one_type(): WWAN hw-enabled 1 sw-enabled 1 daemon-enabled 1
NetworkManager[1173]: <debug> [1382529431.515059] [nm-manager.c:1578] manager_update_radio_enabled(): (cdc-wdm0): setting radio enabled
NetworkManager[1173]: <info> (cdc-wdm0) modem state changed, 'registered' --> 'connecting' (reason: user-requested)
NetworkManager[1173]: <info> (cdc-wdm0) modem state changed, 'connecting' --> 'connected' (reason: user-requested)
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[1173]: <info> (cdc-wdm0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[1173]: <info> (cdc-wdm0): bringing up device.
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) successful.
NetworkManager[1173]: <debug> [1382529434.266985] [nm-device.c:3066] nm_device_activate_schedule_stage3_ip_config_start(): Activation (cdc-wdm0) setting firewall zone 'default'
NetworkManager[1173]: <debug> [1382529434.267207] [nm-firewall-manager.c:107] nm_firewall_manager_add_or_change_zone(): (wwan0) firewall zone add/change skipped (not running)
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[1173]: <debug> [1382529434.267887] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 7 flags 0x11043
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[1173]: <info> (cdc-wdm0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[1173]: <info> Activation (wwan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager[1173]: <debug> [1382529434.274081] [nm-dhcp-dhcpcd.c:152] ip4_start(): running: /sbin/dhcpcd -B -K -L -G -c /usr/libexec/nm-dhcp-client.action -h Budgie wwan0
NetworkManager[1173]: <info> dhcpcd started with pid 1226
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 3 of 5 (IP Configure Start) complete.
dhcpcd[1226]: version 6.0.5 starting
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 4 of 5 (IPv6 Configure Timeout) started...
NetworkManager[1173]: <info> Activation (cdc-wdm0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
dhcpcd[1226]: wwan0: soliciting an IPv6 router
NetworkManager[1173]: <info> (wwan0): DHCPv4 state changed nbi -> preinit
dhcpcd[1226]: wwan0: ipv6rs_sendprobe: sendmsg: Cannot assign requested address
NetworkManager[1173]: <debug> [1382529434.304229] [nm-device.c:1945] dhcp4_state_changed(): (cdc-wdm0): new DHCPv4 client state 1
dhcpcd[1226]: wwan0: soliciting a DHCP lease
NetworkManager[1173]: <debug> [1382529438.697730] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 7 flags 0x1002
dhcpcd[1226]: wwan0: removing interface
NetworkManager[1173]: <debug> [1382529438.699217] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 7 flags 0x1002
NetworkManager[1173]: <debug> [1382529438.703654] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'remove' subsys 'net' device 'wwan0'
NetworkManager[1173]: <debug> [1382529438.704332] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill1 state now 1/0
NetworkManager[1173]: <debug> [1382529438.705054] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill0 state now 1/0
NetworkManager[1173]: <debug> [1382529438.719823] [nm-device.c:5314] nm_device_set_managed(): (cdc-wdm0): now unmanaged
NetworkManager[1173]: <info> (cdc-wdm0): device state change: ip-config -> unmanaged (reason 'removed') [70 10 36]
NetworkManager[1173]: <info> (cdc-wdm0): deactivating device (reason 'removed') [36]
NetworkManager[1173]: <debug> [1382529438.720916] [nm-firewall-manager.c:157] nm_firewall_manager_remove_from_zone(): (wwan0) firewall zone remove skipped (not running)
dhcpcd[1226]: exited
NetworkManager[1173]: <info> (wwan0): canceled DHCP transaction, DHCP client pid 1226
NetworkManager[1173]: <warn> (7) failed to find interface name for index
NetworkManager[1173]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
NetworkManager[1173]: <warn> (7) failed to find interface name for index
NetworkManager[1173]: <warn> (7) failed to find interface name for index
NetworkManager[1173]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
NetworkManager[1173]: <warn> (7) failed to find interface name for index
NetworkManager[1173]: <info> (cdc-wdm0): cleaning up...
NetworkManager[1173]: <info> (cdc-wdm0): taking down device.
NetworkManager[1173]: <info> NetworkManager state is now DISCONNECTED
NetworkManager[1173]: <debug> [1382529438.947634] [nm-dns-manager.c:995] nm_dns_manager_begin_updates(): (update_routing_and_dns): queueing DNS updates (1)
NetworkManager[1173]: <debug> [1382529438.948062] [nm-dns-manager.c:1013] nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS configuration did not change
NetworkManager[1173]: <debug> [1382529438.948313] [nm-dns-manager.c:1017] nm_dns_manager_end_updates(): (update_routing_and_dns): no DNS changes to commit (0)
NetworkManager[1173]: <debug> [1382529438.948594] [nm-manager.c:4088] policy_activating_device_changed(): ActivatingConnection now (none)
NetworkManager[1173]: <warn> (pid 1226) unhandled DHCP event for interface wwan0
NetworkManager[1173]: <warn> (cdc-wdm0) failed to disconnect modem: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: No such interface `org.freedesktop.ModemManager1.Modem.Simple' on object at path /org/freedesktop/ModemManager1/Modem/3
NetworkManager[1173]: <warn> (pid 1226) unhandled DHCP event for interface wwan0
NetworkManager[1173]: <debug> [1382529443.294055] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 8 flags 0x1002
NetworkManager[1173]: <debug> [1382529443.369589] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'add' subsys 'net' device 'wwan0'
NetworkManager[1173]: <debug> [1382529443.370054] [nm-udev-manager.c:477] net_add(): (wwan0): ignoring interface with devtype 'wwan'
NetworkManager[1173]: <debug> [1382529443.370451] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill1 state now 1/0
NetworkManager[1173]: <debug> [1382529443.370882] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill0 state now 1/0
NetworkManager[1173]: <warn> (cdc-wdm0): failed to look up interface index
NetworkManager[1173]: <debug> [1382529457.374430] [nm-device.c:410] device_get_driver_info(): SIOCETHTOOL ioctl() failed: cmd=ETHTOOL_GDRVINFO, iface=cdc-wdm0, errno=19
NetworkManager[1173]: <debug> [1382529457.374778] [NetworkManagerUtils.c:684] nm_utils_get_proc_sys_net_value(): (cdc-wdm0): error reading /proc/sys/net/ipv6/conf/cdc-wdm0/accept_ra: (4) Failed to open file '/proc/sys/net/ipv6/conf/cdc-wdm0/accept_ra': No such file or directory
NetworkManager[1173]: <debug> [1382529457.374946] [NetworkManagerUtils.c:684] nm_utils_get_proc_sys_net_value(): (cdc-wdm0): error reading /proc/sys/net/ipv6/conf/cdc-wdm0/use_tempaddr: (4) Failed to open file '/proc/sys/net/ipv6/conf/cdc-wdm0/use_tempaddr': No such file or directory
NetworkManager[1173]: <info> WWAN now disabled by management service
NetworkManager[1173]: <debug> [1382529457.375443] [nm-manager.c:1723] manager_rfkill_update_one_type(): WWAN hw-enabled 1 sw-enabled 1 daemon-enabled 0
NetworkManager[1173]: <debug> [1382529457.375550] [nm-manager.c:1578] manager_update_radio_enabled(): (cdc-wdm0): setting radio disabled
NetworkManager[1173]: <info> (cdc-wdm0): new Broadband device (driver: 'qmi_wwan, option1' ifindex: 0)
NetworkManager[1173]: <info> (cdc-wdm0): exported as /org/freedesktop/NetworkManager/Devices/3
NetworkManager[1173]: <debug> [1382529457.375896] [nm-device.c:5314] nm_device_set_managed(): (cdc-wdm0): now managed
NetworkManager[1173]: <info> (cdc-wdm0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[1173]: <info> (cdc-wdm0): deactivating device (reason 'managed') [2]
NetworkManager[1173]: <debug> [1382529457.386120] [nm-device.c:5142] nm_device_state_changed(): (cdc-wdm0): device is available, will transition to DISCONNECTED
NetworkManager[1173]: <debug> [1382529457.386234] [nm-device.c:5253] nm_device_queue_state(): (cdc-wdm0): queued state change to disconnected (id 159)
NetworkManager[1173]: <debug> [1382529457.386489] [nm-manager.c:1381] system_create_virtual_devices(): creating virtual devices...
NetworkManager[1173]: <debug> [1382529457.387752] [nm-device.c:5211] queued_set_state(): (cdc-wdm0): running queued state change to disconnected (id 159)
NetworkManager[1173]: <info> (cdc-wdm0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
NetworkManager[1173]: <debug> [1382529467.497793] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 8 flags 0x1002
NetworkManager[1173]: <debug> [1382529467.506371] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'remove' subsys 'net' device 'wwan0'
NetworkManager[1173]: <debug> [1382529467.507255] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill1 state now 1/0
NetworkManager[1173]: <debug> [1382529467.508080] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill0 state now 1/0
NetworkManager[1173]: <debug> [1382529467.524241] [nm-device.c:5314] nm_device_set_managed(): (cdc-wdm0): now unmanaged
NetworkManager[1173]: <info> (cdc-wdm0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
NetworkManager[1173]: <info> (cdc-wdm0): cleaning up...
NetworkManager[1173]: <info> (cdc-wdm0): taking down device.
NetworkManager[1173]: <debug> [1382529471.83192] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
^CNetworkManager[1173]: <info> caught signal 2, shutting down normally.
NetworkManager[1173]: <debug> [1382529475.122086] [nm-device.c:5314] nm_device_set_managed(): (wlan0): now unmanaged
NetworkManager[1173]: <info> (wlan0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
NetworkManager[1173]: <info> (wlan0): cleaning up...
NetworkManager[1173]: <info> (wlan0): taking down device.
NetworkManager[1173]: <debug> [1382529475.150440] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/accept_ra' to '1'
NetworkManager[1173]: <debug> [1382529475.151165] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/use_tempaddr' to '0'
NetworkManager[1173]: <debug> [1382529475.151824] [nm-device.c:5314] nm_device_set_managed(): (eth0): now unmanaged
NetworkManager[1173]: <info> (eth0): device state change: unavailable -> unmanaged (reason 'removed') [20 10 36]
NetworkManager[1173]: <info> (eth0): cleaning up...
NetworkManager[1173]: <info> (eth0): taking down device.
NetworkManager[1173]: <debug> [1382529475.170853] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/accept_ra' to '1'
NetworkManager[1173]: <debug> [1382529475.171512] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/use_tempaddr' to '0'
NetworkManager[1173]: <info> exiting (success)

-------------- next part --------------
modem-manager[3757]: <info>  [1382527579.613962] [main.c:186] main(): ModemManager (version 0.6.2.0) starting...
modem-manager[3757]: <warn>  [1382527579.621411] [main.c:117] create_dbus_proxy(): Could not acquire the org.freedesktop.ModemManager service as it is already taken. Return: 3
NetworkManager[3759]: <info> NetworkManager (version 0.9.8.2) is starting...
NetworkManager[3759]: <info> Read config file /etc/NetworkManager/NetworkManager.conf
NetworkManager[3759]: <info> WEXT support is enabled
NetworkManager[3759]: <info> Loaded plugin keyfile: (c) 2007 - 2010 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
NetworkManager[3759]:    keyfile: parsing Optus - Wireless Broadband ... 
NetworkManager[3759]:    keyfile:     read connection 'Optus - Wireless Broadband'
NetworkManager[3759]:    keyfile: parsing Wired connection 1 ... 
NetworkManager[3759]:    keyfile:     read connection 'Wired connection 1'
NetworkManager[3759]:    keyfile: parsing OPTUSA4680E8 ... 
NetworkManager[3759]:    keyfile:     read connection 'OPTUSA4680E8'
NetworkManager[3759]: <info> modem-manager is now available
NetworkManager[3759]: <info> monitoring kernel firmware directory '/lib/firmware'.
NetworkManager[3759]: <info> rfkill1: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0/ieee80211/phy0/rfkill1) (driver ath9k)
NetworkManager[3759]: <info> rfkill0: found WiFi radio killswitch (at /sys/devices/platform/acer-wmi/rfkill/rfkill0) (platform driver acer-wmi)
NetworkManager[3759]: <debug> [1382527579.947095] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill0 state now 1/0
NetworkManager[3759]: <debug> [1382527579.947689] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill1 state now 1/0
NetworkManager[3759]: <info> WiFi hardware radio set enabled
NetworkManager[3759]: <debug> [1382527580.11784] [nm-firewall-manager.c:248] nm_firewall_manager_init(): firewall is not running
NetworkManager[3759]: <info> WiFi enabled by radio killswitch; enabled by state file
NetworkManager[3759]: <info> WWAN enabled by radio killswitch; enabled by state file
NetworkManager[3759]: <info> WiMAX enabled by radio killswitch; enabled by state file
NetworkManager[3759]: <info> Networking is enabled by state file
NetworkManager[3759]: <debug> [1382527580.27039] [nm-device-wifi.c:309] constructor(): (wlan0): kernel ifindex 3
NetworkManager[3759]: <info> (wlan0): using nl80211 for WiFi device control
NetworkManager[3759]: <info> (wlan0): driver supports Access Point (AP) mode
NetworkManager[3759]: <debug> [1382527580.29605] [nm-device-wifi.c:2930] update_initial_hw_address(): (wlan0): read initial MAC address C4:17:FE:AF:86:B1
NetworkManager[3759]: <debug> [1382527580.30435] [nm-manager.c:1663] manager_rfkill_update_one_type(): WiFi hw-enabled 1 sw-enabled 1
NetworkManager[3759]: <debug> [1382527580.30702] [nm-device-wifi.c:3576] set_enabled(): (wlan0): device now enabled
NetworkManager[3759]: <debug> [1382527580.30888] [nm-device-wifi.c:3582] set_enabled(): (enable): wlan0 blocked by UNMANAGED state
NetworkManager[3759]: <info> (wlan0): new 802.11 WiFi device (driver: 'ath9k' ifindex: 3)
NetworkManager[3759]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/0
NetworkManager[3759]: <debug> [1382527580.31695] [nm-device.c:5305] nm_device_set_managed(): (wlan0): now managed
NetworkManager[3759]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[3759]: <info> (wlan0): bringing up device.
NetworkManager[3759]: <info> (wlan0): preparing device.
NetworkManager[3759]: <info> (wlan0): deactivating device (reason 'managed') [2]
NetworkManager[3759]: <debug> [1382527580.77606] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/accept_ra' to '0'
NetworkManager[3759]: <debug> [1382527580.77805] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/use_tempaddr' to '0'
NetworkManager[3759]: <debug> [1382527580.78033] [nm-device-wifi.c:854] _set_hw_addr(): (wlan0): no MAC address change needed
NetworkManager[3759]: <debug> [1382527580.78950] [nm-system.c:1404] nm_system_iface_flush_routes(): (wlan0): flushing routes ifindex 3 family INET (2)
NetworkManager[3759]: <debug> [1382527580.80418] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[3759]: <debug> [1382527580.80697] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/32
NetworkManager[3759]: <debug> [1382527580.80879] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[3759]: <debug> [1382527580.81049] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.1/32
NetworkManager[3759]: <debug> [1382527580.81307] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.255.255.255/32
NetworkManager[3759]: <debug> [1382527580.82196] [nm-system.c:194] sync_addresses(): (wlan0): syncing addresses (family 2)
NetworkManager[3759]: <debug> [1382527580.82843] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527580.83352] [nm-supplicant-manager.c:90] nm_supplicant_manager_iface_get(): (wlan0): creating new supplicant interface
NetworkManager[3759]: <debug> [1382527580.84221] [nm-supplicant-interface.c:1022] interface_add(): (wlan0): adding interface to supplicant
NetworkManager[3759]: <debug> [1382527580.85103] [nm-device-wifi.c:1381] is_available(): (wlan0): not available because supplicant interface not ready
NetworkManager[3759]: <debug> [1382527580.85484] [nm-device.c:5137] nm_device_state_changed(): (wlan0): device not yet available for transition to DISCONNECTED
NetworkManager[3759]: <debug> [1382527580.86055] [nm-manager.c:1318] system_create_virtual_devices(): creating virtual devices...
NetworkManager[3759]: <warn> failed to allocate link cache: (-10) Operation not supported
NetworkManager[3759]: <debug> [1382527580.89773] [nm-device-ethernet.c:1607] supports_ethtool_carrier_detect(): ethtool is supported
NetworkManager[3759]: <debug> [1382527580.90416] [nm-device-wired.c:313] constructor(): (eth0): kernel ifindex 2
NetworkManager[3759]: <info> (eth0): carrier is OFF
NetworkManager[3759]: <debug> [1382527580.92207] [nm-device-ethernet.c:260] constructor(): (eth0): kernel ifindex 2
NetworkManager[3759]: <debug> [1382527580.94185] [nm-device-ethernet.c:484] update_initial_hw_address(): (eth0): read initial MAC address 70:5A:B6:28:A1:9B
NetworkManager[3759]: <info> (eth0): new Ethernet device (driver: 'atl1c' ifindex: 2)
NetworkManager[3759]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/1
NetworkManager[3759]: <debug> [1382527580.95615] [nm-device.c:5305] nm_device_set_managed(): (eth0): now managed
NetworkManager[3759]: <info> (eth0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[3759]: <info> (eth0): bringing up device.
NetworkManager[3759]: <info> (eth0): preparing device.
NetworkManager[3759]: <info> (eth0): deactivating device (reason 'managed') [2]
NetworkManager[3759]: <debug> [1382527580.118521] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/accept_ra' to '0'
NetworkManager[3759]: <debug> [1382527580.119025] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/use_tempaddr' to '0'
NetworkManager[3759]: <debug> [1382527580.119541] [nm-device-ethernet.c:383] _set_hw_addr(): (eth0): no MAC address change needed
NetworkManager[3759]: <debug> [1382527580.121261] [nm-system.c:1404] nm_system_iface_flush_routes(): (eth0): flushing routes ifindex 2 family INET (2)
NetworkManager[3759]: <debug> [1382527580.123141] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[3759]: <debug> [1382527580.124222] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/32
NetworkManager[3759]: <debug> [1382527580.124456] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[3759]: <debug> [1382527580.124645] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.1/32
NetworkManager[3759]: <debug> [1382527580.124827] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.255.255.255/32
NetworkManager[3759]: <debug> [1382527580.126085] [nm-system.c:194] sync_addresses(): (eth0): syncing addresses (family 2)
NetworkManager[3759]: <debug> [1382527580.126581] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527580.126994] [nm-device.c:5137] nm_device_state_changed(): (eth0): device not yet available for transition to DISCONNECTED
NetworkManager[3759]: <debug> [1382527580.127522] [nm-manager.c:1318] system_create_virtual_devices(): creating virtual devices...
NetworkManager[3759]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[3759]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
NetworkManager[3759]: <debug> [1382527580.132657] [nm-manager.c:1318] system_create_virtual_devices(): creating virtual devices...
NetworkManager[3759]: <debug> [1382527580.132981] [main.c:618] main(): setting up local loopback
NetworkManager[3759]: <debug> [1382527580.135373] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[3759]: <debug> [1382527580.136692] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 2 flags 0x1003
NetworkManager[3759]: <debug> [1382527580.138775] [nm-supplicant-manager.c:182] get_capabilities_cb(): AP mode is supported
NetworkManager[3759]: <debug> [1382527580.139064] [nm-supplicant-manager.c:194] get_capabilities_cb(): EAP-FAST is supported
NetworkManager[3759]: <debug> [1382527580.143900] [nm-agent-manager.c:297] impl_agent_manager_register(): (:1.59/org.freedesktop.nm-applet/503) requesting permissions
NetworkManager[3759]: <debug> [1382527580.154977] [nm-supplicant-interface.c:849] interface_add_done(): (wlan0): interface added to supplicant
NetworkManager[3759]: <info> (wlan0) supports 4 scan SSIDs
NetworkManager[3759]: <debug> [1382527580.168704] [nm-supplicant-interface.c:747] iface_check_netreply_cb(): Supplicant supports network credentials requests
NetworkManager[3759]: <info> (wlan0): supplicant interface state: starting -> ready
NetworkManager[3759]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
NetworkManager[3759]: <debug> [1382527580.170643] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <warn> Trying to remove a non-existant call id.
NetworkManager[3759]: <debug> [1382527580.207757] [nm-agent-manager.c:227] agent_register_permissions_done(): (:1.59/org.freedesktop.nm-applet/503) agent registered
NetworkManager[3759]: <info> (wlan0): supplicant interface state: ready -> disconnected
NetworkManager[3759]: <info> (wlan0) supports 4 scan SSIDs
NetworkManager[3759]: <debug> [1382527580.215600] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 1 flags 0x10049
NetworkManager[3759]: <debug> [1382527580.215898] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 2 flags 0x1003
NetworkManager[3759]: <debug> [1382527580.216168] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[3759]: <debug> [1382527581.85626] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[3759]: <info> (wlan0): supplicant interface state: disconnected -> inactive
NetworkManager[3759]: <debug> [1382527604.304929] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[3759]: <debug> [1382527615.831499] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 10 flags 0x1002
NetworkManager[3759]: <debug> [1382527615.909528] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'add' subsys 'net' device 'wwan0'
NetworkManager[3759]: <debug> [1382527615.910029] [nm-udev-manager.c:477] net_add(): (wwan0): ignoring interface with devtype 'wwan'
NetworkManager[3759]: <debug> [1382527615.910531] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill0 state now 1/0
NetworkManager[3759]: <debug> [1382527615.910988] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill1 state now 1/0
NetworkManager[3759]: <warn> (ttyUSB0): failed to look up interface index
NetworkManager[3759]: <debug> [1382527634.857848] [nm-device.c:410] device_get_driver_info(): SIOCETHTOOL ioctl() failed: cmd=ETHTOOL_GDRVINFO, iface=ttyUSB0, errno=19
NetworkManager[3759]: <debug> [1382527634.858154] [NetworkManagerUtils.c:684] nm_utils_get_proc_sys_net_value(): (ttyUSB0): error reading /proc/sys/net/ipv6/conf/ttyUSB0/accept_ra: (4) Failed to open file '/proc/sys/net/ipv6/conf/ttyUSB0/accept_ra': No such file or directory
NetworkManager[3759]: <debug> [1382527634.858444] [NetworkManagerUtils.c:684] nm_utils_get_proc_sys_net_value(): (ttyUSB0): error reading /proc/sys/net/ipv6/conf/ttyUSB0/use_tempaddr: (4) Failed to open file '/proc/sys/net/ipv6/conf/ttyUSB0/use_tempaddr': No such file or directory
NetworkManager[3759]: <debug> [1382527634.858891] [nm-manager.c:1660] manager_rfkill_update_one_type(): WWAN hw-enabled 1 sw-enabled 1 daemon-enabled 0
NetworkManager[3759]: <info> (ttyUSB0): new GSM/UMTS device (driver: 'option1' ifindex: 0)
NetworkManager[3759]: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/2
NetworkManager[3759]: <debug> [1382527634.859178] [nm-device.c:5305] nm_device_set_managed(): (ttyUSB0): now managed
NetworkManager[3759]: <info> (ttyUSB0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
NetworkManager[3759]: <info> (ttyUSB0): deactivating device (reason 'managed') [2]
NetworkManager[3759]: <debug> [1382527634.884158] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527634.884535] [nm-device.c:5133] nm_device_state_changed(): (ttyUSB0): device is available, will transition to DISCONNECTED
NetworkManager[3759]: <debug> [1382527634.884627] [nm-device.c:5244] nm_device_queue_state(): (ttyUSB0): queued state change to disconnected (id 69)
NetworkManager[3759]: <debug> [1382527634.884875] [nm-manager.c:1318] system_create_virtual_devices(): creating virtual devices...
NetworkManager[3759]: <debug> [1382527634.886698] [nm-device.c:5202] queued_set_state(): (ttyUSB0): running queued state change to disconnected (id 69)
NetworkManager[3759]: <info> (ttyUSB0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
NetworkManager[3759]: <debug> [1382527634.887574] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527637.301914] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
NetworkManager[3759]: <debug> [1382527642.527458] [nm-manager.c:4350] manager_radio_user_toggled(): (WWAN): setting radio enabled by user
NetworkManager[3759]: <debug> [1382527642.566846] [nm-manager.c:1515] manager_update_radio_enabled(): (ttyUSB0): setting radio enabled
NetworkManager[3759]: <info> WWAN now enabled by management service
NetworkManager[3759]: <debug> [1382527643.790634] [nm-manager.c:1660] manager_rfkill_update_one_type(): WWAN hw-enabled 1 sw-enabled 1 daemon-enabled 1
NetworkManager[3759]: <debug> [1382527643.790857] [nm-manager.c:1515] manager_update_radio_enabled(): (ttyUSB0): setting radio enabled
NetworkManager[3759]: <info> Activation (ttyUSB0) starting connection 'Optus - Wireless Broadband'
NetworkManager[3759]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
NetworkManager[3759]: <debug> [1382527657.545487] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager[3759]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0]
NetworkManager[3759]: <debug> [1382527657.622513] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager[3759]: <debug> [1382527657.632853] [nm-device.c:3066] nm_device_activate_schedule_stage3_ip_config_start(): Activation (ttyUSB0) setting firewall zone 'default'
NetworkManager[3759]: <debug> [1382527657.632915] [nm-firewall-manager.c:107] nm_firewall_manager_add_or_change_zone(): (ttyUSB0) firewall zone add/change skipped (not running)
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager[3759]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0]
NetworkManager[3759]: <debug> [1382527657.635307] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <info> starting PPP connection
NetworkManager[3759]: <debug> [1382527657.636440] [nm-ppp-manager.c:1068] nm_ppp_manager_start(): command line: /usr/sbin/pppd nodetach lock nodefaultroute ipv6 , debug ttyUSB0 noipdefault noauth refuse-eap refuse-mschap refuse-mschap-v2 usepeerdns lcp-echo-failure 5 lcp-echo-interval 30 ipparam /org/freedesktop/NetworkManager/PPP/0 plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so
NetworkManager[3759]: <info> pppd started with pid 3818
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 4 of 5 (IPv6 Configure Timeout) started...
NetworkManager[3759]: <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'
using channel 4
NetworkManager[3759]: <debug> [1382527657.712177] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 11 flags 0x1090
Using interface ppp0
NetworkManager[3759]: <debug> [1382527657.713620] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'add' subsys 'net' device 'ppp0'
NetworkManager[3759]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
NetworkManager[3759]: <debug> [1382527657.715145] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill0 state now 1/0
NetworkManager[3759]: <debug> [1382527657.716652] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill1 state now 1/0
Connect: ppp0 <--> /dev/ttyUSB0
** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x42b85753> <pcomp> <accomp>]
rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xe60db5> <pcomp> <accomp>]
sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xe60db5> <pcomp> <accomp>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x42b85753> <pcomp> <accomp>]
sent [LCP EchoReq id=0x0 magic=0x42b85753]
** Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate'
rcvd [LCP DiscReq id=0x1 magic=0xe60db5]
rcvd [CHAP Challenge id=0x1 <beeae99e74b1320f763e20c9221ce563>, name = "UMTS_CHAP_SRVR"]
** 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 <5dd51f3c9a419b9b1a40e1df4f8d9019>, name = ""]
rcvd [LCP EchoRep id=0x0 magic=0xe60db5 42 b8 57 53]
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::7c2c:59c6:fee9:5c16>]
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 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x3 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x4 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0x4 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x5 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0x5 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x6 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
rcvd [IPCP ConfNak id=0x6 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x7 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0x7 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x8 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0x8 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x9 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
rcvd [IPCP ConfNak id=0x9 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xa <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0xa <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xb <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0xb <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xc <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
rcvd [IPCP ConfNak id=0xc <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xd <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0xd <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xe <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0xe <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0xf <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
rcvd [IPCP ConfNak id=0xf <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x10 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfNak id=0x10 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x11 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
rcvd [IPCP ConfReq id=0x0]
sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
rcvd [IPCP ConfRej id=0x11 <compress VJ 0f 01> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x12 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
rcvd [IPCP ConfReq id=0x1]
sent [IPCP ConfAck id=0x1]
rcvd [IPCP ConfNak id=0x12 <addr 10.249.184.157> <ms-dns1 198.142.0.51> <ms-dns2 61.88.88.88>]
sent [IPCP ConfReq id=0x13 <addr 10.249.184.157> <ms-dns1 198.142.0.51> <ms-dns2 61.88.88.88>]
rcvd [IPCP ConfAck id=0x13 <addr 10.249.184.157> <ms-dns1 198.142.0.51> <ms-dns2 61.88.88.88>]
Could not determine remote IP address: defaulting to 10.64.64.64
Script /etc/ppp/ip-pre-up started (pid 3820)
Script /etc/ppp/ip-pre-up finished (pid 3820), status = 0x0
Cannot determine ethernet address for proxy ARP
NetworkManager[3759]: <debug> [1382527674.384958] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 11 flags 0x110D1
local  IP address 10.249.184.157
remote IP address 10.64.64.64
primary   DNS address 198.142.0.51
secondary DNS address 61.88.88.88
** 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...
Can't execute /etc/ppp/ip-up: Invalid argument
NetworkManager[3759]: <info> PPP manager(IP Config Get) reply received.
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 5 of 5 (IPv4 Commit) started...
NetworkManager[3759]: <debug> [1382527674.392532] [nm-system.c:194] sync_addresses(): (ppp0): syncing addresses (family 2)
NetworkManager[3759]: <debug> [1382527674.392888] [nm-system.c:247] sync_addresses(): (ppp0): removing address '10.249.184.157/32'
NetworkManager[3759]: <debug> [1382527674.393296] [nm-system.c:280] sync_addresses(): (ppp0): adding address '10.249.184.157/0'
NetworkManager[3759]: <debug> [1382527675.395487] [nm-netlink-utils.c:356] dump_route():   route idx 11 family INET (2) addr 10.64.64.64/32
NetworkManager[3759]: <debug> [1382527675.395682] [nm-netlink-utils.c:356] dump_route():   route idx 1 family INET (2) addr 127.0.0.0/8
NetworkManager[3759]: <debug> [1382527675.395804] [nm-netlink-utils.c:356] dump_route():   route idx 11 family INET (2) addr 10.249.184.157/32
NetworkManager[3759]: <debug> [1382527675.396823] [nm-dns-manager.c:995] nm_dns_manager_begin_updates(): (device_ip4_config_changed): queueing DNS updates (1)
NetworkManager[3759]: <debug> [1382527675.397009] [nm-dns-manager.c:1013] nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS configuration did not change
NetworkManager[3759]: <debug> [1382527675.397115] [nm-dns-manager.c:1017] nm_dns_manager_end_updates(): (device_ip4_config_changed): no DNS changes to commit (0)
NetworkManager[3759]: <info> (ttyUSB0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
NetworkManager[3759]: <debug> [1382527675.397687] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527675.398301] [nm-device.c:5244] nm_device_queue_state(): (ttyUSB0): queued state change to activated (id 111)
NetworkManager[3759]: <debug> [1382527675.399443] [nm-device.c:5174] nm_device_state_changed(): (ttyUSB0): device entered SECONDARIES state
NetworkManager[3759]: <info> Activation (ttyUSB0) Stage 5 of 5 (IPv4 Commit) complete.
NetworkManager[3759]: <debug> [1382527675.403173] [nm-device.c:5202] queued_set_state(): (ttyUSB0): running queued state change to activated (id 111)
NetworkManager[3759]: <info> (ttyUSB0): device state change: secondaries -> activated (reason 'none') [90 100 0]
NetworkManager[3759]: <debug> [1382527675.463075] [nm-manager.c:591] manager_device_state_changed(): (ttyUSB0): triggered connectivity check due to state change
NetworkManager[3759]: <debug> [1382527675.464588] [nm-dns-manager.c:995] nm_dns_manager_begin_updates(): (device_state_changed): queueing DNS updates (1)
NetworkManager[3759]: <debug> [1382527675.464890] [nm-dns-manager.c:995] nm_dns_manager_begin_updates(): (update_routing_and_dns): queueing DNS updates (2)
NetworkManager[3759]: <info> Policy set 'Optus - Wireless Broadband' (ppp0) as default for IPv4 routing and DNS.
NetworkManager[3759]: <debug> [1382527675.465851] [nm-dns-manager.c:1013] nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS configuration changed
NetworkManager[3759]: <debug> [1382527675.466063] [nm-dns-manager.c:1017] nm_dns_manager_end_updates(): (update_routing_and_dns): no DNS changes to commit (1)
NetworkManager[3759]: <debug> [1382527675.466299] [nm-dns-manager.c:1013] nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS configuration changed
NetworkManager[3759]: <debug> [1382527675.466488] [nm-dns-manager.c:1022] nm_dns_manager_end_updates(): (device_state_changed): committing DNS changes (0)
NetworkManager[3759]: <debug> [1382527675.466656] [nm-dns-manager.c:591] update_dns(): updating resolv.conf
NetworkManager[3759]: <info> Activation (ttyUSB0) successful, device activated.
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
NetworkManager[3759]: <debug> [1382527680.297681] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 3 flags 0x1003
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::7c2c:59c6:fee9:5c16>]
IPV6CP: timeout sending Config-Requests
NetworkManager[3759]: <info> (ttyUSB0): device state change: activated -> disconnected (reason 'user-requested') [100 30 39]
NetworkManager[3759]: <info> (ttyUSB0): deactivating device (reason 'user-requested') [39]
NetworkManager[3759]: <debug> [1382527698.501386] [nm-firewall-manager.c:157] nm_firewall_manager_remove_from_zone(): (ppp0) firewall zone remove skipped (not running)
Terminating on signal 15
** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
** Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
Connect time 0.4 minutes.
Sent 56 bytes, received 0 bytes.
** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
sent [LCP TermReq id=0x2 "User request"]
rcvd [LCP TermAck id=0x2]
** Message: nm-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Connection terminated.
NetworkManager[3759]: <debug> [1382527698.516108] [nm-dns-manager.c:995] nm_dns_manager_begin_updates(): (device_ip4_config_changed): queueing DNS updates (1)
NetworkManager[3759]: <debug> [1382527698.516285] [nm-dns-manager.c:1013] nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS configuration changed
NetworkManager[3759]: <debug> [1382527698.516348] [nm-dns-manager.c:1022] nm_dns_manager_end_updates(): (device_ip4_config_changed): committing DNS changes (0)
NetworkManager[3759]: <debug> [1382527698.516400] [nm-dns-manager.c:591] update_dns(): updating resolv.conf
NetworkManager[3759]: <debug> [1382527698.578903] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527698.579314] [nm-dns-manager.c:995] nm_dns_manager_begin_updates(): (update_routing_and_dns): queueing DNS updates (1)
NetworkManager[3759]: <debug> [1382527698.579481] [nm-dns-manager.c:1013] nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS configuration did not change
NetworkManager[3759]: <debug> [1382527698.579554] [nm-dns-manager.c:1017] nm_dns_manager_end_updates(): (update_routing_and_dns): no DNS changes to commit (0)
NetworkManager[3759]: <debug> [1382527698.585599] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 11 flags 0x1090
NetworkManager[3759]: <debug> [1382527698.587217] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'remove' subsys 'net' device 'ppp0'
NetworkManager[3759]: <debug> [1382527698.588304] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill0 state now 1/0
NetworkManager[3759]: <debug> [1382527698.589323] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill1 state now 1/0
NetworkManager[3759]: <debug> [1382527698.590076] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 11 flags 0x1090
** Message: nm-ppp-plugin: (nm_phasechange): status 1 / phase 'dead'
** Message: nm-ppp-plugin: (nm_exit_notify): cleaning up
NetworkManager[3759]: <debug> [1382527700.392472] [nm-ppp-manager.c:1104] ensure_killed(): waiting for pppd pid 3818 to exit
NetworkManager[3759]: <debug> [1382527700.392942] [nm-ppp-manager.c:1106] ensure_killed(): pppd pid 3818 cleaned up
NetworkManager[3759]: <debug> [1382527706.340649] [nm-netlink-monitor.c:164] link_msg_handler(): netlink link message: iface idx 10 flags 0x1002
NetworkManager[3759]: <debug> [1382527706.346435] [nm-device.c:5305] nm_device_set_managed(): (ttyUSB0): now unmanaged
NetworkManager[3759]: <info> (ttyUSB0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
NetworkManager[3759]: <info> (ttyUSB0): cleaning up...
NetworkManager[3759]: <info> (ttyUSB0): taking down device.
NetworkManager[3759]: <debug> [1382527706.369443] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527706.370623] [nm-udev-manager.c:568] handle_uevent(): UDEV event: action 'remove' subsys 'net' device 'wwan0'
NetworkManager[3759]: <debug> [1382527706.371093] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill platform switch rfkill0 state now 1/0
NetworkManager[3759]: <debug> [1382527706.371562] [nm-udev-manager.c:216] recheck_killswitches(): WiFi rfkill switch rfkill1 state now 1/0
^CNetworkManager[3759]: <info> caught signal 2, shutting down normally.
NetworkManager[3759]: <debug> [1382527713.420917] [nm-device.c:5305] nm_device_set_managed(): (wlan0): now unmanaged
NetworkManager[3759]: <info> (wlan0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
NetworkManager[3759]: <info> (wlan0): cleaning up...
NetworkManager[3759]: <info> (wlan0): taking down device.
NetworkManager[3759]: <debug> [1382527713.445887] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527713.447614] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/accept_ra' to '1'
NetworkManager[3759]: <debug> [1382527713.448191] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/wlan0/use_tempaddr' to '0'
NetworkManager[3759]: <debug> [1382527713.448830] [nm-device.c:5305] nm_device_set_managed(): (eth0): now unmanaged
NetworkManager[3759]: <info> (eth0): device state change: unavailable -> unmanaged (reason 'removed') [20 10 36]
NetworkManager[3759]: <info> (eth0): cleaning up...
NetworkManager[3759]: <info> (eth0): taking down device.
NetworkManager[3759]: <debug> [1382527713.468184] [nm-manager.c:596] manager_device_state_changed(): stopping connectivity checks
NetworkManager[3759]: <debug> [1382527713.469399] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/accept_ra' to '1'
NetworkManager[3759]: <debug> [1382527713.470364] [NetworkManagerUtils.c:637] nm_utils_do_sysctl(): sysctl: setting '/proc/sys/net/ipv6/conf/eth0/use_tempaddr' to '0'
NetworkManager[3759]: <debug> [1382527713.475183] [nm-dns-manager.c:591] update_dns(): updating resolv.conf
NetworkManager[3759]: <info> exiting (success)

-------------- next part --------------

/org/freedesktop/ModemManager1/Modem/4 (device id '8335959fdeb43fd66cb2727060c983bc7b90e51a')
  -------------------------
  Hardware |   manufacturer: 'HUAWEI COMMUNICATION'
           |          model: '33'
           |       revision: 'M6246A-KPRBL-1.2.0022_3H   1  [Nov 16 2009 19:38:03]'
           |      supported: 'gsm-umts'
           |        current: 'gsm-umts'
           |   equipment id: '354765037613361'
  -------------------------
  System   |         device: '/sys/devices/pci0000:00/0000:00:1d.7/usb1/1-3'
           |        drivers: 'qmi_wwan, option1'
           |         plugin: 'Huawei'
           |   primary port: 'cdc-wdm0'
           |          ports: 'ttyUSB0 (at), ttyUSB1 (qcdm), ttyUSB2 (at), cdc-wdm0 (qmi), wwan0 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'sim-pin2'
           | unlock retries: 'sim-pin (3), sim-pin2 (3), sim-puk (10), sim-puk2 (10)'
           |          state: 'disabled'
           |    power state: 'unknown'
           |    access tech: 'unknown'
           | signal quality: '0' (cached)
  -------------------------
  Modes    |      supported: 'allowed: 2g; preferred: none
           |                  allowed: 3g; preferred: none
           |                  allowed: 2g, 3g; preferred: none
           |                  allowed: 2g, 3g; preferred: 2g
           |                  allowed: 2g, 3g; preferred: 3g'
           |        current: 'allowed: any; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4, ipv6, ipv4v6'
  -------------------------
  3GPP     |           imei: '354765037613361'
           |  enabled locks: 'none'
           |    operator id: 'unknown'
           |  operator name: 'unknown'
           |   registration: 'unknown'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/4'

-------------- next part --------------
T:  Bus=01 Lev=01 Prnt=01 Port=02 Cnt=02 Dev#=  4 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=12d1 ProdID=140c Rev=00.00
S:  Manufacturer=HUAWEI Technology
S:  Product=HUAWEI Mobile
C:  #Ifs= 6 Cfg#= 1 Atr=e0 MxPwr=500mA
I:  If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
I:  If#= 1 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=ff Prot=ff Driver=qmi_wwan
I:  If#= 2 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
I:  If#= 3 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
I:  If#= 4 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
I:  If#= 5 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
-------------- next part --------------
Created with 'qmicli -d /dev/cdc-wdm0 --device-open-version-info --dms-get-ids -v'
[22 Oct 2013, 23:35:46] [Debug] [/dev/cdc-wdm0] Checking version info (15 retries)...
[22 Oct 2013, 23:35:46] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 12
<<<<<<   data   = 01:0B:00:00:00:00:00:01:21:00:00:00

[22 Oct 2013, 23:35:46] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 11
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Version Info" (0x0021)

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 12
<<<<<<   data   = 01:0B:00:00:00:00:00:02:21:00:00:00

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 11
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 2
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Version Info" (0x0021)

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 48
>>>>>>   data   = 01:2F:00:80:00:00:01:02:21:00:24:00:02:04:00:00:00:00:00:01:1A:00:05:00:01:00:02:00:01:01:00:03:00:02:01:00:02:00:03:01:00:00:00:E0:00:00:00:00

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 47
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 2
>>>>>>   tlv_length  = 36
>>>>>>   message     = "Get Version Info" (0x0021)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Service list" (0x01)
>>>>>>   length     = 26
>>>>>>   value      = 05:00:01:00:02:00:01:01:00:03:00:02:01:00:02:00:03:01:00:00:00:E0:00:00:00:00
>>>>>>   translated = { [0] = '[ service = 'ctl' major_version = '1' minor_version = '2' ] ' [1] = '[ service = 'wds' major_version = '1' minor_version = '3' ] ' [2] = '[ service = 'dms' major_version = '1' minor_version = '2' ] ' [3] = '[ service = 'nas' major_version = '1' minor_version = '0' ] ' [4] = '[ service = 'cat' major_version = '0' minor_version = '0' ] '}

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] QMI Device supports 5 services:
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0]    ctl (1.2)
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0]    wds (1.3)
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0]    dms (1.2)
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0]    nas (1.0)
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0]    cat (0.0)
[22 Oct 2013, 23:35:48] [Debug] QMI Device at '/dev/cdc-wdm0' ready
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Allocating new client ID...
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:0F:00:00:00:00:00:03:22:00:04:00:01:01:00:02

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 15
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 3
<<<<<<   tlv_length  = 4
<<<<<<   message     = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<<   type       = "Service" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 02
<<<<<<   translated = dms

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:03:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:08

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 3
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Allocate CID" (0x0022)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Allocation Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 02:08
>>>>>>   translated = [ service = 'dms' cid = '8' ]

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Registered 'dms' (version 1.2) client with ID '8'
[22 Oct 2013, 23:35:48] [Debug] Asynchronously getting IDs...
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:08:00:01:00:25:00:00:00

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 8
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get IDs" (0x0025)

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 38
>>>>>>   data   = 01:25:00:80:02:08:02:01:00:25:00:19:00:02:04:00:00:00:00:00:11:0F:00:33:35:34:37:36:35:30:33:37:36:31:33:33:36:31

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 37
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 8
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 1
>>>>>>   tlv_length  = 25
>>>>>>   message     = "Get IDs" (0x0025)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Imei" (0x11)
>>>>>>   length     = 15
>>>>>>   value      = 33:35:34:37:36:35:30:33:37:36:31:33:33:36:31
>>>>>>   translated = 354765037613361

[/dev/cdc-wdm0] Device IDs retrieved:
	 ESN: 'unknown'
	IMEI: '354765037613361'
	MEID: 'unknown'
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Unregistered 'dms' client with ID '8'
[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 17
<<<<<<   data   = 01:10:00:00:00:00:00:04:23:00:05:00:01:02:00:02:08

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 16
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 4
<<<<<<   tlv_length  = 5
<<<<<<   message     = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<<   type       = "Release Info" (0x01)
<<<<<<   length     = 2
<<<<<<   value      = 02:08
<<<<<<   translated = [ service = 'dms' cid = '8' ]

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:04:23:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:08

[22 Oct 2013, 23:35:48] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 4
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Release CID" (0x0023)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Release Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 02:08
>>>>>>   translated = [ service = 'dms' cid = '8' ]

[22 Oct 2013, 23:35:48] [Debug] Client released
-------------- next part --------------
Created with 'qmicli -d /dev/cdc-wdm0 --dms-get-ids -v'
[22 Oct 2013, 23:37:19] [Debug] QMI Device at '/dev/cdc-wdm0' ready
[22 Oct 2013, 23:37:19] [Debug] [/dev/cdc-wdm0] Assuming service 'dms' is supported...
[22 Oct 2013, 23:37:19] [Debug] [/dev/cdc-wdm0] Allocating new client ID...
[22 Oct 2013, 23:37:19] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:0F:00:00:00:00:00:01:22:00:04:00:01:01:00:02

[22 Oct 2013, 23:37:19] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 15
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 4
<<<<<<   message     = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<<   type       = "Service" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 02
<<<<<<   translated = dms

Error is
error: couldn't create client for the 'dms' service: CID allocation failed in the CTL client: Transaction timed out
-------------- next part --------------
Oct 23 22:44:09 Budgie kernel: [18929.289839] nfsd: last server has exited, flushing export cache
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: RSDP 000fe020 00024 (v02 ACRSYS)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: XSDT 3f6fe120 00064 (v01 ACRSYS ACRPRDCT 00000001      01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: FACP 3f6fc000 000F4 (v04 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: DSDT 3f6f0000 0710E (v01 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: FACS 3f688000 00040
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: SSDT 3f6fd000 004C4 (v02  PmRef    CpuPm 00003000 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: HPET 3f6fb000 00038 (v01 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: APIC 3f6fa000 00068 (v02 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: MCFG 3f6f9000 0003C (v01 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: ASF! 3f6f8000 000A5 (v32 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: SLIC 3f6ef000 00176 (v01 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] ACPI: BOOT 3f6ee000 00028 (v01 ACRSYS ACRPRDCT 00000001 1025 01000013)
Oct 23 22:45:17 Budgie kernel: [    0.000000] Zone ranges:
Oct 23 22:45:17 Budgie kernel: [    0.000000]   DMA      [mem 0x00001000-0x00ffffff]
Oct 23 22:45:17 Budgie kernel: [    0.000000]   Normal   [mem 0x01000000-0x379fdfff]
Oct 23 22:45:17 Budgie kernel: [    0.000000]   HighMem  [mem 0x379fe000-0x3f6fffff]
Oct 23 22:45:17 Budgie kernel: [    0.000000] Movable zone start for each node
Oct 23 22:45:17 Budgie kernel: [    0.000000] Early memory node ranges
Oct 23 22:45:17 Budgie kernel: [    0.000000]   node   0: [mem 0x00001000-0x0009efff]
Oct 23 22:45:17 Budgie kernel: [    0.000000]   node   0: [mem 0x00100000-0x3f575fff]
Oct 23 22:45:17 Budgie kernel: [    0.000000]   node   0: [mem 0x3f5bf000-0x3f66cfff]
Oct 23 22:45:17 Budgie kernel: [    0.000000]   node   0: [mem 0x3f6bf000-0x3f6edfff]
Oct 23 22:45:17 Budgie kernel: [    0.000000]   node   0: [mem 0x3f6ff000-0x3f6fffff]
Oct 23 22:45:17 Budgie kernel: [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 257790
Oct 23 22:45:17 Budgie kernel: [    0.000000] Policy zone: HighMem
Oct 23 22:45:17 Budgie kernel: [    0.016753] ACPI: All ACPI Tables successfully acquired
Oct 23 22:45:17 Budgie kernel: [    0.103083] raid6: mmxx1      355 MB/s
Oct 23 22:45:17 Budgie kernel: [    0.120039] raid6: mmxx2      707 MB/s
Oct 23 22:45:17 Budgie kernel: [    0.137090] raid6: sse1x1     292 MB/s
Oct 23 22:45:17 Budgie kernel: [    0.154052] raid6: sse1x2     546 MB/s
Oct 23 22:45:17 Budgie kernel: [    0.171069] raid6: sse2x1     582 MB/s
Oct 23 22:45:17 Budgie kernel: [    0.188020] raid6: sse2x2    1089 MB/s
Oct 23 22:45:17 Budgie kernel: [    0.188127] raid6: using algorithm sse2x2 (1089 MB/s)
Oct 23 22:45:17 Budgie kernel: [    0.188232] raid6: using ssse3x1 recovery algorithm
Oct 23 22:45:17 Budgie kernel: [    0.195482] ACPI: Executed 1 blocks of module-level executable AML code
Oct 23 22:45:17 Budgie kernel: [    0.200799] ACPI: SSDT 3f5b7c90 00239 (v02  PmRef  Cpu0Ist 00003000 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.201792] ACPI: Dynamic OEM Table Load:
Oct 23 22:45:17 Budgie kernel: [    0.202006] ACPI: SSDT   (null) 00239 (v02  PmRef  Cpu0Ist 00003000 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.202488] ACPI: SSDT 3f5b6e10 001C7 (v02  PmRef  Cpu0Cst 00003001 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.203534] ACPI: Dynamic OEM Table Load:
Oct 23 22:45:17 Budgie kernel: [    0.203726] ACPI: SSDT   (null) 001C7 (v02  PmRef  Cpu0Cst 00003001 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.210575] ACPI: SSDT 3f5b7f10 000D0 (v02  PmRef  Cpu1Ist 00003000 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.211605] ACPI: Dynamic OEM Table Load:
Oct 23 22:45:17 Budgie kernel: [    0.211798] ACPI: SSDT   (null) 000D0 (v02  PmRef  Cpu1Ist 00003000 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.212212] ACPI: SSDT 3f5b5f10 00083 (v02  PmRef  Cpu1Cst 00003000 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.213279] ACPI: Dynamic OEM Table Load:
Oct 23 22:45:17 Budgie kernel: [    0.213470] ACPI: SSDT   (null) 00083 (v02  PmRef  Cpu1Cst 00003000 INTL 20051117)
Oct 23 22:45:17 Budgie kernel: [    0.219878] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S1_] (20130328/hwxface-568)
Oct 23 22:45:17 Budgie kernel: [    0.220112] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S2_] (20130328/hwxface-568)
Oct 23 22:45:17 Budgie kernel: [    0.417623] ACPI Error: [CAPB] Namespace lookup failure, AE_ALREADY_EXISTS (20130328/dsfield-211)
Oct 23 22:45:17 Budgie kernel: [    0.417924] ACPI Error: Method parse/execution failed [\_SB_.PCI0._OSC] (Node f683ba68), AE_ALREADY_EXISTS (20130328/psparse-537)
Oct 23 22:45:17 Budgie kernel: [    0.418260] ACPI: Marking method _OSC as Serialized because of AE_ALREADY_EXISTS error
Oct 23 22:45:17 Budgie kernel: [    0.429191] acpiphp_glue: sibling found, but _SUN doesn't match!
Oct 23 22:45:17 Budgie kernel: [    0.429346] acpiphp_glue: sibling found, but _SUN doesn't match!
Oct 23 22:45:17 Budgie kernel: [    0.429495] acpiphp_glue: sibling found, but _SUN doesn't match!
Oct 23 22:45:17 Budgie kernel: [    0.434937] ACPI Error: [CAPB] Namespace lookup failure, AE_ALREADY_EXISTS (20130328/dsfield-211)
Oct 23 22:45:17 Budgie kernel: [    0.435211] ACPI Error: Method parse/execution failed [\_SB_.PCI0._OSC] (Node f683ba68), AE_ALREADY_EXISTS (20130328/psparse-537)
Oct 23 22:45:17 Budgie kernel: [    0.504000] ACPI: Enabled 3 GPEs in block 00 to 1F
Oct 23 22:45:17 Budgie kernel: [    0.584456] pnp 00:00: disabling [io  0x164e-0x164f] because it overlaps 0000:00:1c.3 BAR 7 [io  0x1000-0x1fff]
Oct 23 22:45:17 Budgie kernel: [    0.851384] Simple Boot Flag value 0x5 read from CMOS RAM was invalid
Oct 23 22:45:17 Budgie kernel: [    0.853342] bounce pool size: 64 pages
Oct 23 22:45:17 Budgie kernel: [    0.857678] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Oct 23 22:45:17 Budgie kernel: [    9.993584] ACPI Warning: 0x00000428-0x0000042f SystemIO conflicts with Region \PMBA 1 (20130328/utaddress-251)
Oct 23 22:45:17 Budgie kernel: [    9.994105] ACPI Warning: 0x00000530-0x0000053f SystemIO conflicts with Region \GPIO 1 (20130328/utaddress-251)
Oct 23 22:45:17 Budgie kernel: [    9.994574] ACPI Warning: 0x00000500-0x0000052f SystemIO conflicts with Region \GPIO 1 (20130328/utaddress-251)
Oct 23 22:45:17 Budgie kernel: [    9.994997] lpc_ich: Resource conflict(s) found affecting gpio_ich
Oct 23 22:45:17 Budgie kernel: [   10.011110] ACPI: Deprecated procfs I/F for AC is loaded, please retry with CONFIG_ACPI_PROCFS_POWER cleared
Oct 23 22:45:17 Budgie kernel: [   10.709306] ACPI: Deprecated procfs I/F for battery is loaded, please retry with CONFIG_ACPI_PROCFS_POWER cleared
Oct 23 22:45:17 Budgie kernel: [   11.900054] i915: fixme: max PWM is zero
Oct 23 22:45:24 Budgie kernel: [   29.483261] svc: failed to register lockdv1 RPC service (errno 97).
Oct 23 22:45:24 Budgie kernel: [   29.483601] NFSD: the nfsdcld client tracking upcall will be removed in 3.10. Please transition to using nfsdcltrack.
Oct 23 22:47:24 Budgie kernel: [  149.856197] NFSD: Unable to end grace period: -110
Oct 23 22:47:38 Budgie NetworkManager[931]: <warn> failed to allocate link cache: (-10) Operation not supported
Oct 23 22:47:38 Budgie NetworkManager[931]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:47:38 Budgie NetworkManager[931]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:47:38 Budgie NetworkManager[931]: <warn> Couldn't get managed objects: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.bluez was not provided by any .service files
Oct 23 22:47:38 Budgie NetworkManager[931]: <warn> Trying to remove a non-existant call id.
Oct 23 22:47:41 Budgie ModemManager[938]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0': not supported by any plugin 
Oct 23 22:47:41 Budgie ModemManager[938]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.2/0000:03:00.0': not supported by any plugin 
Oct 23 22:48:19 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:48:19 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:48:19 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:48:20 Budgie kernel: [  205.067079] sr0: scsi-1 drive
Oct 23 22:48:23 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:48:23 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  couldn't load Supported Bands: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  couldn't load Power State: 'Unhandled power state: 'unknown' (255)' 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  couldn't load SIM identifier: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  couldn't load IMSI: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned'' 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  couldn't load current allowed/preferred modes: 'Loading current modes is not supported by this device' 
Oct 23 22:48:33 Budgie ModemManager[938]: <warn>  couldn't load current Bands: 'QMI operation failed: Cannot send message: QMI service 'nas' version '1.1' required, got version '1.0'' 
Oct 23 22:48:33 Budgie NetworkManager[931]: <warn> (cdc-wdm0): failed to look up interface index
Oct 23 22:49:11 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:49:31 Budgie dhcpcd[1014]: wwan0: ipv6rs_sendprobe: sendmsg: Cannot assign requested address
Oct 23 22:49:35 Budgie kernel: [  280.603860] option1 ttyUSB0: option_instat_callback: error -108
Oct 23 22:49:35 Budgie kernel: [  280.616747] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:49:35 Budgie kernel: [  280.616767] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:49:35 Budgie kernel: [  280.616780] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:49:35 Budgie kernel: [  280.618238] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:49:35 Budgie kernel: [  280.618255] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:49:35 Budgie kernel: [  280.618269] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:49:35 Budgie NetworkManager[931]: <warn> (4) failed to find interface name for index
Oct 23 22:49:35 Budgie NetworkManager[931]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Oct 23 22:49:35 Budgie NetworkManager[931]: <warn> (4) failed to find interface name for index
Oct 23 22:49:35 Budgie NetworkManager[931]: <warn> (4) failed to find interface name for index
Oct 23 22:49:35 Budgie NetworkManager[931]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Oct 23 22:49:35 Budgie NetworkManager[931]: <warn> (4) failed to find interface name for index
Oct 23 22:49:35 Budgie NetworkManager[931]: <warn> (cdc-wdm0) failed to disconnect modem: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: No such interface `org.freedesktop.ModemManager1.Modem.Simple' on object at path /org/freedesktop/ModemManager1/Modem/0
Oct 23 22:49:35 Budgie NetworkManager[931]: <warn> (pid 1014) unhandled DHCP event for interface wwan0
Oct 23 22:49:35 Budgie NetworkManager[931]: <warn> (pid 1014) unhandled DHCP event for interface wwan0
Oct 23 22:49:36 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:49:36 Budgie kernel: [  281.325745] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:49:36 Budgie kernel: [  281.325764] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:49:36 Budgie kernel: [  281.325778] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:49:36 Budgie kernel: [  281.325792] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:49:41 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:49:41 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:49:41 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:49:42 Budgie kernel: [  287.072132] sr0: scsi-1 drive
Oct 23 22:49:45 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:49:45 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  couldn't load Supported Bands: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  couldn't load Power State: 'Unhandled power state: 'unknown' (255)' 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  couldn't load SIM identifier: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  couldn't load IMSI: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned'' 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  couldn't load current allowed/preferred modes: 'Loading current modes is not supported by this device' 
Oct 23 22:49:55 Budgie ModemManager[938]: <warn>  couldn't load current Bands: 'QMI operation failed: Cannot send message: QMI service 'nas' version '1.1' required, got version '1.0'' 
Oct 23 22:49:55 Budgie NetworkManager[931]: <warn> (cdc-wdm0): failed to look up interface index
Oct 23 22:50:11 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:50:14 Budgie dhcpcd[1086]: wwan0: ipv6rs_sendprobe: sendmsg: Cannot assign requested address
Oct 23 22:50:19 Budgie kernel: [  323.992049] option1 ttyUSB0: option_instat_callback: error -108
Oct 23 22:50:19 Budgie kernel: [  324.005554] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:50:19 Budgie kernel: [  324.005574] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:50:19 Budgie kernel: [  324.005588] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:50:19 Budgie kernel: [  324.006926] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:50:19 Budgie kernel: [  324.006944] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:50:19 Budgie kernel: [  324.006959] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:50:19 Budgie NetworkManager[931]: <warn> (5) failed to find interface name for index
Oct 23 22:50:19 Budgie NetworkManager[931]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Oct 23 22:50:19 Budgie NetworkManager[931]: <warn> (5) failed to find interface name for index
Oct 23 22:50:19 Budgie NetworkManager[931]: <warn> (5) failed to find interface name for index
Oct 23 22:50:19 Budgie NetworkManager[931]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Oct 23 22:50:19 Budgie NetworkManager[931]: <warn> (5) failed to find interface name for index
Oct 23 22:50:19 Budgie NetworkManager[931]: <warn> (pid 1086) unhandled DHCP event for interface wwan0
Oct 23 22:50:19 Budgie NetworkManager[931]: <warn> (pid 1086) unhandled DHCP event for interface wwan0
Oct 23 22:50:19 Budgie NetworkManager[931]: <warn> (cdc-wdm0) failed to disconnect modem: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: No such interface `org.freedesktop.ModemManager1.Modem.Simple' on object at path /org/freedesktop/ModemManager1/Modem/1
Oct 23 22:50:19 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:50:19 Budgie kernel: [  324.718808] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:50:19 Budgie kernel: [  324.718826] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:50:19 Budgie kernel: [  324.718841] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:50:19 Budgie kernel: [  324.718854] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:50:24 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:50:24 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:50:24 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:50:25 Budgie kernel: [  330.151917] sr0: scsi-1 drive
Oct 23 22:50:28 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:50:28 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  couldn't load Supported Bands: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  couldn't load Power State: 'Unhandled power state: 'unknown' (255)' 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  couldn't load SIM identifier: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  couldn't load IMSI: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned'' 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  couldn't load current allowed/preferred modes: 'Loading current modes is not supported by this device' 
Oct 23 22:50:38 Budgie ModemManager[938]: <warn>  couldn't load current Bands: 'QMI operation failed: Cannot send message: QMI service 'nas' version '1.1' required, got version '1.0'' 
Oct 23 22:50:38 Budgie NetworkManager[931]: <warn> (cdc-wdm0): failed to look up interface index
Oct 23 22:50:45 Budgie kernel: [  350.797065] option1 ttyUSB0: option_instat_callback: error -108
Oct 23 22:56:10 Budgie ModemManager[1169]: <warn>  [1382529370.335253] [main.c:97] name_lost_cb(): Could not acquire the 'org.freedesktop.ModemManager1' service name 
Oct 23 22:56:10 Budgie NetworkManager[1173]: <warn> failed to allocate link cache: (-10) Operation not supported
Oct 23 22:56:10 Budgie NetworkManager[1173]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:56:10 Budgie NetworkManager[1173]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:56:10 Budgie NetworkManager[1173]: <warn> Couldn't get managed objects: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.bluez was not provided by any .service files
Oct 23 22:56:10 Budgie NetworkManager[1173]: <warn> Trying to remove a non-existant call id.
Oct 23 22:56:38 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:56:38 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:56:38 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:56:39 Budgie kernel: [  704.220191] sr0: scsi-1 drive
Oct 23 22:56:42 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:56:42 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  couldn't load Supported Bands: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  couldn't load Power State: 'Unhandled power state: 'unknown' (255)' 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  couldn't load SIM identifier: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  couldn't load IMSI: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned'' 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  couldn't load current allowed/preferred modes: 'Loading current modes is not supported by this device' 
Oct 23 22:56:52 Budgie ModemManager[938]: <warn>  couldn't load current Bands: 'QMI operation failed: Cannot send message: QMI service 'nas' version '1.1' required, got version '1.0'' 
Oct 23 22:56:52 Budgie NetworkManager[1173]: <warn> (cdc-wdm0): failed to look up interface index
Oct 23 22:57:11 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:57:14 Budgie dhcpcd[1226]: wwan0: ipv6rs_sendprobe: sendmsg: Cannot assign requested address
Oct 23 22:57:18 Budgie kernel: [  743.595419] option1 ttyUSB0: option_instat_callback: error -108
Oct 23 22:57:18 Budgie kernel: [  743.608592] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:57:18 Budgie kernel: [  743.608612] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:57:18 Budgie kernel: [  743.608626] option1 ttyUSB1: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:57:18 Budgie kernel: [  743.610839] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:57:18 Budgie kernel: [  743.610856] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:57:18 Budgie kernel: [  743.610869] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-2)
Oct 23 22:57:18 Budgie NetworkManager[1173]: <warn> (7) failed to find interface name for index
Oct 23 22:57:18 Budgie NetworkManager[1173]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Oct 23 22:57:18 Budgie NetworkManager[1173]: <warn> (7) failed to find interface name for index
Oct 23 22:57:18 Budgie NetworkManager[1173]: <warn> (7) failed to find interface name for index
Oct 23 22:57:18 Budgie NetworkManager[1173]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Oct 23 22:57:18 Budgie NetworkManager[1173]: <warn> (7) failed to find interface name for index
Oct 23 22:57:18 Budgie NetworkManager[1173]: <warn> (pid 1226) unhandled DHCP event for interface wwan0
Oct 23 22:57:18 Budgie NetworkManager[1173]: <warn> (cdc-wdm0) failed to disconnect modem: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: No such interface `org.freedesktop.ModemManager1.Modem.Simple' on object at path /org/freedesktop/ModemManager1/Modem/3
Oct 23 22:57:18 Budgie NetworkManager[1173]: <warn> (pid 1226) unhandled DHCP event for interface wwan0
Oct 23 22:57:19 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:57:19 Budgie kernel: [  744.336359] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:57:19 Budgie kernel: [  744.336380] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:57:19 Budgie kernel: [  744.336395] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:57:19 Budgie kernel: [  744.336408] option1 ttyUSB0: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:57:23 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:57:23 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:57:23 Budgie ModemManager[938]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:57:24 Budgie kernel: [  749.227226] sr0: scsi-1 drive
Oct 23 22:57:27 Budgie ModemManager[938]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:57:27 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  couldn't load Supported Bands: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  couldn't load Power State: 'Unhandled power state: 'unknown' (255)' 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  couldn't load SIM identifier: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  couldn't load IMSI: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.2'' 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned'' 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  couldn't load current allowed/preferred modes: 'Loading current modes is not supported by this device' 
Oct 23 22:57:37 Budgie ModemManager[938]: <warn>  couldn't load current Bands: 'QMI operation failed: Cannot send message: QMI service 'nas' version '1.1' required, got version '1.0'' 
Oct 23 22:57:37 Budgie NetworkManager[1173]: <warn> (cdc-wdm0): failed to look up interface index
Oct 23 22:57:47 Budgie kernel: [  772.396554] option1 ttyUSB0: option_instat_callback: error -108
-------------- next part --------------
Oct 23 22:16:47 Budgie kernel: [17287.019691] ACPI Error: [_T_0] Namespace lookup failure, AE_ALREADY_EXISTS (20130328/dswload2-330)
Oct 23 22:16:47 Budgie kernel: [17287.019718] ACPI Exception: AE_ALREADY_EXISTS, During name lookup/catalog (20130328/psobject-222)
Oct 23 22:16:47 Budgie kernel: [17287.019731] ACPI Error: Method parse/execution failed [\_SB_.PCI0.WMID.WMBA] (Node f68405e8), AE_ALREADY_EXISTS (20130328/psparse-537)
Oct 23 22:16:47 Budgie kernel: [17287.062570] ACPI: Marking method WMBA as Serialized because of AE_ALREADY_EXISTS error
Oct 23 22:16:47 Budgie NetworkManager[3565]: <warn> failed to allocate link cache: (-10) Operation not supported
Oct 23 22:16:47 Budgie NetworkManager[3565]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:16:47 Budgie NetworkManager[3565]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:16:47 Budgie NetworkManager[3565]: <warn> Trying to remove a non-existant call id.
Oct 23 22:17:41 Budgie modem-manager[3472]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:17:41 Budgie kernel: [17341.648453] sr0: scsi-1 drive
Oct 23 22:17:47 Budgie modem-manager[3472]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:17:47 Budgie modem-manager[3472]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:17:59 Budgie modem-manager[3472]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:17:59 Budgie NetworkManager[3565]: <warn> (ttyUSB0): failed to look up interface index
Oct 23 22:18:31 Budgie modem-manager[3472]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:18:50 Budgie modem-manager[3472]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:18:50 Budgie NetworkManager[3565]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
Oct 23 22:18:54 Budgie pppd[3650]: Could not determine remote IP address: defaulting to 10.64.64.64
Oct 23 22:18:54 Budgie pppd[3650]: Cannot determine ethernet address for proxy ARP
Oct 23 22:18:54 Budgie pppd[3650]: Can't execute /etc/ppp/ip-up: Invalid argument
Oct 23 22:19:20 Budgie pppd[3650]: IPV6CP: timeout sending Config-Requests 
Oct 23 22:19:47 Budgie kernel: [17467.466905] option1 ttyUSB0: option_instat_callback: error -108
Oct 23 22:19:47 Budgie kernel: [17467.468162] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:19:47 Budgie kernel: [17467.472407] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:19:47 Budgie kernel: [17467.474405] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:19:47 Budgie kernel: [17467.476406] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:26:19 Budgie modem-manager[3757]: <warn>  [1382527579.621411] [main.c:117] create_dbus_proxy(): Could not acquire the org.freedesktop.ModemManager service as it is already taken. Return: 3 
Oct 23 22:26:20 Budgie NetworkManager[3759]: <warn> failed to allocate link cache: (-10) Operation not supported
Oct 23 22:26:20 Budgie NetworkManager[3759]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:26:20 Budgie NetworkManager[3759]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Oct 23 22:26:20 Budgie NetworkManager[3759]: <warn> Trying to remove a non-existant call id.
Oct 23 22:26:55 Budgie modem-manager[3472]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:26:56 Budgie kernel: [17896.542157] sr0: scsi-1 drive
Oct 23 22:27:01 Budgie modem-manager[3472]: <warn>  (ttyUSB1): port attributes not fully set 
Oct 23 22:27:01 Budgie modem-manager[3472]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:27:14 Budgie modem-manager[3472]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:27:14 Budgie NetworkManager[3759]: <warn> (ttyUSB0): failed to look up interface index
Oct 23 22:27:22 Budgie modem-manager[3472]: <warn>  (ttyUSB2): port attributes not fully set 
Oct 23 22:27:37 Budgie modem-manager[3472]: <warn>  (ttyUSB0): port attributes not fully set 
Oct 23 22:27:37 Budgie NetworkManager[3759]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
Oct 23 22:27:54 Budgie pppd[3818]: Could not determine remote IP address: defaulting to 10.64.64.64
Oct 23 22:27:54 Budgie pppd[3818]: Cannot determine ethernet address for proxy ARP
Oct 23 22:27:54 Budgie pppd[3818]: Can't execute /etc/ppp/ip-up: Invalid argument
Oct 23 22:28:07 Budgie pppd[3818]: IPV6CP: timeout sending Config-Requests 
Oct 23 22:28:26 Budgie kernel: [17986.026141] option1 ttyUSB0: option_instat_callback: error -108
Oct 23 22:28:26 Budgie kernel: [17986.026894] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:28:26 Budgie kernel: [17986.031149] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:28:26 Budgie kernel: [17986.035396] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)
Oct 23 22:28:26 Budgie kernel: [17986.037766] option1 ttyUSB2: usb_wwan_indat_callback: resubmit read urb failed. (-19)


More information about the ModemManager-devel mailing list