Re: Cellular modem connection does not come up on boot



Thanks for your guidance.

When the device doesn’t show up in NM, it can’t be seen through mmcli.  I turned up the logging level to see what’s going on.  Maybe you have a different reading of this, but the first thing that jumps out at me is that something seems to be sending NM/MM a TERM signal.

# journalctl --no-pager --unit=ModemManager --unit=NetworkManager -n200
-- Logs begin at Mon 2017-03-06 12:06:25 UTC, end at Mon 2017-03-06 12:08:27 UTC. --
Mar 06 12:06:29 raspberrypi3 systemd[1]: Starting Modem Manager...
Mar 06 12:06:29 raspberrypi3 systemd[1]: Starting Network Manager...
Mar 06 12:06:30 raspberrypi3 ModemManager[637]: <info>  ModemManager (version 1.6.4) starting in system bus...
Mar 06 12:06:30 e5882e6 NetworkManager[723]: <info>  [1488801990.5777] NetworkManager (version 1.4.2) is starting...
Mar 06 12:06:30 e5882e6 NetworkManager[723]: <info>  [1488801990.5783] Read config: /etc/NetworkManager/NetworkManager.conf
Mar 06 12:06:30 e5882e6 NetworkManager[723]: <info>  [1488801990.6102] manager[0x19c9880]: monitoring kernel firmware directory '/lib/firmware'.
Mar 06 12:06:30 e5882e6 NetworkManager[723]: <info>  [1488801990.6647] dns-mgr[0x19d4818]: init: dns=default, rc-manager=resolvconf
Mar 06 12:06:30 e5882e6 NetworkManager[723]: <info>  [1488801990.6692] rfkill0: found WiFi radio killswitch (at /sys/devices/platform/soc/3f300000.mmc/mmc_host/mmc1/mmc1:0001/mmc1:0001:1/ieee80211/phy0/rfkill0) (driver brcmfmac_sdio)
Mar 06 12:06:30 e5882e6 NetworkManager[723]: <info>  [1488801990.6702] manager[0x19c9880]: WiFi hardware radio set enabled
Mar 06 12:06:30 e5882e6 NetworkManager[723]: <info>  [1488801990.6705] manager[0x19c9880]: WWAN hardware radio set enabled
Mar 06 12:06:30 e5882e6 systemd[1]: Started Network Manager.
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.1467] settings: loaded plugin keyfile: (c) 2007 - 2015 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.2602] keyfile: new connection /etc/NetworkManager/system-connections/resin-sample (bcb05b81-52cb-3828-8088-c0f55e950375,"resin-sample")
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.3534] keyfile: new connection /etc/NetworkManager/system-connections/resin-verizon (9290a7a8-70f7-44b0-94e4-83f0b2635f07,"resin-verizon")
Mar 06 12:06:31 e5882e6 systemd[1]: Started Modem Manager.
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8042] settings: hostname: using hostnamed
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8043] settings: hostname changed from (none) to "e5882e6"
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8055] dhcp-init: Using DHCP client 'dhclient'
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8056] manager: WiFi enabled by radio killswitch; enabled by state file
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8059] manager: WWAN enabled by radio killswitch; enabled by state file
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8064] manager: Networking is enabled by state file
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8068] Loaded device plugin: NMVxlanFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8069] Loaded device plugin: NMVlanFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8071] Loaded device plugin: NMVethFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8072] Loaded device plugin: NMTunFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8074] Loaded device plugin: NMMacvlanFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8075] Loaded device plugin: NMIPTunnelFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8077] Loaded device plugin: NMInfinibandFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8079] Loaded device plugin: NMEthernetFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8083] Loaded device plugin: NMBridgeFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8085] Loaded device plugin: NMBondFactory (internal)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.8525] Loaded device plugin: NMWwanFactory (/usr/lib/NetworkManager/libnm-device-plugin-wwan.so)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.9084] Loaded device plugin: NMBluezManager (/usr/lib/NetworkManager/libnm-device-plugin-bluetooth.so)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.9428] Loaded device plugin: NMWifiFactory (/usr/lib/NetworkManager/libnm-device-plugin-wifi.so)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.9704] device (lo): link connected
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.9763] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/0)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.9883] manager: (eth0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/1)
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.9955] keyfile: add connection in-memory (cc17d9e1-cce2-34ec-b860-f0c313cd0a97,"Wired connection 1")
Mar 06 12:06:31 e5882e6 NetworkManager[723]: <info>  [1488801991.9992] settings: (eth0): created default wired connection 'Wired connection 1'
Mar 06 12:06:32 e5882e6 NetworkManager[723]: <info>  [1488801992.0088] device (eth0): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Mar 06 12:06:32 e5882e6 NetworkManager[723]: <info>  [1488801992.1195] (wlan0): using nl80211 for WiFi device control
Mar 06 12:06:32 e5882e6 NetworkManager[723]: <info>  [1488801992.1211] device (wlan0): driver supports Access Point (AP) mode
Mar 06 12:06:32 e5882e6 NetworkManager[723]: <info>  [1488801992.1290] manager: (wlan0): new 802.11 WiFi device (/org/freedesktop/NetworkManager/Devices/2)
Mar 06 12:06:32 e5882e6 NetworkManager[723]: <info>  [1488801992.1392] device (wlan0): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Mar 06 12:06:32 e5882e6 NetworkManager[723]: <info>  [1488801992.7692] device (wlan0): set-hw-addr: set MAC address to 92:9C:1E:F0:69:A4 (scanning)
Mar 06 12:06:32 e5882e6 NetworkManager[723]: <info>  [1488801992.8631] ModemManager available in the bus
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.0872] supplicant: wpa_supplicant running
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.0875] device (wlan0): supplicant interface state: init -> starting
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.1817] sup-iface[0x19d30d8,wlan0]: supports 5 scan SSIDs
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.1873] device (wlan0): supplicant interface state: starting -> ready
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.1877] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Mar 06 12:06:33 e5882e6 ModemManager[637]: <warn>  (ttyUSB3): port attributes not fully set
Mar 06 12:06:33 e5882e6 ModemManager[637]: <warn>  (ttyUSB2): port attributes not fully set
Mar 06 12:06:33 e5882e6 ModemManager[637]: <warn>  (ttyUSB1): port attributes not fully set
Mar 06 12:06:33 e5882e6 ModemManager[637]: <warn>  (ttyUSB0): port attributes not fully set
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6314] device (eth0): link connected
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6500] device (eth0): state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6539] policy: auto-activating connection 'Wired connection 1'
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6617] device (eth0): Activation: starting connection 'Wired connection 1' (cc17d9e1-cce2-34ec-b860-f0c313cd0a97)
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6629] device (eth0): state change: disconnected -> prepare (reason 'none') [30 40 0]
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6637] manager: NetworkManager state is now CONNECTING
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6666] device (eth0): state change: prepare -> config (reason 'none') [40 50 0]
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6708] device (eth0): state change: config -> ip-config (reason 'none') [50 70 0]
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.6761] dhcp4 (eth0): activation: beginning transaction (timeout in 45 seconds)
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.7187] dhcp4 (eth0): dhclient started with pid 833
Mar 06 12:06:33 e5882e6 NetworkManager[723]: <info>  [1488801993.7321] device (wlan0): supplicant interface state: ready -> inactive
Mar 06 12:06:34 e5882e6 dhclient[833]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
Mar 06 12:06:34 e5882e6 ModemManager[637]: <info>  Couldn't check support for device at '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1': not supported by any plugin
Mar 06 12:06:35 e5882e6 dhclient[833]: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Mar 06 12:06:35 e5882e6 dhclient[833]: DHCPOFFER from XXX.XX.1.1
Mar 06 12:06:35 e5882e6 dhclient[833]: DHCPACK from XXX.XX.1.1
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1917] dhcp4 (eth0):   address XXX.XXX.XXX.XXX
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1918] dhcp4 (eth0):   plen 23 (255.255.254.0)
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1920] dhcp4 (eth0):   gateway XXX.XXX.XXX.XXX
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1921] dhcp4 (eth0):   server identifier XXX.XXX.XXX.XXX
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1922] dhcp4 (eth0):   lease time 86400
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1924] dhcp4 (eth0):   nameserver 'XXX.XXX.XXX.XXX'
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1925] dhcp4 (eth0):   nameserver '8.8.8.8'
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1926] dhcp4 (eth0): state changed unknown -> bound
Mar 06 12:06:35 e5882e6 dhclient[833]: bound to XXX.XXX.XXX.XXX -- renewal in 35201 seconds.
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.1988] device (eth0): state change: ip-config -> ip-check (reason 'none') [70 80 0]
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.2033] device (eth0): state change: ip-check -> secondaries (reason 'none') [80 90 0]
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.2055] device (eth0): state change: secondaries -> activated (reason 'none') [90 100 0]
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.2064] manager: NetworkManager state is now CONNECTED_LOCAL
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.2107] manager: NetworkManager state is now CONNECTED_GLOBAL
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.2113] policy: set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.2120] dns-mgr: Writing DNS information to /sbin/resolvconf
Mar 06 12:06:35 e5882e6 NetworkManager[723]: <info>  [1488801995.3174] device (eth0): Activation: successful, device activated.
Mar 06 12:06:39 e5882e6 NetworkManager[723]: <info>  [1488801999.2565] manager: startup complete
Mar 06 12:06:43 e5882e6 ModemManager[637]: <info>  Creating modem with plugin 'Telit' and '4' ports
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  (ttyUSB3): port attributes not fully set
Mar 06 12:06:43 e5882e6 ModemManager[637]: <info>  Modem for device at '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1.4' successfully created
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  couldn't load Supported Bands: 'Unknown error'
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  No respose for step 1: Unknown error
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  No respose for step 2: Unknown error
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  No respose for step 3: Unknown error
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  No respose for step 4: Unknown error
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  Couldn't load unlock retries: 'Could not get any of the SIM unlock retries values'
Mar 06 12:06:43 e5882e6 ModemManager[637]: <warn>  couldn't load current Bands: 'Unknown error'
Mar 06 12:06:43 e5882e6 ModemManager[637]: <info>  Modem: state changed (unknown -> disabled)
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9276] (ttyUSB3): modem state changed, 'disabled' --> 'enabling' (reason: user preference)
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9371] manager: (ttyUSB3): new Broadband device (/org/freedesktop/NetworkManager/Devices/3)
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9401] device (ttyUSB3): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9418] device (ttyUSB3): modem state 'enabling'
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9427] modem-broadband[ttyUSB3]: failed to retrieve SIM object: No SIM object available
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9450] device (ttyUSB3): state change: unavailable -> disconnected (reason 'none') [20 30 0]
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9488] policy: auto-activating connection 'resin-verizon'
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9562] device (ttyUSB3): Activation: starting connection 'resin-verizon' (9290a7a8-70f7-44b0-94e4-83f0b2635f07)
Mar 06 12:06:43 e5882e6 NetworkManager[723]: <info>  [1488802003.9573] device (ttyUSB3): state change: disconnected -> prepare (reason 'none') [30 40 0]
Mar 06 12:06:44 e5882e6 ModemManager[637]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Mar 06 12:06:44 e5882e6 ModemManager[637]: <warn>  (ttyUSB3): port attributes not fully set
Mar 06 12:06:44 e5882e6 ModemManager[637]: <warn>  (ttyUSB2): port attributes not fully set
Mar 06 12:06:44 e5882e6 ModemManager[637]: <info>  Simple connect started...
Mar 06 12:06:44 e5882e6 ModemManager[637]: <info>  Simple connect state (4/8): Wait to get fully enabled
Mar 06 12:06:44 e5882e6 ModemManager[637]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> enabled)
Mar 06 12:06:44 e5882e6 ModemManager[637]: <info>  Simple connect state (5/8): Register
Mar 06 12:06:44 e5882e6 NetworkManager[723]: <info>  [1488802004.9624] (ttyUSB3): modem state changed, 'enabling' --> 'enabled' (reason: user-requested)
Mar 06 12:06:45 e5882e6 ModemManager[637]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabled -> registered)
Mar 06 12:06:45 e5882e6 ModemManager[637]: <info>  Simple connect state (6/8): Bearer
Mar 06 12:06:45 e5882e6 NetworkManager[723]: <info>  [1488802005.0492] (ttyUSB3): modem state changed, 'enabled' --> 'registered' (reason: unknown)
Mar 06 12:06:45 e5882e6 ModemManager[637]: <info>  Simple connect state (7/8): Connect
Mar 06 12:06:45 e5882e6 ModemManager[637]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Mar 06 12:06:45 e5882e6 NetworkManager[723]: <info>  [1488802005.0565] (ttyUSB3): modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Mar 06 12:06:46 e5882e6 ModemManager[637]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
Mar 06 12:06:46 e5882e6 ModemManager[637]: <info>  Simple connect state (8/8): All done
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.2661] (ttyUSB3): modem state changed, 'connecting' --> 'connected' (reason: user-requested)
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <warn>  [1488802006.2745] device (ttyUSB3): failed to look up interface index
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.2754] device (ttyUSB3): state change: prepare -> config (reason 'none') [40 50 0]
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.2772] device (ttyUSB3): state change: config -> ip-config (reason 'none') [50 70 0]
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <warn>  [1488802006.2780] device (ttyUSB3): interface ttyUSB3 not up for IP configuration
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.2782] (ttyUSB3): using modem-specified IP timeout: 20 seconds
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.2807] ppp-manager: starting PPP connection
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.3102] ppp-manager: pppd started with pid 856
Mar 06 12:06:46 e5882e6 pppd[856]: Plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so loaded.
Mar 06 12:06:46 e5882e6 NetworkManager[723]: Plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so loaded.
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (plugin_init): initializing
Mar 06 12:06:46 e5882e6 pppd[856]: pppd 2.4.7 started by root, uid 0
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
Mar 06 12:06:46 e5882e6 pppd[856]: Using interface ppp0
Mar 06 12:06:46 e5882e6 NetworkManager[723]: Using interface ppp0
Mar 06 12:06:46 e5882e6 NetworkManager[723]: Connect: ppp0 <--> /dev/ttyUSB3
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
Mar 06 12:06:46 e5882e6 pppd[856]: Connect: ppp0 <--> /dev/ttyUSB3
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate'
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.5846] manager: (ppp0): new Generic device (/org/freedesktop/NetworkManager/Devices/4)
Mar 06 12:06:46 e5882e6 pppd[856]: local  IP address 166.249.XXX.XXX
Mar 06 12:06:46 e5882e6 NetworkManager[723]: local  IP address 166.249.XXX.XXX
Mar 06 12:06:46 e5882e6 NetworkManager[723]: remote IP address 66.174.XXX.XXX
Mar 06 12:06:46 e5882e6 NetworkManager[723]: primary   DNS address 198.224.191.135
Mar 06 12:06:46 e5882e6 NetworkManager[723]: secondary DNS address 198.224.190.135
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 9 / phase 'running'
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_ip_up): ip-up event
Mar 06 12:06:46 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_ip_up): sending IPv4 config to NetworkManager...
Mar 06 12:06:46 e5882e6 pppd[856]: remote IP address 66.174.XXX.XXX
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.6702] ppp-manager: (IPv4 Config Get) reply received.
Mar 06 12:06:46 e5882e6 pppd[856]: primary   DNS address 198.224.XXX.XXX
Mar 06 12:06:46 e5882e6 pppd[856]: secondary DNS address 198.224.XXX.XXX
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.6887] device (ttyUSB3): state change: ip-config -> ip-check (reason 'none') [70 80 0]
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.6936] device (ttyUSB3): state change: ip-check -> secondaries (reason 'none') [80 90 0]
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.6955] device (ttyUSB3): state change: secondaries -> activated (reason 'none') [90 100 0]
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.6986] dns-mgr: Writing DNS information to /sbin/resolvconf
Mar 06 12:06:46 e5882e6 NetworkManager[723]: <info>  [1488802006.7816] device (ttyUSB3): Activation: successful, device activated.
Mar 06 12:07:16 e5882e6 pppd[856]: IPV6CP: timeout sending Config-Requests
Mar 06 12:07:16 e5882e6 NetworkManager[723]: IPV6CP: timeout sending Config-Requests
Mar 06 12:08:07 e5882e6 NetworkManager[723]: <info>  [1488802087.7799] manager: (docker0): new Bridge device (/org/freedesktop/NetworkManager/Devices/5)
Mar 06 12:08:12 e5882e6 ModemManager[637]: <info>  (tty/ttyUSB1): released by modem /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1.4
Mar 06 12:08:12 e5882e6 ModemManager[637]: <info>  (tty/ttyUSB2): released by modem /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1.4
Mar 06 12:08:12 e5882e6 ModemManager[637]: <info>  (tty/ttyUSB3): released by modem /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1.4
Mar 06 12:08:13 e5882e6 ModemManager[637]: <info>  (tty/ttyUSB0): released by modem /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1.4
Mar 06 12:08:13 e5882e6 NetworkManager[723]: <info>  [1488802093.2978] device (ttyUSB3): state change: activated -> unmanaged (reason 'removed') [100 10 36]
Mar 06 12:08:13 e5882e6 pppd[856]: Terminating on signal 15
Mar 06 12:08:13 e5882e6 NetworkManager[723]: Terminating on signal 15
Mar 06 12:08:13 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
Mar 06 12:08:13 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
Mar 06 12:08:13 e5882e6 NetworkManager[723]: Connect time 1.5 minutes.
Mar 06 12:08:13 e5882e6 NetworkManager[723]: Sent 126 bytes, received 0 bytes.
Mar 06 12:08:13 e5882e6 pppd[856]: Connect time 1.5 minutes.
Mar 06 12:08:13 e5882e6 pppd[856]: Sent 126 bytes, received 0 bytes.
Mar 06 12:08:13 e5882e6 NetworkManager[723]: <info>  [1488802093.3319] dns-mgr: Writing DNS information to /sbin/resolvconf
Mar 06 12:08:13 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
Mar 06 12:08:13 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Mar 06 12:08:13 e5882e6 NetworkManager[723]: Connection terminated.
Mar 06 12:08:13 e5882e6 pppd[856]: Connection terminated.
Mar 06 12:08:13 e5882e6 ModemManager[637]: <info>  (net/eth0): released by modem /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1
Mar 06 12:08:13 e5882e6 NetworkManager[723]: <warn>  [1488802093.4772] modem-broadband[ttyUSB3]: 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
Mar 06 12:08:14 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 1 / phase 'dead'
Mar 06 12:08:14 e5882e6 NetworkManager[723]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_exit_notify): cleaning up
Mar 06 12:08:14 e5882e6 pppd[856]: Exit.


