Gen 3 bug using PaperTrail library

argon
Tags: #<Tag:0x00007fe21c38d640>

#1

Hi all,

Flashing a project using the PaperTrail library causes an Argon to fail to connect to WiFi. Strangely this also effects safe-mode and the only fix is to flash tinker via DFU. The argon goes from slow green to fast green, then stays flashing fast green.

// This #include statement was automatically added by the Particle IDE.
#include <papertrail.h>

unsigned long lastChange;

PapertrailLogHandler papertailHandler("logs.papertrailapp.com", 11111, "Argon");

void setup() {
    pinMode(D7, OUTPUT);
}

void loop() {
    if (millis() > lastChange) {
        digitalWrite(D7, !digitalRead(D7));
        lastChange = millis() + 500;
    }
}

Thanks,
Kev


#2

There was a bug in 0.8.0-rc.27 which should be fixed in the latest release. I havent checked however that this is the fact.
There might also be a problem if you send to much data over UDP, Try to restrict the amount by using

PapertrailLogHandler papertailHandler(“logserver.papertrailapp.com”, 12345, “PapertrailLoggerTest”, System.deviceID(),
LOG_LEVEL_NONE, {
{ “app”, LOG_LEVEL_ALL }
// TOO MUCH!!! { “system”, LOG_LEVEL_ALL },
// TOO MUCH!!! { “comm”, LOG_LEVEL_ALL }
});


#3

Yes I’ve found your GitHub issue. But there’s no comment or mention of a fix?


#4

I didnt have acces to a device until today, but it seems that the changes made to 0.9.0 seem to be sufficient to get papertrail to work.

The problem is that since GEN3 code is still in development, it has itself a lot of debugging which uses the Logging libraries from the Particle OS. Thus you need to restrict the PaperTrail Library to only log the data from your own code.

I tried with the following code and it worked well

/*
 * Project VCTest
 * Description:
 * Author:
 * Date:
 */
#include "application.h"
#include "papertrail.h"

/**
* Declaring the variables.
*/
unsigned int nextTime = 0;    // Next time to contact the server


PapertrailLogHandler papertailHandler("logserver.papertrailapp.com", 12345, "PapertrailLoggerTest", System.deviceID(),
    LOG_LEVEL_NONE, {
    { "app", LOG_LEVEL_ALL }
    // TOO MUCH!!! { "system", LOG_LEVEL_ALL },
    // TOO MUCH!!! { "comm", LOG_LEVEL_ALL }
    });

SerialLogHandler serialLog;


int enabled=0; // 1 if sending enabled, 0 if disabled
int sleeping = 0; // 1 if to sleep

void setup() {
    Particle.variable("Enabled", enabled);
    Particle.function("Logging", EnableLogging);
    Particle.function("Sleep", Sleep);
}

int EnableLogging(String enable) {
    if (enable == "on") {
        enabled=1;
        Log.info("Loop enabled");
    }
    else
    {
        enabled=0;    
        Log.trace("Loop disabled");
    }
  return enabled;
}

int Sleep(String sleepMode) {
    if (sleepMode == "sleep") {
        Log.trace("Sleeping in 0,5s");
        delay(500);
        sleeping = 1;
    }
    else
    {
    }
  return enabled;
}

void loop() {
    if (sleeping==1)
    {
        System.sleep(D2, CHANGE, 5);
        sleeping=0;
    }
    if ((enabled == 0) || (nextTime > millis())) {
        return;
    }
    Log.info("Loop start");
    delay(500);
    Log.info("Loop end");

    nextTime = millis() + 10000;
}

#5

I don’t believe the issue is too much logging. It’s logging too early that causes an issue. Only logging app level logs stops anything logging until setup or loop. But I’m finding the if any logs are sent before millis() > 10000 the Argon freezes.

// This #include statement was automatically added by the Particle IDE.
#include <papertrail.h>

unsigned long nextFlash = 0;
unsigned long nextLog = 0;
int i = 0;

