OS Bug? Photon 1.5.2 SerialLogHandler stops working after delay() function

Firmware Device OS
1

I’m trying to debug some math values using SerialLogHandler but noticed that the CLI outputs the serial monitor data just fine until I hit a delay() call…

here are the relevant code details;

SerialLogHandler LogHandler(LOG_LEVEL_TRACE);

Log.trace("i can see this just fine");
Log.trace("...this also...");
servo.write(255);
Log.trace("...this as well...");
delay(5000);
Log.trace("but not this");

This is what I see on serial output…

image

Is this a bug in the OS? I have no other serial functions going on at all, it’s just a simple servo control sweeping the range from 255 to 0 with a delay between.

2

Just a quick update… I tried Serial.write instead and got the same results…

Serial.write("i can see this just fine");
Serial.write("...this also...");
servo.write(255);
Serial.write("...this as well...");
delay(5000);
Serial.write("but not this");
servo.write(0);
delay(5000);
Serial.write("or this");

Monitor output…

image
image960×427 12.2 KB

3

Can you also provide the context in which this block of code is executed?

4

Just to confirm it's the delay command, I commented them out and I get all expected output, though my servo doesn't move at all because it's starting at 0 and the commands are sent to it one immediately after the other.

//position needle at 0
Log.trace("i can see this just fine");
Log.trace("...this also...");
servo.write(255);
Log.trace("...this as well...");
//delay(5000);
Log.trace("but not this");
servo.write(0);
//delay(5000);
Log.trace("or this");

Monitor output;

image
image960×427 11.1 KB

Sure.. the init SerialLogHandler LogHandler(LOG_LEVEL_TRACE); is literally the first line, just above void setup()

The other calls are in setup.. the sweep motion of the servo is a one-time init kind of thing..

void setup() {
// preload the countdown to trigger immediately on boot
countdown = millis() - periodMillis; 

// attaches the servo on the D0 pin to the servo object
servo.attach(D0);

// Subscribe to the integration response event
Particle.subscribe("hook-response/netsales", myHandler);

//position servo at 0
Log.trace("i can see this just fine");
Log.trace("...this also...");
servo.write(255);
Log.trace("...this as well...");
//delay(5000);
Log.trace("but not this");
servo.write(0);
//delay(5000);
Log.trace("or this");
}
5

I was advised to move that stuff out of setup by a friend just now, so I tried doing that by declaring a bool initDone = false; above setup (not in setup) and in loop() I put;

if (not initDone) {
        //position servo at 0
        Log.trace("i can see this just fine");
        Log.trace("...this also...");
        servo.write(255);
        Log.trace("...this as well...");
        delay(5000);
        Log.trace("but not this");
        servo.write(0);
        delay(5000);
        Log.trace("or this");
        initDone = true;
    }

But still…

image
image979×459 12.9 KB

6

Ok… a bit of a breakthrough… the length of the delay matters apparently. I set the first delay to 1ms and while my servo didn’t move, I got both lines of output following both delay statements;


void loop() {
    
    if (not initDone) {
        //position needle at 0
        Log.trace("i can see this just fine");
        Log.trace("...this also...");
        needle.write(255);
        Log.trace("...this as well...");
        delay(1);
        Log.trace("but not this");
        needle.write(0);
        delay(5000);
        Log.trace("or this");
        initDone = true;
    }

and you can see the output now!

image
image979×459 13.3 KB

So… I figured ok… put a pre-emptive delay(1); in there…


void loop() {
    
    if (not initDone) {
        //position needle at 0
        Log.trace("i can see this just fine");
        Log.trace("...this also...");
        needle.write(255);
        Log.trace("...this as well...");
        delay(1);
        delay(4999);
        Log.trace("but not this");
        needle.write(0);
        delay(5000);
        Log.trace("or this");
        initDone = true;
    }

But this does not work…

image
image979×459 13.2 KB

So… ok… I figure maybe delay(1); has to happen and then some other code needs to execute… then maybe it will work?

void loop() {
    
    if (not initDone) {
        //position needle at 0
        Log.trace("i can see this just fine");
        Log.trace("...this also...");
        needle.write(255);
        Log.trace("...this as well...");
        delay(1);
        Log.trace(".. 1ms ..");
        delay(4999);
        Log.trace("but not this");
        needle.write(0);
        delay(5000);
        Log.trace("or this");
        initDone = true;
    }

But no… hmm.

image
image979×459 13.1 KB

So… ok… let’s give the servo a command between …


void loop() {
    
    if (not initDone) {
        //position needle at 0
        Log.trace("i can see this just fine");
        Log.trace("...this also...");
        needle.write(255);
        Log.trace("...this as well...");
        delay(1);
        Log.trace(".. 1ms ..");
        needle.write(255);
        delay(4999);
        Log.trace("but not this");
        needle.write(0);
        delay(5000);
        Log.trace("or this");
        initDone = true;
    }

Still no…

image
image979×459 13.1 KB

So I guess… back to the code that works but the servo doesn’t…


void loop() {
    
    if (not initDone) {
        //position needle at 0
        Log.trace("i can see this just fine");
        Log.trace("...this also...");
        needle.write(255);
        Log.trace("...this as well...");
        delay(1);
        Log.trace("but not this");
        needle.write(0);
        delay(5000);
        Log.trace("or this");
        initDone = true;
    }

yep… that works…

image
image979×459 12.7 KB

smells like a dirty rotten bug to me.