Archived Forum

Hi, the raspberrypi module for emoncms you refer to is specific to a local emoncms installation and was the interface between emonCMS and the RFM2Pi board before emonHub. The SD card has emonHub installed and that interfaces directly with the RFM2Pi and then forwards the data to emonCMS. So you don't need the raspberrypi module and in fact installing it will cause a conflict with emonHub.

Have you had a look at the emonhub log file ?

cat /var/log/emonhub/emonhub.log 

will show you the contents of the file since boot and

tail -f /var/log/emonhub/emonhub.log

will show you the last 10 log messages and any new ones as they happen

Paul

Ah! Thank you. A log to look at :) 
It's full of error warnings. The first three warnings are: 

1970-01-01 00:00:26,495 WARNING 1 Discarded RX frame 'non-numerical content' : ['>\x00', '84b']

1970-01-01 00:00:26,901 WARNING 3 Discard RX frame 'information' : ['>', '210g']

1970-01-01 00:00:27,308 WARNING 5 Discard RX frame 'information' : ['>', '15i']

Then there's an endless slew of:

.... data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']

And yet, I followed the guide here which states to change the datacodes in /boot/emonhub.conf:

Under the title 'Nodes' replace the lines:
[[99]]
        datacode = h
        datacodes = l, h, h, h,
with:
[[10]]
        datacodes = L, h, h, h, h, l, l, l, l

Have I done something daft?
Also, should I uninstall what I've done so far? Or can the php, pecl and emoncms-module-rfm12pi libraries sit wherever they are as I haven't moved them to the rpi Module folder yet?

[2 near duplicate posts deleted - Moderator (RW)]

I've done a bit more reading on my log warnings. 

I saw your post (paul) re the 1970 date quirk and may follow that route. But I don't think it's the issue. Only the first 6 lines of the log display the wrong date. Subsequent warning logs , instead, display the correct time (minus 2hrs):

1970-01-01 00:00:23,427 INFO EmonHub Pre-Release Development Version (rc1.0)
1970-01-01 00:00:23,429 INFO Opening hub...
1970-01-01 00:00:26,463 WARNING 1 Discarded RX frame 'non-numerical content' : ['>\x00', '4b']
1970-01-01 00:00:26,870 WARNING 3 Discard RX frame 'information' : ['>', '210g']
1970-01-01 00:00:27,283 WARNING 5 RX data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']
1970-01-01 00:00:27,499 WARNING 6 Discard RX frame 'information' : ['>', '15i']
2014-10-10 06:06:32,230 WARNING 8 RX data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']

So I assume that emonhub is setting the time to 0 (1970) in the 27seconds or so that it takes the raspberry to retrieve the real network's time. 

If I run the the fake-hwclock command and then the date command I'm "roughly" in the right place give or take an hour or two:

pi@raspberrypi ~ $ cat /etc/fake-hwclock.data
2014-10-10 07:17:01
pi@raspberrypi ~ $ date
Fri Oct 10 08:16:45 UTC 2014

I've checked my router and it's correctly set to GMT+1, which is my current location. I'm not too worried about the +1-2 hour discrepency.

Following another post I've just set the loglevel (/boot/emonhub.conf) to DEBUG and this is what the log reports:

2014-10-10 08:01:43,409 INFO Logging level set to DEBUG
2014-10-10 08:01:50,734 DEBUG 667 NEW FRAME : 1412928110.73  10 55 2 0 0 0 0 0 0 248 104 0 0
2014-10-10 08:01:50,738 WARNING 667 RX data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']
2014-10-10 08:02:01,305 DEBUG 668 NEW FRAME : 1412928121.31  10 155 1 0 0 0 0 0 0 230 103 0 0
2014-10-10 08:02:01,309 WARNING 668 RX data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']
2014-10-10 08:02:11,893 DEBUG 669 NEW FRAME : 1412928131.89  10 63 2 0 0 0 0 0 0 242 104 0 0
2014-10-10 08:02:11,897 WARNING 669 RX data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']
2014-10-10 08:02:22,465 DEBUG 670 NEW FRAME : 1412928142.47  10 44 1 0 0 0 0 0 0 18 103 0 0
2014-10-10 08:02:22,471 WARNING 670 RX data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']
2014-10-10 08:02:33,039 DEBUG 671 NEW FRAME : 1412928153.04  10 119 1 0 0 0 0 0 0 197 103 0 0
2014-10-10 08:02:33,044 WARNING 671 RX data length: 12 is not valid for datacodes ['L', 'h', 'h', 'h', 'h', 'l', 'l', 'l', 'l']

