Airvantage session not working properly. Starts... but then just stops///

karlkuhn · November 7, 2018, 8:38am

Hi, I have installed the sample app LWM2MControl. All installs OK and then I start the application and the trace is as follows. What could I have missed? I have an AirVantage account and have registered this device on it.

Edited
I should have added I am running 16.10.1.m3 (effectively 16.10.3) on a FX30s and my AirVantage account is on the EU servers.

Thanks,
Karl

Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c app_Stop() 2731 | Stopping app 'lwm2mControl'
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | apps.c DeactivateAppContainer() 340 | Application 'lwm2mControl' has stopped.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c CreateTmpFs() 1204 | Mounted tmpfs at /legato/systems/current/appsWriteable/lwm2mControl/tmp.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c CreateFileLink() 1504 | Created file link '/tmp/legato/serviceDirectoryServer' to '/legato/systems/current/appsWriteable/lwm2mControl/tmp/legato/serviceDirectoryServer'.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c CreateFileLink() 1504 | Created file link '/tmp/legato/serviceDirectoryClient' to '/legato/systems/current/appsWriteable/lwm2mControl/tmp/legato/serviceDirectoryClient'.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxCoreDumpFileBytes to value 102400.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxFileBytes to value 102400.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxLockedMemoryBytes to value 8192.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxFileDescriptors to value 256.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxMQueueBytes to value 512.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxThreads to value 20.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxQueuedSignals to value 100.
Nov  7 08:28:04 | Legato |  INFO | supervisor[523]/supervisor T=main | proc.c proc_Start() 1190 | Starting process 'lwm2mCtrlDaemon' with pid 26744
Nov  7 08:28:04 | Legato |  INFO | supervisor[26744]/supervisor T=main | proc.c proc_Start() 1155 | Execing 'lwm2mCtrlDaemon'
Nov  7 08:28:04 | Legato | -WRN- | _UNKNOWN_[26744]/framework T=main | LE_FILENAME le_fdMonitor_Create() 672 | FD Monitor object name 'lwm2mCtrlDaemon.lwm2mControl.le_avc' truncated to 'lwm2mCtrlDaemon.lwm2mControl.le'.
Nov  7 08:28:04 | Legato |  INFO | lwm2mCtrlDaemon[26744]/lwm2mControl T=main | lwm2mControl.c _lwm2mControl_COMPONENT_INIT() 170 | Air Vantage Connection Controller started.
Nov  7 08:28:04 | Legato |  INFO | lwm2mCtrlDaemon[26744]/lwm2mControl T=main | lwm2mControl.c _lwm2mControl_COMPONENT_INIT() 198 | Air Vantage session started successfully.
Nov  7 08:28:16 | Legato |  INFO | lwm2mCtrlDaemon[26744]/lwm2mControl T=main | lwm2mControl.c StatusHandler() 128 | Air Vantage agent reported update status: SESSION_STOPPED
Nov  7 08:28:27 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c app_Stop() 2731 | Stopping app 'lwm2mControl'
Nov  7 08:28:27 | Legato |  INFO | avcDaemon[11769]/avcDaemon T=main | avcServer.c ClientCloseSessionHandler() 566 | Client 0x65b94 closed, remove allocated resources
Nov  7 08:28:27 | Legato | -WRN- | _appStopClient[26869]/framework T=main | LE_FILENAME CreateSocket() 550 | Socket opened as standard i/o file descriptor 2!
Nov  7 08:28:27 | Legato |  INFO | supervisor[523]/supervisor T=main | apps.c DeactivateAppContainer() 340 | Application 'lwm2mControl' has stopped.
Nov  7 08:28:29 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c CreateTmpFs() 1204 | Mounted tmpfs at /legato/systems/current/appsWriteable/lwm2mControl/tmp.
Nov  7 08:28:29 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c CreateFileLink() 1504 | Created file link '/tmp/legato/serviceDirectoryServer' to '/legato/systems/current/appsWriteable/lwm2mControl/tmp/legato/serviceDirectoryServer'.
Nov  7 08:28:29 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c CreateFileLink() 1504 | Created file link '/tmp/legato/serviceDirectoryClient' to '/legato/systems/current/appsWriteable/lwm2mControl/tmp/legato/serviceDirectoryClient'.
Nov  7 08:28:29 | Legato |  INFO | supervisor[523]/supervisor T=main | proc.c proc_Start() 1033 | Process 'lwm2mCtrlDaemon' is configured to not run.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxCoreDumpFileBytes to value 8192.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxFileBytes to value 90112.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxLockedMemoryBytes to value 8192.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxFileDescriptors to value 256.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxMQueueBytes to value 512.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxThreads to value 20.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | resourceLimits.c SetRLimitValue() 282 | Setting resource limit maxQueuedSignals to value 100.
Nov  7 08:28:32 | Legato |  INFO | supervisor[523]/supervisor T=main | proc.c proc_Start() 1190 | Starting process 'strace' with pid 26937
Nov  7 08:28:32 | Legato |  INFO | supervisor[26937]/supervisor T=main | proc.c proc_Start() 1155 | Execing 'strace'
Nov  7 08:28:32 | Legato | -WRN- | _UNKNOWN_[26940]/framework T=main | LE_FILENAME le_fdMonitor_Create() 672 | FD Monitor object name 'lwm2mCtrlDaemon.lwm2mControl.le_avc' truncated to 'lwm2mCtrlDaemon.lwm2mControl.le'.
Nov  7 08:28:32 | Legato |  INFO | lwm2mCtrlDaemon[26940]/lwm2mControl T=main | lwm2mControl.c _lwm2mControl_COMPONENT_INIT() 170 | Air Vantage Connection Controller started.
Nov  7 08:28:32 | Legato |  INFO | lwm2mCtrlDaemon[26940]/lwm2mControl T=main | lwm2mControl.c _lwm2mControl_COMPONENT_INIT() 198 | Air Vantage session started successfully.
Nov  7 08:28:42 | Legato |  INFO | lwm2mCtrlDaemon[26940]/lwm2mControl T=main | lwm2mControl.c StatusHandler() 128 | Air Vantage agent reported update status: SESSION_STOPPED
Nov  7 08:31:59 | Legato |  INFO | supervisor[523]/supervisor T=main | app.c app_Stop() 2731 | Stopping app 'lwm2mControl'

