waitfor(Particle.connected,timeout) does not time out

[kwolley]

Hi all,
I want to maintain full control of cellular and cloud connections through SYSTEM_MODE(MANUAL). When I attempt a Particle.connect() followed by a waitFor the timeout occurs much much much later than I indicate. For example, if I ask for a timeout of 60000, the waitFor function does not return for 10 minutes! This occurs repeatedly and on multiple electrons running 2.0.1.

Here is my code:

SYSTEM_MODE(MANUAL); 

void setup() {
  Serial.begin(9600);
  delay(2000);
}

void loop() {
  delay(2000);
  Serial.println("\n\n==== LOOP ====");
  unsigned long startTime = millis();

  if (waitFor(Particle.connected, 60000))
    {
      Serial.printlnf("time to connect %lu", millis()-startTime);
    }
 else
    {
      Serial.println("did not connect");
    }
  SystemSleepConfiguration config;
  config.mode(SystemSleepMode::HIBERNATE)
        .duration(900000);  // 15min
  System.sleep(config);
}

I have been through these posts

WaitFor(Particle.connected, 10000) is not timing out

@peekay123, I didn’t realise that we had to have the Particle in SEMI_AUTOMATIC mode for this? I changed some code and seem to have a work around in AUTOMATIC mode so will let the Particle run a few days and then see from there. Thanks for the note.

WaitFor(Particle.connected, 10000) is not timing out

I have a prototype that has been working well for sometime - last night I just noticed that during a ‘wakeup from standby’ function that calls WaitFor(Particle.connected, 10000) it has got stuck on this function and the timeout has not, well, timed-out. The LED is flashing cyan, the application had gone through checking the wifi connection. Is there a reason for this application blocking/not timing out? Is there a better/more reliable way to wait for a cloud connection for a period then move on? …

Is waitFor(Particle.connected()) needed?

On the Electron, I’m in SEMI_AUTOMATIC mode with a sketch that looks something like this: Particle.connect(); waitFor(Particle.connected, 30000); char data[50]; snprintf(data, sizeof(data), "{\"temp\": %.1f, \"humidity\": %.1f}", temp, hum); Particle.publish("weather", data, PRIVATE); Particle.disconnect(); Can I safely omit the waitFor? Thanks in advance

Particle.connect - v0.7.0-rc.2 - issue with waitFor timeout

Hi there I am using threading and manual mode. and version V0.7.0-rc.2 (I want to test the publish with_ack is working) If I use the following code below in a loop and disconnect the antenna to test lack of service on an electron. the Device will try and connect a single time only, I then put the device to sleep, when coming out of sleep the unit never turns the modem back on. Yet it does the first time through. and it does when it is successful in connecting to the cellular service. I think…

[rickkas7]

I wasn’t able to reproduce that problem. I ran it successfully as-is and the device went to sleep after 60 seconds.

I then modified the code slightly to produce more logging:

#include "Particle.h"

SYSTEM_MODE(MANUAL);

SerialLogHandler logHandler(LOG_LEVEL_TRACE);

void setup()
{
  Serial.begin(9600);
  delay(2000);
}

void loop()
{
  delay(2000);
  Log.info("==== LOOP ====");
  unsigned long startTime = millis();

  if (waitFor(Particle.connected, 60000))
  {
    Log.info("time to connect %lu", millis() - startTime);
  }
  else
  {
    Log.info("did not connect connect %lu", millis() - startTime);
  }
  SystemSleepConfiguration config;
  config.mode(SystemSleepMode::HIBERNATE)
      .duration(900000); // 15min
  System.sleep(config);
}

and got these logs:

Serial monitor opened successfully:
0000004022 [app] INFO: ==== LOOP ====
0000064022 [app] INFO: did not connect connect 60000
0000064022 [system.sleep] TRACE: Entering system_sleep_ext()

[ Modem::cancel ] = = = = = = = = = = = = = = =

[ Modem::powerOff ] = = = = = = = = = = = = = =

