EmonCMS error: Now data from RF not being logged into EmonCMS? Panicking!

My EmonCMS had an issue a few hours ago in that the data logging stopped.
After a quick check to see the SD card was OK, I restarted the Pi.
Now, although the RF module is receiving the data fine (as seen in EmonHub and MQTT) it’s not being stored in the database. Data from MQTT and from HTTP calls seems to be store OK.
I’m seeing the odd

"WARNING emoncms local emoncms local couldn't send to server: HTTPConnectionPool(host='10.0.0.4', port=81): Read timed out. (read timeout=60)"

message in EmonHub log.
And EmonHub is also trying to send VERY large http calls (big wads of EmonTX data).
I’ve been playing for hours with several restarts and restarting EmonHub, service-runner, etc but I’m at a loss to fix the issue. Google has also failed me.

Any ideas? I’ve got a 7 hour loss of data and losing more by the second… :worried:

As additional info I seem to be getting a lot of these errors in the Emoncms.log
Next RedisException: Connection closed in /var/www/emoncms/Modules/input/input_model.php:240
Stack trace:
#0 /var/www/emoncms/Modules/input/input_model.php(240): Redis->exec()
#1 /var/www/emoncms/Modules/input/input_model.php(220): Input->redis_get_inputs(1)
#2 /var/www/emoncms/scripts/services/emoncms_mqtt/emoncms_mqtt.php(325): Input->get_inputs(1)
#3 [internal function]: message(Object(Mosquitto\Message))
#4 /var/www/emoncms/scripts/services/emoncms_mqtt/emoncms_mqtt.php(140): Mosquitto\Client->loop()
#5 {main}

Next RedisException: Connection closed in /var/www/emoncms/Modules/input/input_model.php:240
Stack trace:
#0 /var/www/emoncms/Modules/input/input_model.php(240): Redis->exec()
#1 /var/www/emoncms/Modules/input/input_model.php(220): Input->redis_get_inputs(1)
#2 /var/www/emoncms/scripts/services/emoncms_mqtt/emoncms_mqtt.php(325): Input->get_inputs(1)
#3 [internal function]: message(Object(Mosquitto\Message))
#4 /var/www/emoncms/scripts/services/emoncms_mqtt/emoncms_mqtt.php(140): Mosquitto\Client->loop()
#5 {main}

Next RedisException: Connection closed in /var/www/emoncms/Modules/input/input_model.php:240
Stack trace:
#0 /var/www/emoncms/Modules/input/input_model.php(240): Redis->exec()
#1 /var/www/emoncms/Modules/input/input_model.php(220): Input->redis_get_inputs(1)
#2 /var/www/emoncms/scripts/services/emoncms_mqtt/emoncms_mqtt.php(325): Input->get_inputs(1)
#3 [internal function]: message(Object(Mosquitto\Message))
#4 /var/www/emoncms/scripts/services/emoncms_mqtt/emoncms_mqtt.php(140): Mosquitto\Client->loop()
#5 {main}
2022-04-30 21:03:57.560|WARN|emoncms_mqtt.php|Not connected, retrying connection
2022-04-30 21:03:57.576|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0

Edit - formatted text. Moderator - BT

Is this buffer size going to be an issue?

