Particle-som-gnss getting fix impacting the cloud connection?

gusgonnet · April 3, 2025, 3:12pm

Hey,

While using this library on a Muon, DeviceOS6.3.0, I am observing a certain timeout or something that impacts the cloud connection around the 70-80 seconds mark.
The cloud connection eventually reconnects, but this behaviour is intriguing.

I see it happening when the location fix takes longer than 70 seconds:

the connection to the cloud is deemed down
the connection is then restarted

Logs of the "issue"


0000073608 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000074652 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000075695 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000075842 [net.pppncp] ERROR: PPP error event data=9
0000075846 [net.pppncp] ERROR: PPP error event data=5
0000086454 [ncp.client] ERROR: Failed to enter data mode
0000086455 [net.ppp.client] ERROR: Failed to dial
0000087373 [mux] INFO: Stopping GSM07.10 muxer
0000087374 [mux] INFO: GSM07.10 muxer thread exiting
0000087376 [mux] INFO: GSM07.10 muxer stopped
0000087377 [net.pppncp] ERROR: Failed to initialize cellular NCP client: -210
0000090259 [comm.coap] ERROR: CoAP message timeout; ID: 10
0000090290 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 0
0000090324 [comm.protocol] ERROR: Event loop error 3
0000090351 [system] WARN: Communication loop error, closing cloud socket
0000090388 [system] INFO: Cloud: disconnecting
0000090412 [system] INFO: Cloud: disconnected
0000092888 [ncp.client] ERROR: Failed to enter data mode
0000092889 [net.ppp.client] ERROR: Failed to dial
0000092893 [net.pppncp] ERROR: PPP error event data=5
0000097102 [mux] INFO: Starting GSM07.10 muxer
0000097104 [mux] INFO: Opening mux channel 0
0000097104 [mux] INFO: GSM07.10 muxer thread started
0000097207 [mux] INFO: Opening mux channel 1
0000097287 [loc] TRACE: Sending asynchronous completion

Is this expected? Why would a location fix impact the cloud connection?
Thanks!

Full logs:

