Network Manager - pppd timed out or didn't initialize our dbus module

Product support balenaOS
,
1

Hi!

I have a raspberry Pi with a Quectel EG95 hat using latest BalenaOS 2.47.0+rev1 (production mode) that shows up fine in ModemManager:

mmcli -L
    /org/freedesktop/ModemManager1/Modem/0 [Quectel] EG95

Then when I try to connect to the internet the pppd process fails at status 3 / phase 'serial connection, and gives the error:
" ppp-manager: pppd timed out or didn't initialize our dbus module". NM then disconnects the device.

If I run my own pppd call script it successfully connects to the internet, however I want it to be manageable by the Network manager.

As you see in the logs below, I have tried to play around with different ppp options (or none) in /etc/ppp/options without any different result.

Detailed debug logs from both MM and NM below:
ModemManager:

May 12 13:15:58 85305ec ModemManager[673]: Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (80)
May 12 13:15:58 85305ec ModemManager[673]: Periodic signal quality and access technology checks scheduled
May 12 13:15:58 85305ec ModemManager[673]: (ttyS0) device open count is 1 (close)
May 12 13:16:27 85305ec ModemManager[673]: User request to connect modem
May 12 13:16:27 85305ec ModemManager[673]: Simple connect started...
May 12 13:16:27 85305ec ModemManager[673]:    PIN: unspecified
May 12 13:16:27 85305ec ModemManager[673]:    Operator ID: unspecified
May 12 13:16:27 85305ec ModemManager[673]:    Allowed roaming: yes
May 12 13:16:27 85305ec ModemManager[673]:    APN: online.telia.se
May 12 13:16:27 85305ec ModemManager[673]:    IP family: ipv4v6
May 12 13:16:27 85305ec ModemManager[673]:    Allowed authentication: none, pap, chap, mschap, mschapv2, eap
May 12 13:16:27 85305ec ModemManager[673]:    User: unspecified
May 12 13:16:27 85305ec ModemManager[673]:    Password: unspecified
May 12 13:16:27 85305ec ModemManager[673]: Simple connect state (4/8): Wait to get fully enabled
May 12 13:16:27 85305ec ModemManager[673]: Simple connect state (5/8): Register
May 12 13:16:27 85305ec ModemManager[673]: Already registered in network '24001', automatic registration not launched...
May 12 13:16:27 85305ec ModemManager[673]: Simple connect state (6/8): Bearer
May 12 13:16:27 85305ec ModemManager[673]: Creating new bearer...
May 12 13:16:27 85305ec ModemManager[673]: Creating Broadband bearer in broadband modem
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 2 (open)
May 12 13:16:27 85305ec ModemManager[673]: Simple connect state (7/8): Connect
May 12 13:16:27 85305ec ModemManager[673]: Connecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
May 12 13:16:27 85305ec ModemManager[673]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
May 12 13:16:27 85305ec ModemManager[673]: Launching 3GPP connection attempt with APN 'online.telia.se'
May 12 13:16:27 85305ec ModemManager[673]: Checking context definition format...
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 3 (open)
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 2 (close)
May 12 13:16:27 85305ec ModemManager[673]: Unhandled PDP type in CGDCONT=? reply: 'PPP'
May 12 13:16:27 85305ec ModemManager[673]: Checking currently defined contexts...
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 3 (open)
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 2 (close)
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): --> 'AT+CGDCONT?<CR>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<CR>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<LF>+C'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'G'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'D'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'C'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'ON'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'T'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ':'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ' '
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '1'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ',"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'I'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'P'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '",'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'o'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'nl'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'i'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'ne'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'tel'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'ia'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 's'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'e"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ','
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '"0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ','
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0,'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ','
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0,'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<CR><LF>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '+'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'CG'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'D'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'CO'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'N'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'T:'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ' '
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '2,'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'IP'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'V'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '4V'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '6"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ','
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '"o'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'nl'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'i'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'ne'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.t'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'e'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'li'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'a.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 's'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'e"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ',"'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0.0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '.0.'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '0",0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ',0,0'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- ',0<CR><LF>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<CR><LF>OK'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<CR><LF>'
May 12 13:16:27 85305ec ModemManager[673]: Found '2' PDP contexts
May 12 13:16:27 85305ec ModemManager[673]:   PDP context [cid=1] [type='ipv4'] [apn='online.telia.se']
May 12 13:16:27 85305ec ModemManager[673]:   PDP context [cid=2] [type='ipv4v6'] [apn='online.telia.se']
May 12 13:16:27 85305ec ModemManager[673]: Looking for best CID matching APN 'online.telia.se' and PDP type 'ipv4v6'...
May 12 13:16:27 85305ec ModemManager[673]: Found exact context at CID 2
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 3 (open)
May 12 13:16:27 85305ec ModemManager[673]: Connection through a plain serial AT port (ttyS0)
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 4 (open)
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 3 (close)
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): --> 'ATD*99***2#<CR>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<CR>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<LF>CON'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'NEC'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- 'T 1'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '500'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '000'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '00<CR>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): <-- '<LF>'
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0): port now connected
May 12 13:16:27 85305ec ModemManager[673]: Connected bearer '/org/freedesktop/ModemManager1/Bearer/0'
May 12 13:16:27 85305ec ModemManager[673]: PPP is required for connection, will ignore disconnection reports
May 12 13:16:27 85305ec ModemManager[673]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
May 12 13:16:27 85305ec ModemManager[673]: Simple connect state (8/8): All done
May 12 13:16:27 85305ec ModemManager[673]: (ttyS0) device open count is 2 (close)
May 12 13:16:28 85305ec ModemManager[673]: loading signal quality...
May 12 13:16:28 85305ec ModemManager[673]: Couldn't refresh signal quality: 'No AT port available to run command'
May 12 13:16:28 85305ec ModemManager[673]: Periodic signal quality and access technology checks scheduled
May 12 13:16:57 85305ec ModemManager[673]: Connection monitoring is unsupported by the device
May 12 13:16:58 85305ec ModemManager[673]: Signal quality value not updated in 60s, marking as not being recent
May 12 13:16:58 85305ec ModemManager[673]: loading signal quality...
May 12 13:16:58 85305ec ModemManager[673]: Couldn't refresh signal quality: 'No AT port available to run command'
May 12 13:16:58 85305ec ModemManager[673]: Periodic signal quality and access technology checks scheduled

