Armadilloフォーラム

特定の処理をするとLTE接続が切断され、その後再接続されない

mcrest_kozawa

2021年10月20日 15時41分

2点不可思議な現象が出ます。

★前提条件
LTEは閉域ネットワークでインターネットには抜けません。
閉域ネットワーク内に専用DNSサーバがあり、IPアドレス付与時にDNSサーバ情報も付与されます。
閉域ネットワーク内の専用サーバとの通信を行うために専用DNSサーバでの名前解決が必須です。

★1点目
LTE接続設定後
nmcli connection modify gsm-ttyACM0 ipv4.ignore-auto-dns yes
nmcli connection modify gsm-ttyACM0 +ipv4.dns "<特定のDNSサーバ>"

こちらのコマンド実行すると、しばらくするとLTEが切断され、その後再接続されなくなります。

その際のログを抜粋していますので記載します。
--
root@armadillo:~# nmcli connection down gsm-ttyACM0
root@armadillo:~# nmcli connection up gsm-ttyACM0
Error: Connection activation failed.

Oct 20 15:29:01 armadillo NetworkManager[949]: Activation (ttyACM0) starting connection 'gsm-ttyACM0'
Oct 20 15:29:01 armadillo NetworkManager[949]: Activation (ttyACM0) Stage 1 of 5 (Device Prepare) scheduled...
Oct 20 15:29:01 armadillo NetworkManager[949]: Activation (ttyACM0) Stage 1 of 5 (Device Prepare) started...
Oct 20 15:29:01 armadillo NetworkManager[949]: (ttyACM0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Oct 20 15:29:01 armadillo NetworkManager[949]: NetworkManager state is now CONNECTING
Oct 20 15:29:01 armadillo NetworkManager[949]: (ttyACM0): device state change: prepare -> need-auth (reason 'none') [40 60 0]
Oct 20 15:29:01 armadillo NetworkManager[949]: Activation (ttyACM0) Stage 1 of 5 (Device Prepare) complete.
Oct 20 15:29:01 armadillo NetworkManager[949]: No agents were available for this request.
Oct 20 15:29:01 armadillo NetworkManager[949]: (ttyACM0): device state change: need-auth -> failed (reason 'no-secrets') [60 120 7]
Oct 20 15:29:01 armadillo NetworkManager[949]: NetworkManager state is now CONNECTED_LOCAL
Oct 20 15:29:01 armadillo NetworkManager[949]: Activation (ttyACM0) failed for connection 'gsm-ttyACM0'
Oct 20 15:29:01 armadillo NetworkManager[949]: (ttyACM0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Oct 20 15:29:01 armadillo NetworkManager[949]: (ttyACM0): deactivating device (reason 'none') [0]

#nmcli connection modify gsm-ttyACM0 ipv4.ignore-auto-dns yes
を行い、再起動したあとLTE接続不可になる際のログ

Oct 20 15:38:52 armadillo NetworkManager[981]: ModemManager available in the bus
Oct 20 15:38:54 armadillo NetworkManager[981]: (usb1): link connected
Oct 20 15:38:54 armadillo NetworkManager[981]: (usb1): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Oct 20 15:38:54 armadillo NetworkManager[981]: Auto-activating connection 'Wired connection 1'.
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) starting connection 'Wired connection 1'
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 1 of 5 (Device Prepare) scheduled...
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 1 of 5 (Device Prepare) started...
Oct 20 15:38:54 armadillo NetworkManager[981]: (usb1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Oct 20 15:38:54 armadillo NetworkManager[981]: NetworkManager state is now CONNECTING
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 2 of 5 (Device Configure) scheduled...
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 1 of 5 (Device Prepare) complete.
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 2 of 5 (Device Configure) starting...
Oct 20 15:38:54 armadillo NetworkManager[981]: (usb1): device state change: prepare -> config (reason 'none') [40 50 0]
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 2 of 5 (Device Configure) successful.
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 3 of 5 (IP Configure Start) scheduled.
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 2 of 5 (Device Configure) complete.
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 3 of 5 (IP Configure Start) started...
Oct 20 15:38:54 armadillo NetworkManager[981]: (usb1): device state change: config -> ip-config (reason 'none') [50 70 0]
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Beginning DHCPv4 transaction (timeout in 45 seconds)
Oct 20 15:38:54 armadillo NetworkManager[981]: dhclient started with pid 2210
Oct 20 15:38:54 armadillo NetworkManager[981]: Activation (usb1) Stage 3 of 5 (IP Configure Start) complete.
Oct 20 15:38:54 armadillo NetworkManager[981]: (usb1): DHCPv4 state changed nbi -> preinit
Oct 20 15:38:54 armadillo dhclient: DHCPDISCOVER on usb1 to 255.255.255.255 port 67 interval 3
Oct 20 15:38:54 armadillo ModemManager[2203]: Creating modem with plugin 'Cinterion ELS' and '2' ports
Oct 20 15:38:54 armadillo ModemManager[2203]: Modem for device at '/sys/devices/soc/30800000.aips-bus/30b20000.usb/ci_hdrc.1/usb2/2-1' successfully created
Oct 20 15:38:56 armadillo avahi-daemon[1017]: Joining mDNS multicast group on interface usb1.IPv6 with address fe80::80:70ff:fe27:5300.
Oct 20 15:38:56 armadillo avahi-daemon[1017]: New relevant interface usb1.IPv6 for mDNS.
Oct 20 15:38:56 armadillo avahi-daemon[1017]: Registering new address record for fe80::80:70ff:fe27:5300 on usb1.*.
Oct 20 15:38:57 armadillo dhclient: DHCPDISCOVER on usb1 to 255.255.255.255 port 67 interval 4
Oct 20 15:39:00 armadillo dhclient: DHCPREQUEST on usb1 to 255.255.255.255 port 67
Oct 20 15:39:00 armadillo dhclient: DHCPOFFER from 192.168.15.1
Oct 20 15:39:00 armadillo dhclient: DHCPACK from 192.168.15.1
Oct 20 15:39:00 armadillo NetworkManager[981]: (usb1): DHCPv4 state changed preinit -> bound
Oct 20 15:39:00 armadillo NetworkManager[981]: address 192.168.15.234
Oct 20 15:39:00 armadillo NetworkManager[981]: plen 24 (255.255.255.0)
Oct 20 15:39:00 armadillo NetworkManager[981]: gateway 192.168.15.1
Oct 20 15:39:00 armadillo NetworkManager[981]: server identifier 192.168.15.1
Oct 20 15:39:00 armadillo NetworkManager[981]: lease time 43200
Oct 20 15:39:00 armadillo NetworkManager[981]: hostname 'armadillo'
Oct 20 15:39:00 armadillo NetworkManager[981]: nameserver '192.168.15.1'
Oct 20 15:39:00 armadillo NetworkManager[981]: domain name 'lan'
Oct 20 15:39:00 armadillo NetworkManager[981]: Activation (usb1) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Oct 20 15:39:00 armadillo NetworkManager[981]: Activation (usb1) Stage 5 of 5 (IPv4 Commit) started...
Oct 20 15:39:00 armadillo avahi-daemon[1017]: Joining mDNS multicast group on interface usb1.IPv4 with address 192.168.15.234.
Oct 20 15:39:00 armadillo avahi-daemon[1017]: New relevant interface usb1.IPv4 for mDNS.
Oct 20 15:39:00 armadillo avahi-daemon[1017]: Registering new address record for 192.168.15.234 on usb1.IPv4.
Oct 20 15:39:00 armadillo dhclient: bound to 192.168.15.234 -- renewal in 19993 seconds.
Oct 20 15:39:00 armadillo NetworkManager[981]: (usb1): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
Oct 20 15:39:00 armadillo NetworkManager[981]: Activation (usb1) Stage 5 of 5 (IPv4 Commit) complete.
Oct 20 15:39:00 armadillo NetworkManager[981]: (usb1): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
Oct 20 15:39:00 armadillo NetworkManager[981]: (usb1): device state change: secondaries -> activated (reason 'none') [90 100 0]
Oct 20 15:39:00 armadillo NetworkManager[981]: NetworkManager state is now CONNECTED_LOCAL
Oct 20 15:39:00 armadillo NetworkManager[981]: NetworkManager state is now CONNECTED_GLOBAL
Oct 20 15:39:00 armadillo NetworkManager[981]: Policy set 'Wired connection 1' (usb1) as default for IPv4 routing and DNS.
Oct 20 15:39:00 armadillo NetworkManager[981]: Activation (usb1) successful, device activated.
Oct 20 15:39:00 armadillo dbus[1026]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Oct 20 15:39:00 armadillo systemd[1]: Starting Network Manager Script Dispatcher Service...
Oct 20 15:39:00 armadillo dbus[1026]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Oct 20 15:39:00 armadillo systemd[1]: Started Network Manager Script Dispatcher Service.
Oct 20 15:39:00 armadillo nm-dispatcher: Dispatching action 'up' for usb1
Oct 20 15:39:00 armadillo ntpdate[2257]: Can't find host 0.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo systemd[1]: Reloading OpenBSD Secure Shell server.
Oct 20 15:39:00 armadillo ntpdate[2257]: Can't find host 1.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo ntpdate[2257]: Can't find host 2.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo systemd[1]: Reloaded OpenBSD Secure Shell server.
Oct 20 15:39:00 armadillo ntpdate[2257]: Can't find host 3.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo ntpdate[2257]: no servers can be used, exiting
Oct 20 15:39:00 armadillo ntpdate[2323]: Can't find host 0.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo ntpdate[2323]: Can't find host 1.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo ntpdate[2323]: Can't find host 2.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo ntpdate[2323]: Can't find host 3.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo ntpdate[2323]: no servers can be used, exiting
Oct 20 15:39:01 armadillo systemd[1]: Reloading OpenBSD Secure Shell server.
Oct 20 15:39:01 armadillo systemd[1]: Reloaded OpenBSD Secure Shell server.
Oct 20 15:39:01 armadillo CRON[2367]: (root) CMD (/opt/kuroko/bin/kuroko_ctl.sh check /opt/kuroko > /dev/null 2>&1)
Oct 20 15:39:14 armadillo ModemManager[2203]: (ttyACM0) response array is not empty when using cached reply, cleaning up 13 bytes
Oct 20 15:39:14 armadillo rsyslogd-2007: action 'action 17' suspended, next retry is Wed Oct 20 15:39:44 2021 [try http://www.rsyslog.com/e/2007 ]
Oct 20 15:39:16 armadillo ModemManager[2203]: Modem: state changed (unknown -> disabled)
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): failed to look up interface index
Oct 20 15:39:16 armadillo NetworkManager[981]: (usb1): device state change: activated -> unmanaged (reason 'removed') [100 10 36]
Oct 20 15:39:16 armadillo NetworkManager[981]: (usb1): deactivating device (reason 'removed') [36]
Oct 20 15:39:16 armadillo NetworkManager[981]: (usb1): canceled DHCP transaction, DHCP client pid 2210
Oct 20 15:39:16 armadillo avahi-daemon[1017]: Withdrawing address record for fe80::80:70ff:fe27:5300 on usb1.
Oct 20 15:39:16 armadillo avahi-daemon[1017]: Leaving mDNS multicast group on interface usb1.IPv6 with address fe80::80:70ff:fe27:5300.
Oct 20 15:39:16 armadillo avahi-daemon[1017]: Interface usb1.IPv6 no longer relevant for mDNS.
Oct 20 15:39:16 armadillo avahi-daemon[1017]: Withdrawing address record for 192.168.15.234 on usb1.
Oct 20 15:39:16 armadillo avahi-daemon[1017]: Leaving mDNS multicast group on interface usb1.IPv4 with address 192.168.15.234.
Oct 20 15:39:16 armadillo avahi-daemon[1017]: Interface usb1.IPv4 no longer relevant for mDNS.
Oct 20 15:39:16 armadillo NetworkManager[981]: NetworkManager state is now CONNECTED_LOCAL
Oct 20 15:39:16 armadillo NetworkManager[981]: (usb1): link disconnected
Oct 20 15:39:16 armadillo kernel: IPv6: ADDRCONF(NETDEV_UP): usb1: link is not ready
Oct 20 15:39:16 armadillo dbus[1026]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Oct 20 15:39:16 armadillo systemd[1]: Starting Network Manager Script Dispatcher Service...
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): modem state changed, 'disabled' --> 'enabling' (reason: user preference)
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): new Broadband device (driver: 'cdc_acm, cdc_ether' ifindex: 0)
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): exported as /org/freedesktop/NetworkManager/Devices/13
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Oct 20 15:39:16 armadillo ModemManager[2203]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): preparing device
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): modem state 'enabling'
Oct 20 15:39:16 armadillo NetworkManager[981]: (ttyACM0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
Oct 20 15:39:17 armadillo dbus[1026]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Oct 20 15:39:17 armadillo systemd[1]: Started Network Manager Script Dispatcher Service.
Oct 20 15:39:17 armadillo nm-dispatcher: Dispatching action 'down' for usb1
Oct 20 15:39:18 armadillo ModemManager[2203]: Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> registering)
Oct 20 15:39:19 armadillo ModemManager[2203]: Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
Oct 20 15:39:20 armadillo ModemManager[2203]: Modem /org/freedesOct 20 15:39:00 armadillo ntpdate[2323]: Can't find host 2.debian.pool.ntp.org: Name or service not known (-2)
Oct 20 15:39:00 armadillo ntpdate[2323]: Can't find host 3.debian.pool.ntp.org: Name or service not known (-2)ktop/ModemManager1/Modem/0: state changed (enabling -> registered)
Oct 20 15:39:20 armadillo NetworkManager[981]: (ttyACM0): modem state changed, 'enabling' --> 'registered' (reason: user-requested)