0000002312 [comm] INFO: channel inited
0000002429 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
0000002448 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000002469 [net.ifapi] INFO: Netif pp3 state UP
0000002473 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000002578 [mux] INFO: Starting GSM07.10 muxer
0000002579 [mux] INFO: Opening mux channel 0
0000002579 [mux] INFO: GSM07.10 muxer thread started
0000002582 [mux] INFO: Opening mux channel 1
0000002636 [mux] INFO: Mux channel 1 already opened
0000002664 [mux] INFO: Opening mux channel 2
0000003840 [net.ifapi] INFO: Netif pp3 link UP, profile=NONE
0000003843 [system.nm] INFO: State changed: IFACE_UP -> IFACE_LINK_UP
0000003845 [hal] INFO: DNS server list changed
0000003847 [system.nm] INFO: State changed: IFACE_LINK_UP -> IP_CONFIGURED
0000003849 [hal] INFO: DNS server list changed
0000003883 [system] INFO: Cloud: connecting
0000003896 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
0000003917 [system] WARN: Failed to load session data from persistent storage
0000003938 [system] INFO: Discarding session data
0000005031 [system] INFO: Cloud socket=0, connecting to 34.231.252.59#5684 using if 4
0000005053 [system] INFO: Bound cloud socket to lwip if 4 ("pp3")
0000005071 [system] INFO: Cloud socket connected
0000005084 [system] INFO: Starting handshake: presense_announce=0
0000005101 [comm.protocol.handshake] INFO: Establish secure connection
0000005120 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
0000006875 [comm.protocol.handshake] INFO: Sending HELLO message
0000007049 [comm.protocol.handshake] INFO: Handshake completed
0000007066 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000007083 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000007595 [comm] INFO: Sending TIME request
0000007608 [system] INFO: Send spark/device/last_reset event
0000007753 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000008282 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000008301 [comm.protocol] INFO: Received TIME response: 1743691983
0000008320 [system] INFO: All handshake messages have been processed
0000008438 [system] INFO: Cloud connected
0000008450 [system.ledger] INFO: Subscribing to ledger updates
0000008469 [comm] INFO: Forcing a cloud ping
0000009012 [system.ledger] INFO: Subscribed to ledger updates
0000009051 [comm.protocol] INFO: Received DESCRIBE request; flags: 0x04
0000009329 [loc] INFO: Beginning location library
0000009343 [loc] INFO: Detecting modem type
0000009361 [loc] TRACE: Modem ID is 19
0000009372 [loc] TRACE: BG95-M5 detected
0000009385 [loc] TRACE: Starting asynchronous aquisition
0000009386 [system] INFO: Sending application DESCRIBE
0000009401 [loc] TRACE: Started aquisition
0000009400 [app] INFO: GNSS acquisition started
0000009417 [system] INFO: Sending subscriptions
0000009442 [comm.protocol] INFO: Sending subscriptions
0000009483 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000010526 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000011555 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000012600 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000013644 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000014657 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000015701 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000016743 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000017761 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000018804 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000019846 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000020863 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000021908 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000022952 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000023967 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000025012 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000026056 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000027072 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000028117 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000029160 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000030174 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000031217 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000032260 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000033276 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000034319 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000035362 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000036379 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000037422 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000038466 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000039480 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000040522 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000041566 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000042583 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000043627 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000044670 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000045684 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000046727 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000047770 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000048787 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000049830 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000050873 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000051890 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000052935 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000053979 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000054994 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000056038 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000057083 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000058097 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000059141 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000060183 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000061198 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000062241 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000063283 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000063833 [net.ifapi] INFO: Netif pp3 link DOWN, profile=NONE
0000063834 [hal] INFO: DNS server list changed
0000063835 [system.nm] INFO: State changed: IP_CONFIGURED -> IFACE_LINK_UP
0000063837 [hal] INFO: DNS server list changed
0000063839 [system.nm] INFO: State changed: IFACE_LINK_UP -> IFACE_UP
0000064303 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000065346 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000066388 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000067404 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000068447 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000069491 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000070506 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000071548 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000072592 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000073608 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000074652 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000075695 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000075842 [net.pppncp] ERROR: PPP error event data=9
0000075846 [net.pppncp] ERROR: PPP error event data=5
0000086454 [ncp.client] ERROR: Failed to enter data mode
0000086455 [net.ppp.client] ERROR: Failed to dial
0000087373 [mux] INFO: Stopping GSM07.10 muxer
0000087374 [mux] INFO: GSM07.10 muxer thread exiting
0000087376 [mux] INFO: GSM07.10 muxer stopped
0000087377 [net.pppncp] ERROR: Failed to initialize cellular NCP client: -210
0000090259 [comm.coap] ERROR: CoAP message timeout; ID: 10
0000090290 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 0
0000090324 [comm.protocol] ERROR: Event loop error 3
0000090351 [system] WARN: Communication loop error, closing cloud socket
0000090388 [system] INFO: Cloud: disconnecting
0000090412 [system] INFO: Cloud: disconnected
0000092888 [ncp.client] ERROR: Failed to enter data mode
0000092889 [net.ppp.client] ERROR: Failed to dial
0000092893 [net.pppncp] ERROR: PPP error event data=5
0000097102 [mux] INFO: Starting GSM07.10 muxer
0000097104 [mux] INFO: Opening mux channel 0
0000097104 [mux] INFO: GSM07.10 muxer thread started
0000097207 [mux] INFO: Opening mux channel 1
0000097287 [loc] TRACE: Sending asynchronous completion
0000097316 [app] INFO: async callback returned 0
0000097341 [app] INFO: Position fixed!
0000097352 [app] INFO: Lat 0.00000, lon 0.00000
0000097364 [app] INFO: Alt 0.0 m, speed 0.0 m/s, heading 0.0 deg
0000097685 [mux] INFO: Opening mux channel 2
0000104845 [net.ifapi] INFO: Netif pp3 link UP, profile=NONE
0000104848 [system.nm] INFO: State changed: IFACE_UP -> IFACE_LINK_UP
0000104850 [hal] INFO: DNS server list changed
0000104851 [system.nm] INFO: State changed: IFACE_LINK_UP -> IP_CONFIGURED
0000104853 [hal] INFO: DNS server list changed
0000104938 [system] INFO: Cloud: connecting
0000104962 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
0000105004 [system] WARN: Failed to load session data from persistent storage
0000105044 [system] INFO: Discarding session data
0000105592 [system] INFO: Cloud socket=0, connecting to 34.231.252.59#5684 using if 4
0000105636 [system] INFO: Bound cloud socket to lwip if 4 ("pp3")
0000105670 [system] INFO: Cloud socket connected
0000105695 [system] INFO: Starting handshake: presense_announce=0
0000105728 [comm.protocol.handshake] INFO: Establish secure connection
0000105766 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
0000109036 [comm.protocol.handshake] INFO: Sending HELLO message
0000109198 [comm.protocol.handshake] INFO: Handshake completed
0000109231 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000109263 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000110297 [comm] INFO: Sending TIME request
0000110326 [system] INFO: Sending application DESCRIBE
0000110356 [system] INFO: Sending subscriptions
0000110380 [comm.protocol] INFO: Sending subscriptions
0000110480 [comm.protocol] INFO: Received TIME response: 1743692086
0000110515 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000110545 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000110574 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000111632 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000111660 [system] INFO: All handshake messages have been processed
0000111689 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000111714 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000111740 [comm.protocol] INFO: Received DESCRIBE request; flags: 0x04
0000111797 [system] INFO: Cloud connected
0000111819 [system.ledger] INFO: Subscribing to ledger updates
0000111847 [comm] INFO: Forcing a cloud ping
0000112134 [system.ledger] INFO: Subscribed to ledger updates
0000127381 [app] INFO: retrying acquisition
0000127392 [loc] TRACE: Starting asynchronous aquisition
0000127407 [app] INFO: GNSS acquisition started
0000127408 [loc] TRACE: Started aquisition
0000127466 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000128511 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000129544 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000130586 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000131628 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000132646 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000133689 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516
0000134733 [loc] TRACE: glocCallback: (120000) +CME ERROR: 516

