在我们的一个系统中,我们最近遇到了这样的问题:与 4G 网络断开连接后,即使 4G 连接再次恢复,调制解调器也无法重新建立连接。需要手动重新启动机器才能重新连接。由于我们的机器位于偏远地区,这非常不方便。这就是为什么我想了解发生了什么以及我们将来如何避免这种情况。
我对 Linux 还很陌生,所以如果我问了一个明显的问题,我很抱歉。我已经尝试在互联网上搜索日志文件中的大部分行,但这对我没有多大帮助。
您可以在下面找到一些日志。这些是问题开始时的日志,但最后还显示系统经历的连续连接循环,直到我们重新启动。
如果有人可以帮助我了解这里发生的事情以及如何避免这种情况,那就太好了。感谢您的帮助!
系统信息:
- Ubuntu 18.04.3 LTS
- 调制解调器:华为ME909s-120
- 调制解调器管理器版本:1.12.2
- 网络管理器版本:1.10.6
日志
Jan 29 23:41:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (roaming -> idle)
Jan 29 23:41:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connected -> enabled)
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8456] modem["ttyUSB0"]: modem state changed, 'connected' --> 'enabled' (reason: unknown)
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8457] device (ttyUSB0): state change: activated -> failed (reason 'modem-no-carrier', sys-iface-state: 'managed')
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8463] manager: NetworkManager state is now DISCONNECTED
Jan 29 23:41:02 NetworkManager[746]: <warn> [1580341262.8600] device (ttyUSB0): Activation: failed for connection 'lte0'
Jan 29 23:41:02 dbus-daemon[682]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.8' (uid=0 pid=746 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8638] device (ttyUSB0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jan 29 23:41:02 kernel: [3073082.377544] IPv6: ADDRCONF(NETDEV_UP): wwp0s20u3c2: link is not ready
Jan 29 23:41:02 systemd[1]: Starting Network Manager Script Dispatcher Service...
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8696] policy: auto-activating connection 'lte0'
Jan 29 23:41:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabled -> disconnecting)
Jan 29 23:41:02 ModemManager[836]: <warn> Couldn't find associated cdc-wdm port for 'net/wwp0s20u3c2'
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8759] modem["ttyUSB0"]: modem state changed, 'enabled' --> 'disconnecting' (reason: user-requested)
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8774] device (ttyUSB0): Activation: starting connection 'lte0' (3a37dbea-8a70-44ed-87ae-3330cadd316c)
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8783] device (ttyUSB0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.8786] manager: NetworkManager state is now CONNECTING
Jan 29 23:41:02 ModemManager[836]: <info> Simple connect started...
Jan 29 23:41:02 ModemManager[836]: <info> Simple connect state (4/8): Wait to get fully enabled
Jan 29 23:41:02 dbus-daemon[682]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 29 23:41:02 systemd[1]: Started Network Manager Script Dispatcher Service.
Jan 29 23:41:02 nm-dispatcher: req:1 'down' [wwp0s20u3c2]: new request (1 scripts)
Jan 29 23:41:02 nm-dispatcher: req:1 'down' [wwp0s20u3c2]: start running ordered scripts...
Jan 29 23:41:02 nm-dispatcher: req:2 'connectivity-change': new request (1 scripts)
Jan 29 23:41:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting -> connected)
Jan 29 23:41:02 ModemManager[836]: <info> Simple connect state (5/8): Register
Jan 29 23:41:02 NetworkManager[746]: <info> [1580341262.9043] modem["ttyUSB0"]: modem state changed, 'disconnecting' --> 'connected' (reason: user-requested)
Jan 29 23:41:02 nm-dispatcher: req:2 'connectivity-change': start running ordered scripts...
Jan 29 23:41:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> searching)
Jan 29 23:42:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> idle)
Jan 29 23:42:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connected -> enabled)
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9355] modem["ttyUSB0"]: modem state changed, 'connected' --> 'enabled' (reason: unknown)
Jan 29 23:42:02 NetworkManager[746]: <warn> [1580341322.9602] modem-broadband[ttyUSB0]: failed to connect modem: Network timeout
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9603] device (ttyUSB0): state change: prepare -> failed (reason 'gsm-registration-timeout', sys-iface-state: 'managed')
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9609] manager: NetworkManager state is now DISCONNECTED
Jan 29 23:42:02 NetworkManager[746]: <warn> [1580341322.9620] device (ttyUSB0): Activation: failed for connection 'lte0'
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9648] device (ttyUSB0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9669] policy: auto-activating connection 'lte0'
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9703] device (ttyUSB0): Activation: starting connection 'lte0' (3a37dbea-8a70-44ed-87ae-3330cadd316c)
Jan 29 23:42:02 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabled -> disconnecting)
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9709] device (ttyUSB0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jan 29 23:42:02 ModemManager[836]: <warn> Couldn't find associated cdc-wdm port for 'net/wwp0s20u3c2'
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9713] manager: NetworkManager state is now CONNECTING
Jan 29 23:42:02 NetworkManager[746]: <info> [1580341322.9748] modem["ttyUSB0"]: modem state changed, 'enabled' --> 'disconnecting' (reason: user-requested)
Jan 29 23:42:02 ModemManager[836]: <info> Simple connect started...
Jan 29 23:42:02 ModemManager[836]: <info> Simple connect state (4/8): Wait to get fully enabled
Jan 29 23:42:03 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting -> connected)
Jan 29 23:42:03 ModemManager[836]: <info> Simple connect state (5/8): Register
Jan 29 23:42:03 NetworkManager[746]: <info> [1580341323.0029] modem["ttyUSB0"]: modem state changed, 'disconnecting' --> 'connected' (reason: user-requested)
Jan 29 23:42:03 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> searching)
Jan 29 23:42:26 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> registering)
Jan 29 23:42:27 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> roaming)
Jan 29 23:42:29 ModemManager[836]: <info> Simple connect state (6/8): Bearer
Jan 29 23:42:29 NetworkManager[746]: <warn> [1580341349.9281] modem-broadband[ttyUSB0]: failed to connect modem: Cannot create new bearer: all existing bearers are connected
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9282] device (ttyUSB0): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9288] manager: NetworkManager state is now DISCONNECTED
Jan 29 23:42:29 NetworkManager[746]: <warn> [1580341349.9299] device (ttyUSB0): Activation: failed for connection 'lte0'
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9318] device (ttyUSB0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9339] policy: auto-activating connection 'lte0'
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9374] device (ttyUSB0): Activation: starting connection 'lte0' (3a37dbea-8a70-44ed-87ae-3330cadd316c)
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9382] device (ttyUSB0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9388] manager: NetworkManager state is now CONNECTING
Jan 29 23:42:29 ModemManager[836]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connected -> disconnecting)
Jan 29 23:42:29 ModemManager[836]: <warn> Couldn't find associated cdc-wdm port for 'net/wwp0s20u3c2'
Jan 29 23:42:29 NetworkManager[746]: <info> [1580341349.9436] modem["ttyUSB0"]: modem state changed, 'connected' --> 'disconnecting' (reason: user-requested)