2022-05-01 01:31:42,019 DEBUG    emoncmslocal Buffer size: 256
2022-05-01 01:31:42,028 INFO     emoncmslocal sending: http://10.0.0.4:81/input/bulk.json? data=[[1651364490.2303972,10,27,0,0,173,24749,-50],[1651364493.1813252,10,19,0,0,172,24765,-50],[1651364496.1321027,10,19,0,16,176,24755,-51],[1651364499.0918474,10,19,0,0,174,24766,-51],[1651364501.9503975,10,22,0,0,177,24764,-51],[1651364504.9199579,10,23,0,0,169,24759,-49],[1651364506.7510028,16,1600,3476,-61],[1651364507.8865068,10,18,0,0,174,24758,-51],[1651364510.8351007,10,21,0,0,173,24752,-49],[1651364512.3866704,17,1918,3587,-62],[1651364513.7294815,10,22,0,0,172,24769,-51],[1651364516.7047615,10,18,0,0,174,24771,-50],[1651364519.673407,10,19,0,0,174,24780,-49],[1651364522.5459347,10,29,0,0,176,24780,-51],[1651364525.5021498,10,20,0,15,175,24772,-51],[1651364528.391665,8,0,3805,0,-64],[1651364528.5159645,10,18,0,0,177,24761,-51],[1651364531.4623375,10,19,0,0,176,24766,-51],[1651364534.3329284,10,17,0,0,172,24774,-49],[1651364537.284383,10,18,0,0,172,24771,-51],[1651364540.2635996,10,20,0,0,179,24788,-50],[1651364543.2208288,10,22,0,15,171,24768,-52],[1651364544.3882854,20,1812,-66],[1651364544.6082616,21,1993,1906,3542,-77],[1651364546.1399555,10,31,0,0,174,24786,-49],[1651364549.1184623,10,38,0,0,174,24785,-51],[1651364552.0718377,10,19,0,0,174,24784,-49],[1651364554.9172025,10,21,0,0,175,24772,-51],[1651364557.8817134,10,26,0,0,176,24778,-52],[1651364558.8032947,24,1737,3693,-81],[1651364560.848498,10,22,0,0,176,24794,-51],[1651364563.7994258,10,20,0,0,176,24795,-50],[1651364566.7546337,10,21,0,0,170,24794,-50],[1651364569.3986607,17,1918,3587,-62],[1651364569.721197,10,18,0,0,173,24801,-50],[1651364572.6723506,10,20,0,0,172,24798,-51],[1651364575.6134691,10,21,0,0,172,24792,-51],[1651364578.4624863,10,31,0,0,173,24788,-50],[1651364581.4199514,10,22,0,0,172,24779,-49],[1651364584.3951693,10,19,0,0,171,24769,-51],[1651364587.3640711,10,22,0,0,174,24787,-51],[1651364590.123127,8,0,3805,0,-64],[1651364590.2468386,10,21,0,0,173,24796,-49],[1651364593.2165663,10,22,0,0,177,24791,-50],[1651364596.1789796,10,29,0,0,173,24782,-51],[1651364599.1554387,10,18,0,0,165,24791,-51],[1651364602.0235655,10,19,0,0,173,24784,-51],[1651364602.350115,22,1720,1740,5530,5810,3897,5670,-65],[1651364604.999307,10,19,0,0,171,24780,-51],[1651364605.4142106,20,1818,-66],[1651364607.9530041,10,23,0,0,173,24803,-50],[1651364610.9028747,10,20,0,0,187,24808,-50],[1651364613.786924,10,22,0,0,191,24798,-51],[1651364616.7454572,10,22,0,0,189,24789,-50],[1651364619.7261014,10,20,0,0,194,24805,-51],[1651364622.6013079,10,19,0,0,188,24789,-49],[1651364625.5706396,10,23,0,0,191,24792,-49],[1651364626.2949731,17,1918,3587,-62],[1651364628.561919,10,16,0,0,187,24810,-49],[1651364631.4246917,10,20,0,0,193,24785,-51],[1651364632.9888551,16,1600,3476,-62],[1651364634.428432,10,24,0,0,193,24795,-51],[1651364637.3785417,10,22,0,0,194,24789,-50],[1651364640.323416,10,22,0,0,192,24806,-50],[1651364643.1812944,10,15,0,0,191,24805,-51],[1651364646.1455572,10,20,0,0,192,24789,-51],[1651364649.085974,10,33,0,0,193,24787,-49],[1651364651.9327745,8,16,3805,41,-63],[1651364652.0497139,10,28,0,0,190,24799,-52],[1651364654.943679,10,25,0,0,195,24786,-50],[1651364657.932035,10,17,0,0,189,24801,-52],[1651364660.8892097,10,19,0,0,197,24798,-51],[1651364663.8441157,10,21,0,0,189,24800,-50],[1651364666.396856,20,1818,-66],[1651364666.7118886,10,20,0,0,192,24794,-51],[1651364669.666447,10,23,0,0,189,24792,-51],[1651364672.6232991,10,18,0,0,192,24793,-51],[1651364675.5859184,10,18,0,0,187,24819,-50],[1651364678.4631743,10,17,0,0,193,24802,-51],[1651364681.4213731,10,22,0,0,195,24804,-50],[1651364683.2596295,17,1918,3587,-62],[1651364684.4145498,10,19,0,0,194,24828,-49],[1651364684.7483296,24,1737,3693,-81],[1651364687.2823646,10,20,0,0,194,24815,-52],[1651364690.3029048,10,18,0,0,187,24825,-51],[1651364693.2281055,10,20,0,0,191,24811,-51],[1651364696.181417,10,20,0,0,189,24811,-50],[1651364699.0435715,10,20,0,0,184,24778,-49],[1651364701.9992352,10,21,0,0,188,24802,-49],[1651364704.9735558,10,23,0,0,190,24795,-51],[1651364707.8552432,10,21,0,0,191,24811,-50],[1651364710.830458,10,21,0,0,188,24811,-51],[1651364713.6106155,8,16,3805,41,-63],[1651364713.7509248,10,25,0,0,188,24836,-51],[1651364716.715789,10,26,0,0,192,24830,-51],[1651364719.5959601,10,17,0,0,190,24822,-51],[1651364722.5585704,10,20,0,0,187,24820,-49],[1651364724.114135,22,1720,1750,5530,5810,3897,5670,-65],[1651364725.4967039,10,30,0,0,188,24807,-49],[1651364727.3774085,20,1812,-65]]&sentat=1651365102&apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y

