agps: SUPL session failed, error: -13

[Johan]

Hi,

We are using 1.5.1 tag and building on the agps-sample called "v1.5.1\nrf\samples\nrf9160\agps\".

We see problems with downloading SUPL-data and also EVT_BLOCKED and stops searching at all.

No apparent reason for it what we can see. Perhaps bugs that were not fixed in 1.5.1 but in later commits? We need help with this.

See log below.

Best

Johan

LOG BELOW

[00:00:00.204,956] <inf> resetinfo: Reset reason = 0x00000001
[00:00:00.213,317] <err> resetinfo: Reboot reason: RESET_REASON_RESET_PIN
[00:00:00.234,619] <dbg> 9160.provision_certificates
[00:00:01.975,952] <inf> agps_sample: A-GPS sample has started
[00:00:01.991,210] <dbg> nrf9160_gps.configure_antenna: MAGPIO set: AT%XMAGPIO=1,0,0,1,1,1574,1577
[00:00:02.002,838] <dbg> nrf9160_gps.open_socket: GPS socket created, fd: 1232491587
[00:00:03.329,071] <inf> modem: ICCID: 89462008001000226627
[00:00:03.337,249] <inf> modem: IMSI: 248030105093729
[00:00:03.344,940] <inf> modem: MFW: mfw_nrf9160_1.3.0
[00:00:03.367,614] <dbg> modem.modem_set_gps_active: Activating GPS...
[00:00:03.431,091] <dbg> nrf9160_gps.gps_priority_set: GPS priority disabled
[00:00:03.448,272] <dbg> nrf9160_gps.start: GPS operational
[00:00:03.456,726] <inf> agps_sample: Periodic GPS search started with interval 0 s, timeout 0 s
[00:00:03.468,139] <inf> agps_sample: GPS_EVT_SEARCH_STARTED
[00:00:03.476,501] <dbg> nrf9160_gps.gps_thread: A-GPS data update needed
[00:00:03.485,839] <inf> agps_sample: GPS_EVT_AGPS_DATA_NEEDED
[00:00:03.494,262] <inf> modem: LTE connecting...
[00:00:03.501,556] <dbg> modem.modem_lte_connect: Activating LTE
[00:00:03.569,091] <wrn> gps_storage: store nrf52 uptime = 11321473 ms
[00:00:11.130,187] <dbg> modem.lte_lc_evt_handler: REG status: 2
[00:00:20.234,680] <dbg> modem.lte_lc_evt_handler: REG status: 5
[00:00:20.243,377] <inf> modem: LTE connected
[00:00:20.250,335] <dbg> agps.init_supl: Using GPS driver to input assistance data
[00:00:20.260,498] <inf> agps: SUPL is initialized
[00:00:20.267,913] <dbg> agps.open_supl_socket: CONFIG_POSIX_MAX_FDS=8
[00:00:20.277,038] <dbg> agps.open_supl_socket: CONFIG_NRF_MODEM_LIB_HEAP_SIZE=2048
[00:00:20.288,757] <dbg> agps.open_supl_socket: ip 173.194.222.192 (c0dec2ad) port 7276
[00:00:20.568,572] <inf> agps: Starting SUPL session
[00:00:20.578,186] <dbg> agps.supl_logger: ULP encoding length: 38
[00:00:20.587,493] <dbg> agps.supl_logger: Bytes sent: 38
[00:00:21.248,138] <dbg> agps.supl_logger: Bytes received: 34, total 34
[00:00:21.257,873] <dbg> agps.supl_logger: ULP ossDecode success, choice 3
[00:00:21.267,425] <dbg> agps.supl_logger: SUPL server responded using version 2.0.4
[00:00:21.277,770] <dbg> agps.supl_logger: SUPL response received
[00:00:21.286,621] <dbg> agps.supl_logger: ULP encoding length: 57
[00:00:21.295,989] <dbg> agps.supl_logger: Bytes sent: 57
[00:00:22.303,161] <dbg> agps.supl_logger: read again
[00:00:22.600,952] <dbg> agps.supl_logger: Bytes received: 708, total 708
[00:00:22.610,961] <dbg> agps.supl_logger: ULP ossDecode more input 4
[00:00:23.620,422] <dbg> agps.supl_logger: read again
[00:00:23.753,448] <dbg> agps.supl_logger: Bytes received: 708, total 1416
[00:00:23.763,458] <dbg> agps.supl_logger: ULP ossDecode more input 4
[00:00:24.772,583] <dbg> agps.supl_logger: read again
[00:00:25.640,686] <dbg> agps.supl_logger: Bytes received: 708, total 2124
[00:00:25.650,665] <dbg> agps.supl_logger: ULP ossDecode more input 4
[00:00:26.659,851] <dbg> agps.supl_logger: read again
[00:00:27.667,388] <dbg> agps.supl_logger: read again
[00:00:28.675,170] <dbg> agps.supl_logger: read again
[00:00:29.682,861] <dbg> agps.supl_logger: read again
[00:00:30.690,643] <dbg> agps.supl_logger: read again
[00:00:31.698,425] <dbg> agps.supl_logger: read again
[00:00:32.706,237] <dbg> agps.supl_logger: Timeout expired
[00:00:32.714,294] <dbg> agps.supl_logger: SUPL error: 3
[00:00:32.722,290] <dbg> agps.supl_logger: ULP encoding length: 34
[00:00:32.731,628] <dbg> agps.supl_logger: Bytes sent: 34
[00:00:32.739,624] <dbg> agps.supl_logger: SUPL session internal resources released
[00:00:32.749,847] <dbg> agps.supl_logger: SUPL session finished
[00:00:32.758,422] <err> agps: SUPL session failed, error: -13
[00:00:32.767,089] <err> agps: SUPL request failed, error: -13
[00:00:32.775,756] <err> agps_sample: Failed to request A-GPS data, error: -13
[00:00:32.785,980] <dbg> nrf9160_gps.print_satellite_stats: Tracking: 0 Using: 0 Unhealthy: 0
[00:00:32.797,088] <dbg> nrf9160_gps.print_satellite_stats: Seconds since last fix 32
[00:00:32.808,319] <dbg> nrf9160_gps.gps_thread: Waiting for time window to operate
[00:00:32.818,542] <inf> agps_sample: GPS_EVT_OPERATION_BLOCKED
[00:00:37.287,292] <dbg> nrf9160_gps.gps_thread: GPS has time window to operate
[00:00:37.297,180] <inf> agps_sample: GPS_EVT_OPERATION_UNBLOCKED
[00:00:37.305,908] <dbg> nrf9160_gps.print_satellite_stats: Tracking: 0 Using: 0 Unhealthy: 0
[00:00:37.317,016] <dbg> nrf9160_gps.print_satellite_stats: Seconds since last fix 37
[00:00:38.287,475] <dbg> nrf9160_gps.print_satellite_stats: Tracking: 0 Using: 0 Unhealthy: 0
[00:00:38.298,614] <dbg> nrf9160_gps.print_satellite_stats: Seconds since last fix 38
[00:00:39.287,536] <dbg> nrf9160_gps.print_satellite_stats: Tracking: 0 Using: 0 Unhealthy: 0
[00:00:39.298,645] <dbg> nrf9160_gps.print_satellite_stats: Seconds since last fix 39
[00:00:40.287,567] <dbg> nrf9160_gps.print_satellite_stats: Tracking: 0 Using: 0 Unhealthy: 0
[00:00:40.298,675] <dbg> nrf9160_gps.print_satellite_stats: Seconds since last fix 40
[00:00:42.383,605] <dbg> nrf9160_gps.gps_thread: Waiting for time window to operate
[00:00:42.393,859] <inf> agps_sample: GPS_EVT_OPERATION_BLOCKED

