Resolv.conf sometimes not accessable

Legato Application Framework
1

We’re using a WP7702 and we have the occasional issue that the device will not connect to our server. This has been hard to duplicate, but we may have found a possible source.

When powercycling device it got into a situation where the Legato platform was not started. We then SSHed into the device and using legato start started the device. However at that point the device was unable to connect to the server and looking in the log we get the following:

Jun 19 13:28:26 swi-mdm9x28-wp user.err Legato: =ERR= | modemDaemon[9308]/swiQmi T=main | swiQmi.c swiQmi_CheckResponse() 799 | Sending QMI_WDS_START_NETWORK_INTERFACE_REQ_V01 failed: rc=0 (), resp.result=1.[0x01], resp.error=14.[0x0e]
Jun 19 13:28:26 swi-mdm9x28-wp user.err Legato: =ERR= | modemDaemon[9308]/le_pa T=main | pa_mdc_qmi.c StartSession() 1978 | Data connection failure Call End provided 45, Code 1
Jun 19 13:28:26 swi-mdm9x28-wp user.err Legato: =ERR= | modemDaemon[9308]/le_pa T=main | pa_mdc_qmi.c StartSession() 1989 | Data connection failure Verbose Call End provided Type 2, Verbose 210
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsCellular T=main | dcsCellular.c le_dcsCellular_Start() 1079 | Succeeded starting cellular connection 1
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsCellular T=main | dcsCellular.c DcsCellularConnEventStateHandler() 254 | State of connection 1 transitioned from down to up
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsDaemon T=main | dcsServer.c ChannelEventHandler() 780 | Received for channel reference 0x145 event Up
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsDaemon T=main | dcsServer.c SetDefaultGWConfiguration() 426 | Setting default GW address on device
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsNet T=main | dcsNet.c le_net_SetDefaultGW() 827 | Succeeded to set default GW addr on interface rmnet_data0 for channel 1 of technology cellular
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsDaemon T=main | dcsServer.c SetDnsConfiguration() 584 | Setting DNS server addresses on device
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/le_pa_dcs T=main | pa_dcs_linux.c pa_dcs_SetDnsNameServers() 367 | Set DNS '10.10.20.20' ''
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsNet T=main | dcsNet.c le_net_SetDNS() 1246 | Succeeded to set DNS address(es) of channel 1 of technology cellular onto device
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsDaemon T=main | dcsServer.c SetDnsConfiguration() 603 | Succeeded setting DNS configuration
Jun 19 13:28:26 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[9280]/dcsDaemon T=main | dcsServer.c SetDefaultRouteAndDns() 658 | Succeeded setting DNS configuration
Jun 19 11:28:26 swi-mdm9x28-wp user.info Legato:  INFO | myClock[9183]/clock T=main | clockComponent.c ConnectionStateHandler() 215 | Syncing NTPD on rmnet_data0 using 1
Jun 19 13:28:26 swi-mdm9x28-wp user.notice kernel: [ 3905.978751] audit: type=1400 audit(1687174106.239:18): lsm=SMACK fn=smack_inode_getattr action=denied subject="app.Antares_Legato" object="admin" requested=r pid=9183 comm="myClock" path="/etc/resolv.conf" dev="tmpfs" ino=27
Jun 19 13:28:26 swi-mdm9x28-wp user.notice kernel: [ 3905.978884] audit: type=1400 audit(1687174106.239:19): lsm=SMACK fn=smack_inode_permission action=denied subject="app.Antares_Legato" object="admin" requested=r pid=9183 comm="myClock" name="hosts" dev="tmpfs" ino=27346
Jun 19 13:28:26 swi-mdm9x28-wp user.notice kernel: [ 3905.979778] audit: type=1400 audit(1687174106.239:20): lsm=SMACK fn=smack_socket_sock_rcv_skb action=denied subject="app.Antares_Legato" object="_" requested=w pid=9183 comm="myClock" saddr=127.0.0.1 src=49563 daddr=127.0.0.
Jun 19 13:28:26 swi-mdm9x28-wp user.notice kernel: [ 3905.980551] audit: type=1400 audit(1687174106.249:21): lsm=SMACK fn=smack_socket_sock_rcv_skb action=denied subject="app.Antares_Legato" object="_" requested=w pid=9183 comm="myClock" saddr=127.0.0.1 src=49563 daddr=127.0.0.
Jun 19 11:28:26 swi-mdm9x28-wp user.warn Legato: -WRN- | myClock[9183]/clock T=main | clockComponent.c DoNtpSync() 163 | Could not resolve inetAddr pool.ntp.org: -3

However in the SSH console it was possible for us to ping google.com without issue. Restarting the app did not fix the issue but when we reset the device (AT!RESET in the AT interface) on next startup it could connect with our server and looking in the logging we get the following for the same statements