rickkas7 · April 3, 2025, 3:39pm

It probably should not do that. There is a known situation where if the device is trying to connect to cellular, and you start GNSS, if the cellular modem is locked, the thread making the GNSS call will block because the cellular modem is locked. The GNSS library uses Cellular.command(). But I don't think that's what you are seeing.

+CME ERROR: 516 is 516 Not fixed now so that's not really an error, it's just a result that says there is no fix yet, which is to be expected.

You should be able to have a working cellular connection while doing GNSS.

Where are you calling getLocation() from? Are there any mutex locks or interrupt level changes that could prevent the system thread from running during the execution of getLocation, which is synchronous within the calling thread, and will wait for a GNSS fix?

Edit: This would only apply to the overload without the callback. The one with the callback is asynchronous and should not be affected.

gusgonnet · April 3, 2025, 4:01pm

The code I'm using is this, I think I got it from the example plus some mods from a community post but I can't find it right now.

No mutex, no IRQs, nothing fancy.

EDIT: to easily reproduce the issue, I removed the gnss antenna.
But just placing the device far away from a window gives me the same issue often.
Thanks


#include "Particle.h"
#include "location.h"

SYSTEM_MODE(AUTOMATIC);
SerialLogHandler logHandler(LOG_LEVEL_INFO, {
                                                {"loc", LOG_LEVEL_TRACE},
                                            });