Edit formatted text. Moderator - BT

Hello @Vster looks like the issue has something to do with redis but it’s not giving a lot of information on what that might be. Is this a standard emonSD SD card running on a Pi? Can you access the redis cli locally on the pi?

$ redis-cli

Hui @TrystanLea Yes, I can get to the redis cli -

[email protected]:~ $ redis-cli
127.0.0.1:6379> help
redis-cli 5.0.14
To get help about Redis commands type:
      "help @<group>" to get a list of commands in <group>
      "help <command>" for help on <command>
      "help <tab>" to get a list of possible help topics
      "quit" to exit

What can check from here?

Hello @Vster ok looks fine, Im not sure what’s happening unfortunately, the error above looks to be redis related, there’s an exception that’s closing the connection.

You could try clearing the redis cache locally via the emoncms admin interface, there’s an option to flush redis lower down…

or via the cli:

$ redis-cli flushall

I doubt that will fix it as it should clear after a restart.

Sorry not sure what’s going on here or how best to debug further

Might be faster to migrate to a new SD card running the latest image?
Do you know which image version you are running? how long has it run for before this issue?

Hi @TrystanLea yes, I came to the same conclusion a few hours hours ago.
Sadly, it’s not going so well.
I pulled out a brand new 64GB SD card, used Balena to flash the latest image of EmonCMS onto it.
Shutdown the Pi, put the existing card into a USB reader, and the new card into the Pi.
Ran apt to upgrade the OS , set the IP address to the old one. And then got into EmonCMS and used the import from SD card to move the data over. That all worked as it should.

However, now in EmonCMS I’m getting 100’s of those annoying popup boxes saying things like “There was an error creating device: nodeid=253 message=Device already exists”.
And also fully collapsed version inputs screen -


which I can’t expand, as the popups keep occuring, so I can’t see the inputs.
Which I need, as while things seemed to be going OK for a while, it looks like data aren’t being stored again.

Lost nearly 24 hours of data now… :anguished:

Ok, that’s annoying, sorry about that. Can you try running a full emoncms update from the emoncms admin page? and perhaps again a redis flush from the admin info page?

You could also try typing the following url directly:

IP-ADDRESS/device/clean.json

I remember reading a thread that talked about upgrading outside of emonCMS.
IIRC, the general consensus was upgrades via that path could be problematic and
the best way to upgrade was via the emonCMS admin function.

@TrystanLea, Is that still the case or is it a non-issue now?

It’s not something that we’ve done any work on to resolve either way, I would usually expect it not to be an issue but it could be. I think @Vster’s issue here (the new issue after switching the card) is something else. Something to do with a mismatch between what is stored in redis and what is stored in the mysql data base. There was a related fix for this in a relatively recent emoncms release, cant remember which one.

Hi @Bill.Thomson yes, I’m sure I’ve seen that mentioned before, but on a brand new instance that the data hadn’t been imported into yet, I can’t see it causing a problem. And in my defence, it’s just force of habit, I’ve been looking after Debian/Ubuntu servers for too long and do it as instinct on new installs or machines I haven’t logged into recently.