Jun 19 13:45:02 swi-mdm9x28-wp user.err Legato: =ERR= | modemDaemon[1245]/swiQmi T=main | swiQmi.c swiQmi_CheckResponse() 799 | Sending QMI_WDS_START_NETWORK_INTERFACE_REQ_V01 failed: rc=0 (), resp.result=1.[0x01], resp.error=14.[0x0e]
Jun 19 13:45:02 swi-mdm9x28-wp user.err Legato: =ERR= | modemDaemon[1245]/le_pa T=main | pa_mdc_qmi.c StartSession() 1978 | Data connection failure Call End provided 45, Code 1
Jun 19 13:45:02 swi-mdm9x28-wp user.err Legato: =ERR= | modemDaemon[1245]/le_pa T=main | pa_mdc_qmi.c StartSession() 1989 | Data connection failure Verbose Call End provided Type 2, Verbose 210
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsCellular T=main | dcsCellular.c le_dcsCellular_Start() 1079 | Succeeded starting cellular connection 1
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsCellular T=main | dcsCellular.c DcsCellularConnEventStateHandler() 254 | State of connection 1 transitioned from down to up
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsDaemon T=main | dcsServer.c ChannelEventHandler() 780 | Received for channel reference 0x1b9 event Up
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsDaemon T=main | dcsServer.c SetDefaultGWConfiguration() 426 | Setting default GW address on device
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsNet T=main | dcsNet.c le_net_SetDefaultGW() 827 | Succeeded to set default GW addr on interface rmnet_data0 for channel 1 of technology cellular
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsDaemon T=main | dcsServer.c SetDnsConfiguration() 584 | Setting DNS server addresses on device
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/le_pa_dcs T=main | pa_dcs_linux.c pa_dcs_SetDnsNameServers() 367 | Set DNS '10.10.20.20' ''
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsNet T=main | dcsNet.c le_net_SetDNS() 1246 | Succeeded to set DNS address(es) of channel 1 of technology cellular onto device
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsDaemon T=main | dcsServer.c SetDnsConfiguration() 603 | Succeeded setting DNS configuration
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | dcsDaemon[1196]/dcsDaemon T=main | dcsServer.c SetDefaultRouteAndDns() 658 | Succeeded setting DNS configuration
Jun 19 13:45:02 swi-mdm9x28-wp user.warn Legato: -WRN- | avcDaemon[1178]/avcDaemon T=main | tpfServer.c tpfServer_GetTpfState() 79 | FW update install pending not found
Jun 19 13:45:02 swi-mdm9x28-wp user.info Legato:  INFO | avcDaemon[1178]/avcDaemon T=main | avcClient.c BearerEventCb() 321 | Connected 1
Jun 19 11:45:02 swi-mdm9x28-wp user.info Legato:  INFO | myClock[1104]/clock T=main | clockComponent.c ConnectionStateHandler() 215 | Syncing NTPD on rmnet_data0 using 1
Jun 19 11:45:03 swi-mdm9x28-wp user.info Legato:  INFO | myClock[1104]/clock T=main | clockComponent.c DoNtpSync() 185 | Read 48 bytes from NTP server

What could have resulted in:
A: the legato platform not starting correctly in the first place? and B: /etc/resolv.conf to be unusable the one time, but after reboot working correctly?

2

For legato not started, you need to capture the uart boot log with ok case to see why legato cannot be started

For /etc/resolv.conf cannot be used, do you mean no problem is found when using real ip address in application?

3

as you can see in the provided logging the first time i got the following error: ...action=denied subject="app.Antares_Legato" ... path="/etc/resolv.conf" which resulted in Could not resolve inetAddr pool.ntp.org: -3

However after rebooting the exact same code worked correctly (able to do dns resolving and accessing /etc/resolv.con).

4

Do you see problem with unsandboxed application?

maybe you also need to run an init script to check whether legato is running, if not running, then reset the module

5

I will try with an unsandboxed application to see if starting the Legato platform after it fails on startup.

Do you have an example of such an init script?

6

no, i don’t have such script
Probably you need to modify /etc/init.d/startlegato.sh and check if the legato is running after it has been initialized.

7

as for running the application (after fixing the tty paths that were renamed in the .adef file) it works and it will connect correctly.

I think my plan for now is to run a script that after 5 seconds will automatically run legato start

8

Looking through the log when it is not starting up a bit more carefully i think i’ve found the issue of legato not starting:

Jun 20 09:01:50 swi-mdm9x28-wp user.emerg Legato: *EMR* | startSystem[1032]/framework T=main | start.c CheckAndInstallCurrentSystem() 2021 | Golden system entered boot loop -- not starting Legato

With running in non-sandboxed mode resolv.conf seems to be accessible in the situation it wasn’t previously, so I guess that will be the solution.