imp restarted, reason: memory error

Hi everyone,

I've had an electricimp controlling a relay for about 3 years, running the same code without any issue. Recently I had to update the code to remove a couple of deprecated/not-supported-anymore calls and ever since a made the changes, I'm seeing random restarts, pointing the reason is memory error.

I've gone through the code many times, but I don't seem to find anything that could be causing this (maybe an infinite recursion, or some excess memory allocation?).

This is an excerpt of the log; there is a suspicious amount of reconnects, likely those are also resets

2015-11-20 23:30:17 UTC+1 [Status] Device connected
2015-11-20 23:30:17 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-20 23:30:48 UTC+1 [Exit Code] imp restarted, reason: memory error
2015-11-20 23:30:48 UTC+1 [Status] Device connected
2015-11-20 23:30:48 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-20 23:31:52 UTC+1 [Status] Device connected
2015-11-20 23:31:52 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-20 23:35:08 UTC+1 [Status] Device connected
2015-11-20 23:35:09 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-20 23:37:04 UTC+1 [Status] Device connected
2015-11-20 23:37:04 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:00:45 UTC+1 [Status] Device connected
2015-11-21 00:00:45 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:03:31 UTC+1 [Status] Device connected
2015-11-21 00:03:31 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:04:49 UTC+1 [Status] Device connected
2015-11-21 00:04:49 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:05:04 UTC+1 [Status] Device connected
2015-11-21 00:05:04 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:05:55 UTC+1 [Status] Device connected
2015-11-21 00:05:56 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:06:31 UTC+1 [Status] Device connected
2015-11-21 00:06:31 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:07:32 UTC+1 [Status] Device connected
2015-11-21 00:07:32 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:07:45 UTC+1 [Exit Code] imp restarted, reason: memory error
2015-11-21 00:07:45 UTC+1 [Status] Device connected
2015-11-21 00:07:45 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:07:57 UTC+1 [Status] Device connected
2015-11-21 00:07:57 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:08:09 UTC+1 [Status] Device connected
2015-11-21 00:08:09 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:08:22 UTC+1 [Status] Device connected
2015-11-21 00:08:22 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:08:33 UTC+1 [Exit Code] imp restarted, reason: memory error
2015-11-21 00:08:33 UTC+1 [Status] Device connected
2015-11-21 00:08:34 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-21 00:09:42 UTC+1 [Status] Device connected
2015-11-21 00:09:42 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-22 07:32:23 UTC+1 [Status] Device connected
2015-11-22 07:32:24 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
2015-11-22 07:33:19 UTC+1 [Agent] Received state: 0
2015-11-22 07:33:19 UTC+1 [Agent] My state: 1
This is the code on the device:

local currentState = 0;


/* __ State management ______________________________________________________ */


function ConfigureThermostatState()
{
/* Relay pin */
hardware.pin8.configure(DIGITAL_OUT);

/* Button pin */
hardware.pin9.configure(DIGITAL_IN_PULLUP, ButtonChanged);

/* Retrieve any previous state in server storage */
if ("lastState" in server.permanent)
{
currentState = server.permanent.lastState;
//server.log("Loaded: " + currentState);
SetState(currentState);
}
}

// value = 0: relay ON
// value = 1: relay OFF
function SetState(value)
{
//server.log("D: SetState f: " + value);
local bit = value.tointeger();
//server.log("D: SetState b: " + bit);
hardware.pin8.write(bit);
imp.sleep(0.5);
//server.show(format("State: %s", bit ? "On" : "Off"));
currentState = bit;
}

function GetState()
{
return hardware.pin8.read();
}

function GetButtonState()
{
return hardware.pin9.read();
}

function ButtonChanged()
{
// Process button_down only
if (GetButtonState() == 1) return;

//server.log("Button pressed");

SetState(GetReverseState());
SaveCurrentState();
}

function GetReverseState()
{
return currentState == 0 ? 1 : 0;
}

function SaveCurrentState()
{
//server.log("save: " + currentState);
server.setpermanentvalues( { lastState = currentState } );

// Send to the server for consumption logging
// server.log("send state to server: " + currentState);
agent.send("setstateresponse", currentState);
}


/* __ Watchdog ______________________________________________________________ */


/* This code prevents NAT routers from dropping the connection after
inactivity by pinging the server every 5 minutes (the ping is actually done
by the wakeup call)
*/

function WatchdogHandler() {
imp.wakeup(5 * 60, WatchdogHandler);
//server.log("ss " + GetSignalStrength());
}

function GetSignalStrength()
{
local dbs = imp.rssi();
if (dbs < -87) return "-----";
if (dbs < -82) return "O----";
if (dbs < -77) return "OO---";
if (dbs < -72) return "OOO--";
if (dbs < -67) return "OOOO-";
if (dbs == 0) return "Wifi off";

return "OOOOO";
}

