Armadilloフォーラム

LTEのデバイスファイルがttyACM0 -> ttyACM1 に変更される

user_2018-02-14

2018年4月18日 16時29分

LTEのデバイスファイルがttyACM0 -> ttyACM1 に変更されていると思われる事象が発生しているのですが、
原因について、ご教授いただけないでしょうか。

# tail /va/log/syslog
18-04-18 06:04:46 kern info kernel: usb 2-1: USB disconnect, device number 2
2018-04-18 06:04:46 kern info kernel: cdc_ether 2-1:1.0 usb1: unregister 'cdc_ether' usb-ci_hdrc.1-1, CDC Ethernet Device
2018-04-18 06:04:46 daemon info avahi-daemon[1395]: Interface usb1.IPv4 no longer relevant for mDNS.
2018-04-18 06:04:46 daemon info avahi-daemon[1395]: Leaving mDNS multicast group on interface usb1.IPv4 with address 192.168.15.194.
2018-04-18 06:04:46 daemon err dhclient: receive_packet failed on usb1: Network is down
2018-04-18 06:04:46 daemon warning avahi-daemon[1395]: IP_DROP_MEMBERSHIP failed: No such device
2018-04-18 06:04:46 daemon info avahi-daemon[1395]: Withdrawing address record for 192.168.15.194 on usb1.
2018-04-18 06:04:46 daemon info avahi-daemon[1395]: Withdrawing workstation service for usb1.
2018-04-18 06:04:46 daemon info ModemManager[1221]: (net/usb1): released by modem /sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1
2018-04-18 06:04:46 daemon err NetworkManager[1212]: [1523999086.575744] [platform/nm-linux-platform.c:1714] add_object(): Netlink error adding 0.0.0.0/0 via 192.168.15.1 dev 3 metric 1024 mss 0 src user: Unspecific failure
2018-04-18 06:04:46 daemon err NetworkManager[1212]: [1523999086.579107] [platform/nm-linux-platform.c:1714] add_object(): Netlink error adding 192.168.15.1/32 via 0.0.0.0 dev 3 metric 1024 mss 0 src user: No such device
2018-04-18 06:04:46 daemon err NetworkManager[1212]: [1523999086.579492] [platform/nm-linux-platform.c:1714] add_object(): Netlink error adding 0.0.0.0/0 via 192.168.15.1 dev 3 metric 1024 mss 0 src user: Unspecific failure
2018-04-18 06:04:46 daemon err NetworkManager[1212]: [1523999086.579736] [nm-policy.c:693] update_ip4_routing(): Failed to set default route.
2018-04-18 06:04:46 daemon info NetworkManager[1212]: devices removed (path: /sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1/2-1:1.0/net/usb1, iface: usb1)
2018-04-18 06:04:46 daemon info NetworkManager[1212]: inet default table main
2018-04-18 06:04:46 daemon info NetworkManager[1212]: priority 0x400 protocol static
2018-04-18 06:04:46 daemon info NetworkManager[1212]: nexthop via 192.168.15.1 dev 3
2018-04-18 06:04:46 daemon info NetworkManager[1212]: inet 192.168.15.1 table main
2018-04-18 06:04:46 daemon info NetworkManager[1212]: priority 0x400 protocol static
2018-04-18 06:04:46 daemon info NetworkManager[1212]: nexthop dev 3
2018-04-18 06:04:46 daemon info NetworkManager[1212]: inet default table main
2018-04-18 06:04:46 daemon info NetworkManager[1212]: priority 0x400 protocol static
2018-04-18 06:04:46 daemon info NetworkManager[1212]: nexthop via 192.168.15.1 dev 3
2018-04-18 06:04:46 daemon info ModemManager[1221]: (tty/ttyACM0): released by modem /sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1
2018-04-18 06:04:46 daemon info NetworkManager[1212]: (ttyACM0): device state change: activated -> unmanaged (reason 'removed') [100 10 36]
2018-04-18 06:04:46 daemon info NetworkManager[1212]: (ttyACM0): deactivating device (reason 'removed') [36]
2018-04-18 06:04:46 daemon info NetworkManager[1212]: (usb1): canceled DHCP transaction, DHCP client pid 11995
2018-04-18 06:04:46 daemon notice dbus[1401]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
2018-04-18 06:04:46 daemon warning NetworkManager[1212]: (ttyACM0) 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
2018-04-18 06:04:46 daemon info systemd[1]: Starting Network Manager Script Dispatcher Service...
2018-04-18 06:04:46 daemon notice dbus[1401]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
2018-04-18 06:04:46 daemon info systemd[1]: Started Network Manager Script Dispatcher Service.
2018-04-18 06:04:46 daemon notice nm-dispatcher: Dispatching action 'down' for ttyACM0
2018-04-18 06:04:47 user notice fu_resolvconf_modify_check_main.sh: [INFO] /etc/resovl.conf changed.
2018-04-18 06:04:58 kern info kernel: usb 2-1: new high-speed USB device number 3 using ci_hdrc
2018-04-18 06:04:58 kern info kernel: cdc_ether 2-1:1.0 usb1: register 'cdc_ether' at usb-ci_hdrc.1-1, CDC Ethernet Device, 02:80:70:01:07:70
2018-04-18 06:04:58 kern err kernel: cdc_acm 2-1:1.2: This device cannot do calls on its own. It is not a modem.
2018-04-18 06:04:58 kern info kernel: cdc_acm 2-1:1.2: ttyACM1: USB ACM device
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): carrier is OFF
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): new Ethernet device (driver: 'cdc_ether' ifindex: 12)
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): exported as /org/freedesktop/NetworkManager/Devices/12
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): link connected
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): preparing device
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): created default wired connection 'Wired connection 2'
2018-04-18 06:04:58 daemon info NetworkManager[1212]: devices added (path: /sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1/2-1:1.0/net/usb1, iface: usb1)
2018-04-18 06:04:58 daemon info NetworkManager[1212]: device added (path: /sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1/2-1:1.0/net/usb1, iface: usb1): no ifupdown configuration found.
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
2018-04-18 06:04:58 daemon info NetworkManager[1212]: Auto-activating connection 'Wired connection 2'.
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): link disconnected
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): device state change: disconnected -> unavailable (reason 'carrier-changed') [30 20 40]
2018-04-18 06:04:58 daemon info NetworkManager[1212]: (usb1): deactivating device (reason 'carrier-changed') [40]
2018-04-18 06:04:59 daemon warning NetworkManager[1212]: Failed to activate 'Wired connection 2': Activation failed because dependencies failed.
2018-04-18 06:05:01 daemon info NetworkManager[1212]: (usb1): link connected
2018-04-18 06:05:01 daemon info NetworkManager[1212]: (usb1): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Auto-activating connection 'Wired connection 2'.
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) starting connection 'Wired connection 2'
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 1 of 5 (Device Prepare) scheduled...
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 1 of 5 (Device Prepare) started...
2018-04-18 06:05:01 daemon info NetworkManager[1212]: (usb1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 2 of 5 (Device Configure) scheduled...
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 1 of 5 (Device Prepare) complete.
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 2 of 5 (Device Configure) starting...
2018-04-18 06:05:01 daemon info NetworkManager[1212]: (usb1): device state change: prepare -> config (reason 'none') [40 50 0]
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 2 of 5 (Device Configure) successful.
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 3 of 5 (IP Configure Start) scheduled.
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 2 of 5 (Device Configure) complete.
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 3 of 5 (IP Configure Start) started...
2018-04-18 06:05:01 daemon info NetworkManager[1212]: (usb1): device state change: config -> ip-config (reason 'none') [50 70 0]
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Beginning DHCPv4 transaction (timeout in 45 seconds)
2018-04-18 06:05:01 daemon info NetworkManager[1212]: dhclient started with pid 4636
2018-04-18 06:05:01 daemon info NetworkManager[1212]: Activation (usb1) Stage 3 of 5 (IP Configure Start) complete.
2018-04-18 06:05:01 daemon info NetworkManager[1212]: (usb1): DHCPv4 state changed nbi -> preinit
2018-04-18 06:05:01 daemon info dhclient: DHCPDISCOVER on usb1 to 255.255.255.255 port 67 interval 3
2018-04-18 06:05:02 daemon info ModemManager[1221]: Creating modem with plugin 'Cinterion ELS' and '2' ports
2018-04-18 06:05:02 daemon info ModemManager[1221]: Modem for device at '/sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1' successfully created
2018-04-18 06:05:02 daemon info avahi-daemon[1395]: Joining mDNS multicast group on interface usb1.IPv6 with address fe80::80:70ff:fe01:770.
2018-04-18 06:05:02 daemon info avahi-daemon[1395]: New relevant interface usb1.IPv6 for mDNS.
2018-04-18 06:05:02 daemon info avahi-daemon[1395]: Registering new address record for fe80::80:70ff:fe01:770 on usb1.*.
2018-04-18 06:05:04 daemon info dhclient: DHCPREQUEST on usb1 to 255.255.255.255 port 67
2018-04-18 06:05:04 daemon info dhclient: DHCPOFFER from 192.168.15.1
2018-04-18 06:05:04 daemon info dhclient: DHCPACK from 192.168.15.1
2018-04-18 06:05:04 daemon info NetworkManager[1212]: (usb1): DHCPv4 state changed preinit -> bound
2018-04-18 06:05:04 daemon info NetworkManager[1212]: address 192.168.15.194
2018-04-18 06:05:04 daemon info NetworkManager[1212]: plen 24 (255.255.255.0)
2018-04-18 06:05:04 daemon info NetworkManager[1212]: gateway 192.168.15.1
2018-04-18 06:05:04 daemon info NetworkManager[1212]: server identifier 192.168.15.1
2018-04-18 06:05:04 daemon info NetworkManager[1212]: lease time 43200
2018-04-18 06:05:04 daemon info NetworkManager[1212]: hostname 'armadillo'
2018-04-18 06:05:04 daemon info NetworkManager[1212]: nameserver '192.168.15.1'
2018-04-18 06:05:04 daemon info NetworkManager[1212]: domain name 'lan'
2018-04-18 06:05:04 daemon info NetworkManager[1212]: Activation (usb1) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
2018-04-18 06:05:04 daemon info NetworkManager[1212]: Activation (usb1) Stage 5 of 5 (IPv4 Commit) started...
2018-04-18 06:05:04 daemon info avahi-daemon[1395]: Joining mDNS multicast group on interface usb1.IPv4 with address 192.168.15.194.
2018-04-18 06:05:04 daemon info avahi-daemon[1395]: New relevant interface usb1.IPv4 for mDNS.
2018-04-18 06:05:04 daemon info avahi-daemon[1395]: Registering new address record for 192.168.15.194 on usb1.IPv4.
2018-04-18 06:05:04 daemon info dhclient: bound to 192.168.15.194 -- renewal in 20895 seconds.
2018-04-18 06:05:04 daemon info NetworkManager[1212]: (usb1): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
2018-04-18 06:05:04 daemon info NetworkManager[1212]: Activation (usb1) Stage 5 of 5 (IPv4 Commit) complete.
2018-04-18 06:05:04 daemon info NetworkManager[1212]: (usb1): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
2018-04-18 06:05:04 daemon info NetworkManager[1212]: (usb1): device state change: secondaries -> activated (reason 'none') [90 100 0]
2018-04-18 06:05:04 daemon info NetworkManager[1212]: Policy set 'Wired connection 2' (usb1) as default for IPv4 routing and DNS.
2018-04-18 06:05:04 daemon info NetworkManager[1212]: Activation (usb1) successful, device activated.
2018-04-18 06:05:04 daemon notice dbus[1401]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
2018-04-18 06:05:04 daemon info systemd[1]: Starting Network Manager Script Dispatcher Service...
2018-04-18 06:05:04 daemon notice dbus[1401]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
2018-04-18 06:05:04 daemon info systemd[1]: Started Network Manager Script Dispatcher Service.
2018-04-18 06:05:04 daemon notice nm-dispatcher: Dispatching action 'up' for usb1
2018-04-18 06:05:04 daemon info systemd[1]: Reloading OpenBSD Secure Shell server.
2018-04-18 06:05:04 daemon info systemd[1]: Reloaded OpenBSD Secure Shell server.
2018-04-18 06:05:04 daemon info nm-dispatcher[5169]: SIOCDELRT: No such process
2018-04-18 06:05:04 daemon info systemd[1]: Reloading OpenBSD Secure Shell server.
2018-04-18 06:05:05 daemon info systemd[1]: Reloaded OpenBSD Secure Shell server.
2018-04-18 06:05:05 daemon info nm-dispatcher[5169]: SIOCDELRT: No such process
2018-04-18 06:05:05 daemon info nm-dispatcher[5169]: SIOCADDRT: File exists
2018-04-18 06:05:05 daemon info nm-dispatcher[5169]: run-parts: /etc/network/if-up.d/static-routes exited with return code 7
2018-04-18 06:05:05 daemon warning nm-dispatcher: Script '/etc/NetworkManager/dispatcher.d/01ifupdown' exited with error status 1.
2018-04-18 06:05:05 user notice fu_resolvconf_modify_check_main.sh: [INFO] /etc/resovl.conf changed.
2018-04-18 06:05:05 daemon warning NetworkManager[1212]: (18) 01ifupdown failed (failed): Script '/etc/NetworkManager/dispatcher.d/01ifupdown' exited with error status 1.
2018-04-18 06:05:07 syslog warning fu_osaprequest_check.py[4250]: request not found. osapservice restart left cnt[2]
2018-04-18 06:05:22 daemon warning ModemManager[1221]: (ttyACM1) response array is not empty when using cached reply, cleaning up 13 bytes
2018-04-18 06:05:24 daemon info ModemManager[1221]: Modem: state changed (unknown -> disabled)
2018-04-18 06:05:24 daemon warning NetworkManager[1212]: (ttyACM1): failed to look up interface index
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (usb1): device state change: activated -> unmanaged (reason 'removed') [100 10 36]
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (usb1): deactivating device (reason 'removed') [36]
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (usb1): canceled DHCP transaction, DHCP client pid 4636
2018-04-18 06:05:24 daemon info avahi-daemon[1395]: Withdrawing address record for fe80::80:70ff:fe01:770 on usb1.
2018-04-18 06:05:24 daemon info avahi-daemon[1395]: Leaving mDNS multicast group on interface usb1.IPv6 with address fe80::80:70ff:fe01:770.
2018-04-18 06:05:24 daemon info avahi-daemon[1395]: Interface usb1.IPv6 no longer relevant for mDNS.
2018-04-18 06:05:24 daemon info avahi-daemon[1395]: Withdrawing address record for 192.168.15.194 on usb1.
2018-04-18 06:05:24 daemon info avahi-daemon[1395]: Leaving mDNS multicast group on interface usb1.IPv4 with address 192.168.15.194.
2018-04-18 06:05:24 daemon info avahi-daemon[1395]: Interface usb1.IPv4 no longer relevant for mDNS.
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (usb1): link disconnected
2018-04-18 06:05:24 kern info kernel: IPv6: ADDRCONF(NETDEV_UP): usb1: link is not ready
2018-04-18 06:05:24 daemon notice dbus[1401]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
2018-04-18 06:05:24 daemon info systemd[1]: Starting Network Manager Script Dispatcher Service...
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (ttyACM1): modem state changed, 'disabled' --> 'enabling' (reason: user preference)
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (ttyACM1): new Broadband device (driver: 'cdc_acm, cdc_ether' ifindex: 0)
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (ttyACM1): exported as /org/freedesktop/NetworkManager/Devices/13
2018-04-18 06:05:24 daemon info NetworkManager[1212]: (ttyACM1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
2018-04-18 06:05:25 daemon info ModemManager[1221]: Modem /org/freedesktop/ModemManager1/Modem/1: state changed (disabled -> enabling)
2018-04-18 06:05:25 daemon info NetworkManager[1212]: (ttyACM1): preparing device
2018-04-18 06:05:25 daemon info NetworkManager[1212]: (ttyACM1): modem state 'enabling'
2018-04-18 06:05:25 daemon info NetworkManager[1212]: (ttyACM1): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
2018-04-18 06:05:25 daemon notice dbus[1401]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
2018-04-18 06:05:25 daemon info systemd[1]: Started Network Manager Script Dispatcher Service.
2018-04-18 06:05:25 daemon notice nm-dispatcher: Dispatching action 'down' for usb1
2018-04-18 06:05:25 user notice fu_resolvconf_modify_check_main.sh: [INFO] /etc/resovl.conf changed.
2018-04-18 06:05:26 daemon info ModemManager[1221]: Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP Registration state changed (unknown -> registering)
2018-04-18 06:05:26 daemon info ModemManager[1221]: Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP Registration state changed (registering -> home)
2018-04-18 06:05:27 daemon info ModemManager[1221]: Modem /org/freedesktop/ModemManager1/Modem/1: state changed (enabling -> registered)
2018-04-18 06:05:27 daemon info NetworkManager[1212]: (ttyACM1): modem state changed, 'enabling' --> 'registered' (reason: user-requested)

# mmcli -m 0
error: couldn't find modem at '/org/freedesktop/ModemManager1/Modem/0'

# mmcli -m 1

/org/freedesktop/ModemManager1/Modem/1 (device id '930f74bd759f2ff25fc4386bb7af06fac5094fc5')
-------------------------
Hardware | manufacturer: 'Cinterion'
| model: 'ELS31-J'
| revision: 'REVISION 4.3.2.1b'
| supported: 'gsm-umts, lte'
| current: 'gsm-umts, lte'
| equipment id: '356778070010773'
-------------------------
System | device: '/sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1'
| drivers: 'cdc_acm, cdc_ether'
| plugin: 'Cinterion ELS'
| primary port: 'ttyACM1'
| ports: 'ttyACM1 (at), usb1 (net)'
-------------------------
Numbers | own : '*******************'
-------------------------
Status | lock: 'none'
| unlock retries: 'unknown'
| state: 'registered'
| power state: 'on'
| access tech: 'lte'
| signal quality: '100' (recent)
-------------------------
Modes | supported: 'allowed: 4g; preferred: none'
| current: 'allowed: 4g; preferred: none'
-------------------------
Bands | supported: 'unknown'
| current: 'unknown'
-------------------------
IP | supported: 'none'
-------------------------
3GPP | imei: '*******************************'
| enabled locks: 'none'
| operator id: 'unknown'
| operator name: 'unknown'
| subscription: 'unknown'
| registration: 'home'
-------------------------
SIM | path: '/org/freedesktop/ModemManager1/SIM/1'

-------------------------
Bearers | paths: 'none'