[ Modem::resume ] = = = = = = = = = = = = = = =

[ Modem::powerOff ] took 1 ms
[ ElectronSerialPipe::end ] pipeTx=0 pipeRx=0

[ Modem::cancel ] = = = = = = = = = = = = = = =
0000065124 [system.sleep] TRACE: Waiting interface to be off...


Serial connection closed.  Attempting to reconnect...

Tested with an Electron U260 and Device OS 2.0.1.

[kwolley]

Will you repeat the test without the antenna connected? This is when it fails for me.

[rickkas7]

I disconnected the antenna and it still stops waiting at 60 seconds. Is your RGB status light breathing white the whole time? If it’s going into a different color then something else is causing the modem to attempt to connect. Using the verbose logging in my code above may help determine why.

[kwolley]

I noticed that I did not include the call Particle.connect() prior to calling Particle.waitFor in the example I sent to you which is my fault. I am seeing the following with “if (waitFor(Particle.connected, 60000))”:

Scenerio 1 - Particle.connect() called, green flashing for ~10min
the log during the ~60s mark is:

Scenerio 2 - no Particle.connect() called, breathing white throughout (even with antenna attached), terminates at 60s

my full code with your logging suggestion:

SYSTEM_MODE(MANUAL);  
SerialLogHandler logHandler(LOG_LEVEL_TRACE);
#define CELL_CONNECT_SECONDS 60 // time to attempt to connect to cellular
unsigned long connectMillis = CELL_CONNECT_SECONDS * 1000;
int failures = 0;

// setup() runs once, when the device is first turned on.
void setup() {
  Serial.begin(9600);
  delay(2000);
}
// loop() runs over and over again, as quickly as it can execute.
void loop() {
  delay(2000);
  Log.info("\n\n==== LOOP ====");
  Log.info("Cellular = %d. Cloud = %d.",(int)Cellular.ready(), (int)Particle.connected());
  unsigned long startTime = millis();
  Particle.connect();
  if (waitFor(Particle.connected, connectMillis))
  {
    if (Particle.connected())
    {
      delay(20000);
      Particle.disconnect();
      Cellular.disconnect();
      Cellular.off();
    }
  }
  else
  {
    failures++;
  }
  Log.info("total time: %lu, failures: %d", millis()-startTime, failures);
  SystemSleepConfiguration config;
  config.mode(SystemSleepMode::HIBERNATE)
        .duration(900000);  // 15min
  System.sleep(config);
}

[rickkas7]

There a few issues:

1. Since you are using non-threaded, manual mode, Particle.connect() is blocking, which why the waitFor doesn’t do what you’d expect.

2. The best solution is to never use MANUAL mode as there are surprising gotchas in that mode, like Particle.connect is blocking. Using SEMI_AUTOMATIC with threading enabled is the recommended mode to use.

SYSTEM_MODE(SEMI_AUTOMATIC);
SYSTEM_THREAD(ENABLED);

3. Even with that change, you need to disable cellular in both the connected and not connected cases. Otherwise, sleep will block until the connection finishes, or times out, which also takes 10 minutes.

Full code that works for me with the antenna disconnected. Sleep occurs at 60 seconds.

#include "Particle.h"

SYSTEM_MODE(SEMI_AUTOMATIC);
SYSTEM_THREAD(ENABLED);

SerialLogHandler logHandler(LOG_LEVEL_TRACE);
#define CELL_CONNECT_SECONDS 60 // time to attempt to connect to cellular
unsigned long connectMillis = CELL_CONNECT_SECONDS * 1000;
int failures = 0;

