Asset Tracker V2: A-GPS not working? LOCATION_MODULE_EVT_AGPS_NEEDED but no CLOUD_WRAP_EVT_AGPS_DATA_RECEIVED

Hi there!

I'm evaluating A-GPS performance on the Asset Tracker V2 app packaged with nRF Connect SDK v2.2.0-rc1 on a Thingy:91 on NB-IoT with a contract SIM. The modem FW is mfw_nrf9160_1.3.2

The nRF9160 platform is new to me and maybe my understanding is not correct yet. From my observation it appears that the Thingy:91 is requesting A-GPS data from nRF Cloud but it is never received(?)

I have enabled debug level log output for the Cloud, Data, Location and Modem module. Here is the captured log:

thingy91.log

I can see that the LOCATION_MODULE_EVT_AGPS_NEEDED event is generated and that the Data module sends an "A-GPS request":

[00:01:19.190,338] <dbg> data_module: State transition STATE_CLOUD_DISCONNECTED --> STATE_CLOUD_CONNECTED                                                       
[00:01:19.192,230] <dbg> location: A-GPS request from modem (ephe: 0xffffffff alm: 0xffffffff flags: 0x3b)                                                      
[00:01:19.383,300] <dbg> location: Waiting for the RRC connection release...                                                                                    
[00:01:19.387,420] <inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_DATA_READY                                                                                 
[00:01:19.434,570] <inf> app_event_manager: MODEM_EVT_MODEM_STATIC_DATA_READY                                                                                   
[00:01:19.486,694] <inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY                                                                                  
[00:01:19.538,330] <inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY                                                                                        
[00:02:21.802,764] <dbg> modem_module: RRC mode: Idle                                                                                                           
[00:02:21.805,450] <dbg> location: Starting timer with timeout=90000                                                                                            
[00:02:21.805,511] <dbg> location: Request A-GPS data from application: ephe 0xffffffff, alm 0xffffffff, data_flags 0x3b                                        
[00:02:21.805,511] <dbg> location_module: Requested A-GPS data                                                                                                  
[00:02:21.805,603] <inf> app_event_manager: LOCATION_MODULE_EVT_AGPS_NEEDED                                                                                     
[00:02:21.861,663] <dbg> data_module: A-GPS request sent                                                                                                        
[00:02:22.294,494] <dbg> modem_module: Incoming RSRP status message, RSRP value is -104                                                                         
[00:02:22.615,173] <dbg> modem_module: RRC mode: Connected

I don't see the CLOUD_WRAP_EVT_AGPS_DATA_RECEIVED event in the log output. I have also put a breakpoint in cloud_module.c line 347 but it is never hit where agps_data_handle() must be called:

	case CLOUD_WRAP_EVT_AGPS_DATA_RECEIVED:
		LOG_DBG("CLOUD_WRAP_EVT_AGPS_DATA_RECEIVED");
		agps_data_handle(evt->data.buf, evt->data.len);
		break;

I can see the AGPS message on the nRF Cloud dashboard:

I also see that nRF Cloud sends an error message to the device:

I suspect that the JSON packet that request AGPS data is not correctly formatted... am I correct? Does this have to do with the modem FW version? When I started to evaluate the Thingy:91 I programmed v1.3.2 but I see that there is a newer version v1.3.3

Thanks in advance,

