Error messages in Pachube log

17 replies [Last post]
EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011

Hi all

I'm having a bit of a hard time nailing a lua/scripting/pachube error.....

I have several scripts running that receive inputs from an EnviR, do some maths on the values then post those values to Pachube on several different feeds.....my problem is that one (or more) of the scripts occasionally causes Pachube to error out - and its a fatal error as it takes a manual reboot from me to get the Pachube module to re-start sending data, even though it still has a heart beat in xFx viewer!

I've tried going back to basics and just having one script working, then adding in another and another till it fails - but it fails randomly......

The xap-pachube error log shows:-

[err][pachulib.c:196:read_data] errno 22 (Invalid argument)
[err][pachulib.c:196:read_data] Err!! desconexion en recv

multiple times.....

Is there somewhere I can get xap-pachube error log to show more detail - like which script caused the posting error?

ALSO - as an asside, is there a beep() command in lua I can use to alert me as to when an error or a specific event has occured?

hope you can help....

EJ

brett
Offline
Providence, United States
Joined: 9 Jan 2010
The error above means that

The error above means that you sent something to pachube and the code is now waiting to get a response from the pachube webserver.  The response never happens so an error is reported, which is reasonable.  It should however not crash after doing this.  Are you sure at this point you HAH still has internet connectivity to pachube?   You might want to verify that one you get a "lock up".  Something as simple as this.

# wget http://www.pachube.com/

I should upgrade the error messages from spanish to english too I guess.   I borrowed this library.

If you are still seeing a heartbeat then the process is still running.  If however its no longer sending/receiving data then that is more a connectivity issue to the pachube webserver.  Is your ISP doing something nasty?

Brett

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Thanks for that...

So I tried the wget and I got....

Connecting to www.pachube.com (216.52.233.122:80)
wget: not an http or ftp url: https://pachube.com/

However linking to Pachube from Firefox / Chrome / IE all OK

Here's the snippet I'm using to post to Pachube.....

function CumulativeDataPost0()
    CumulativeData = string.format([[xap-header
{
class=pachube.update
target=dbzoo.livebox.pachube
}
datastream
{
id=13
tag=BoilerUSE
Value=%s
}]], CurrentKwH)

xap.sendShort(CumulativeData)
end

....in 99.9% of cases it works fine......!!

 

regards

EJ

brett
Offline
Providence, United States
Joined: 9 Jan 2010
I found some buffer