Seb

The most important issue here is the incorrect time and date, see http://openenergymonitor.org/emon/node/5899 for more insight and how to reset the time. 

The datacodes error says the frame received only contains 12 byte values and therefore it cannot translate it to the string of datacodes you have specified (1 unsigned long (4bytes) + 4 signed ints (8bytes) + 4 signed longs (16bytes) = 28 bytes) I suspect you are running the standard sketch on the emonTx, if that is the case the payload is all ints and requires no declaration in emonhub.conf [nodes].

you can remove the emoncms module using

sudo apt-get remove emoncms-module-rfm12pi

just to avoid any future clashes or confusion and I suspect the php stuff should be ok.

Once you've sorted those and tried again we can have another look, the 1st line of your log looks a little odd too, that frame would normally end ['>', '4b'] or ['>', '8b'] depending on if you are using 433 or 868 MHz so that looks a little confused but may clear with the above items.

Paul

Thanks Paul.

Fristly, there's a post to this thread that's still awaiting moderation. It's got some extra details to what I've done so far and some more logs and readings re the date issue and debug log.

Secondly, I've got it working without tackling the date stamp issue. Although I've got a sneaking suspicion that it's still not quite right. Here's what I've done: 

I re-instated the default datacodes in /boot/emonhub.conf file to:

[[99]]
        #datacodes = L, h, h, h, h, l, l, l, l
    datacode = h
    datacodes = l, h, h, h,

And now the input feeds are displaying and actively updating my readings. Hurrah! One of the CT Sensors isn't giving me anything, but that's probably my goof and needs reclamping elsewhere. 

That aside. Just before (partially?) solving the palava I restarted emonhub and ran cat /var/log/emonhub/emonhub.log just to check what was going on. It still displays the 1970 datestamp for the first 27 seconds, thereafter it finds the network reading (-2hrs): 