On Mar 30, 2017, at 1:10 PM, Dan Williams <dcbw redhat com> wrote:

On Wed, 2017-03-29 at 10:48 -0400, Liam Monahan wrote:
I have a USB cellular modem that will not show up in nm on boot.  If
the system is started up and I unplug and plug it back in, it shows
up then.  These device are deployed out in the field, so manual
intervention is not a real option for my use case unfortunately.

device is ttyUSB3 and does not show up at first:

# nmcli d
DEVICE     TYPE      STATE         CONNECTION         
eth0       ethernet  connected     Wired connection 1 
wlan0      wifi      disconnected  --                 
docker0    bridge    unmanaged     --                 
lo         loopback  unmanaged     --                 
resin-vpn  tun       unmanaged     — 

When the device doesn't show up in NM, can you see it with "mmcli -L"
before you replug it?

If you can see it in mmcli, then the problem is likely in
NetworkManager.  Getting debug logs would be necessary, which you can
do by adding this to /etc/NetworkManager/NetworkManager.conf:

[logging]
level=trace

If you can't see it in ModemManager, then the bug is likely in MM.  You
can enable verbose MM debugging by modifying the ModemManager system
unit file and adding "--log-level=debug" to the Exec= line.

One of those should give us more info about the issue.

Dan

and then after unplugging and plugging back in:
 