[Martin Lesund]

Hi Johan,

<dbg> agps.supl_logger: Lat: 5851520 Lon: 780606

These are not really coordinates, but coordinates converted into a different format expected by the modem. So that is why you cannot just use the same numbers and plot them on the gps-coordinates page.

The formulas are described here: https://github.com/nrfconnect/sdk-nrfxlib/blob/a6baa0748c486ce71918a97740ae105ba586092e/nrf_modem/include/nrf_socket.h#L1365

---

<dbg> agps.supl_logger: No location data available

This happens because of a bug in currently available SUPL libraries. The current cell ID is encoded incorrectly and the server isn't able to determine the location of the device. Because of this SUPL lib falls back to the MCC based location, which is injected here:

[00:00:15.384,246] <dbg> agps.supl_logger: MCC location info injected, MCC: 240
[00:00:15.394,226] <dbg> agps.supl_logger: Lat: 5851520 Lon: 780606
[00:00:15.403,320] <dbg> agps.supl_logger: Unc semiminor/semimajor: 119/119
[00:00:15.412,994] <dbg> agps.supl_logger: Unc altitude: 127
[00:00:15.421,386] <dbg> agps.supl_logger: Confidence: 100
[00:00:15.429,595] <dbg> agps.supl_logger: Orientation: 0

