2024-05-09 20:54:57,661 u_report_32.2 NOTICE - test start 2024-05-09 20:54:57,661 u_run_log_32.2 INFO - starting "inv -r /home/ubxlib/workspace/ubxlib_platform_stm32u5_rmea/ubxlib/port/platform/common/automation automation.log --build-dir=. 32.2"... 2024-05-09 20:54:57,667 u_run_log_32.2 INFO - inv pid 24 started 2024-05-09 20:54:57,669 u_monitor_32.2 INFO - watching output until run completes... 2024-05-09 20:55:08,073 u_monitor_32.2 INFO - u_settings: creating/re-writing global settings file "/home/ubxlib/.ubx_automation/settings_v2.json". 2024-05-09 20:55:08,105 u_monitor_32.2 INFO - u_settings: creating/re-writing global settings file "/home/ubxlib/.ubx_automation/settings_v2_agent_specific.json". 2024-05-09 20:55:08,116 u_monitor_32.2 INFO - === Loading u_packages === 2024-05-09 20:55:08,127 u_monitor_32.2 INFO - Found make 2024-05-09 20:55:08,139 u_monitor_32.2 INFO - Found unity 2024-05-09 20:55:08,150 u_monitor_32.2 INFO - Found arm_embedded_gcc 2024-05-09 20:55:08,160 u_monitor_32.2 INFO - Found stm32cubeu5 2024-05-09 20:55:08,171 u_monitor_32.2 INFO - Found stm32_cmsis_freertos 2024-05-09 20:55:08,182 u_monitor_32.2 INFO - Found openocd 2024-05-09 20:55:08,192 u_monitor_32.2 INFO - Using ELF file: /home/ubxlib/workspace/ubxlib_platform_stm32u5_rmea/_jenkins_work/32.2/build/runner.elf 2024-05-09 20:55:08,203 u_monitor_32.2 INFO - U_APP: 1: preambleHeapDefence[preamble] 2024-05-09 20:55:08,213 u_monitor_32.2 INFO - U_APP: 2: preambleCell[preamble] 2024-05-09 20:55:08,224 u_monitor_32.2 INFO - U_APP: 3: preambleCleanUp[preamble] 2024-05-09 20:55:08,234 u_monitor_32.2 INFO - U_APP: 4: portInitialisation[port] 2024-05-09 20:55:08,245 u_monitor_32.2 INFO - U_APP: 5: portRentrancy[port] 2024-05-09 20:55:08,255 u_monitor_32.2 INFO - U_APP: 6: portOs[port] 2024-05-09 20:55:08,266 u_monitor_32.2 INFO - U_APP: 7: portOsSemaphore[port] 2024-05-09 20:55:08,276 u_monitor_32.2 INFO - U_APP: 8: portOsExtended[port] 2024-05-09 20:55:08,287 u_monitor_32.2 INFO - U_APP: 9: portEventQueue[port] 2024-05-09 20:55:08,297 u_monitor_32.2 INFO - U_APP: 10: portHeap[port] 2024-05-09 20:55:08,308 u_monitor_32.2 INFO - U_APP: 11: portStrtok_r[port] 2024-05-09 20:55:08,318 u_monitor_32.2 INFO - U_APP: 12: portMktime64[port] 2024-05-09 20:55:08,329 u_monitor_32.2 INFO - U_APP: 13: portGmtime_r[port] 2024-05-09 20:55:08,339 u_monitor_32.2 INFO - U_APP: 14: portGetTimezoneOffsetSeconds[port] 2024-05-09 20:55:08,350 u_monitor_32.2 INFO - U_APP: 15: portGpioRequiresSpecificWiring[port] 2024-05-09 20:55:08,360 u_monitor_32.2 INFO - U_APP: 16: portUartRequiresSpecificWiring[port] 2024-05-09 20:55:08,371 u_monitor_32.2 INFO - U_APP: 17: portI2cRequiresSpecificWiring[port] 2024-05-09 20:55:08,381 u_monitor_32.2 INFO - U_APP: 18: portTimers[port] 2024-05-09 20:55:08,392 u_monitor_32.2 INFO - U_APP: 19: portCriticalSection[port] 2024-05-09 20:55:08,402 u_monitor_32.2 INFO - U_APP: 20: portCleanUp[port] 2024-05-09 20:55:08,413 u_monitor_32.2 INFO - U_APP: 21: atClientInitialisation[atClient] 2024-05-09 20:55:08,423 u_monitor_32.2 INFO - U_APP: 22: atClientConfiguration[atClient] 2024-05-09 20:55:08,433 u_monitor_32.2 INFO - U_APP: 23: atClientCleanUp[atClient] 2024-05-09 20:55:08,444 u_monitor_32.2 INFO - U_APP: 24: cellCfgBandMask[cellCfg] 2024-05-09 20:55:08,454 u_monitor_32.2 INFO - U_APP: 25: cellCfgGetSetRat[cellCfg] 2024-05-09 20:55:08,465 u_monitor_32.2 INFO - U_APP: 26: cellCfgSetGetRatRank[cellCfg] 2024-05-09 20:55:08,475 u_monitor_32.2 INFO - U_APP: 27: cellCfgGetSetMnoProfile[cellCfg] 2024-05-09 20:55:08,486 u_monitor_32.2 INFO - U_APP: 28: cellCfgUdconf[cellCfg] 2024-05-09 20:55:08,496 u_monitor_32.2 INFO - U_APP: 29: cellCfgAutoBaud[cellCfg] 2024-05-09 20:55:08,507 u_monitor_32.2 INFO - U_APP: 30: cellCfgGreeting[cellCfg] 2024-05-09 20:55:08,517 u_monitor_32.2 INFO - U_APP: 31: cellCfgGnssProfile[cellCfg] 2024-05-09 20:55:08,528 u_monitor_32.2 INFO - U_APP: 32: cellCfgTime[cellCfg] 2024-05-09 20:55:08,538 u_monitor_32.2 INFO - U_APP: 33: cellCfgCleanUp[cellCfg] 2024-05-09 20:55:08,549 u_monitor_32.2 INFO - U_APP: 34: cellFileWrite[cellFile] 2024-05-09 20:55:08,559 u_monitor_32.2 INFO - U_APP: 35: cellFileSize[cellFile] 2024-05-09 20:55:08,569 u_monitor_32.2 INFO - U_APP: 36: cellFileBlockRead[cellFile] 2024-05-09 20:55:08,580 u_monitor_32.2 INFO - U_APP: 37: cellFileRead[cellFile] 2024-05-09 20:55:08,590 u_monitor_32.2 INFO - U_APP: 38: cellFileListAll[cellFile] 2024-05-09 20:55:08,601 u_monitor_32.2 INFO - U_APP: 39: cellFileListAllReentrant[cellFile] 2024-05-09 20:55:08,611 u_monitor_32.2 INFO - U_APP: 40: cellFileDelete[cellFile] 2024-05-09 20:55:08,622 u_monitor_32.2 INFO - U_APP: 41: cellFileCleanUp[cellFile] 2024-05-09 20:55:08,633 u_monitor_32.2 INFO - U_APP: 42: cellFotaVeryBasicIndeed[cellFota] 2024-05-09 20:55:08,643 u_monitor_32.2 INFO - U_APP: 43: cellFotaCleanUp[cellFota] 2024-05-09 20:55:08,653 u_monitor_32.2 INFO - U_APP: 44: cellGpioBasic[cellGpio] 2024-05-09 20:55:08,664 u_monitor_32.2 INFO - U_APP: 45: cellGpioCleanUp[cellGpio] 2024-05-09 20:55:08,674 u_monitor_32.2 INFO - U_APP: 46: cellHttp[cellHttp] 2024-05-09 20:55:08,685 u_monitor_32.2 INFO - U_APP: 47: cellHttpCleanUp[cellHttp] 2024-05-09 20:55:08,696 u_monitor_32.2 INFO - U_APP: 48: cellInfoImeiEtc[cellInfo] 2024-05-09 20:55:08,706 u_monitor_32.2 INFO - U_APP: 49: cellInfoRadioParameters[cellInfo] 2024-05-09 20:55:08,717 u_monitor_32.2 INFO - U_APP: 50: cellInfoTime[cellInfo] 2024-05-09 20:55:08,728 u_monitor_32.2 INFO - U_APP: 51: cellInfoCleanUp[cellInfo] 2024-05-09 20:55:08,738 u_monitor_32.2 INFO - U_APP: 52: cellLocCfg[cellLoc] 2024-05-09 20:55:08,749 u_monitor_32.2 INFO - U_APP: 53: cellLocLoc[cellLoc] 2024-05-09 20:55:08,759 u_monitor_32.2 INFO - U_APP: 54: cellLocAssistNow[cellLoc] 2024-05-09 20:55:08,770 u_monitor_32.2 INFO - U_APP: 55: cellLocCleanUp[cellLoc] 2024-05-09 20:55:08,780 u_monitor_32.2 INFO - U_APP: 56: cellMqtt[cellMqtt] 2024-05-09 20:55:08,791 u_monitor_32.2 INFO - U_APP: 57: cellMqttSn[cellMqtt] 2024-05-09 20:55:08,801 u_monitor_32.2 INFO - U_APP: 58: cellMqttCleanUp[cellMqtt] 2024-05-09 20:55:08,812 u_monitor_32.2 INFO - U_APP: 59: cellMuxPrivateBackToBack[cellMuxPrivate] 2024-05-09 20:55:08,822 u_monitor_32.2 INFO - U_APP: 60: cellMuxBasic[cellMux] 2024-05-09 20:55:08,832 u_monitor_32.2 INFO - U_APP: 61: cellMuxSock[cellMux] 2024-05-09 20:55:08,843 u_monitor_32.2 INFO - U_APP: 62: cellMuxMqtt[cellMux] 2024-05-09 20:55:08,853 u_monitor_32.2 INFO - U_APP: 63: cellMuxHttp[cellMux] 2024-05-09 20:55:08,864 u_monitor_32.2 INFO - U_APP: 64: cellMuxCleanUp[cellMux] 2024-05-09 20:55:08,875 u_monitor_32.2 INFO - U_APP: 65: cellNetConnectDisconnectPlus[cellNet] 2024-05-09 20:55:08,885 u_monitor_32.2 INFO - U_APP: 66: cellNetScanRegActDeact[cellNet] 2024-05-09 20:55:08,895 u_monitor_32.2 INFO - U_APP: 67: cellNetCleanUp[cellNet] 2024-05-09 20:55:08,906 u_monitor_32.2 INFO - U_APP: 68: cellPppBasic[cellPpp] 2024-05-09 20:55:08,916 u_monitor_32.2 INFO - U_APP: 69: cellPppWithGnss[cellPpp] 2024-05-09 20:55:08,927 u_monitor_32.2 INFO - U_APP: 70: cellPppCleanUp[cellPpp] 2024-05-09 20:55:08,937 u_monitor_32.2 INFO - U_APP: 71: cellPwr[cellPwr] 2024-05-09 20:55:08,948 u_monitor_32.2 INFO - U_APP: 72: uCellPwrAnyModule[cellPwr] 2024-05-09 20:55:08,958 u_monitor_32.2 INFO - U_APP: 73: cellPwrReboot[cellPwr] 2024-05-09 20:55:08,969 u_monitor_32.2 INFO - U_APP: 74: cellPwrReset[cellPwr] 2024-05-09 20:55:08,979 u_monitor_32.2 INFO - U_APP: 75: cellPwrSavingUart[cellPwr] 2024-05-09 20:55:08,990 u_monitor_32.2 INFO - U_APP: 76: cellPwrCleanUp[cellPwr] 2024-05-09 20:55:09,000 u_monitor_32.2 INFO - U_APP: 77: cellSecTlsSettings[cellSecTls] 2024-05-09 20:55:09,011 u_monitor_32.2 INFO - U_APP: 78: cellSecTlsCleanUp[cellSecTls] 2024-05-09 20:55:09,021 u_monitor_32.2 INFO - U_APP: 79: cellSimFplmnDelete[cellSim] 2024-05-09 20:55:09,032 u_monitor_32.2 INFO - U_APP: 80: cellSimCleanUp[cellSim] 2024-05-09 20:55:09,042 u_monitor_32.2 INFO - U_APP: 81: cellSockBasic[cellSock] 2024-05-09 20:55:09,053 u_monitor_32.2 INFO - U_APP: 82: cellSockOptionSetGet[cellSock] 2024-05-09 20:55:09,064 u_monitor_32.2 INFO - U_APP: 83: cellSockCleanUp[cellSock] 2024-05-09 20:55:09,074 u_monitor_32.2 INFO - U_APP: 84: cellTimeBasic[cellTime] 2024-05-09 20:55:09,085 u_monitor_32.2 INFO - U_APP: 85: cellTimeCleanUp[cellTime] 2024-05-09 20:55:09,095 u_monitor_32.2 INFO - U_APP: 86: cellInitialisation[cell] 2024-05-09 20:55:09,105 u_monitor_32.2 INFO - U_APP: 87: cellAdd[cell] 2024-05-09 20:55:09,116 u_monitor_32.2 INFO - U_APP: 88: cellCleanUp[cell] 2024-05-09 20:55:09,126 u_monitor_32.2 INFO - U_APP: 89: deviceSerial[device] 2024-05-09 20:55:09,137 u_monitor_32.2 INFO - U_APP: 90: deviceSerialWrapper[device] 2024-05-09 20:55:09,147 u_monitor_32.2 INFO - U_APP: 91: deviceSerialCleanup[device] 2024-05-09 20:55:09,158 u_monitor_32.2 INFO - U_APP: 92: exampleC030ModuleFwUpdate[example] 2024-05-09 20:55:09,168 u_monitor_32.2 INFO - U_APP: 93: exampleCellLteCfg[example] 2024-05-09 20:55:09,179 u_monitor_32.2 INFO - U_APP: 94: exampleCellPowerSaving3gpp[example] 2024-05-09 20:55:09,189 u_monitor_32.2 INFO - U_APP: 95: exampleCellPowerSavingEDrx[example] 2024-05-09 20:55:09,200 u_monitor_32.2 INFO - U_APP: 96: exampleGnssCfgVal[example] 2024-05-09 20:55:09,210 u_monitor_32.2 INFO - U_APP: 97: exampleGnssDec[example] 2024-05-09 20:55:09,221 u_monitor_32.2 INFO - U_APP: 98: exampleGnssGeofence[example] 2024-05-09 20:55:09,231 u_monitor_32.2 INFO - U_APP: 99: exampleGnssMsg[example] 2024-05-09 20:55:09,242 u_monitor_32.2 INFO - U_APP: 100: exampleGnssPos[example] 2024-05-09 20:55:09,252 u_monitor_32.2 INFO - U_APP: 101: exampleHttpClient[example] 2024-05-09 20:55:09,263 u_monitor_32.2 INFO - U_APP: 102: exampleLocCellLocate[example] 2024-05-09 20:55:09,273 u_monitor_32.2 INFO - U_APP: 103: exampleLocGnss[example] 2024-05-09 20:55:09,284 u_monitor_32.2 INFO - U_APP: 104: exampleLocGnssCell[example] 2024-05-09 20:55:09,294 u_monitor_32.2 INFO - U_APP: 105: exampleLocGnssCellContinuous[example] 2024-05-09 20:55:09,305 u_monitor_32.2 INFO - U_APP: 106: exampleLocGnssCloudLocate[example] 2024-05-09 20:55:09,315 u_monitor_32.2 INFO - U_APP: 107: exampleLocGnssContinuous[example] 2024-05-09 20:55:09,325 u_monitor_32.2 INFO - U_APP: 108: exampleMqttClient[example] 2024-05-09 20:55:09,336 u_monitor_32.2 INFO - U_APP: 109: exampleSecPsk[example] 2024-05-09 20:55:09,346 u_monitor_32.2 INFO - U_APP: 110: exampleSockets[example] 2024-05-09 20:55:09,357 u_monitor_32.2 INFO - U_APP: 111: exampleSocketsDtls[example] 2024-05-09 20:55:09,367 u_monitor_32.2 INFO - U_APP: 112: exampleSocketsTls[example] 2024-05-09 20:55:09,378 u_monitor_32.2 INFO - U_APP: 113: example{CleanUp}[example] 2024-05-09 20:55:09,388 u_monitor_32.2 INFO - U_APP: 114: gnssCfgBasic[gnssCfg] 2024-05-09 20:55:09,399 u_monitor_32.2 INFO - U_APP: 115: gnssCfgValBasic[gnssCfg] 2024-05-09 20:55:09,409 u_monitor_32.2 INFO - U_APP: 116: gnssCfgCleanUp[gnssCfg] 2024-05-09 20:55:09,420 u_monitor_32.2 INFO - U_APP: 117: gnssDecCallback[gnssDec] 2024-05-09 20:55:09,431 u_monitor_32.2 INFO - U_APP: 118: gnssDecKnown[gnssDec] 2024-05-09 20:55:09,441 u_monitor_32.2 INFO - U_APP: 119: gnssInfoStatic[gnssInfo] 2024-05-09 20:55:09,451 u_monitor_32.2 INFO - U_APP: 120: gnssInfoTime[gnssInfo] 2024-05-09 20:55:09,462 u_monitor_32.2 INFO - U_APP: 121: gnssMgaBasic[gnssMga] 2024-05-09 20:55:09,472 u_monitor_32.2 INFO - U_APP: 122: gnssMgaCleanUp[gnssMga] 2024-05-09 20:55:09,483 u_monitor_32.2 INFO - U_APP: 123: gnssMsgReceiveBlocking[gnssMsg] 2024-05-09 20:55:09,493 u_monitor_32.2 INFO - U_APP: 124: gnssMsgReceiveNonBlocking[gnssMsg] 2024-05-09 20:55:09,504 u_monitor_32.2 INFO - U_APP: 125: gnssMsgCleanUp[gnssMsg] 2024-05-09 20:55:09,514 u_monitor_32.2 INFO - U_APP: 126: gnssPosPos[gnssPos] 2024-05-09 20:55:09,525 u_monitor_32.2 INFO - U_APP: 127: gnssPosRrlp[gnssPos] 2024-05-09 20:55:09,535 u_monitor_32.2 INFO - U_APP: 128: gnssPosStreamed[gnssPos] 2024-05-09 20:55:09,546 u_monitor_32.2 INFO - U_APP: 129: gnssPosCleanUp[gnssPos] 2024-05-09 20:55:09,556 u_monitor_32.2 INFO - U_APP: 130: gnssPwrBasic[gnssPwr] 2024-05-09 20:55:09,567 u_monitor_32.2 INFO - U_APP: 131: gnssPwrCleanUp[gnssPwr] 2024-05-09 20:55:09,577 u_monitor_32.2 INFO - U_APP: 132: gnssUtilTransparent[gnssUtil] 2024-05-09 20:55:09,588 u_monitor_32.2 INFO - U_APP: 133: gnssUtilCleanUp[gnssUtil] 2024-05-09 20:55:09,598 u_monitor_32.2 INFO - U_APP: 134: gnssInitialisation[gnss] 2024-05-09 20:55:09,609 u_monitor_32.2 INFO - U_APP: 135: gnssAddStream[gnss] 2024-05-09 20:55:09,619 u_monitor_32.2 INFO - U_APP: 136: gnssCleanUp[gnss] 2024-05-09 20:55:09,630 u_monitor_32.2 INFO - U_APP: 137: gnssPrivateNmea[gnss] 2024-05-09 20:55:09,640 u_monitor_32.2 INFO - U_APP: 138: gnssPrivateRtcm[gnss] 2024-05-09 20:55:09,651 u_monitor_32.2 INFO - U_APP: 139: gnssPrivateUbx[gnss] 2024-05-09 20:55:09,661 u_monitor_32.2 INFO - U_APP: 140: gnssPrivateCleanUp[gnss] 2024-05-09 20:55:09,671 u_monitor_32.2 INFO - U_APP: 141: httpClient[httpClient] 2024-05-09 20:55:09,682 u_monitor_32.2 INFO - U_APP: 142: httpClientCleanUp[httpClient] 2024-05-09 20:55:09,692 u_monitor_32.2 INFO - U_APP: 143: linkedListBasic[linkedList] 2024-05-09 20:55:09,703 u_monitor_32.2 INFO - U_APP: 144: linkedListCleanUp[linkedList] 2024-05-09 20:55:09,713 u_monitor_32.2 INFO - U_APP: 145: locationBasic[location] 2024-05-09 20:55:09,724 u_monitor_32.2 INFO - U_APP: 146: locationCleanUp[location] 2024-05-09 20:55:09,734 u_monitor_32.2 INFO - U_APP: 147: mempoolBasic[mempool] 2024-05-09 20:55:09,745 u_monitor_32.2 INFO - U_APP: 148: mempoolFull[mempool] 2024-05-09 20:55:09,755 u_monitor_32.2 INFO - U_APP: 149: mempoolFreeAllMem[mempool] 2024-05-09 20:55:09,766 u_monitor_32.2 INFO - U_APP: 150: mqttClient[mqttClient] 2024-05-09 20:55:09,776 u_monitor_32.2 INFO - U_APP: 151: mqttClientSn[mqttClient] 2024-05-09 20:55:09,787 u_monitor_32.2 INFO - U_APP: 152: mqttClientCleanUp[mqttClient] 2024-05-09 20:55:09,797 u_monitor_32.2 INFO - U_APP: 153: networkSock[network] 2024-05-09 20:55:09,808 u_monitor_32.2 INFO - U_APP: 154: networkLoc[network] 2024-05-09 20:55:09,818 u_monitor_32.2 INFO - U_APP: 155: networkShortRange[network] 2024-05-09 20:55:09,829 u_monitor_32.2 INFO - U_APP: 156: networkCleanUp[network] 2024-05-09 20:55:09,839 u_monitor_32.2 INFO - U_APP: 157: pbufInsertPayload[pbuf] 2024-05-09 20:55:09,850 u_monitor_32.2 INFO - U_APP: 158: pbufPktList[pbuf] 2024-05-09 20:55:09,860 u_monitor_32.2 INFO - U_APP: 159: ringbufferBasic[ringbuffer] 2024-05-09 20:55:09,871 u_monitor_32.2 INFO - U_APP: 160: securityCredentialTest[securityCredential] 2024-05-09 20:55:09,881 u_monitor_32.2 INFO - U_APP: 161: securityCredentialCleanUp[securityCredential] 2024-05-09 20:55:09,891 u_monitor_32.2 INFO - U_APP: 162: securitySeal[security] 2024-05-09 20:55:09,902 u_monitor_32.2 INFO - U_APP: 163: securityPskGeneration[security] 2024-05-09 20:55:09,912 u_monitor_32.2 INFO - U_APP: 164: securityZtp[security] 2024-05-09 20:55:09,923 u_monitor_32.2 INFO - U_APP: 165: securityCleanUp[security] 2024-05-09 20:55:09,933 u_monitor_32.2 INFO - U_APP: 166: shortRangeInitialisation[shortRange] 2024-05-09 20:55:09,944 u_monitor_32.2 INFO - U_APP: 167: sockAddressStrings[sock] 2024-05-09 20:55:09,954 u_monitor_32.2 INFO - U_APP: 168: sockBasicUdp[sock] 2024-05-09 20:55:09,965 u_monitor_32.2 INFO - U_APP: 169: sockBasicTcp[sock] 2024-05-09 20:55:09,975 u_monitor_32.2 INFO - U_APP: 170: sockMaxNumSockets[sock] 2024-05-09 20:55:09,986 u_monitor_32.2 INFO - U_APP: 171: sockOptionsSetGet[sock] 2024-05-09 20:55:09,996 u_monitor_32.2 INFO - U_APP: 172: sockLocalPort[sock] 2024-05-09 20:55:10,007 u_monitor_32.2 INFO - U_APP: 173: sockNonBlocking[sock] 2024-05-09 20:55:10,017 u_monitor_32.2 INFO - U_APP: 174: sockUdpEchoNonPingPong[sock] 2024-05-09 20:55:10,028 u_monitor_32.2 INFO - U_APP: 175: sockAsyncUdpEchoMayFailDueToInternetDatagramLoss[sock] 2024-05-09 20:55:10,038 u_monitor_32.2 INFO - U_APP: 176: sockAsyncTcpEcho[sock] 2024-05-09 20:55:10,049 u_monitor_32.2 INFO - U_APP: 177: sockCleanUp[sock] 2024-05-09 20:55:10,059 u_monitor_32.2 INFO - U_APP: 178: spartnCrc[spartn] 2024-05-09 20:55:10,070 u_monitor_32.2 INFO - U_APP: 179: spartnMessage[spartn] 2024-05-09 20:55:10,080 u_monitor_32.2 INFO - U_APP: 180: spartnCleanUp[spartn] 2024-05-09 20:55:10,090 u_monitor_32.2 INFO - U_APP: 181: ubxProtocolBackToBack[ubxProtocol] 2024-05-09 20:55:10,101 u_monitor_32.2 INFO - U_APP: 182: ubxProtocolCleanUp[ubxProtocol] 2024-05-09 20:55:10,111 u_monitor_32.2 INFO - U_APP: 183: postambleResourceCheck[postamble] 2024-05-09 20:55:10,129 u_monitor_32.2 INFO - U_APP: running functions that begin with "port.exampleGnss.gnss". 2024-05-09 20:55:10,159 u_monitor_32.2 INFO - U_APP: Running preambleHeapDefence... 2024-05-09 20:55:10,160 u_monitor_32.2 INFO - progress update - item preambleHeapDefence() started on 20:55:10.160268. 2024-05-09 20:55:10,171 u_monitor_32.2 INFO - U_PREAMBLE_TEST: at start(ish) of day main task stack had a minimum of 7544 byte(s) free. 2024-05-09 20:55:10,183 u_monitor_32.2 INFO - U_PREAMBLE_TEST: at start(ish) of day heap had a minimum of 740096 byte(s) free. 2024-05-09 20:55:10,194 u_monitor_32.2 INFO - U_PREAMBLE_TEST: calling platform APIs that might allocate memory when first called... 2024-05-09 20:55:10,205 u_monitor_32.2 INFO - U_PREAMBLE_TEST: resetting GNSS module by toggling pin 93 (0x5d) low. 2024-05-09 20:55:10,915 u_monitor_32.2 INFO - U_PREAMBLE_TEST: 32 byte(s) of heap were lost to the platform. 2024-05-09 20:55:10,926 u_monitor_32.2 INFO - /home/ubxlib/workspace/ubxlib_platform_stm32u5_rmea@4/ubxlib/port/platform/common/test/u_preamble_test.c:120:preambleHeapDefence:PASS 2024-05-09 20:55:10,927 u_monitor_32.2 INFO - progress update - item preambleHeapDefence() passed on 20:55:10.927192 after running for 1 second(s). 2024-05-09 20:55:10,927 u_report_32.2 SUCCESS - test PASSED (preambleHeapDefence() passed on 20:55:10.927192 after running for 1 second(s)) 2024-05-09 20:55:10,957 u_monitor_32.2 INFO - U_APP: Running preambleCell... 2024-05-09 20:55:10,957 u_monitor_32.2 INFO - progress update - item preambleCell() started on 20:55:10.957413. 2024-05-09 20:55:10,967 u_monitor_32.2 INFO - U_CELL_TEST_PREAMBLE: start. 2024-05-09 20:55:10,978 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: test preamble start. 2024-05-09 20:55:10,989 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: opening UART 2... 2024-05-09 20:55:10,999 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: adding an AT client on UART 2... 2024-05-09 20:55:11,010 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: adding a cellular instance on the AT client... 2024-05-09 20:55:11,021 u_monitor_32.2 INFO - U_CELL: initialising with enable power pin not connected, PWR_ON pin 94 (0x5e) (and is toggled from 1 to 0) and VInt pin not connected. 2024-05-09 20:55:11,032 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: powering on... 2024-05-09 20:55:11,043 u_monitor_32.2 INFO - AT 2024-05-09 20:55:11,102 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,141 u_monitor_32.2 INFO - AT 2024-05-09 20:55:11,200 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,211 u_monitor_32.2 INFO - U_CELL_PWR: powering on, module is already on. 2024-05-09 20:55:11,240 u_monitor_32.2 INFO - ATE0 2024-05-09 20:55:11,300 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,340 u_monitor_32.2 INFO - AT+CMEE=2 2024-05-09 20:55:11,399 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,439 u_monitor_32.2 INFO - AT+UDCONF=1,0 2024-05-09 20:55:11,498 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,537 u_monitor_32.2 INFO - ATI9 2024-05-09 20:55:11,596 u_monitor_32.2 INFO - 23.60,A01.06 2024-05-09 20:55:11,627 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,637 u_monitor_32.2 INFO - AT&C1 2024-05-09 20:55:11,695 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,736 u_monitor_32.2 INFO - AT&D0 2024-05-09 20:55:11,795 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,837 u_monitor_32.2 INFO - AT&K0 2024-05-09 20:55:11,894 u_monitor_32.2 INFO - OK 2024-05-09 20:55:11,934 u_monitor_32.2 INFO - AT+UPSV=0 2024-05-09 20:55:11,993 u_monitor_32.2 INFO - OK 2024-05-09 20:55:12,034 u_monitor_32.2 INFO - AT+UGPRF? 2024-05-09 20:55:12,092 u_monitor_32.2 INFO - +UGPRF: 2,0,"" 2024-05-09 20:55:12,123 u_monitor_32.2 INFO - OK 2024-05-09 20:55:12,133 u_monitor_32.2 INFO - AT+CFUN=0 2024-05-09 20:55:12,191 u_monitor_32.2 INFO - OK 2024-05-09 20:55:12,231 u_monitor_32.2 INFO - AT+CIMI 2024-05-09 20:55:12,290 u_monitor_32.2 INFO - 901405108768550 2024-05-09 20:55:12,321 u_monitor_32.2 INFO - OK 2024-05-09 20:55:12,336 u_monitor_32.2 INFO - U_CELL_INFO: IMSI is 901405108768550. 2024-05-09 20:55:12,346 u_monitor_32.2 INFO - AT+CSGT=1,"Module has booted." 2024-05-09 20:55:12,390 u_monitor_32.2 INFO - OK 2024-05-09 20:55:12,430 u_monitor_32.2 INFO - AT+CFUN? 2024-05-09 20:55:12,489 u_monitor_32.2 INFO - +CFUN: 0,0 2024-05-09 20:55:12,519 u_monitor_32.2 INFO - OK 2024-05-09 20:55:13,461 u_monitor_32.2 INFO - AT+CFUN=1 2024-05-09 20:55:13,519 u_monitor_32.2 INFO - OK 2024-05-09 20:55:14,492 u_monitor_32.2 INFO - AT+URAT? 2024-05-09 20:55:14,551 u_monitor_32.2 INFO - +URAT: 0 2024-05-09 20:55:14,581 u_monitor_32.2 INFO - OK 2024-05-09 20:55:14,593 u_monitor_32.2 INFO - U_CELL_CFG: RAT is 1 (in module terms 0). 2024-05-09 20:55:14,604 u_monitor_32.2 INFO - AT+CFUN=0 2024-05-09 20:55:14,649 u_monitor_32.2 INFO - OK 2024-05-09 20:55:14,690 u_monitor_32.2 INFO - AT+CFUN? 2024-05-09 20:55:14,749 u_monitor_32.2 INFO - +CFUN: 0,0 2024-05-09 20:55:14,779 u_monitor_32.2 INFO - OK 2024-05-09 20:55:15,720 u_monitor_32.2 INFO - AT+CFUN=1 2024-05-09 20:55:15,778 u_monitor_32.2 INFO - OK 2024-05-09 20:55:16,751 u_monitor_32.2 INFO - AT+URAT? 2024-05-09 20:55:16,809 u_monitor_32.2 INFO - +URAT: 0 2024-05-09 20:55:16,840 u_monitor_32.2 INFO - OK 2024-05-09 20:55:16,851 u_monitor_32.2 INFO - U_CELL_CFG: RAT is 0 (in module terms 0). 2024-05-09 20:55:16,862 u_monitor_32.2 INFO - AT+CFUN=0 2024-05-09 20:55:16,908 u_monitor_32.2 INFO - OK 2024-05-09 20:55:16,949 u_monitor_32.2 INFO - AT+CGDCONT? 2024-05-09 20:55:17,009 u_monitor_32.2 INFO - +CGDCONT: 1,"IP","iot.1nce.net","0.0.0.0",0,0 2024-05-09 20:55:17,039 u_monitor_32.2 INFO - OK 2024-05-09 20:55:18,882 u_monitor_32.2 INFO - U_AT_CLIENT_0-1: AT error -10. 2024-05-09 20:55:18,893 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: test preamble end. 2024-05-09 20:55:18,905 u_monitor_32.2 INFO - U_CELL_PWR: powering off with AT command. 2024-05-09 20:55:18,940 u_monitor_32.2 INFO - AT+CPWROFF 2024-05-09 20:55:19,098 u_monitor_32.2 INFO - OK 2024-05-09 20:55:19,138 u_monitor_32.2 INFO - AT 2024-05-09 20:55:21,071 u_monitor_32.2 INFO - U_AT_CLIENT_0-1: AT error -10. 2024-05-09 20:55:22,062 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: deinitialising cellular API... 2024-05-09 20:55:22,073 u_monitor_32.2 INFO - U_CELL_TEST_PRIVATE: removing AT client... 2024-05-09 20:55:22,120 u_monitor_32.2 INFO - U_CELL_TEST_PREAMBLE: complete. 2024-05-09 20:55:22,131 u_monitor_32.2 INFO - U_PREAMBLE_TEST: main task stack had a minimum of 6940 byte(s) free (minimum is 5120). 2024-05-09 20:55:22,142 u_monitor_32.2 INFO - U_PREAMBLE_TEST: heap had a minimum of 726184 byte(s) free (minimum is 512000). 2024-05-09 20:55:22,153 u_monitor_32.2 INFO - U_PREAMBLE_TEST: resources are good (1 outstanding OS resource(s), as expected). 2024-05-09 20:55:22,164 u_monitor_32.2 INFO - /home/ubxlib/workspace/ubxlib_platform_stm32u5_rmea@4/ubxlib/port/platform/common/test/u_preamble_test.c:258:preambleCell:PASS 2024-05-09 20:55:22,165 u_monitor_32.2 INFO - progress update - item preambleCell() passed on 20:55:22.165895 after running for 11 second(s). 2024-05-09 20:55:22,166 u_report_32.2 SUCCESS - test PASSED (preambleCell() passed on 20:55:22.165895 after running for 11 second(s)) 2024-05-09 20:55:22,195 u_monitor_32.2 INFO - U_APP: Running preambleCleanUp... 2024-05-09 20:55:22,195 u_monitor_32.2 INFO - progress update - item preambleCleanUp() started on 20:55:22.195868. 2024-05-09 20:55:22,206 u_monitor_32.2 INFO - U_PREAMBLE_TEST: main task stack had a minimum of 6940 byte(s) free (minimum is 5120). 2024-05-09 20:55:22,217 u_monitor_32.2 INFO - U_PREAMBLE_TEST: heap had a minimum of 726184 byte(s) free (minimum is 512000). 2024-05-09 20:55:22,228 u_monitor_32.2 INFO - U_PREAMBLE_TEST: resources are good (1 outstanding OS resource(s), as expected). 2024-05-09 20:55:22,239 u_monitor_32.2 INFO - /home/ubxlib/workspace/ubxlib_platform_stm32u5_rmea@4/ubxlib/port/platform/common/test/u_preamble_test.c:281:preambleCleanUp:PASS 2024-05-09 20:55:22,240 u_monitor_32.2 INFO - progress update - item preambleCleanUp() passed on 20:55:22.240158 after running for 0 second(s). 2024-05-09 20:55:22,240 u_report_32.2 SUCCESS - test PASSED (preambleCleanUp() passed on 20:55:22.240158 after running for 0 second(s)) 2024-05-09 20:55:22,269 u_monitor_32.2 INFO - U_APP: Running portInitialisation... 2024-05-09 20:55:22,270 u_monitor_32.2 INFO - progress update - item portInitialisation() started on 20:55:22.270260. 2024-05-09 20:55:22,280 u_monitor_32.2 INFO - U_PORT_TEST: main task stack had a minimum of 6940 byte(s) free (minimum is 5120). 2024-05-09 20:55:22,291 u_monitor_32.2 INFO - U_PORT_TEST: heap had a minimum of 726184 byte(s) free (minimum is 512000). 2024-05-09 20:55:22,302 u_monitor_32.2 INFO - U_PORT_TEST: resources are good (1 outstanding OS resource(s), as expected). 2024-05-09 20:55:22,313 u_monitor_32.2 INFO - /home/ubxlib/workspace/ubxlib_platform_stm32u5_rmea@4/ubxlib/port/test/u_port_test.c:1305:portInitialisation:PASS 2024-05-09 20:55:22,314 u_monitor_32.2 INFO - progress update - item portInitialisation() passed on 20:55:22.313988 after running for 0 second(s).