@TrystanLea Doing the Full Update from the Admin screen didn’t seem to update anything (though oddly I saw a serial connection error to the RFMPi69 in the EmobHub log after this, but it hasn’t stopped it working).
I’m not sure what effect the redis flush had, it didn’t seem to do anything.
But the emonpi.local/device/clean.json does seem to fix (but only temporarily) the hundreds of "Error creating device) popups and the fully collapsed Input View.
This allowed me to clean up the duplicated inputs (yes, that old chestnut) which let the logging sort itself out.
Some head scratching in the ported across Node Red code (all the account/passwords for MQTT disappear and the serial ports all moved around) later and everything seems to be working again now.
There was some weirdness in a few of the daily kWh figures, like 66kWh imported from the PV (I wish!) but I edited out those with the EditDaily in the Visualisation page - never used it before but it worked great!

So, what does the clean.json do? I can’t find it on the Pi to have a look at it.
Looking at the Pi this morning the “Unable to create device” popups have occurred a couple of times, but only a single instance each time. What causes those? Yesterday I would have said it’s editing/deleting inputs, but I’ve only been looking at them this morning so I’m at a loss.

The duplicated inputs issue is annoying, I’ve not seen that in a while, I thought it had been finally sorted.

Still, on the plus side, it’s all up and running, on a fresh SD card, latest EmonCMS software, cleaned up data, and now I have an updated Reinstallation Guide, with all the issues I have to look out for next time!

Hi Lee,

IIRC, it was a “version” problem.

From the thread linked above:

But… That thread is about two years old, so may not be relevant any longer, not to mention
it likely had nothing to do with the type of issue you had.
It was one of those things that came to mind when I read your post.

Glad you have this running again, what a pain!

Yes that’s strange, I thought it was sorted as well, makes me wonder if whatever caused redis to close on the old SD card was also then creating an issue on the new one, somehow messing up the redis cache of the input list data.

device/clean deleted all devices and inputs for devices that have not been configured with any input processing so can help clean up devices created in error.

Is it always and still node 11 giving the error?

I have found a way to replicate the device error, simply if I delete the device from the redis cache but not mysql it reproduces the error. Forcing a cache reload before checking if the device exists when trying to create a device fixes the error - or at least stops it from reoccurring more than once.

I’ve uploaded this fix to v2.1.8 of the device module (current only in the master branch): reload device cache on device create · emoncms/[email protected] · GitHub

The error shown should now look like this:

image

Reloading the page automatically fixes the issue. It should be possible to get this to happen in a way that’s a bit more hidden from the user but it’s one step forwards hopefully.

This is a different fix from an earlier cause of this error which was to do with node name capitalisation differences.

1 Like

No, at the high of the issue it was all of them, I had to hold down the Escape key and it quickly flicked though 100’s of them (I have many inputs and feeds).
Now, it’s the odd one here and there, it changes every time.

With regards to the emonpi.local/device/clean.json there must be more to it, I can run it repeatedly, one after another and get different results every time -
DeepinScreenshot_select-area_20220502103608
DeepinScreenshot_select-area_20220502103626
DeepinScreenshot_select-area_20220502103636
DeepinScreenshot_select-area_20220502103646
What nodes are being delete here? And what’s recreating them? I’m still not sure I understand what’s happening behind the scenes. :thinking:

Excellent! Should/can I “Full Update” to this fix?

I think there is now an option to “Switch Branch” so you need to switch to Master until the fix is released to Stable.

@borpin So it is!
But before I do something daft, can I just check that the “Device Module” that @TrystanLea is referring to is the same thing as the “Device Component” on the Admin/Components page?
I set this to Master and then go another Full Update?

I just logged in again after not logging in for 14 hours and there were dozens of pop ups on the Inputs page. If I run this update, and log out for a few hours, it’ll prove the fix one way or the other.

I’ll let @TrystanLea answer that!

Yes you can now do this. I’ve merged the changes to stable.

Well, I’ve updated and I thought I’d leave it a few days to see if it re-occurs, but so far so good!
Many thanks @TrystanLea !

Can I request a small “ease of use” addition?
The window that displays the log as the Full Upate is running, could that have a “pull handle in the corner that always the window to be expanded” added to it?
With so few lines, it’s hard to see what’s gone when you’re watching it like a hawk for errors.
Many thanks again!