NetworkManager:

May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.7365] device (ttyS0): Activation: starting connection 'cellular' (57929095-bcf5-40b1-9690-3bf54b4dc6c4)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7368] device[0xb78430] (ttyS0): activation-stage: schedule activate_stage1_device_prepare,v4 (id 976)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7369] manager: ActivatingConnection now (none)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7386] create NMAuditManager singleton (793d6384c795a1c9)
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.7388] audit: op="connection-activate" uuid="57929095-bcf5-40b1-9690-3bf54b4dc6c4" name="cellular" pid=1827 uid=0 result="success"
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7389] device[0xb78430] (ttyS0): activation-stage: invoke activate_stage1_device_prepare,v4 (id 976)
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.7397] device (ttyS0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7429] active-connection[0xa89a00]: set state activating (was unknown)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7444] active-connection[0xa89a00]: check-master-ready: not signalling (state activating, no master)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7450] modem-broadband[ttyS0]: launching connection with ip type 'ipv4v6' (try 1)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7457] device[0xb78430] (ttyS0): activation-stage: complete activate_stage1_device_prepare,v4 (id 976)
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.7514] modem["ttyS0"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7516] device[0xb78430] (ttyS0): add_pending_action (2): 'recheck-available'
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.7517] device[0xb78430] (ttyS0): remove_pending_action (1): 'recheck-available'
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.8062] modem["ttyS0"]: modem state changed, 'connecting' --> 'connected' (reason: user-requested)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8064] device[0xb78430] (ttyS0): add_pending_action (2): 'recheck-available'
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8066] device[0xb78430] (ttyS0): remove_pending_action (1): 'recheck-available'
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8173] device[0xb78430] (ttyS0): activation-stage: schedule activate_stage2_device_config,v4 (id 992)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8183] device[0xb78430] (ttyS0): activation-stage: invoke activate_stage2_device_config,v4 (id 992)
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.8186] device (ttyS0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8230] rules-manager: sync
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8232] device[0xb78430] (ttyS0): bringing up device 0
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8233] firewall: [0x940fb8,change*:"ttyS0"]: firewall zone change ttyS0:default (not running, simulate success)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8233] device[0xb78430] (ttyS0): activation-stage: complete activate_stage2_device_config,v4 (id 992)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8234] firewall: [0x940fb8,change*:"ttyS0"]: complete: fake success
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8235] device[0xb78430] (ttyS0): activation-stage: schedule activate_stage3_ip_config_start,v4 (id 994)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8235] device[0xb78430] (ttyS0): activation-stage: invoke activate_stage3_ip_config_start,v4 (id 994)
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8236] active-connection[0xa89a00]: set state-flags layer2-ready (was none)
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.8241] device (ttyS0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8249] modem["ttyS0"]: ip4_config_start
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.8251] modem["ttyS0"]: using modem-specified IP timeout: 20 seconds
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.8307] loaded PPP plugin /usr/lib/NetworkManager/1.20.2/libnm-ppp-plugin.so
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.8315] ppp-manager: starting PPP connection
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8316] ppp-manager: command line: /usr/sbin/pppd nodetach lock nodefaultroute ipv6 , debug ttyS0 noipdefault 115200 noauth nobsdcomp novj nodeflate usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 idle 0 ipparam /org/freedesktop/NetworkManager/PPP/1 plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so
May 12 13:16:27 85305ec NetworkManager[749]: <info>  [1589289387.8442] ppp-manager: pppd started with pid 1831
May 12 13:16:27 85305ec NetworkManager[749]: <debug> [1589289387.8446] device[0xb78430] (ttyS0): activation-stage: complete activate_stage3_ip_config_start,v4 (id 994)
May 12 13:16:27 85305ec NetworkManager[749]: Plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so loaded.
May 12 13:16:27 85305ec NetworkManager[749]: nm-pppd-plugin-Message: 13:16:27.894: nm-ppp-plugin: initializing
May 12 13:16:27 85305ec NetworkManager[749]: pppd options in effect:
May 12 13:16:27 85305ec NetworkManager[749]: debug debug                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: nodetach                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: idle 0                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: dump                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: noauth                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: user internet                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: remotename 3gppp                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: /dev/ttyS0                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: 115200                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: lock                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: nocrtscts                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: modem                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: asyncmap 0                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: lcp-echo-failure 0                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: lcp-echo-interval 0                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: hide-password                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: novj                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: novjccomp                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: ipcp-accept-local                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: ipcp-accept-remote                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: ipparam /org/freedesktop/NetworkManager/PPP/1                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: noipdefault                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: ipcp-max-failure 30                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]:                 # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: nodefaultroute                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: usepeerdns                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: ipv6 ,                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: noccp                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: nobsdcomp                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: nodeflate                # (from command line)
May 12 13:16:27 85305ec NetworkManager[749]: noipx                # (from /etc/ppp/options)
May 12 13:16:27 85305ec NetworkManager[749]: nm-pppd-plugin-Message: 13:16:27.919: nm-ppp-plugin: status 3 / phase 'serial connection'
May 12 13:16:29 85305ec NetworkManager[749]: <debug> [1589289389.7081] connectivity: (ttyS0,IPv4,43) start fake request (fake result)
May 12 13:16:29 85305ec NetworkManager[749]: <debug> [1589289389.7083] connectivity: (ttyS0,IPv6,44) start fake request (fake result)
May 12 13:16:29 85305ec NetworkManager[749]: <debug> [1589289389.7085] connectivity: (ttyS0,IPv4,43) check completed: FAKE; fake result
May 12 13:16:29 85305ec NetworkManager[749]: <debug> [1589289389.7086] connectivity: (ttyS0,IPv6,44) check completed: FAKE; fake result
May 12 13:16:47 85305ec NetworkManager[749]: <warn>  [1589289407.9561] ppp-manager: pppd timed out or didn't initialize our dbus module
May 12 13:16:47 85305ec NetworkManager[749]: <debug> [1589289407.9569] kill child process 'pppd' (1831): wait for process to terminate after sending SIGTERM (15) (send SIGKILL in 1500 milliseconds)...
May 12 13:16:47 85305ec NetworkManager[749]: <debug> [1589289407.9571] device[0xb78430] (ttyS0): activation-stage: schedule activate_stage4_ip_config_timeout_4,v4 (id 1006)
May 12 13:16:47 85305ec NetworkManager[749]: <debug> [1589289407.9573] device[0xb78430] (ttyS0): activation-stage: invoke activate_stage4_ip_config_timeout_4,v4 (id 1006)
May 12 13:16:47 85305ec NetworkManager[749]: <debug> [1589289407.9575] device[0xb78430] (ttyS0): activation-stage: complete activate_stage4_ip_config_timeout_4,v4 (id 1006)
May 12 13:16:48 85305ec NetworkManager[749]: nm-pppd-plugin-Message: 13:16:48.957: nm-ppp-plugin: status 1 / phase 'dead'
May 12 13:16:48 85305ec NetworkManager[749]: nm-pppd-plugin-Message: 13:16:48.958: nm-ppp-plugin: cleaning up
May 12 13:16:48 85305ec NetworkManager[749]: <debug> [1589289408.9617] kill child process 'pppd' (1831): terminated normally with status 9 (1004742 usec elapsed)
May 12 13:17:33 85305ec NetworkManager[749]: <debug> [1589289453.7124] connectivity: (ttyS0,IPv4,45) start fake request (fake result)
May 12 13:17:33 85305ec NetworkManager[749]: <debug> [1589289453.7126] connectivity: (ttyS0,IPv6,46) start fake request (fake result)
May 12 13:17:33 85305ec NetworkManager[749]: <debug> [1589289453.7128] connectivity: (ttyS0,IPv4,45) check completed: FAKE; fake result
May 12 13:17:33 85305ec NetworkManager[749]: <debug> [1589289453.7129] connectivity: (ttyS0,IPv6,46) check completed: FAKE; fake result
May 12 13:17:58 85305ec NetworkManager[749]: <debug> [1589289478.0076] agent-manager: req[0xbd6928, :1.67/nmcli-connect/0]: agent unregistered or disappeared