Pieter

  • If it helps, here is the format of the JSON msg (note that MCC is 655 and MNC is 1 for the contract SIM that I'm using):

    {
      "appId": "AGPS",
      "messageType": "DATA",
      "data": {
        "mcc": 655,
        "mnc": 1,
        "tac": 21001,
        "eci": 243210529,
        "rsrp": -140,
        "types": [
          1,
          2,
          3,
          4,
          6,
          7,
          8,
          9
        ]
      }
    }

    And here is the response from the server:

    {
      "message": "src property must be a valid json object"
    }

  • Hi, 

    I'm evaluating A-GPS performance on the Asset Tracker V2 app packaged with nRF Connect SDK v2.2.0-rc1 on a Thingy:91 on NB-IoT with a contract SIM.

    nRF Connect SDK v2.2.0 is released. You should use it. 

    When I started to evaluate the Thingy:91 I programmed v1.3.2 but I see that there is a newer version v1.3.3

    It should use mfw v1.3.3 for NCS v2.2.0

    I would suggest you test with the latest precompiled image which can be downloaded from the Nordic Semiconductor website in the Download firmware step. It provides the mfw v1.3.3 and images compiled with NCSv2.2.0. 

    Regards,
    Amanda H.

  • Hi Amanda,

    I have upgraded the modem FW to v1.3.3 and NCS to v2.2.0 as requested. I have also upgraded the asset_tracker_v2 app accordingly and am seeing exactly the same symptom as reported above.

    I have also tried the precompiled image "thingy91_asset_tracker_v2_2022-12-08_188a1603.hex" and it behaves exactly the same. Here is the captured log:

    [2022-12-09 11:14:22.237] *** Booting Zephyr OS build v3.2.99-ncs1 ***
    [2022-12-09 11:14:23.266] [00:00:01.503,723] <inf> at_host: UART check failed: 12. Dropping buffer and retrying.
    [2022-12-09 11:14:23.266] [00:00:01.514,343] <inf> app_event_manager: APP_EVT_START
    [2022-12-09 11:14:23.266] [00:00:01.526,275] <inf> app_event_manager: DATA_EVT_CONFIG_INIT
    [2022-12-09 11:14:23.266] [00:00:01.526,916] <inf> app_event_manager: MODEM_EVT_INITIALIZED
    [2022-12-09 11:14:23.266] [00:00:01.605,957] <inf> app_event_manager: MODEM_EVT_LTE_CONNECTING
    [2022-12-09 11:14:26.003] %CESQ: 36,1,18,2
    [2022-12-09 11:14:26.003] +CEREG: 2,"5209","0E7F1921",9
    [2022-12-09 11:14:26.296] +CSCON: 1
    [2022-12-09 11:14:27.015] [00:00:05.277,343] <inf> app_event_manager: MODEM_EVT_LTE_CELL_UPDATE
    [2022-12-09 11:14:27.823] +CSCON: 0
    [2022-12-09 11:14:32.243] %CESQ: 37,1,7,1
    [2022-12-09 11:14:37.936] %CESQ: 38,1,22,3
    [2022-12-09 11:14:38.138] +CSCON: 1
    [2022-12-09 11:14:39.799] +CGEV: ME PDN ACT 0,0
    [2022-12-09 11:14:39.799] +CNEC_ESM: 50,0
    [2022-12-09 11:14:39.799] %MDMEV: SEARCH STATUS 2
    [2022-12-09 11:14:39.799] +CEREG: 1,"5209","0E7F1921",9,,,"00001010","11000001"
    [2022-12-09 11:14:39.871] %XTIME: ,"22219090419380",
    [2022-12-09 11:14:40.834] [00:00:19.072,326] <err> modem_module: Event: PDP context 0, PDN type IPv4 only allowed
    [2022-12-09 11:14:40.834] [00:00:19.080,932] <inf> app_event_manager: MODEM_EVT_LTE_CONNECTED
    [2022-12-09 11:14:40.834] [00:00:19.081,573] <inf> app_event_manager: MODEM_EVT_LTE_PSM_UPDATE
    [2022-12-09 11:14:40.834] [00:00:19.082,824] <inf> app_event_manager: CLOUD_EVT_CONNECTING
    [2022-12-09 11:14:40.834] [00:00:19.137,054] <inf> app_event_manager: DATA_EVT_DATE_TIME_OBTAINED
    [2022-12-09 11:14:43.221] %CESQ: 37,1,17,2
    [2022-12-09 11:14:45.700] %CESQ: 39,1,22,3
    [2022-12-09 11:14:51.659] [00:00:29.923,217] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
    [2022-12-09 11:14:51.659] [00:00:29.931,243] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
    [2022-12-09 11:14:51.659] [00:00:29.931,976] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
    [2022-12-09 11:14:53.789] [00:00:32.003,021] <inf> app_event_manager: CLOUD_EVT_CONNECTED
    [2022-12-09 11:14:53.789] [00:00:32.003,906] <inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, MOD_STAT, LOCATION)
    [2022-12-09 11:14:53.789] [00:00:32.004,547] <inf> app_event_manager: LOCATION_MODULE_EVT_ACTIVE
    [2022-12-09 11:14:53.789] [00:00:32.005,889] <inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_DATA_READY
    [2022-12-09 11:14:53.789] [00:00:32.059,539] <inf> app_event_manager: MODEM_EVT_MODEM_STATIC_DATA_READY
    [2022-12-09 11:14:53.789] [00:00:32.111,907] <inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY
    [2022-12-09 11:14:53.789] [00:00:32.164,855] <inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY
    [2022-12-09 11:15:02.919] %CESQ: 35,1,17,2
    [2022-12-09 11:15:25.011] %CESQ: 38,1,22,3
    [2022-12-09 11:15:55.204] +CSCON: 0
    [2022-12-09 11:15:55.723] %CESQ: 38,1,17,2
    [2022-12-09 11:15:56.022] +CSCON: 1
    [2022-12-09 11:15:56.211] [00:01:34.487,243] <inf> app_event_manager: LOCATION_MODULE_EVT_AGPS_NEEDED
    [2022-12-09 11:16:01.620] %CESQ: 39,1,22,3
    [2022-12-09 11:16:50.171] [00:02:22.005,767] <inf> app_event_manager: DATA_EVT_DATA_READY
    [2022-12-09 11:16:50.171] [00:02:22.022,094] <inf> app_event_manager: DATA_EVT_DATA_SEND_BATCH
    [2022-12-09 11:16:50.171] [00:02:22.022,918] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
    

    And here is the screenshot of the nRF Cloud dashboard where the same error is reported to the device:

    So in short: no, upgrading to the latest release does not fix the problem.

    FYI: I was already on v2.2.0-rc1... I don't see how moving to the final released version would make a significant difference.

    Regards,

    Pieter

  • Hi, Pieter,

    I was able to recreate identical behavior on one of my work devices.

    It turns out, though, that despite the errors in the c2d column, AGPS responses actually are sent to and processed by my device. And I suspect the same is true of yours!

    To check, add 

    -DCONFIG_NRF_CLOUD_GPS_LOG_LEVEL_DBG=y


    to your build arguments when building ATV2.


    If it works, you should see output from the agps_send_to_modem function in nrf/subsys/net/lib/nrf_cloud/src/nrf_cloud_agps.c


    For instance, here is a snippet of what some of mine look like:

    [00:00:20.305,511] <dbg> nrf_cloud_agps: nrf_cloud_agps_process: TOW 25 copied
    [00:00:20.305,541] <dbg> nrf_cloud_agps: nrf_cloud_agps_process: Parsed_len: 1095
    [00:00:20.305,572] <dbg> nrf_cloud_agps: nrf_cloud_agps_process: TOW 26 copied
    [00:00:20.305,572] <dbg> nrf_cloud_agps: nrf_cloud_agps_process: Parsed_len: 1099
    [00:00:20.305,603] <dbg> nrf_cloud_agps: nrf_cloud_agps_process: TOW 28 copied
    [00:00:20.305,633] <dbg> nrf_cloud_agps: nrf_cloud_agps_process: Parsed_len: 1103



    The presence of output from this function like this indicates that a valid AGPS response was received by the device from nRF Cloud.


    As for CLOUD_WRAP_EVT_AGPS_DATA_RECEIVED, we have recently (in 2.2.0) transferred the responsibility for calling nrf_cloud_agps_process away from the application, and integrated it directly into the nrf_cloud library. Thus, the CLOUD_WRAP_EVT_AGPS_DATA_RECEIVED is never actually called.

    Finally, regarding the errors you see in c2d, those are benign and can be ignored. In fact, they appear to be directly caused by the AGPS responses themselves, rather than an indication of failure! We are looking into why errors are being raised, but at first glance it seems our FE is misinterpreting the raw binary AGPS payloads as invalid messages. The AGPS payloads are still sent to the device, however, and you can confirm they are successfully received using the suggested check above.

  • ,

    Thanks for investigating and the tip regarding CONFIG_NRF_CLOUD_GPS_LOG_LEVEL_DBG Slight smile

    Here is my new log:

    thingy91_2022-12-13_08h38_agps_data.log

    I can see that the AGPS data (Almanac, TOW, Ephemerides, etc.) is received and parsed (lines 164 to 369) but the first GNSS fix still times out after 83 seconds (lines 370 to 477). Here is the last part:

    [2022-12-13 08:22:58.775] [00:03:58.875,946] <dbg> location: Tracked satellites: 0, fix valid: false, insuf. time window: false
    [2022-12-13 08:22:58.775] [00:03:59.876,251] <dbg> location: Tracked satellites: 0, fix valid: false, insuf. time window: false
    [2022-12-13 08:23:00.864] [00:04:00.885,711] <dbg> location: Tracked satellites: 0, fix valid: false, insuf. time window: false
    [2022-12-13 08:23:00.864] [00:04:01.515,625] <inf> app_event_manager: APP_EVT_DATA_GET_ALL
    [2022-12-13 08:23:00.864] [00:04:01.516,265] <inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, LOCATION)
    [2022-12-13 08:23:00.864] [00:04:01.516,326] <dbg> location_module: Location request already active and will not be restarted
    [2022-12-13 08:23:00.864] [00:04:01.516,357] <dbg> location_module: Seeing this message sometimes is normal, especially, when trying to acquire the first GNSS fix.
    [2022-12-13 08:23:00.864] [00:04:01.516,357] <dbg> location_module: If you see this often for other than the first location search, try setting the sample/publication interval a bit greater.
    [2022-12-13 08:23:00.864] [00:04:01.520,538] <inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_DATA_READY
    [2022-12-13 08:23:00.864] [00:04:01.568,847] <inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_NOT_READY
    [2022-12-13 08:23:00.864] [00:04:01.621,063] <inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY
    [2022-12-13 08:23:00.864] [00:04:01.886,077] <dbg> location: Tracked satellites: 0, fix valid: false, insuf. time window: false
    [2022-12-13 08:23:02.784] [00:04:02.886,413] <dbg> location: Tracked satellites: 0, fix valid: false, insuf. time window: false
    [2022-12-13 08:23:02.784] [00:04:03.891,845] <dbg> location: Tracked satellites: 0, fix valid: false, insuf. time window: false
    [2022-12-13 08:23:04.541] %NCELLMEAS: 0,"0E7F1921","65501","5209",336,3623,203,40,24,245160,207827
    [2022-12-13 08:23:04.663] [00:04:04.892,211] <dbg> location: Tracked satellites: 0, fix valid: false, insuf. time window: false
    [2022-12-13 08:23:04.663] [00:04:05.649,597] <inf> location: Method specific timeout expired

    After the first try that resulted in a failure, the next GNSS fix worked and took 14.236 seconds.

    I do not know what performance to expect from AGPS... is this normal? Does it have to do with the RRC connection not being released?

    Regards,

    Pieter

Related