--

★2点目
閉域SIMを使用していますが、DNSサーバは閉域内には存在します。
ドキュメントでは 192.168.15.1がDNSとなり、モバイル接続の際に割り当てられたDNSサーバにフォワードするとありますが、
実施にはDNSフォワードしません。

閉域内のDNSで参照可能なドメインを hoge.close.netと仮定します。

nslookup hoge.close.net

Server: 192.168.15.1
Address: 192.168.15.1#53

*** Can't find api.kuroko.cloud: No answer

閉域ネットワークは 172.X.Xのプライベートアドレスとなっています。
閉域DNSを 172.18.65.100と過程します。

nslookup - 172.18.65.100
nslookup hoge.close.net
とすればIPアドレスを引くことができます。

モバイルから割り振られるIPアドレスにはDNS情報として172.18.65.100が設定されており、
LTE USBドングル等他のデバイスでは正常に名前解決できますが、G3Lでは192.168.15.1がDNSとデフォルトなるため
そこでエラーになり名前解決ができません。

この2点目の問題があるために、1点目の
nmcli connection modify gsm-ttyACM0 ipv4.ignore-auto-dns yes
を行うのですが、これを行うとLTEが切断されてしまいます。

上記設定をしなければLTEは継続接続できますが、これでは名前解決ができないため困っています。