PapertrailLogHandler papertailHandler(“logs.papertrailapp.com”, 12345, “MyArgon”, System.deviceID(),
LOG_LEVEL_NONE, {
{ “app”, LOG_LEVEL_ALL }
// TOO MUCH!!! { “system”, LOG_LEVEL_ALL },
// TOO MUCH!!! { “comm”, LOG_LEVEL_ALL }
});

void setup() {
pinMode(D7, OUTPUT);
}

void loop() {
if (millis() > nextFlash) {
digitalWrite(D7, !digitalRead(D7));
nextFlash = millis() + 500;
}

// changing 10000 to 9000 or lower results in a freeze
if (millis() > 10000 && millis() > nextLog) {
    nextLog = millis() + 5000;
    Log.info("This is test %d", ++i);
}

}


#6

I ran into a problem with the Argon being unable to connect to Wi-Fi and generally acting strangely with SdCardLogHandlerRK.

I believe it’s caused by Gen 3 devices being more sensitive to what you do in a log handler callback. What I ended up doing is using an interrupt and thread-safe ring buffer and only queue the logs from the log handler. From loop it goes and writes the data to SD card.


#7

Yes that’s the same symptoms I’m seeing. WiFi fails to connect or the device locks completely.

I’m using a Photon inside an alarm system and logging serial data to papertrail for easy viewing and troubleshooting. I’m hoping I’ll be able to replace it with an Argon in the near future :slight_smile:


#8

There was a bug fixed in release 0.8.0-rc.3 which is not included in Gen 3 devices. This fixed an issue with recursive logging, which is exactly what happens if you create a LogHandler which uses UDP or TCP and the UDP/TCP logs a message while your log message is beeing processed.

See https://github.com/particle-iot/device-os/pull/1517 and https://github.com/particle-iot/device-os/pull/1517/files/27ad29ef6871ce2e0cd0e401ec4219b4f6a96bfb

I will try to change my local device os code and see if that helps.


#9

Huh? 0.8.0-rc.3 was not a version released for Gen3.
The versioning was a bit misleading as the Gen1&2 0.8.0-rc.x were no actual upstream versions for Gen3.
AFAIK the versions “paths” are still not fully merged.

You can add a comment to the issues to have them reopenedor to create a follow-up issue for Gen3.


#10

I fully understand that the versions where forked some time back and that 0.8.0-rc.3 for Gen1/2 is not part of 0.9.0 of Gen3. I comparedthe files between 1.0.1 Gen 1/2 and 0.9.0 for Gen3 and nothing else has chaned since the fix I mentioned.

I replaced the files in 0.9.0 and is rebuilding the OS right now and we will see if it fixes the issue.


#11

Replacing sparc_wiring_logging.h and sparc_wiring_logging.cpp with the ones from release 1.0.1 (Gen 1/2) seems to fix the problem.

As @JumpMaster said above its not possible to log over IP for the fist 10? seconds, propably due to the fact that the network firmware needs to be initialized Before you can use it.

I will report my findings on GitHub.


#12

I just tried this with an Argon and OS 1.2.1 and the issue is still there. Is this a regression as the GitHub issue is marked as resolved?


#13

I’m seeing this on my Argon with OS 1.3.1 as well; but disabling the system logging seems to work.


#14

I’m using it successfully but have to add a few bodges to my code.

  unsigned long resetTime = 0;

  PapertrailLogHandler 
  papertrailHandler(papertrailAddress, papertrailPort,
  "DeviceName", System.deviceID(),
  LOG_LEVEL_NONE, {
  { "app", LOG_LEVEL_ALL }
  // TOO MUCH!!! { “system”, LOG_LEVEL_ALL },
  // TOO MUCH!!! { “comm”, LOG_LEVEL_ALL }
  });

  void setup() {
    waitFor(Particle.connected, 30000);
    do {
        resetTime = Time.now();
        Particle.process();
    } while (resetTime < 1500000000 || millis() < 10000);
  }

#15

1.4.0 seems to work well too. I still waitFor Particle.connected otherwise the first logs are missed as the network connection isn’t up yet if threading is enabled.