I found some buffer corruption, overflows and an invalid flag in the pachube library.  This is what you get for using somebody elses code.  :(  Try upgrading to the beta and let me know if this resolves your problems.  Those errors should disappear now.

I also improved the logging.

# xap-pachube -i br0 -d 6

Should let you see what is going on.

Brett

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Super service.....

Have downloaded BETA 305.1 and have it running - will let you know how it performs in the daylight (which is when it normally goes t-u)....

Thanks for your help - its always appreciated....

EJ

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Still testing

Hi Brett

I haven't been able to do a full test today as the sun she not shine!!!  However, preliminary results look good - I've had no strange fall overs and the lua scripts are all running well....I have found this in the pachube error log....


Pachube Connector for xAP v12
Copyright (C) DBzoo 2009-2010

[err][pachulib.c:195:read_data] errno 22 (Invalid argument)
[err][pachulib.c:195:read_data] No data from pachube
[err][pachulib.c:195:read_data] errno 22 (Invalid argument)
[err][pachulib.c:195:read_data] No data from pachube
[err][pachulib.c:185:read_data] errno 131 (Connection reset by peer)
[err][pachulib.c:185:read_data] Receiving data from pachube
[err][pachulib.c:185:read_data] errno 131 (Connection reset by peer)
[err][pachulib.c:185:read_data] Receiving data from pachube
[err][pachulib.c:185:read_data] errno 131 (Connection reset by peer)
[err][pachulib.c:185:read_data] Receiving data from pachube
[err][pachulib.c:195:read_data] errno 22 (Invalid argument)
[err][pachulib.c:195:read_data] N

This is exactly as is in the file - but Pachube heartbeat and posting is functioing OK...

I'll keep you posted....

Thanks again

EJ

brett
Offline
Providence, United States
Joined: 9 Jan 2010
Those errors are to be

Those errors are to be expected if there are issues on the server side.  It just the client "xap-pachube" complaining that there are webserver issues posting and retrieving data.   What is happening now thou is that its recovering as it should.  Lets monitor how this goes over a longer period if it all looks well I'll push up a new build with this single fix in it as everybody will want/need this one.

Brett

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Ho-Humm!!

Hi Brett

Well the sun broke through the clouds at about 11:45, which kicked in the Boiler sensor - which promptly bombed Pachube!  I've been adding debug outputs to the code and I can't see anything untoward as to the values being posted....but I can repeat the error on demand so I know where to concentrate..... I used your debug line and output that to a file (attached) which captured one of these events, however you'll have to interpret the data!!!  The data in RunningW.txt shows the values I'm trying to post .... nothing out of the ordinary - but it does indicate when Pachube falls over (and there were errors in the first log pachube01 but nothing in the subsequent error log)

Background info:-

CCSettings                                         Pachube

ID1 Digital Bianry Temp                         dbzoo.livebox.CurrentCost:temp

ID2 Digital Watts Consumed                   dbzoo.livebox.CurrentCost:ch.2

ID3 Digital Watts Generated                   dbzoo.livebox.CurrentCost:ch.1

ID4 Digital Watts DeltaBoiler                   dbzoo.livebox.CurrentCost:ch.3

Anything else you need?

Happy hunting......EJ

AttachmentSize
PachubeLog.txt 33.61 KB
RunningW.txt 9.9 KB
xap-pachube 01.log_.txt 6.25 KB
xap-pachube.log_.txt 0 bytes
brett
Offline
Providence, United States
Joined: 9 Jan 2010
I see the problem its a

I see the problem its a buffer overrun issue as I suspected.   However the code I added in the beta should have prevent it from crashing, I'll see why it didn't too.

The buffer is only 1500 bytes so this has to be a candidate for concern and the crash.

[inf][pachulib.c:154:send_data] send 1505 bytes

The library I'm using can't handle pushing a large number of endpoint up in a single transaction which is how I'm using it.   I'll have to rework some bits so that a dynamic array is created to handle larger buffer sizes needed when multiple readings are all being pushed up together.  I could just increase the 1500 bytes to a larger number but that just delays the crash to some later point.  I'll fix this properly.

Thx that was a great help the extra debug I added proved its worth.

Brett

brett
Offline
Providence, United States
Joined: 9 Jan 2010
Lets try again with the next beta

Update to 305.2 I'm pretty sure I've nailed it this time given the information from the logs you provided me.

Brett

g7pkf
Offline
United Kingdom
Joined: 11 Jan 2011
how many

endpoints could have caused this crash?

brett
Offline
Providence, United States
Joined: 9 Jan 2010
Once you log over a 1500

Once you log over a 1500 bytes worth of Pachube ID's it overflows an internal buffer.  The more you log the more likely you are to hit this boundary.  EJ is feeding lots of stuff.  Also don't forget the labels and units types also take up more space in this precious buffer until BANG it overflows.

I used the word endpoint perhaps I should have used pachube datastream.   The more datastreams you have in a feed the more likely you are to hit this arbitary buffer limitation.

Each Feed is fed up to pachube as a group of datastreams and the XML representing their new data values all had to fit inside this tiny buffer, it was a bad design decision bythe author of this library that i've now corrected.

Brett

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Back now!!!

Hi Brett

Sorry about not being here when you posted the fix - I was elbows deep in a Beef and Guiness Pie and chips at the local hostelry.....but I'm back now and I've installed the Beta, so all I have to do is wait a couple of hours (sun is expected to poke through the mist by about 11:00) and see if it copes....

Is there any other way of manageing the amount of data I'm pushing up to the Pachube feeds - could I schedule the posting events?

Anyway looking forward to an error free day.....thanks for all your efforts....

Regards...EJ

brett
Offline
Providence, United States
Joined: 9 Jan 2010
EJ there was nothing you

EJ there was nothing you could have done to fix this bug, bar spliting your datastream out into individual feeds to workaround the issue.   It not something you should have been working arround anyway as its MY bug.  I think you should find its solid now.   We'll leave it run for a few more days.

Brett

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Looking good....

Hi Brett

3 hours of boiler on/off datastream posting and not a hicup - yeah!!!  Feeling very confident about this...but as you say....let it run for a couple more days to nail it!

I can start striping out all the debug code and tidy it up now.....

All the very best, from an extremely thankful end-user.....(smile from ear to ear)

EJ

Make that a full sunny days worth of smooth activity!!!!   No errors...... EJ

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Further observations

Hi Brett

Had a glitch last night just before midnight - traced it to an ISP problem but had to physically re-boot the HAH so I couldn't get at the error logs - I'm running fine again now, so I'll put that one down to "influences beyond our control".....as a result, I've been monitoring the error logs periodically and the Pachube log gets quite full then stops tracking - it seems to hit a size limit of about 7424 bytes!!  Is this normal?

Also, as a consequence of the hard re-set on the hub where I lost all the error logs - would it be possible to implement a "copy existing log to a backup location before initialising a new log on start-up", or a grandfather - father - son rotation dynamically assigned at start-up?

I know error logging is small potatoes, but I like having data to show what was happening when things went T-up.

Anyway - another 12 hours of solid Pachube posting, so I think we're in the clear - I noticed you've put up ver 306 with the changes....glad to be of help....

Regards, and thanks.....EJ

brett
Offline
Providence, United States
Joined: 9 Jan 2010
Regarding the accumulating

Regarding the accumulating errors when the ISP connection drops.  Yes this would build the error logs, I realized this before I checked in 306 which has these downgraded from error to warning so they don't log.  This solves the problem and as the system recoverys from them they aren't really errors.

The logs are not in persistent storage so if you need to examine what went wrong do so before a reboot.

I could copy them into /etc on a reboot, or rotate them, but things should not go wrong such that you need them !

EJ-Ambient
Offline
Ringwood, United Kingdom
Joined: 5 Aug 2011
Thanks for that...

Hi Brett

Been going solidly for 36+ hours without a glitch....posting shedloads of data!

I'd still hanker for a rotate failsafe if it's possible!!!

Also, a couple of pointers please - which flavour of Lua should I be using....can you point at the definitive site for reference....ta!

And - how do I put a date/time text item into a file from the Cron scheduler? Is it a unix command, if so ditto above....ta!

Thanks for all the great work.....EJ

Hardware Info