1970-01-01 00:00:23,429 INFO EmonHub Pre-Release Development Version (rc1.0)
1970-01-01 00:00:23,432 INFO Opening hub...
1970-01-01 00:00:23,435 INFO Logging level set to DEBUG
1970-01-01 00:00:23,438 INFO Creating EmonHubEmoncmsReporter 'emonCMS'
1970-01-01 00:00:23,443 INFO Set up reporter 'emonCMS' (buffer: memory | size: 1000)
1970-01-01 00:00:23,448 INFO Creating EmonHubJeeInterfacer 'RFM2Pi'
1970-01-01 00:00:23,451 DEBUG Opening serial port: /dev/ttyAMA0
1970-01-01 00:00:23,455 INFO Opened serial port: /dev/ttyAMA0 9600 bits/s
1970-01-01 00:00:23,457 DEBUG Setting RFM2Pi frequency: 433 (4b)
1970-01-01 00:00:24,462 DEBUG Setting RFM2Pi group: 210 (210g)
1970-01-01 00:00:25,466 DEBUG Setting RFM2Pi baseid: 15 (15i)
1970-01-01 00:00:26,487 DEBUG 1 NEW FRAME : 26.49 > 84b
1970-01-01 00:00:26,490 WARNING 1 Discarded RX frame 'non-numerical content' : ['>\x00', '84b']
1970-01-01 00:00:26,694 DEBUG 2 NEW FRAME : 26.69
1970-01-01 00:00:26,696 INFO 2 Ignoring frame consisting of SOH character
1970-01-01 00:00:26,901 DEBUG 3 NEW FRAME : 26.9 > 210g
1970-01-01 00:00:26,903 WARNING 3 Discard RX frame 'information' : ['>', '210g']
1970-01-01 00:00:27,107 DEBUG 4 NEW FRAME : 27.11
1970-01-01 00:00:27,109 INFO 4 Ignoring frame consisting of SOH character
1970-01-01 00:00:27,313 DEBUG 5 NEW FRAME : 27.31 > 15i
1970-01-01 00:00:27,316 WARNING 5 Discard RX frame 'information' : ['>', '15i']
1970-01-01 00:00:27,532 DEBUG 6 NEW FRAME : 27.53
1970-01-01 00:00:27,534 INFO 6 Ignoring frame consisting of SOH character
1970-01-01 00:00:27,744 DEBUG 7 NEW FRAME : 27.74  10 21 8 0 0 0 0 0 0 91 112 0 0
1970-01-01 00:00:27,748 DEBUG 7 Timestamp : 27.74
1970-01-01 00:00:27,751 DEBUG 7      Node : 10
1970-01-01 00:00:27,753 DEBUG 7    Values : [2069, 0, 0, 0, 28763, 0]
1970-01-01 00:00:27,781 DEBUG 7 Append to 'emonCMS' buffer => time: 27.74, data: [10, 2069, 0, 0, 0, 28763, 0], ref: 7
1970-01-01 00:00:27,884 INFO Sending: http://emoncms.org/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[27.74,10,2069,0,0,0,28763,0]]&sentat=27
1970-01-01 00:00:28,382 DEBUG Receipt acknowledged with 'ok' from http://emoncms.org
2014-10-10 10:56:48,473 DEBUG 8 NEW FRAME : 1412938608.47  10 154 7 0 0 0 0 0 0 240 111 0 0
2014-10-10 10:56:48,478 DEBUG 8 Timestamp : 1412938608.47
2014-10-10 10:56:48,480 DEBUG 8      Node : 10
2014-10-10 10:56:48,482 DEBUG 8    Values : [1946, 0, 0, 0, 28656, 0]
2014-10-10 10:56:48,517 DEBUG 8 Append to 'emonCMS' buffer => time: 1412938608.47, data: [10, 1946, 0, 0, 0, 28656, 0], ref: 8
2014-10-10 10:56:48,621 INFO Sending: http://emoncms.org/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[1412938608.47,10,1946,0,0,0,28656,0]]&sentat=1412938608

Another thing from the above log struck me: I'm running EmonHub rc1.0. Digging around I've seen that there's an rc1.1. Could this be the source of my problems?

Many thanks for the support. 

Seb

The fact that the time can some, maybe even most of the time correct itself isn't really reliable and can cause issues of varying degrees. The topic is discussed in some detail on this Read-only image time issues thread.

Aside from the date issue that last log looks fine except for the odd " ['>\x00', '84b'] " response from the RFM2Pi, I can't tell why that is happening at this point but It seems to have no effect on the function. The "Setting RFM2Pi frequency: 433 (4b)" log confirms the correct command was sent by emonHub and the successful receipt of data confirms the RFM2Pi is on 433MHz. I'm not sure where the "8" comes from but the "'>\x00'" is frequently seen the first time the RFM2Pi communicates following powering up.

The rc1.1 version has very minor changes and is "in testing" at the moment so you must of seen one of my posted logs, it offers very little and will probably get merged in time for the next SD image update, there are a couple of other tweaks that may make it into rc1.1 before then. The current version is still rc1.0 and as far as I'm aware (fingers crossed and touch wood etc etc) there haven't been any issues yet ( why do I feel like I'm gonna regret saying that ?)

The Pi's time is not sourced from your router, the Pi will check online with NTP servers to ascertain UTC, If you want GMT/BST you will need to set the timezone locally on the Pi (personally I leave my emonHub Pi as UTC for simple consistency) .

Every hour from boot the Pi's current time gets backed up by fake-hwclock and the fake-time you saw, presumably at 09:16:45 BST would of updated 16 seconds later from 07:17:01 UTC to 08:17:01 UTC so the time on the Pi looks correct at that time.

Paul

Super.

So it's just the date setting thing that I should tie up. Goodie. 

Re the datacodes, maybe you should add a note (for the thickies among us) about setting them in your online guide. Re-reading it I realised that I never set up the Arduino environment / firmware on the EmonTX. I just used it as is out-the-box. That's probably where I tripped over when following the instructions. I changed the datacodes that were set for something I hadn't implemented: 

"The emontx firmware that we installed above has a non standard packet structure, it uses the long datatype in addition to integers. We therefore need to tell emonhub to decode the data received from the emontx accordingly. This is done in the nodes section:"

Anyhoo, thanks again for the great support. And may I also add that emoncms is deeply awesome. :) 