Thanks in advance!

2

so just find out that this bug is related: https://github.com/balena-os/meta-balena/issues/1846, where the comment:
it looks like adding an empty connection string in the ppp settings serves as a workaround.
So if the /etc/ppp/options file has a connect “”, it doesn’t fail,

fixed the issue.

Is there a way to fix this in a better way without modifying hostOs? Maybe the system-connections file?

Thanks again

7

Hi, I was about to resume working on the same issue this week. Unfortunately the previous UART modem I was working with broke while I was working on that task and I ordered another one. I have it here with me now and I am planning to resume working on this in the following days.

Thanks for clarifying that the workaround fixes the issue for you as well. Currently there is not a way to incorporate the workaround with the currently released OS, however from the looks of it we may include it in a next OS release. I just need to do more testing to determine the right approach for fixing this. In any way this issue is high in my priority list.

Thanks,
Zahari

9

hi @majorz,

Ok great to hear that. Do you know when you plan to release the next OS version?

Thanks

11

Hey,
Please keep track of this issue https://github.com/balena-os/meta-balena/issues/1846, it will let you know when it is done.

13

Hi @tibhel, we just merged the fix for this issue which will be available as part of balenaOS v2.67.2 (and later). We will release the new balenaOS version once we complete all our tests.

Thanks again for reporting this issue.