On Mon, 2017-04-03 at 11:15 -0400, Liam Monahan wrote:
> 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.

Ok, if the device cannot be seen in 'mmcli' that means ModemManager
didn't find it either.  MM must see it, because MM presents the modem
to NetworkManager.

If MM doesn't see it, then there are two possibilities:

(a) ModemManager bug with device detection; here we need boot-time logs
of ModemManager with debug log level to see if MM is told about the
device by the kernel/udev, and what it does with that device.  To do
this, edit /usr/lib/systemd/system/ModemManager.service and change the
ExecStart= line to add "--log-level=debug" and reboot the machine until
the problem occurs.  Then grab ModemManager journal output so we can
debug.

(b) kernel driver problems; usually due to your USB Host Controller
driver rather than a modem driver itself; there are sometimes issues
with device enumeration and specific USB chipsets.  'dmesg' output
usually shows this as the device simply not being enumerated on boot-up 
and not showing up in 'lsusb'.  Unfortunately, can take some pretty
heavy kernel debugging.

I see this is a Raspberry Pi 3 using dwc_otg as the USB host controller
driver.  Is the modem behind that USB hub I see being enumerated?  Have
you tried using a different hub to see if that makes a difference?  Is
the hub powered?

Dan

> # 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:0
> 001: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 <d...@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 (and...@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
> 
> 
_______________________________________________
networkmanager-list mailing list
networkmanager-list@gnome.org
https://mail.gnome.org/mailman/listinfo/networkmanager-list

Reply via email to