# nmcli d
DEVICE     TYPE      STATE         CONNECTION         
ttyUSB3    cdma      connected     resin-verizon      
eth0       ethernet  connected     Wired connection 1 
wlan0      wifi      disconnected  --                 
docker0    bridge    unmanaged     --                 
lo         loopback  unmanaged     --                 
resin-vpn  tun       unmanaged     --   

# mmcli -L

Found 1 modems:
/org/freedesktop/ModemManager1/Modem/0 [Telit] DE910-DUAL


dmesg makes it seem like the modem connected briefly and then
disappeared.  Does anyone have any thoughts on what’s going on or how
I could do a better job of going about debugging this?

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 4.4.48 (andrei misc1 dev resin io) (gcc
version 6.2.0 (GCC) ) #2 SMP Sat Mar 11 03:08:12 UTC 2017
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7),
cr=10c5383d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing
instruction cache
[    0.000000] Machine model: Raspberry Pi 3 Model B Rev 1.2
[    0.000000] cma: Reserved 8 MiB at 0x3d800000
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] On node 0 totalpages: 253952
[    0.000000] free_area_init_node: node 0, pgdat 80ca84c0,
node_mem_map bcf3a000
[    0.000000]   Normal zone: 2232 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 253952 pages, LIFO batch:31
[    0.000000] [bcm2709_smp_init_cpus] enter (9540->f3003010)
[    0.000000] [bcm2709_smp_init_cpus] ncores=4
[    0.000000] PERCPU: Embedded 13 pages/cpu @bcef6000 s23052 r8192
d22004 u53248
[    0.000000] pcpu-alloc: s23052 r8192 d22004 u53248 alloc=13*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping
on.  Total pages: 251720
[    0.000000] Kernel command line: 8250.nr_uarts=1
dma.dmachans=0x7f35 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416
bcm2709.boardrev=0xa22082 bcm2709.serial=0xca8e10ef
smsc95xx.macaddr=B8:27:EB:8E:10:EF bcm2708_fb.fbdepth=16
bcm2708_fb.fbswap=1 bcm2709.uart_clock=48000000
vc_mem.mem_base=0x3ea00000
vc_mem.mem_size=0x3f000000  dwc_otg.lpm_enable=0 console=tty1
console=ttyS0,115200 root=/dev/mmcblk0p2 rootfstype=ext4 rootwait
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7,
524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6,
262144 bytes)
[    0.000000] Memory: 983796K/1015808K available (7029K kernel code,
454K rwdata, 1956K rodata, 3524K init, 775K bss, 23820K reserved,
8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xbe800000 - 0xff800000   (1040 MB)
                   lowmem  : 0x80000000 - 0xbe000000   ( 992 MB)
                   modules : 0x7f000000 - 0x80000000   (  16 MB)
                     .text : 0x80008000 - 0x808ce6fc   (8986 kB)
                     .init : 0x808cf000 - 0x80c40000   (3524 kB)
                     .data : 0x80c40000 - 0x80cb1a80   ( 455 kB)
                      .bss : 0x80cb4000 - 0x80d75f84   ( 776 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4,
Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  Build-time adjustment of leaf fanout to 32.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] Architected cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff
max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000008] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps
every 4398046511078ns
[    0.000024] Switching to timer-based delay loop, resolution 52ns
[    0.000269] Console: colour dummy device 80x30
[    0.001295] console [tty1] enabled
[    0.001349] Calibrating delay loop (skipped), value calculated
using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.001417] pid_max: default: 32768 minimum: 301
[    0.001746] Mount-cache hash table entries: 2048 (order: 1, 8192
bytes)
[    0.001791] Mountpoint-cache hash table entries: 2048 (order: 1,
8192 bytes)
[    0.002732] Disabling cpuset control group subsystem
[    0.002790] Initializing cgroup subsys io
[    0.002841] Initializing cgroup subsys memory
[    0.002904] Initializing cgroup subsys devices
[    0.002947] Initializing cgroup subsys freezer
[    0.002989] Initializing cgroup subsys net_cls
[    0.003057] CPU: Testing write buffer coherency: ok
[    0.003147] ftrace: allocating 23395 entries in 69 pages
[    0.058204] CPU0: update cpu_capacity 1024
[    0.058265] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.058299] [bcm2709_smp_prepare_cpus] enter
[    0.058459] Setting up static identity map for 0x8240 - 0x8274
[    0.060108] [bcm2709_boot_secondary] cpu:1 started (0) 18
[    0.060323] [bcm2709_secondary_init] enter cpu:1
[    0.060366] CPU1: update cpu_capacity 1024
[    0.060372] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.060751] [bcm2709_boot_secondary] cpu:2 started (0) 17
[    0.060926] [bcm2709_secondary_init] enter cpu:2
[    0.060946] CPU2: update cpu_capacity 1024
[    0.060952] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.061314] [bcm2709_boot_secondary] cpu:3 started (0) 16
[    0.061442] [bcm2709_secondary_init] enter cpu:3
[    0.061462] CPU3: update cpu_capacity 1024
[    0.061467] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.061528] Brought up 4 CPUs
[    0.061627] SMP: Total of 4 processors activated (153.60
BogoMIPS).
[    0.061656] CPU: All CPU(s) started in HYP mode.
[    0.061682] CPU: Virtualization extensions available.
[    0.062314] devtmpfs: initialized
[    0.072946] VFP support v0.3: implementor 41 architecture 3 part
40 variant 3 rev 4
[    0.073313] clocksource: jiffies: mask: 0xffffffff max_cycles:
0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.074055] pinctrl core: initialized pinctrl subsystem
[    0.074602] NET: Registered protocol family 16
[    0.079711] DMA: preallocated 4096 KiB pool for atomic coherent
allocations
[    0.086830] bcm2709: Mini UART enabled
[    0.086890] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4
watchpoint registers.
[    0.086937] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.087110] Serial: AMBA PL011 UART driver
[    0.087264] uart-pl011 3f201000.uart: could not find pctldev for
node /soc/gpio@7e200000/uart0_pins, deferring probe
[    0.087464] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.150273] bcm2835-dma 3f007000.dma: DMA legacy API manager at
f3007000, dmachans=0x1
[    0.150899] SCSI subsystem initialized
[    0.151102] usbcore: registered new interface driver usbfs
[    0.151201] usbcore: registered new interface driver hub
[    0.151312] usbcore: registered new device driver usb
[    0.157747] raspberrypi-firmware soc:firmware: Attached to
firmware from 2016-11-25 16:05
[    0.184829] clocksource: Switched to clocksource arch_sys_counter
[    0.230483] FS-Cache: Loaded
[    0.230782] CacheFiles: Loaded
[    0.242888] NET: Registered protocol family 2
[    0.243743] TCP established hash table entries: 8192 (order: 3,
32768 bytes)
[    0.243881] TCP bind hash table entries: 8192 (order: 4, 65536
bytes)
[    0.244091] TCP: Hash tables configured (established 8192 bind
8192)
[    0.244206] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.244273] UDP-Lite hash table entries: 512 (order: 2, 16384
bytes)
[    0.244522] NET: Registered protocol family 1
[    0.244891] RPC: Registered named UNIX socket transport module.
[    0.244923] RPC: Registered udp transport module.
[    0.244951] RPC: Registered tcp transport module.
[    0.244978] RPC: Registered tcp NFSv4.1 backchannel transport
module.
[    0.499843] hw perfevents: enabled with armv7_cortex_a7 PMU
driver, 7 counters available
[    0.501237] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.514403] VFS: Disk quotas dquot_6.6.0
[    0.514744] VFS: Dquot-cache hash table entries: 1024 (order 0,
4096 bytes)
[    0.516650] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.517153] FS-Cache: Netfs 'nfs' registered for caching
[    0.518056] NFS: Registering the id_resolver key type
[    0.518128] Key type id_resolver registered
[    0.518156] Key type id_legacy registered
[    0.519889] aufs 4.4-20160912
[    0.521345] Block layer SCSI generic (bsg) driver version 0.4
loaded (major 252)
[    0.521501] io scheduler noop registered
[    0.521537] io scheduler deadline registered
[    0.521605] io scheduler cfq registered (default)
[    0.524215] BCM2708FB: allocated DMA memory fdc10000
[    0.524263] BCM2708FB: allocated DMA channel 0 @ f3007000
[    0.529430] Console: switching to colour frame buffer device 82x26
[    0.607836] Serial: 8250/16550 driver, 1 ports, IRQ sharing
disabled
[    0.610911] console [ttyS0] disabled
[    0.612602] 3f215040.uart: ttyS0 at MMIO 0x3f215040 (irq = 59,
base_baud = 31250000) is a 16550
[    1.351198] console [ttyS0] enabled
[    2.342984] bcm2835-rng 3f104000.rng: hwrng registered
[    2.350152] vc-cma: Videocore CMA driver
[    2.355881] vc-cma: vc_cma_base      = 0x00000000
[    2.362328] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
[    2.369453] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
[    2.376750] vc-mem: phys_addr:0x00000000 mem_base=0x3ea00000
mem_size:0x3f000000(1008 MiB)
[    2.402945] brd: module loaded
[    2.416363] loop: module loaded
[    2.421958] vchiq: vchiq_init_state: slot_zero = 0xbdc80000,
is_master = 0
[    2.431945] Loading iSCSI transport class v2.0-870.
[    2.439091] tun: Universal TUN/TAP device driver, 1.6
[    2.445880] tun: (C) 1999-2004 Max Krasnyansky <maxk qualcomm com>
[    2.454093] usbcore: registered new interface driver smsc95xx
[    2.461584] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.669293] Core Release: 2.80a
[    2.674094] Setting default values for core params
[    2.680641] Finished setting default values for core params
[    2.888300] Using Buffer DMA mode
[    2.893340] Periodic Transfer Interrupt Enhancement - disabled
[    2.900980] Multiprocessor Interrupt Enhancement - disabled
[    2.908339] OTG VER PARAM: 0, OTG VER FLAG: 0
[    2.914428] Dedicated Tx FIFOs mode
[    2.919865] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers:
virt = 0xbdc04000 dma = 0xfdc04000 len=9024
[    2.933170] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    2.964168] dwc_otg: Microframe scheduler enabled
[    2.964229] WARN::hcd_init_fiq:413: FIQ on core 1 at 0x80481ef8
[    2.971952] WARN::hcd_init_fiq:414: FIQ ASM at 0x80482258 length
36
[    2.979974] WARN::hcd_init_fiq:439: MPHI regs_base at 0xbe87e000
[    2.987783] dwc_otg 3f980000.usb: DWC OTG Controller
[    2.994534] dwc_otg 3f980000.usb: new USB bus registered, assigned
bus number 1
[    3.003694] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[    3.011068] Init: Port Power? op_state=1
[    3.016708] Init: Power Port (0)
[    3.021786] usb usb1: New USB device found, idVendor=1d6b,
idProduct=0002
[    3.030361] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[    3.039371] usb usb1: Product: DWC OTG Controller
[    3.045792] usb usb1: Manufacturer: Linux 4.4.48 dwc_otg_hcd
[    3.053178] usb usb1: SerialNumber: 3f980000.usb
[    3.060187] hub 1-0:1.0: USB hub found
[    3.065630] hub 1-0:1.0: 1 port detected
[    3.071726] dwc_otg: FIQ enabled
[    3.071735] dwc_otg: NAK holdoff enabled
[    3.071742] dwc_otg: FIQ split-transaction FSM enabled
[    3.071772] Module dwc_common_port init
[    3.072020] usbcore: registered new interface driver usb-storage
[    3.079955] mousedev: PS/2 mouse device common for all mice
[    3.087879] bcm2835-cpufreq: min=600000 max=1200000
[    3.094683] sdhci: Secure Digital Host Controller Interface driver
[    3.102565] sdhci: Copyright(c) Pierre Ossman
[    3.108808] sdhost: log_buf @ bdc07000 (fdc07000)
[    3.174858] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    3.184314] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    3.191851] mmc-bcm2835 3f300000.mmc: DMA channel allocated
[    3.254943] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.262666] ledtrig-cpu: registered to indicate activity on CPUs
[    3.270471] Indeed it is in host mode hprt0 = 00021501
[    3.295045] hidraw: raw HID events driver (C) Jiri Kosina
[    3.302346] usbcore: registered new interface driver usbhid
[    3.309643] usbhid: USB HID core driver
[    3.316276] nf_conntrack version 0.5.0 (15499 buckets, 61996 max)
[    3.337759] ip_tables: (C) 2000-2006 Netfilter Core Team
[    3.344991] Initializing XFRM netlink socket
[    3.347127] mmc0: host does not support reading read-only switch,
assuming write-enable
[    3.350467] mmc0: new high speed SDXC card at address aaaa
[    3.351173] mmcblk0: mmc0:aaaa SL64G 59.5 GiB
[    3.368775]  mmcblk0: p1 p2 p3 p4 < p5 p6 >
[    3.383344] NET: Registered protocol family 10
[    3.386935] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    3.388488] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    3.390042] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    3.392838] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    3.419647] NET: Registered protocol family 17
[    3.425795] bridge: automatic filtering via arp/ip/ip6tables has
been deprecated. Update your scripts to load br_netfilter if you need
this.
[    3.441979] Key type dns_resolver registered
[    3.448408] Registering SWP/SWPB emulation handler
[    3.454874] usb 1-1: new high-speed USB device number 2 using
dwc_otg
[    3.455014] Indeed it is in host mode hprt0 = 00001101
[    3.470876] registered taskstats version 1
[    3.476866] vc-sm: Videocore shared memory driver
[    3.483289] [vc_sm_connected_init]: start
[    3.483387] mmc1: new high speed SDIO card at address 0001
[    3.505074] vc_vchi_sm_init: failed to open VCHI service (-1)
[    3.510815] [vc_sm_connected_init]: failed to initialize shared
memory service
[    3.521606] [vc_sm_connected_init]: end - returning -1
[    3.529758] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 87,
base_baud = 0) is a PL011 rev2
[    3.542381] of_cfs_init
[    3.546538] of_cfs_init: OK
[    3.556218] Freeing unused kernel memory: 3524K (808cf000 -
80c40000)
[    3.655220] usb 1-1: New USB device found, idVendor=0424,
idProduct=9514
[    3.664274] usb 1-1: New USB device strings: Mfr=0, Product=0,
SerialNumber=0
[    3.674620] hub 1-1:1.0: USB hub found
[    3.680578] hub 1-1:1.0: 5 ports detected
[    3.964918] usb 1-1.1: new high-speed USB device number 3 using
dwc_otg
[    4.085270] usb 1-1.1: New USB device found, idVendor=0424,
idProduct=ec00
[    4.094280] usb 1-1.1: New USB device strings: Mfr=0, Product=0,
SerialNumber=0
[    4.104314] random: udevd: uninitialized urandom read (16 bytes
read, 65 bits of entropy available)
[    4.107092] smsc95xx v1.0.4
[    4.110606] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.110869] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.110981] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.111393] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.111799] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.112199] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.113772] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.114238] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.114788] random: udevadm: uninitialized urandom read (16 bytes
read, 66 bits of entropy available)
[    4.168446] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-
3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:8e:10:ef
[    4.244874] usb 1-1.2: new high-speed USB device number 4 using
dwc_otg
[    4.346726] usb 1-1.2: New USB device found, idVendor=2109,
idProduct=2813
[    4.356346] usb 1-1.2: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[    4.366269] usb 1-1.2: Product: USB2.0 Hub
[    4.372809] usb 1-1.2: Manufacturer: VIA Labs, Inc.
[    4.381150] hub 1-1.2:1.0: USB hub found
[    4.387810] hub 1-1.2:1.0: 4 ports detected
[    4.684914] usb 1-1.2.1: new high-speed USB device number 5 using
dwc_otg
[    4.806707] usb 1-1.2.1: New USB device found, idVendor=2109,
idProduct=2813
[    4.816319] usb 1-1.2.1: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[    4.828320] usb 1-1.2.1: Product: USB2.0 Hub
[    4.834803] usb 1-1.2.1: Manufacturer: VIA Labs, Inc.
[    4.844192] hub 1-1.2.1:1.0: USB hub found
[    4.851478] hub 1-1.2.1:1.0: 4 ports detected
[    5.071690] EXT4-fs (mmcblk0p2): mounted filesystem with ordered
data mode. Opts: (null)
[    5.122129] EXT4-fs (mmcblk0p5): mounted filesystem with ordered
data mode. Opts: (null)
[    5.440757] systemd[1]: System time before build time, advancing
clock.
[    5.495438] systemd[1]: systemd 230 running in system mode. (-PAM
-AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP
-GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN)
[    5.520088] systemd[1]: Detected architecture arm.
[    5.558280] systemd[1]: Set hostname to <raspberrypi3>.
[    5.915955] systemd[1]: brcm43438.service: Cannot add dependency
job, ignoring: Unit brcm43438.service is masked.
[    5.934618] systemd[1]: Listening on Syslog Socket.
[    5.965144] systemd[1]: Listening on udev Kernel Socket.
[    6.013951] systemd[1]: Reached target Swap.
[    6.036703] systemd[1]: Created slice User and Session Slice.
[    6.065247] systemd[1]: Started Forward Password Requests to Wall
Directory Watch.
[    6.095032] systemd[1]: Reached target Remote File Systems.
[    6.125239] systemd[1]: Listening on Journal Socket.
[    6.155232] systemd[1]: Listening on udev Control Socket.
[    6.185135] systemd[1]: Listening on /dev/initctl Compatibility
Named Pipe.
[    6.215100] systemd[1]: Listening on Journal Socket (/dev/log).
[    6.245643] systemd[1]: Created slice System Slice.
[    6.275737] systemd[1]: Created slice system-getty.slice.
[    6.335211] systemd[1]: Mounting POSIX Message Queue File
System...
[    6.354647] systemd[1]: Starting Create list of required static
device nodes for the current kernel...
[    6.397755] systemd[1]: Starting Apply Kernel Variables...
[    6.428238] systemd[1]: Mounting Temporary Directory...
[    6.441175] systemd[1]: Created slice system-resin\x2dinfo.slice.
[    6.475808] systemd[1]: Created slice system-
serial\x2dgetty.slice.
[    6.535185] systemd[1]: Mounting Configuration File System...
[    6.567876] systemd[1]: Starting Journal Service...
[    6.598113] systemd[1]: Mounting Debug File System...
[    6.627682] systemd[1]: Starting Remount Root and Kernel File
Systems...
[    6.642643] systemd[1]: Reached target Slices.
[    6.652408] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    6.678043] systemd[1]: Starting Setup Virtual Console...
[    6.715769] systemd[1]: Mounted Configuration File System.
[    6.745141] systemd[1]: Mounted POSIX Message Queue File System.
[    6.775074] systemd[1]: Mounted Debug File System.
[    6.805059] systemd[1]: Mounted Temporary Directory.
[    6.835426] systemd[1]: Started Journal Service.
[    7.460913] random: nonblocking pool is initialized
[    7.511711] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835
watchdog timer
[    7.521140] bcm2708_i2c 3f804000.i2c: BSC1 Controller at
0x3f804000 (irq 83) (baudrate 100000)
[    7.618164] gpiomem-bcm2835 3f200000.gpiomem: Initialised:
Registers at 0x3f200000
[    7.924559] usbcore: registered new interface driver brcmfmac
[    8.071455] brcmfmac: brcmf_c_preinit_dcmds: Firmware version =
wl0: Aug 29 2016 20:48:16 version 7.45.41.26 (r640327) FWID 01-
4527cfab
[    8.115653] brcmfmac: brcmf_cfg80211_reg_notifier: not a ISO3166
code
[    8.171708] brcmfmac: brcmf_cfg80211_reg_notifier: not a ISO3166
code
[    8.180085] cfg80211: World regulatory domain updated:
[    8.187070] cfg80211:  DFS Master region: unset
[    8.191563] cfg80211:   (start_freq - end_freq @ bandwidth),
(max_antenna_gain, max_eirp), (dfs_cac_time)
[    8.206654] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz),
(N/A, 2000 mBm), (N/A)
[    8.218500] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz,
92000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[    8.231899] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz),
(N/A, 2000 mBm), (N/A)
[    8.244070] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz,
160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[    8.257930] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz,
160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[    8.272011] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz),
(N/A, 2000 mBm), (0 s)
[    8.284778] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz),
(N/A, 2000 mBm), (N/A)
[    8.297509] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000
KHz), (N/A, 0 mBm), (N/A)
[    8.728734] FAT-fs (mmcblk0p1): Volume was not properly unmounted.
Some data may be corrupt. Please run fsck.
[   11.034879] usb 1-1.2.1.4: new high-speed USB device number 6
using dwc_otg
[   11.163270] usb 1-1.2.1.4: New USB device found, idVendor=1bc7,
idProduct=1010
[   11.173591] usb 1-1.2.1.4: New USB device strings: Mfr=3,
Product=2, SerialNumber=0
[   11.186183] usb 1-1.2.1.4: Product: Telit HS-USB Modem
[   11.193822] usb 1-1.2.1.4: Manufacturer: Telit Wireless Solutions
[   11.298375] usbcore: registered new interface driver usbserial
[   11.306974] usbcore: registered new interface driver
usbserial_generic
[   11.310874] i2c /dev entries driver
[   11.322683] usbserial: USB Serial support registered for generic
[   11.457307] usbcore: registered new interface driver option
[   11.465653] usbserial: USB Serial support registered for GSM modem
(1-port)
[   11.476030] option 1-1.2.1.4:1.0: GSM modem (1-port) converter
detected
[   11.485725] usb 1-1.2.1.4: GSM modem (1-port) converter now
attached to ttyUSB0
[   11.495740] option 1-1.2.1.4:1.1: GSM modem (1-port) converter
detected
[   11.505452] usb 1-1.2.1.4: GSM modem (1-port) converter now
attached to ttyUSB1
[   11.515829] option 1-1.2.1.4:1.2: GSM modem (1-port) converter
detected
[   11.525445] usb 1-1.2.1.4: GSM modem (1-port) converter now
attached to ttyUSB2
[   11.535416] option 1-1.2.1.4:1.3: GSM modem (1-port) converter
detected
[   11.545109] usb 1-1.2.1.4: GSM modem (1-port) converter now
attached to ttyUSB3
[   11.850674] brcmfmac: power management disabled
[   12.755171] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   12.817140] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of
remote wakeup
[   12.826826] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   12.859391] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   12.907950] brcmfmac: brcmf_add_if: ERROR: netdev:wlan0 already
exists
[   12.916649] brcmfmac: brcmf_add_if: ignore IF event
[   12.925860] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   12.933950] brcmfmac: power management disabled
[   13.461267] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   13.469380] brcmfmac: power management disabled
[   14.036469] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   27.920076] PPP generic driver version 2.4.2
[   27.998212] PPP BSD Compression module registered
[   28.043248] PPP Deflate Compression module registered
[  111.945594] EXT4-fs (mmcblk0p6): mounted filesystem with ordered
data mode. Opts: (null)
[  113.227019] Bridge firewalling registered
[  113.797830] IPv6: ADDRCONF(NETDEV_UP): docker0: link is not ready
[  113.993171] aufs au_opts_verify:1597:docker[903]: dirperm1 breaks
the protection by the permission bits on the lower branch
[  115.797146] EXT4-fs (mmcblk0p6): Unrecognized mount option
"mode=755" or missing value
[  116.533554] systemd-udevd[49]: starting version 215
[  116.957152] systemd-journald[41]: Received request to flush
runtime journal from PID 1
[  127.553331] uart-pl011 3f201000.uart: no DMA platform data
_______________________________________________
networkmanager-list mailing list
networkmanager-list gnome org
https://mail.gnome.org/mailman/listinfo/networkmanager-list



[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]