// setup() runs once, when the device is first turned on.
void setup()
{
  Serial.begin(9600);
  delay(2000);
}
// loop() runs over and over again, as quickly as it can execute.
void loop()
{
  delay(2000);
  Log.info("\n\n==== LOOP ====");
  Log.info("Cellular = %d.Cloud = %d.", (int)Cellular.ready(), (int)Particle.connected());
  unsigned long startTime = millis();
  Particle.connect();
  if (waitFor(Particle.connected, connectMillis))
  {
    if (Particle.connected())
    {
      delay(20000);
    }
  }
  else
  {
    failures++;
  }
  Log.info("total time: %lu, failures: %d", millis() - startTime, failures);
  Particle.disconnect();
  Cellular.disconnect();
  Cellular.off();


  SystemSleepConfiguration config;
  config.mode(SystemSleepMode::HIBERNATE)
      .duration(900000); // 15min
  System.sleep(config);
}

Log:

Serial monitor opened successfully:
0000004022 [app] INFO: 

==== LOOP ====
0000004022 [app] INFO: Cellular = 0.Cloud = 0.
[ ElectronSerialPipe::begin ] pipeTx=0 pipeRx=0

[ Modem::powerOn ] = = = = = = = = = = = = = =
     4.432 AT send       4 "AT\r\n"
     5.269 AT read  +   12 "\r\n+CREG: 0\r\n"
     5.271 AT read  +   13 "\r\n+CGREG: 0\r\n"
     5.272 AT read OK    6 "\r\nOK\r\n"
     5.272 AT send       9 "AT+CGMM\r\n"
     5.277 AT read UNK  13 "\r\nSARA-U260\r\n"
     5.278 AT read OK    6 "\r\nOK\r\n"
     5.479 AT send       6 "ATE0\r\n"
     5.483 AT read OK    6 "\r\nOK\r\n"
     5.483 AT send      11 "AT+CMEE=2\r\n"
     5.488 AT read OK    6 "\r\nOK\r\n"
     5.488 AT send      19 "AT+CMER=1,0,0,2,1\r\n"
     5.494 AT read OK    6 "\r\nOK\r\n"
     5.494 AT send      15 "AT+IPR=115200\r\n"
     5.500 AT read OK    6 "\r\nOK\r\n"
     5.600 AT send      10 "AT+CPIN?\r\n"
     5.605 AT read  +   16 "\r\n+CPIN: READY\r\n"
     5.606 AT read OK    6 "\r\nOK\r\n"

[ Modem::init (attempt 1/8) ] = = = = = = = = = =
     5.606 AT send       9 "AT+CGSN\r\n"
     5.623 AT read UNK  19 "\r\nxxx\r\n"
     5.624 AT read OK    6 "\r\nOK\r\n"
     5.624 AT send       9 "AT+CGMI\r\n"
     5.629 AT read UNK  10 "\r\nu-blox\r\n"
     5.630 AT read OK    6 "\r\nOK\r\n"
     5.630 AT send       9 "AT+CGMR\r\n"
     5.634 AT read UNK   9 "\r\n23.20\r\n"
     5.635 AT read OK    6 "\r\nOK\r\n"
     5.635 AT send       6 "ATI9\r\n"
     5.650 AT read UNK  16 "\r\n23.20,A01.00\r\n"
     5.651 AT read OK    6 "\r\nOK\r\n"
     5.651 AT send       9 "AT+CCID\r\n"
     5.658 AT read  +   30 "\r\n+CCID: xxx\r\n"
     5.661 AT read OK    6 "\r\nOK\r\n"
     5.661 AT send      11 "AT+CMGF=1\r\n"
     5.666 AT read OK    6 "\r\nOK\r\n"
     5.666 AT send      13 "AT+CNMI=2,1\r\n"
     5.671 AT read OK    6 "\r\nOK\r\n"
     5.671 AT send       9 "AT+CIMI\r\n"
     5.677 AT read UNK  19 "\r\nxxx\r\n"
     5.678 AT read OK    6 "\r\nOK\r\n"
     5.678 AT send      13 "AT+COPS=3,2\r\n"
     5.683 AT read OK    6 "\r\nOK\r\n"
     5.683 AT send      11 "AT+UPSV=1\r\n"
     5.688 AT read OK    6 "\r\nOK\r\n"