/* __ Agent commands ________________________________________________________ */


agent.on("querystate", function(msg)
{
agent.send("querystateresponse", GetState());
});

agent.on("setstate", function(msg)
{
//server.log("D: SetState: " + msg);

// Reverse
local bit = msg.tointeger();
bit = bit == 0 ? 1 : 0;

SetState(bit);
SaveCurrentState();

});


/* __ Initialization ________________________________________________________ */

server.log(imp.getsoftwareversion());

WatchdogHandler();
ConfigureThermostatState();

Any help would be much appreciated!

Cheers,

David

Comments

  • How's it powered? Could you log hardware.voltage() in your WatchdogHandler?

    Peter
  • Hey Peter, added voltage per your request. Here is the output:

    2015-11-22 13:02:36 UTC+1 [Status] Downloading new code; 2.35% program storage used
    2015-11-22 13:02:36 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 13:02:36 UTC+1 [Device] Voltage: 3
  • @peter

    Peter, it would be helpful to understand the possible causes of [Exit Code] imp restarted, reason: memory error
    I'm looking at a unit that restarted with this a couple of days ago. It had been operating normally since its last restart 3 weeks prior. I send a wifi_status event message from our units every 5 minutes and this particular device restarted 3 seconds after one of those. The device is permanently powered and device memory is regularly checked, hovering between 49.8K and 50.2K. RSSI is only regularly reported and sits between -76 and -81. The API calls that I make on each 5 minute boundary are: imp.rssi(), imp.getbssid(), hardware.millis(), server.isconnected(), agent.send() and imp.wakeup()
  • A memory error is the result of an illegal memory access within the system. This can be due to a bug, but also can be due to a corrupted processor read from flash due to an unstable power supply.

    @dsuarezv could you provide a device mac address? We can then look at your particular memory errors and get more detail.
  • @Hugo: this is the mac address: 0c2a69000bf2

    I'll try replacing the power supply and see if that helps. Here is some more logging of the voltage output (logged every 5 minutes).

    2015-11-22 13:02:36 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 13:02:36 UTC+1 [Device] Voltage: 3
    2015-11-22 13:07:37 UTC+1 [Device] Voltage: 3.291
    2015-11-22 13:12:38 UTC+1 [Device] Voltage: 3.295
    2015-11-22 13:17:40 UTC+1 [Device] Voltage: 3.289
    2015-11-22 13:22:40 UTC+1 [Device] Voltage: 3.287
    2015-11-22 13:27:41 UTC+1 [Device] Voltage: 3.291
    2015-11-22 13:32:43 UTC+1 [Device] Voltage: 3.291
    2015-11-22 13:37:46 UTC+1 [Device] Voltage: 3.291
    2015-11-22 13:42:46 UTC+1 [Device] Voltage: 3.284
    2015-11-22 13:47:47 UTC+1 [Device] Voltage: 3.291
    2015-11-22 13:52:48 UTC+1 [Device] Voltage: 3.291
    2015-11-22 13:57:50 UTC+1 [Device] Voltage: 3.289
    2015-11-22 14:02:52 UTC+1 [Device] Voltage: 3.284
    2015-11-22 14:07:52 UTC+1 [Device] Voltage: 3.284
    2015-11-22 14:12:54 UTC+1 [Device] Voltage: 3.287
    2015-11-22 14:17:54 UTC+1 [Device] Voltage: 3.3
    2015-11-22 14:22:56 UTC+1 [Device] Voltage: 3.293
    2015-11-22 14:27:57 UTC+1 [Device] Voltage: 3.284
    2015-11-22 14:32:58 UTC+1 [Device] Voltage: 3.289
    2015-11-22 14:37:59 UTC+1 [Device] Voltage: 3.289
    2015-11-22 14:43:00 UTC+1 [Device] Voltage: 3.289
    2015-11-22 14:48:01 UTC+1 [Device] Voltage: 3.284
    2015-11-22 14:53:01 UTC+1 [Device] Voltage: 3.284
    2015-11-22 14:58:03 UTC+1 [Device] Voltage: 3.289
    2015-11-22 15:03:04 UTC+1 [Device] Voltage: 3.282
    2015-11-22 15:08:04 UTC+1 [Device] Voltage: 3.289
    2015-11-22 15:13:05 UTC+1 [Device] Voltage: 3.287
    2015-11-22 15:18:05 UTC+1 [Device] Voltage: 3.284
    2015-11-22 15:23:07 UTC+1 [Device] Voltage: 3.291
    2015-11-22 15:28:09 UTC+1 [Device] Voltage: 3.287
    2015-11-22 15:33:09 UTC+1 [Device] Voltage: 3.282
    2015-11-22 15:38:10 UTC+1 [Device] Voltage: 3.284
    2015-11-22 15:43:10 UTC+1 [Device] Voltage: 3.284
    2015-11-22 15:48:11 UTC+1 [Device] Voltage: 3.291
    2015-11-22 15:53:13 UTC+1 [Device] Voltage: 3.287
    2015-11-22 15:58:14 UTC+1 [Device] Voltage: 3.291
    2015-11-22 16:03:14 UTC+1 [Device] Voltage: 3.291
    2015-11-22 16:08:14 UTC+1 [Device] Voltage: 3.291
    2015-11-22 16:13:16 UTC+1 [Device] Voltage: 3.284
    2015-11-22 16:18:16 UTC+1 [Device] Voltage: 3.287
    2015-11-22 16:23:18 UTC+1 [Device] Voltage: 3.293
    2015-11-22 16:28:18 UTC+1 [Device] Voltage: 3.289
    2015-11-22 16:33:18 UTC+1 [Device] Voltage: 3.28
    2015-11-22 16:38:19 UTC+1 [Device] Voltage: 3.284
    2015-11-22 16:43:20 UTC+1 [Device] Voltage: 3.287
    2015-11-22 16:48:21 UTC+1 [Device] Voltage: 3.282
    2015-11-22 16:53:23 UTC+1 [Device] Voltage: 3.287
    2015-11-22 16:54:53 UTC+1 [Agent] Received state: 1
    2015-11-22 16:54:53 UTC+1 [Agent] My state: 0
    2015-11-22 16:58:24 UTC+1 [Device] Voltage: 3.287
    2015-11-22 17:01:38 UTC+1 [Status] Device connected
    2015-11-22 17:01:38 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:01:38 UTC+1 [Device] Voltage: 3.233
    2015-11-22 17:02:26 UTC+1 [Status] Device connected
    2015-11-22 17:02:26 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:02:26 UTC+1 [Device] Voltage: 3.274
    2015-11-22 17:03:52 UTC+1 [Status] Device connected
    2015-11-22 17:03:52 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:03:52 UTC+1 [Device] Voltage: 3.082
    2015-11-22 17:04:39 UTC+1 [Status] Device connected
    2015-11-22 17:04:39 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:04:39 UTC+1 [Device] Voltage: 3.287
    2015-11-22 17:10:51 UTC+1 [Status] Device connected
    2015-11-22 17:10:51 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:10:51 UTC+1 [Device] Voltage: 3.295
    2015-11-22 17:11:50 UTC+1 [Exit Code] imp restarted, reason: memory error
    2015-11-22 17:11:50 UTC+1 [Status] Device connected
    2015-11-22 17:11:51 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:11:51 UTC+1 [Device] Voltage: 3.291
    2015-11-22 17:16:37 UTC+1 [Status] Device connected
    2015-11-22 17:16:37 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:16:37 UTC+1 [Device] Voltage: 3.287
    2015-11-22 17:16:46 UTC+1 [Status] Device connected
    2015-11-22 17:16:46 UTC+1 [Device] 78f540f - release-32.12 - Thu Jul 16 09:55:33 2015
    2015-11-22 17:16:46 UTC+1 [Device] Voltage: 3.284
  • Sampling the voltage doesn't work brilliantly like that, as it's transient conditions that cause the issues - ones you're very unlikely to catch checking even several times per second.

    Can you describe the hardware the imp is plugged into? April board? etc.
  • The imp is connected to an April board, powered with a USB charger on the vcc/gnd pins (not the USB connector). It is actuating a relay on a breakout board.

    Do you need any other specific details?
  • @Hugo what voltage levels are tolerable? I may be able to check with an oscilloscope.
  • If you're seeing any excursions down below ~2.8v then that's likely a problem.
  • revisiting this, is there any other reason that could cause this error?

    It happens rarely on our devices.

    I have an imp002 that restarted with this error a few days ago. It happened to be one that was monitoring voltage every 100ms. At the time, voltage never dropped below 3.1v.

    I'm monitoring voltage on a few hundred imps at the moment. Using our standard power supplies, voltage never drops below 3v
  • Yes, bugs in impOS can cause the error; we collect the crashlogs and attempt to determine the root cause of the issues & fix them in future releases.

    If you file a ticket with that imp's mac address, we may be able to tell you whether this is a known issue addressed in release 36, or whether we have not been able to replicate/fix it yet.
  • Damn! My computer restarted and I've lost the detail on this. Will look out for more.
Sign In or Register to comment.