Waking up from sleep too early

I put my device to sleep for long periods but I wanted to know when it would wake up, so I put in code that rounds to the top of the hour. Take a look at the logs… and it’s waking up about 1.5 mins early.

Any one else seeing issues like this??

SLEEP <- 3600;
imp.onidle(function() {
// Go to sleep and wake up on the hour.
server.sleepfor(SLEEP - (time() % SLEEP));

2016-12-20 19:58:37 UTC-5 [Device] Sleeping until 2016-12-21 02:00:00Z
2016-12-20 20:58:34 UTC-5 [Status] Device disconnected
2016-12-20 20:58:34 UTC-5 [Status] Device connected
2016-12-20 20:58:34 UTC-5 [Device] Waking up…
2016-12-20 20:58:34 UTC-5 [Device] Sleeping until 2016-12-21 03:00:00Z

Ya know… looking at what I just posted… this must be a time sync error either on the agent or device… because… if it were really waking at 58:34… it would just sleep for 86 seconds… not the next hour. So… I guess the revised question is why is the time on agent vs device different.??

Interesting. How about printing time() before you enter sleep? The device should be getting its time set by the server on every wakeup.

OK… so I added a line to print the time it was woken. So clearly there is a time issue on the logging server. How do you report that?

2016-12-22 08:58:26 UTC-5 [Device] Sleeping until 2016-12-22 15:00:00Z
2016-12-22 09:58:23 UTC-5 [Status] Device disconnected
2016-12-22 09:58:23 UTC-5 [Status] Device connected
2016-12-22 09:58:23 UTC-5 [Device] Waking up…
2016-12-22 09:58:23 UTC-5 [Device] Device: 15:0:1
2016-12-22 09:58:23 UTC-5 [Device] Sleeping until 2016-12-22 16:00:00Z

The time shown in logs is local to your browser (the UTC-5 bit - the actual time is UTC).

Are you in UTC-5?

Yes… but it’s not the hour that I’m concerned about. It’s the min’s. The logging server and the device are off by 1.5 mins

I mean, that is indeed strange as all our servers are NTP synchronized. I just spot checked and everything looks fine.

Can you post your device code? If you’re not using onidle() correctly then you may not be getting the time sync from the server and so your imp is drifting off over time (the crystal is only, as I remember, 30ppm). Do you have any issues pushing new code to these devices? You shouldn’t need to power cycle them.

Well… what happened this morning… at some point the clocks became in-sync.

2016-12-25 07:58:02 UTC-5 [Status] Device connected
2016-12-25 07:58:02 UTC-5 [Device] Waking up…
2016-12-25 07:58:02 UTC-5 [Device] Device: 13:0:1
2016-12-25 07:58:02 UTC-5 [Device] Sleeping until 2016-12-25 14:00:00Z
2016-12-25 08:58:04 UTC-5 [Status] Device connected
2016-12-25 08:58:04 UTC-5 [Status] Device disconnected
2016-12-25 08:58:04 UTC-5 [Device] Waking up…
2016-12-25 08:58:04 UTC-5 [Device] Device: 13:58:4
2016-12-25 08:58:04 UTC-5 [Device] Sleeping until 2016-12-25 14:00:00Z
2016-12-25 09:00:01 UTC-5 [Status] Device disconnected
2016-12-25 09:00:01 UTC-5 [Status] Device connected
2016-12-25 09:00:01 UTC-5 [Device] Waking up…
2016-12-25 09:00:01 UTC-5 [Device] Device: 14:0:1
2016-12-25 09:00:01 UTC-5 [Device] Sleeping until 2016-12-25 15:00:00Z
2016-12-25 10:00:01 UTC-5 [Status] Device disconnected

Yeah, seeing your code would help determine why that’s happening. I suspect it’s you sleeping without processing data from the server.

Still drifting. It would be nice to know when does the device sync it’s time. It bothers me that the 2 systems don’t match even after wake up.

Here’s the device code.

// Monitor driveway alarm and send status to the internet.

// How long imp should sleep for.
SLEEP <- 3600;
// How long to delay after receiving alert from remote sensor.
DELAY <- 10;

// “visitor” light on the receiver.
visitor <- hardware.pin1;
// “low bat” light on the receiver.
low_battery <- hardware.pin2;
// Transistor switch to reset unit to turn off “visitor” light.
reset_button <- hardware.pin5;
// “power” light on receiver. Can be used to check when recovered from reset.
power_led <- hardware.pin9;

reset_button.configure(DIGITAL_OUT, 0);

imp.onidle(function() {
// Go to sleep and wake up on the hour.
server.sleepfor(SLEEP - (time() % SLEEP));

server.log(“Waking up…”);

// Get the time we woke up.
local now = time();

// DEBUG date/time logging error.
local tdebug = date(now);
server.log(“Device Time: " + format(”%02u", tdebug.hour) + “:” + format("%02u", tdebug.min) + “:” + format("%02u", tdebug.sec));

// Check/create vars for flags in NV memory.
// These flags are used so that only 1 message is sent
// if the alerts are still triggered right after a reset.
if (!(“nv” in getroottable() && “lowBat” in nv)) {
server.log(“In NV init”);
nv <- { “lowBat” : 0, “lastAlert” : 0 };

// We woke up from sleep or driveway alert.
// First check if driveway alert was activated.
if (visitor.read() == 1) {
server.log(“Driveway alert triggered”);
agent.send(“visitor”, now);
nv.lastAlert = now;

// Delay for DELAY seconds so that a unit reset doesn't trigger multiple
// alarms if someone drives slowly across the sensor.
while ((time() - now) < DELAY) { imp.sleep(0.1); }

// We have to reset the receiver in order to reset the visitor LED

// Wait until the unit has reset.
while (power_led.read() != 1)  { imp.sleep(0.1); }


// Did we get a low battery indication?
if (low_battery.read() == 1) {
if (nv.lowBat == 0) {
server.log(“The outside driveway sensor has a low battery”);
agent.send(“lowBattery”, now);
nv.lowBat = 1;
} else {
if (nv.lowBat == 1) { nv.lowBat = 0 };

So, the incoming time set packet wouldn’t have been processed by the time you log your device time (as your squirrel code takes priority over processing inbound data).

It’d be interesting for you to wrap up everything below the “waking up” server.log in a function and trigger it with say, imp.wakeup(0.5, xxx) - then see if your time looked ok. As it is, the server.sleepfor should be correct (as by the time onidle fires, the time will be set) but the log would show any drift between sleep intervals.

Over a minute drift per hour would be pretty extreme though. Is the device in a very cold or hot place?

I put all the main code in a function then added the imp.wakeup() as the last line… the device would then go into idle mode. So i added a imp.sleep(1) after the wakeup. Here are the results. No different.

2016-12-28 12:19:39 UTC-5 [Device] Sleeping until 2016-12-28 17:25:00Z
2016-12-28 12:24:38 UTC-5 [Status] Device connected
2016-12-28 12:24:38 UTC-5 [Device] Waking up…
2016-12-28 12:24:39 UTC-5 [Status] Device disconnected
2016-12-28 12:24:39 UTC-5 [Device] Device Time: 17:25:02
2016-12-28 12:24:39 UTC-5 [Device] Sleeping until 2016-12-28 17:30:00Z

imp.sleep does nothing useful - it’s a busy wait. It does not allow any inbound packets to be processed.

Move the imp.onidle() into the main function that is called after half a second.