0000005688 [system] INFO: ARM_WLAN_WD 1
     5.690 AT send       4 "AT\r\n"
     5.693 AT read OK    6 "\r\nOK\r\n"

[ Modem::register ] = = = = = = = = = = = = = =
     5.693 AT send      10 "AT+CFUN?\r\n"
     5.700 AT read  +   14 "\r\n+CFUN: 1,0\r\n"
     5.701 AT read OK    6 "\r\nOK\r\n"
     5.701 AT send      12 "AT+CGREG=2\r\n"
     5.706 AT read OK    6 "\r\nOK\r\n"
     5.706 AT send      11 "AT+CREG=2\r\n"
     5.711 AT read OK    6 "\r\nOK\r\n"
     5.711 AT send      10 "AT+CREG?\r\n"
     5.716 AT read  +   14 "\r\n+CREG: 2,0\r\n"
     5.717 AT read OK    6 "\r\nOK\r\n"
     5.717 AT send      11 "AT+CGREG?\r\n"
     5.722 AT read  +   15 "\r\n+CGREG: 2,0\r\n"
     5.723 AT read OK    6 "\r\nOK\r\n"
     5.723 AT send      10 "AT+URAT?\r\n"
     5.729 AT read  +   14 "\r\n+URAT: 1,2\r\n"
     5.730 AT read OK    6 "\r\nOK\r\n"
     5.730 AT send       4 "AT\r\n"
     5.733 AT read OK    6 "\r\nOK\r\n"
     5.733 AT send      10 "AT+CFUN?\r\n"
     5.739 AT read  +   14 "\r\n+CFUN: 1,0\r\n"
     5.740 AT read OK    6 "\r\nOK\r\n"
     5.740 AT send      10 "AT+COPS?\r\n"
     5.745 AT read  +   12 "\r\n+COPS: 0\r\n"
     5.746 AT read OK    6 "\r\nOK\r\n"
     5.746 AT send      10 "AT+CREG?\r\n"
     5.752 AT read  +   14 "\r\n+CREG: 2,0\r\n"
     5.753 AT read OK    6 "\r\nOK\r\n"
     5.753 AT send      11 "AT+CGREG?\r\n"
     5.758 AT read  +   15 "\r\n+CGREG: 2,0\r\n"
     5.759 AT read OK    6 "\r\nOK\r\n"
    10.269 AT read  +   12 "\r\n+CREG: 2\r\n"
    10.270 AT read  +   13 "\r\n+CGREG: 2\r\n"
    10.766 AT read  +   12 "\r\n+CREG: 0\r\n"
    10.767 AT read  +   13 "\r\n+CGREG: 0\r\n"
    15.777 AT read  +   12 "\r\n+CREG: 2\r\n"
    15.779 AT read  +   13 "\r\n+CGREG: 2\r\n"
    16.054 AT read  +   12 "\r\n+CREG: 0\r\n"
    16.056 AT read  +   13 "\r\n+CGREG: 0\r\n"
    20.763 AT send      10 "AT+CREG?\r\n"
    21.071 AT read  +   14 "\r\n+CREG: 2,0\r\n"
    21.072 AT read OK    6 "\r\nOK\r\n"
    21.072 AT send      11 "AT+CGREG?\r\n"
    21.072 AT read  +   12 "\r\n+CREG: 2\r\n"
    21.075 AT read  +   13 "\r\n+CGREG: 2\r\n"
    21.077 AT read  +   15 "\r\n+CGREG: 2,2\r\n"
    21.078 AT read OK    6 "\r\nOK\r\n"
    21.345 AT read  +   12 "\r\n+CREG: 0\r\n"
    21.346 AT read  +   13 "\r\n+CGREG: 0\r\n"
    26.345 AT read  +   12 "\r\n+CREG: 2\r\n"
    26.346 AT read  +   13 "\r\n+CGREG: 2\r\n"
    26.616 AT read  +   12 "\r\n+CREG: 0\r\n"
    26.617 AT read  +   13 "\r\n+CGREG: 0\r\n"
    31.627 AT read  +   12 "\r\n+CREG: 2\r\n"
    31.628 AT read  +   13 "\r\n+CGREG: 2\r\n"
    31.894 AT read  +   12 "\r\n+CREG: 0\r\n"
    31.896 AT read  +   13 "\r\n+CGREG: 0\r\n"
    36.082 AT send      10 "AT+CREG?\r\n"
    36.905 AT read  +   14 "\r\n+CREG: 2,0\r\n"
    36.906 AT read OK    6 "\r\nOK\r\n"
    36.906 AT send      11 "AT+CGREG?\r\n"
    36.908 AT read  +   12 "\r\n+CREG: 2\r\n"
    36.909 AT read  +   13 "\r\n+CGREG: 2\r\n"
    36.913 AT read  +   15 "\r\n+CGREG: 2,2\r\n"
    36.914 AT read OK    6 "\r\nOK\r\n"
    37.176 AT read  +   12 "\r\n+CREG: 0\r\n"
    37.177 AT read  +   13 "\r\n+CGREG: 0\r\n"
    42.176 AT read  +   12 "\r\n+CREG: 2\r\n"
    42.177 AT read  +   13 "\r\n+CGREG: 2\r\n"
    42.447 AT read  +   12 "\r\n+CREG: 0\r\n"
    42.448 AT read  +   13 "\r\n+CGREG: 0\r\n"
    47.459 AT read  +   12 "\r\n+CREG: 2\r\n"
    47.461 AT read  +   13 "\r\n+CGREG: 2\r\n"
    47.739 AT read  +   12 "\r\n+CREG: 0\r\n"
    47.741 AT read  +   13 "\r\n+CGREG: 0\r\n"
    51.921 AT send      10 "AT+CREG?\r\n"
    52.753 AT read  +   12 "\r\n+CREG: 2\r\n"
    52.754 AT read  +   13 "\r\n+CGREG: 2\r\n"
    52.755 AT read  +   14 "\r\n+CREG: 2,2\r\n"
    52.756 AT read OK    6 "\r\nOK\r\n"
    52.756 AT send      11 "AT+CGREG?\r\n"
    52.761 AT read  +   15 "\r\n+CGREG: 2,2\r\n"
    52.762 AT read OK    6 "\r\nOK\r\n"