Seb

hiya,

I ran your easy to install script here:

git clone https://github.com/emonhub/ntp-backup.git && ~/ntp-backup/install

but I'm getting a no such file or directory error :(

Cloning into 'ntp-backup'...
remote: Counting objects: 58, done.
remote: Compressing objects: 100% (56/56), done.
remote: Total 58 (delta 28), reused 5 (delta 1)
Unpacking objects: 100% (58/58), done.
-bash: /home/pi/ntp-backup/install: No such file or directory

I tried creating one (mkdir) and pulled git repo again. But I still got no joy (fatal: destination path 'ntp-backup' already exists and is not an empty directory).

As you predicted the date issue has come back to bite me. I've set up my GLCD and it's not picking up the correct time.

Setting emonhub.conf back to 'debug' I get the usual 27sec lapse before the correct time kicks in: 

1970-01-01 00:00:23,572 INFO EmonHub Pre-Release Development Version (rc1.0)
1970-01-01 00:00:23,574 INFO Opening hub...
1970-01-01 00:00:26,628 WARNING 1 Discarded RX frame 'non-numerical content' : ['>\x00', '4b']
1970-01-01 00:00:27,035 WARNING 3 Discard RX frame 'information' : ['>', '210g']
1970-01-01 00:00:27,668 WARNING 6 Discard RX frame 'information' : ['>', '15i']
2014-10-17 07:46:39,648 INFO Logging level set to DEBUG
2014-10-17 07:46:41,074 DEBUG 121 NEW FRAME : 1413532001.07  20 83 9
.... [etc]

Hi Seb,

Did you run it from the home directory? 

Paul

I think so:

pi@raspberrypi /home $...

Should I have been in a different home? :)

Seb

Aha! Yes, no, well sort of !

I apologize for using general terms when the home directory is referred to, it meant the home directory of the user rather than the directory called home, so for the user pi it would be /home/pi. Its the place that the prompt starts at when first booted and where it ends up if you just type "cd" and enter. Perhaps I should of said the users home directory.

I have now changed it to be less dependent on location so you should be able to run 

git clone https://github.com/emonhub/ntp-backup.git ~/ntp-backup && ~/ntp-backup/install

from anywhere or if you prefer you can still go to the users home dir and run the original command

cd

git clone https://github.com/emonhub/ntp-backup.git && ~/ntp-backup/install

Paul

I'm kicking myself too, because I didn't heed my suspicion that there may have been 'another' home. Doh! 

Holy moly, it's worked. Lovely. Big thanks!

I'm glad you brought it up, hopefully the changes will make it easier to use.

btw, anyone running Paul's ntp script can also change their time zone (UTC+ whatever) by navigating to:
/usr/share/zoneinfo/
Then find your continent or country and/or the country or city therein and then run the command:
sudo ln -sf /usr/share/zoneinfo/<country or zone>/<city> /etc/localtime
Eg, if you're in Paris:
sudo ln -sf /usr/share/zoneinfo/Europe/Paris /etc/localtime
Happily synced now.
Seb

Good to hear you are all sorted, Seb.

You can also use the "raspi-config" menu system to select your time zone etc. Although it doesn't work at boot up because you are in read-only mode by default. You can start it from the command line after changing to write mode using

rpi-rw

sudo raspi-config

The only function that won't work is expanding the file system as the 3rd "data" partition confuses the process. see http://openenergymonitor.org/emon/node/5740 for a workaround if you need to expand the partition sizes.

Paul