karlkuhn · November 7, 2018, 2:34pm

Digging a bit more and trying to connect using the AT commands, resulted in

AT+WDSG
+WDSG:0,2
+WDSG:1,0

The first response (when checking the AT reference pdf) indicated

2—AirVantage Management Services must be provisioned. A bootstrap session is
required.

What is the bootstrap session referred to, and how to I provide it?

karlkuhn · November 8, 2018, 8:23am

A little more information from trace… This is still not working. I am stumped… Any thoughts?

Nov  8 08:22:15 | Legato |  INFO | AirvantageConnect[585]/AirvantageComponent T=main | AirvantageComponent.c avcSessionOpen() 280 | AVC_CONTROLLER:      >Starting AVC session
Nov  8 08:22:15 | Legato |  DBUG | AirvantageConnect[585]/framework T=main | le_avc_client.c le_avc_StartSession() 942 | Sending message to server and waiting for response : 0 bytes sent
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/swiQmi T=main | swiQmi.c swiQmi_CheckResponse() 775 | QMI_SWI_M2M_AVMS_SESSION_START_REQ_V01 sent to Modem
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/framework T=main | le_avc_server.c Handle_le_avc_StartSession() 712 | Sending response to client session 0x6811c : 4 bytes sent
Nov  8 08:22:15 | Legato |  INFO | AirvantageConnect[585]/AirvantageComponent T=main | AirvantageComponent.c avcSessionOpen() 288 | AVC_CONTROLLER:      >Start AVC session - OK!
Nov  8 08:22:15 | Legato |  INFO | AirvantageConnect[585]/AirvantageComponent T=main | AirvantageComponent.c StartAvcTimer() 79 | AVC_CONTROLLER:AVC Timer started: will retry in 60 seconds...
Nov  8 08:22:15 | Legato |  INFO | AirvantageConnect[585]/AirvantageComponent T=main | AirvantageComponent.c avcSessionCtrl_StatusHandler() 217 | AVC_CONTROLLER: Air Vantage agent reported update status: SESSION_STOPPED
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/swiQmi T=unknown | swiQmi.c IndicationsHandler() 288 | serviceType=0x6
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/swiQmi T=unknown | swiQmi.c IndicationsHandler() 289 | msg_id=0xA3
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 499 | Got AVMS message
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 527 | No session info available
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 536 | No config info available
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 558 | No notifications info available
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 566 | No connection_request available
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 573 | No reg_status available
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 577 | avmsInd.avms_data_session.notif_type=1
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 578 | avmsInd.avms_data_session.err_code=0
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 589 | No session_type available.
Nov  8 08:22:15 | Legato |  DBUG | avcDaemon[572]/le_pa_avc T=unknown | pa_avc_qmi.c AvmsIndicationHandler() 598 | No http status available.

karlkuhn · November 8, 2018, 12:23pm

Ok, so I have it working although not entirely sure why. In AirVantage I deleted the device and added it again, selecting a FW at this point as opposed to adding it later on. That seems to have made the difference? Not sure why. And yes I did have the correct IMEI and serial numbers…

Topic		Replies	Views
15.08 and Airvantage Legato Application Framework	1	597	February 9, 2016
AirVantage apps don't work Legato Application Framework	7	753	November 25, 2014
Airvantage stops working Legato Application Framework	7	731	June 25, 2015
AirVantage - Cannot install application over the air Legato Application Framework	1	633	May 6, 2019
AirVantage service failing to connect Legato Application Framework	12	1608	August 9, 2018

Airvantage session not working properly. Starts... but then just stops///

Related topics