0000064023 [app] INFO: total time: 60000, failures: 1

[ Modem::cancel ] = = = = = = = = = = = = = = =

[ Modem::resume ] = = = = = = = = = = = = = = =
0000064024 [system] INFO: Clearing WLAN WD in disconnect()
0000064025 [system] INFO: Clearing WLAN WD in disconnect()

[ Modem::powerOff ] = = = = = = = = = = = = = =
    64.025 AT send       4 "AT\r\n"
    64.512 AT read OK    6 "\r\nOK\r\n"

[ Modem::softPowerOff ] Powering down the modem using AT+CPWROFF....
    64.512 AT send      12 "AT+CPWROFF\r\n"
    64.551 AT read OK    6 "\r\nOK\r\n"

[ Modem::powerOff ] took 1261 ms
[ ElectronSerialPipe::end ] pipeTx=0 pipeRx=0
0000065812 [system.sleep] TRACE: Entering system_sleep_ext()

[ Modem::cancel ] = = = = = = = = = = = = = = =
0000065813 [system.sleep] TRACE: Waiting interface to be off...


Serial connection closed.  Attempting to reconnect...

[kwolley]

We have tried both with and without SYSTEM_THREAD(ENABLED) and it appears that the connection time is much greater when thread is enabled. Quite often the connection fails, given we set a max connection time of 90sec (due to battery use concerns). Is this finding consistent to what you have seen?

(Basically our concerns originate from wanting to minimize battery usage, and for example our PCB with the Electron is down below 1 mA during our sleeps.)