enum class State
{
  START,
  ACQUIRING,
  CALLBACK_RECEIVED,
  RETRY,
  IDLE
};
State state = State::START;

void setup()
{
  waitFor(Serial.isConnected, 10000);
  delay(2000);

  // WiFi.clearCredentials();
  WiFi.off();

  Cellular.on();
  waitFor(Cellular.isOn, 60000);

  delay(5000);

  LocationConfiguration config;
  config.maximumFixTime(270);

  // config.enableAntennaPower(GNSS_ANT_PWR);
  Location.begin(config);
}

LocationResults locationResults;
LocationPoint locationPoint = {};
unsigned long stateTime = 0;
const std::chrono::milliseconds retryPeriod = 30s;

void getLocationCallback(LocationResults results)
{
  locationResults = results;
  Log.info("async callback returned %d", (int)locationResults);
  state = State::CALLBACK_RECEIVED;
}

void loop()
{
  if (state == State::START)
  {
    // if (Particle.connected())
    {
      Location.getLocation(locationPoint, getLocationCallback, true);
      // Location.getLocation(locationPoint, true);
      Log.info("GNSS acquisition started");
      state = State::ACQUIRING;
    }
  }
  else if (state == State::CALLBACK_RECEIVED)
  {

    Log.info("Position fixed!");
    Log.info("Lat %0.5lf, lon %0.5lf", locationPoint.latitude, locationPoint.longitude);
    Log.info("Alt %0.1f m, speed %0.1f m/s, heading %0.1f deg", locationPoint.altitude, locationPoint.speed, locationPoint.heading);

    // Particle.publish("loc", String::format("{\"lat\":%0.5lf,\"lon\":%0.5lf,\"alt\":%0.1f,\"speed\":%0.1f,\"heading\":%0.1f}", locationPoint.latitude, locationPoint.longitude, locationPoint.altitude, locationPoint.speed, locationPoint.heading), PRIVATE);

    if (locationPoint.fix)
    {
      state = State::IDLE;
    }
    else
    {
      state = State::RETRY;
      stateTime = millis();
    }
  }
  else if (state == State::RETRY)
  {
    if (millis() - stateTime >= retryPeriod.count())
    {
      state = State::START;
      Log.info("retrying acquisition");
    }
  }
}

rickkas7 · April 7, 2025, 10:42am

You should use the shorter scan time. The problem is that on the BG95 (M404), GNSS and cellular share some RF components, and cannot be used at exactly the same time. By default, the modem is configured to GNSS priority, so that's why the cellular connection fails during a lengthy scan. But cellular can't be set as the priority, because it will only allow GNSS during eDRX, which is not used on Particle devices.

Also it's best to only get GNSS location when you're in Particle.connected() state to prevent GNSS from interrupting the cellular connection process.

gusgonnet · April 7, 2025, 1:14pm

Thank you for the explanation. Now, few remarks/questions:

What is the max scan time I should use?

Yes, that is what I'm trying to do and the act of getting GNSS location impacts the Particle.connected() state due to the explanation you provided.

Thanks

gusgonnet · April 8, 2025, 2:55pm

Hey @rickkas7 , what would be the recommended max time for getting a location fix on a muon as to avoid an impact on the cloud connection?
Thanks!

rickkas7 · April 8, 2025, 3:13pm

I don't have a recommended value at this time.

Topic		Replies	Views
deviceOS@2.2.0 - Timeout on Particle Cloud reconnection? Connectivity boron	7	652	April 1, 2022
Power consumption on Muon: GPS vs cloud connected Hardware muon	2	16	March 31, 2025
Intermittent Connection Timeouts - Looking for Advice Connectivity boron	10	1141	June 2, 2022
UDP COAP not working when Cloud not connected Firmware	4	787	June 22, 2018
[External Issue, Resolved] Particle Cloud down - any updates? Troubleshooting	6	723	January 8, 2019

Particle-som-gnss getting fix impacting the cloud connection?

Related topics