※閉域モバイルを使用していますので、
/etc/connection-recover/gsm-ttyACM0_connection-recover.confの
PING_DEST_IPは適切な通信先を指定しています。

コメント

mcrest_kozawa

2021年10月20日 17時50分

原因はわかったのですが、回避方法を教えて下さい。
nmcli connection add type gsm ifname ttyACM0 apn user password <パスワード>
で設定した際に
vi /etc/NetworkManager/system-connections/gsm-ttyACM0
を確認すると
password=<パスワード>
が存在していますが、その後
nmcli connection modify gsm-ttyACM0 ipv4.ignore-auto-dns yes
を実行すると
passwordの行が削除されていました。
vi /etc/NetworkManager/system-connections/gsm-ttyACM0
を手動で編集して、rebootしたところ設定したとおりの形でLTEが自動接続できるようになりましたが、
nmcliコマンドで編集するとLTEのpasswordの値は無くなってしまうのでしょうか。

また、★2点目の 192.168.15.2のDNSフォワードエラーが出る件については解決できていないため、本件回避方法をご教示下さい。
それとも ignore-auto-dns yesで 192.168.15.1を使わないようにするしか回避方法はないでしょうか。

at_mitsuhiro.yoshida

2021年10月22日 17時45分

吉田です。

> nmcliコマンドで編集するとLTEのpasswordの値は無くなってしまうのでしょうか。

はい、そのような動作となります。
わかりにくくて申し訳ありませんが、製品マニュアルにも記載があります。
お手数ですが、ご対応よろしくお願いします。
https://manual.atmark-techno.com/armadillo-iot-g3l/armadillo-iotg-g3l_p…

> また、★2点目の 192.168.15.2のDNSフォワードエラーが出る件については解決できていないため、本件回避方法をご教示下さい。

製品マニュアルの以下に記載がありますが、
LTE 側ネットワークの名前解決として、 LTE の内部 DNS は必要です。
https://manual.atmark-techno.com/armadillo-iot-g3l/armadillo-iotg-g3l_p…

LTE モジュールが閉塞網の DNS サーバーアドレスを取得出来ていない可能性が考えられます。
以下の手順で手動にて LTE モジュールに DNS を設定し、動作が変化するか試してもらえますでしょうか。
以下の例は、DNS を 172.18.65.100 とした場合のコマンドとなります。

armadillo~ #  cu -l /dev/ttymxc6 -s 115200
AT^SICS=1,"dns1","172.18.65.100"
~.  (チルダ ドット で cu から抜けます)

この設定をした後、再度 nmcli コマンドで接続の確立を実施ください。