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

Vster · 2022-05-01T00:40:12.471Z

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

TrystanLea · 2022-05-01T09:29:17.422Z

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

Vster · 2022-05-01T10:03:59.094Z

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

pi@emonpi:~ $ 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?

TrystanLea · 2022-05-01T15:41:55.189Z

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

TrystanLea · 2022-05-01T16:24:46.174Z

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?

Vster · 2022-05-01T17:04:31.763Z

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 -

DeepinScreenshot_select-area_202205011702591363×558 39.5 KB

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…

TrystanLea · 2022-05-01T18:01:05.576Z

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

Bill.Thomson · 2022-05-01T18:24:49.715Z

Vster:

Ran apt to upgrade the OS

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?

TrystanLea · 2022-05-01T18:29:37.887Z

Bill.Thomson:

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.

Vster · 2022-05-02T10:12:18.597Z

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!

Bill.Thomson · 2022-05-02T16:36:42.708Z

Hi Lee,

IIRC, it was a “version” problem.

Php-redis not recognised by php [solved] Emoncms

My machine has missed an update, then, as emoncms/admin/view shows: PHP Version 7.0.33-0+deb9u3 (Zend Version 3.0.0) How do I get emoncms to use php7.3?

From the thread linked above:

Php-redis not recognised by php [solved]

PHP is not updated as part of the emonCMS updates - it tends to break things.

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.

TrystanLea · 2022-05-02T17:08:14.229Z

Glad you have this running again, what a pain!

Vster:

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

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?

TrystanLea · 2022-05-02T17:47:19.236Z

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/device@5556e42 · GitHub

The error shown should now look like this:

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.

Vster · 2022-05-02T23:42:35.025Z

TrystanLea:

Is it always and still node 11 giving the error?

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

What nodes are being delete here? And what’s recreating them? I’m still not sure I understand what’s happening behind the scenes.

TrystanLea:

I have found a way to replicate the device error

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

borpin · 2022-05-03T06:08:16.788Z

Vster:

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.

Vster · 2022-05-03T16:48:52.913Z

@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.

borpin · 2022-05-04T06:45:58.751Z

I’ll let @TrystanLea answer that!

TrystanLea · 2022-05-05T10:24:44.606Z

Vster:

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

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

Vster · 2022-05-09T10:48:21.596Z

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!

TrystanLea · 2022-05-10T09:33:30.707Z

Vster:

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!

Good to hear, thanks!

I’ve raised an issue on the emoncms repo with your suggestion to expand the log window:
Consider having option to expand admin update log window · Issue #1798 · emoncms/emoncms · GitHub. Im focused on hardware development at the moment so will come back to that later on. Cheers!