This will be fixed in the next SUPL library release which should be available shortly.

When you take the new SUPL lib into use, you will get a more accurate location. The only remaining issue is related to the data connectivity which I don't think there's a bug in the library but some bad network configurations. I suspect that you may have an overly long "rrc inactivity timer". (since that has been an issue in one of the networks in SWE before)

Best regards,

Martin L.

[Johan]

All right, seems good. Looking forward to! 
Is there a way to see the coordinate in googlemaps, ie possible to see the real coords also in the debug prints? Is it difficult conversion from modem format to google maps normal decimal format? Good for verification for example..

But then, 
even if network config is strange here, is it really an error, or just that the read ended and that's normal? Just to know, what's the important error code really, and did SUPL finish reading data? Then we are ok right? If someone wants to know if the network ended the connection socket correctly or not, might not be relevant for the supl get a-gps data right? So in practice could handle the read error internally and still return 0 (we are good, supl read correctly to end).

How about that ?

[Martin Lesund]

Hi Johan,

Johan said:

Is there a way to see the coordinate in googlemaps, ie possible to see the real coords also in the debug prints? Is it difficult conversion from modem format to google maps normal decimal format? Good for verification for example.

Not if you are talking about this output:

agps.supl_logger: Lat: 5851520 Lon: 780606

Since that is actually only for the MCC-based assistance location. That will not be printed out when we get the location from the SUPL server. The MCC-based location is constant and points roughly to the middle of Sweden in your case. (Here's that MCC based location converted into location: https://goo.gl/maps/ELB682MiMgkTUQR76) That location is always used when the device is registered to a network in Sweden. With the next SUPL library release, the location will be much more accurate and based on the LTE network cell ID. This location is used to assist GNSS to get the first fix and it doesn't have to be that accurate.

The AGPS sample prints the coordinates when it gets a GPS fix. Those can be copy-pasted to for example to Google Maps. (that means you would need to have the device outside a window to actually acquire the satellites)

You are right that we could return 0 from the library when SUPL data was received correctly but got an error when ending the SUPL session. I think we can probably fix this in a future version.

Best regards,

Martin L.

[Johan]

All right. I will continue ignoring the return code for now.
It could be good in future to repeat request if it fails for some reason, but I guess that could happen only with bad coverage or network issues.

[Johan]

Martin Lesund

You have another bug in supl library.
If session fails, you don't close the socket.

static int supl_start(const struct gps_agps_request request)
{
int err;
nrf_gnss_agps_data_frame_t req = {
.sv_mask_ephe = request.sv_mask_ephe,
.sv_mask_alm = request.sv_mask_alm,
.data_flags =
(request.utc ?
BIT(NRF_GNSS_AGPS_GPS_UTC_REQUEST) : 0) |
(request.klobuchar ?
BIT(NRF_GNSS_AGPS_KLOBUCHAR_REQUEST) : 0) |
(request.nequick ?
BIT(NRF_GNSS_AGPS_NEQUICK_REQUEST) : 0) |
(request.system_time_tow ?
BIT(NRF_GNSS_AGPS_SYS_TIME_AND_SV_TOW_REQUEST) : 0) |
(request.position ?
BIT(NRF_GNSS_AGPS_POSITION_REQUEST) : 0) |
(request.integrity ?
BIT(NRF_GNSS_AGPS_INTEGRITY_REQUEST) : 0),
};

err = open_supl_socket();
if (err) {
LOG_ERR("Failed to open SUPL socket");
return err;
}

LOG_INF("Starting SUPL session");

err = supl_session(&req);
if (err) {
   LOG_ERR("SUPL session failed, error: %d", err);
   return err;
}

LOG_INF("SUPL session finished successfully");

close_supl_socket();

return err;
}