Feeds not updating - PHPFina:post timestamp out of range

Hi there,

since few days I get no remote (emonth and emontx) feeds updates. All script updates by API are fine (I run scripts from few rpi to push some informations in my emoncms server)

If I look at the logs I see :

- from my pi emonhub :

2016-02-20 22:39:25,321 INFO Sending: http://192.168.1.2/emoncms/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[31.75,8,2824,0,0,0,25714,173,3000,3000,3000,3000,3000,1,0],[1456003382.79,8,1386,0,0,0,25829,173,3000,3000,3000,3000,3000,1,0],[1456003392.62,8,575,0,0,0,25883,173,3000,3000,3000,3000,3000,1,0],[1456003402.47,8,1381,0,0,0,25822,173,3000,3000,3000,3000,3000,1,0],[1456003412.51,8,2839,0,0,0,25673,173,3000,3000,3000,3000,3000,1,0],[1456003416.0,19,200,0,401,31],[1456003422.36,8,3571,0,0,0,25544,173,3000,3000,3000,3000,3000,1,0],[1456003432.2,8,2812,0,0,0,25605,173,3000,3000,3000,3000,3000,1,0],[1456003442.2,8,573,0,0,0,25736,173,3000,3000,3000,3000,3000,1,0],[1456003452.06,8,1355,0,0,0,25654,173,3000,3000,3000,3000,3000,1,0],[1456003461.87,8,568,0,0,0,25758,173,3000,3000,3000,3000,3000,1,0],[1456003471.87,8,3582,0,0,0,25480,173,3000,3000,3000,3000,3000,1,0],[1456003477.99,19,200,0,401,30],[1456003481.7,8,2785,0,0,0,25533,173,3000,3000,3000,3000,3000,1,0],[1456003491.72,8,3552,0,0,0,25468,173,3000,3000,3000,3000,3000,1,0],[1456003501.53,8,562,0,0,0,25695,173,3000,3000,3000,3000,3000,1,0],[1456003511.54,8,583,0,0,0,25695,173,3000,3000,3000,3000,3000,1,0],[1456003521.34,8,1362,0,0,0,25651,173,3000,3000,3000,3000,3000,1,0],[1456003531.36,8,571,0,0,0,25688,173,3000,3000,3000,3000,3000,1,0],[1456003540.13,19,200,0,402,30],[1456003541.18,8,3569,0,0,0,25516,173,3000,3000,3000,3000,3000,1,0],[1456003550.99,8,2808,0,0,0,25580,173,3000,3000,3000,3000,3000,1,0],[1456003561.0,8,2020,0,0,0,25659,173,3000,3000,3000,3000,3000,1,0],[1456003570.8,8,564,0,0,0,25749,173,3000,3000,3000,3000,3000,1,0],[1456003580.84,8,586,0,0,0,25798,173,3000,3000,3000,3000,3000,1,0],[1456003590.65,8,1373,0,0,0,25726,173,3000,3000,3000,3000,3000,1,0],[1456003600.65,8,2804,0,0,0,25536,173,3000,3000,3000,3000,3000,1,0],[1456003602.3,19,200,0,402,30],[1456003610.48,8,3578,0,0,0,25474,173,3000,3000,3000,3000,3000,1,0],[1456003620.3,8,2809,0,0,0,25563,173,3000,3000,3000,3000,3000,1,0],[1456003630.28,8,1393,0,0,0,25687,173,3000,3000,3000,3000,3000,1,0],[1456003640.26,8,628,0,0,0,25745,173,3000,3000,3000,3000,3000,1,0],[1456003650.05,8,706,0,0,0,25742,173,3000,3000,3000,3000,3000,1,0],[1456003660.04,8,3599,0,0,0,25512,173,3000,3000,3000,3000,3000,1,0],[1456003664.32,19,199,0,402,30],[1456003669.83,8,2842,0,0,0,25591,173,3000,3000,3000,3000,3000,1,0],[1456003679.82,8,3593,0,0,0,25508,173,3000,3000,3000,3000,3000,1,0],[1456003689.62,8,611,0,0,0,25767,173,3000,3000,3000,3000,3000,1,0],[1456003699.59,8,1410,0,0,0,25746,173,3000,3000,3000,3000,3000,1,0],[1456003709.61,8,614,0,0,0,25780,173,3000,3000,3000,3000,3000,1,0],[1456003719.42,8,2839,0,0,0,25595,173,3000,3000,3000,3000,3000,1,0],[1456003726.38,19,200,0,402,30],[1456003729.25,8,3602,0,0,0,25515,173,3000,3000,3000,3000,3000,1,0],[1456003739.26,8,2885,0,0,0,25575,173,3000,3000,3000,3000,3000,1,0],[1456003749.1,8,1429,0,0,0,25725,173,3000,3000,3000,3000,3000,1,0],[1456003759.14,8,616,0,0,0,25791,173,3000,3000,3000,3000,3000,1,0],[1456003768.96,8,1421,0,0,0,25759,173,3000,3000,3000,3000,3000,1,0],[1456003778.79,8,2838,0,0,0,25645,173,3000,3000,3000,3000,3000,1,0],[1456003788.36,19,199,0,402,30],[1456003788.81,8,2927,0,0,0,25627,173,3000,3000,3000,3000,3000,1,0],[1456003798.59,8,3623,0,0,0,25574,173,3000,3000,3000,3000,3000,1,0],[1456003808.47,8,625,0,0,0,25845,173,3000,3000,3000,3000,3000,1,0],[1456003818.48,8,1434,0,0,0,25813,173,3000,3000,3000,3000,3000,1,0],[1456003828.3,8,660,0,0,0,25862,173,3000,3000,3000,3000,3000,1,0],[1456003838.33,8,3644,0,0,0,25579,173,3000,3000,3000,3000,3000,1,0],[1456003848.16,8,2879,0,0,0,25670,173,3000,3000,3000,3000,3000,1,0],[1456003850.42,19,199,0,403,30],[1456003858.19,8,2866,0,0,0,25657,173,3000,3000,3000,3000,3000,1,0],[1456003868.01,8,1426,0,0,0,25836,173,3000,3000,3000,3000,3000,1,0],[1456003877.83,8,643,0,0,0,25842,173,3000,3000,3000,3000,3000,1,0],[1456003887.85,8,1421,0,0,0,25822,173,3000,3000,3000,3000,3000,1,0],[1456003897.66,8,2869,0,0,0,25670,173,3000,3000,3000,3000,3000,1,0],[1456003907.67,8,3665,0,0,0,25616,173,3000,3000,3000,3000,3000,1,0],[1456003912.57,19,199,0,402,30],[1456003917.48,8,2868,0,0,0,25677,173,3000,3000,3000,3000,3000,1,0],[1456003927.33,8,1424,0,0,0,25793,173,3000,3000,3000,3000,3000,1,0],[1456003937.37,8,633,0,0,0,25845,173,3000,3000,3000,3000,3000,1,0],[1456003947.16,8,640,0,0,0,25851,173,3000,3000,3000,3000,3000,1,0],[1456003957.17,8,3647,0,0,0,25592,173,3000,3000,3000,3000,3000,1,0],[1456003966.98,8,2860,0,0,0,25643,173,3000,3000,3000,3000,3000,1,0],[1456003974.75,19,199,0,403,30],[1456003977.05,8,3628,0,0,0,25551,173,3000,3000,3000,3000,3000,1,0],[1456003986.91,8,624,0,0,0,25808,173,3000,3000,3000,3000,3000,1,0],[1456003996.74,8,1421,0,0,0,25798,173,3000,3000,3000,3000,3000,1,0],[1456004006.55,8,625,0,0,0,25827,173,3000,3000,3000,3000,3000,1,0],[1456004016.59,8,2879,0,0,0,25636,173,3000,3000,3000,3000,3000,1,0],[1456004026.41,8,3647,0,0,0,25576,173,3000,3000,3000,3000,3000,1,0],[1456004036.43,8,2867,0,0,0,25642,173,3000,3000,3000,3000,3000,1,0],[1456004036.66,19,199,0,403,30],[1456004046.28,8,1426,0,0,0,25754,173,3000,3000,3000,3000,3000,1,0],[1456004056.1,8,639,0,0,0,25809,173,3000,3000,3000,3000,3000,1,0],[1456004066.14,8,1420,0,0,0,25759,173,3000,3000,3000,3000,3000,1,0],[1456004075.99,8,2851,0,0,0,25574,173,3000,3000,3000,3000,3000,1,0],[1456004085.83,8,2846,0,0,0,25571,173,3000,3000,3000,3000,3000,1,0],[1456004095.84,8,3630,0,0,0,25530,173,3000,3000,3000,3000,3000,1,0],[1456004098.91,19,198,0,403,30],[1456004105.69,8,647,0,0,0,25798,173,3000,3000,3000,3000,3000,1,0],[1456004115.5,8,1430,0,0,0,25754,173,3000,3000,3000,3000,3000,1,0],[1456004125.55,8,631,0,0,0,25763,173,3000,3000,3000,3000,3000,1,0],[1456004135.34,8,3641,0,0,0,25521,173,3000,3000,3000,3000,3000,1,0],[1456004145.37,8,2843,0,0,0,25562,173,3000,3000,3000,3000,3000,1,0],[1456004155.2,8,2842,0,0,0,25571,173,3000,3000,3000,3000,3000,1,0],[1456004160.92,19,198,0,402,30],[1456004165.05,8,1420,0,0,0,25705,173,3000,3000,3000,3000,3000,1,0],[1456004175.09,8,631,0,0,0,25740,173,3000,3000,3000,3000,3000,1,0],[1456004184.91,8,1419,0,0,0,25716,173,3000,3000,3000,3000,3000,1,0],[1456004194.73,8,2822,0,0,0,25528,173,3000,3000,3000,3000,3000,1,0],[1456004204.79,8,3607,0,0,0,25444,173,3000,3000,3000,3000,3000,1,0],[1456004214.62,8,2849,0,0,0,25572,173,3000,3000,3000,3000,3000,1,0],[1456004223.02,19,198,0,403,30]]&sentat=1456004365
2016-02-20 22:39:25,371 WARNING Send failure: wanted 'ok' but got <br />
<b>Fatal error</b>:  Call to a member function setTimezone() on boolean in <b>/var/www/localhost/htdocs/emoncms/Modules/input/process_model.php</b> on line <b>669</b><br />
 

- from my emoncms server :

WARN - 2016-2-20 22:31:13, PHPFina:post timestamp out of range
INFO - input() received time=31, value=2824
INFO - PHPFiwa:post id=27 timestamp=31 value=2824
WARN - 2016-2-20 22:31:13, PHPFiwa:post timestamp out of range
INFO - PHPFina:post post id=32 timestamp=31 value=0
WARN - 2016-2-20 22:31:13, PHPFina:post timestamp out of range
 

Looks like something is wrong with timestamp, as is stay at 31 (and is far from the actual timestamp).

Any ideas ?

Thanks a lot

KR,

Anthony

pb66's picture

Re: Feeds not updating - PHPFina:post timestamp out of range

Any clues as to what system you are running? emonhub and emoncms versions, image or self-built? Is the OS read-only? 

The data above is 14mins worth and starts with an unrealistic timestamp so was this following a reboot? or was the previously buffered data posted correctly?

If this is following a reboot on a "read-only" OS and there are/were any lines in the log dated 1970 then you need to install "ntp-backup" any other scenarios will require significantly more info about your system, logs and some context, was it working ok previously? Did you change anything? Have you updated? Have you tried rebooting?

Paul

dthp's picture

Re: Feeds not updating - PHPFina:post timestamp out of range

Hi Paul, thanks for your answer.

Regarding versions :

Emonhub image with Linux EmonCMS 3.12.22+ #691 PREEMPT

EmonCMS  8.5.0 hosted on a self-made gentoo LAMP server, php 5.6

I looked at the logs gain, the out of range timestamps as gone, so I guess the buffered data just passed.

ntp is on, both systems are on time

Regarding context, I updated php from 5.5 to 5.6 since 3 weeks, but the issue has started 1 week ago.

I rebooted both systems without luck.

I self host every services I can (owncloud, roundcube & mail server, IM server) and I have no issue at all except with emoncms.

If I can describe my monitoring system :

I have a rpi with emonhub that sends data from an emonth and emonth (monitoring temperatures and power from the grid) to my server.

I have a second rpi plugged to a Morningstar TriStar MPPT 60 solar charger that pushes data to the server via emonCMS API, monitoring solar in and out, and solar hot water.

I have a third one plugged to a deltasol BS2+ heating controller to monitor my wood boiling system for hot water (hot domestic water & ground heating system).

Both Tristar MPPT and deltasol BS2+ are pushing data correctly without any errors.

I can provide you any needed information.

Anthony

pb66's picture

Re: Feeds not updating - PHPFina:post timestamp out of range

Hi Anthony

That quite and elaborate set-up, the bits of particular interest to this issue are the 

"Emonhub image with Linux EmonCMS 3.12.22+ #691 PREEMPT"

and 

"I have a rpi with emonhub that sends data from an emonth and emonth (monitoring temperatures and power from the grid) to my server."

Is this Pi using a read-only OS ? can you identify the image by name or a link? the fact you call it an "emonhub image" suggests a pre-built image and as far as I recall all images containing emonhub have been read-only OS's. 

Your original log shows the first timestamp as "31.75" as in 31.75 seconds since 1970-1-1 00:00, there was an issue on several OEM images of that (emonhub + v8.5) era that prevented NTP from accessing the previously saved time at boot up and/or updating that saved time for the next boot, this means that for a moment at boot up the Pi thought it was 1970-1-1 00:00 and the clock worked from that time until it was overridden by an NTP update which was dependent on a network connection. So if 31.75 seconds after booting the Pi but fractionally before a NTPupdate was performed, a data packet was received from the rfm2pi it would be "correctly?" timestamped as 31.75 as that was the time as far as the Pi was concerned, subsequent timestamps look correct so the NTP update seems to have occurred.

Without additional logs this is difficult to prove but it is my best guess based on the data supplied.

Search this site for "ntp-backup" for more info, it is a helper script for NTP on a Read-only OS, written specifically for this problem and is used on the current OEM images.

Paul

dthp's picture

Re: Feeds not updating - PHPFina:post timestamp out of range

Hi Paul, thanks for the ntp tip - you were right: the logs told me that emonhub was sending 1970's timestamps at boot. This is now corrected, the out of range timestamp is sorted (the pi is using a read only pre-built image).

I can  confirm that the issue with emonhub not pushing emontx and emonth data is definitely with this error :

2016-02-21 15:46:55,180 WARNING Send failure: wanted 'ok' but got <br />
<b>Fatal error</b>:  Call to a member function setTimezone() on boolean in <b>/var/www/localhost/htdocs/emoncms/Modules/input/process_model.php</b> on line <b>669</b><br />

Looks like I messed with php, but to me I made nothing significant (there is no configuration modification when moving from php5.5 to php5.6 on gentoo).

If I reverse to php5.5, I get the same errors.

pb66's picture

Re: Feeds not updating - PHPFina:post timestamp out of range

Sorry server stuff isn't my strong point so I cannot offer any advice there on php or the specifics of the emoncms error. I had assumed the error was a result of the wrong timestamp, as every packet in the batch must comply with emoncms requirements for the total batch to be accepted (or rejected) .

Are you still seeing this error, even with all good timestamps for all packets?

Have you checked the user timezone setting again in emoncms? at some point in v8 to 8.6 the timezone stucture was changed and forced the user to reselect his timezone and perform a database update from the admin screen.

Paul

dthp's picture

Re: Feeds not updating - PHPFina:post timestamp out of range

I finally fully recompiled and installed php5.5, everything is now fine.

I have to figure what is different between php5.5 and 5.6, I'll post here when I'll find, some people may be interested.

Thanks a lot again

Anthony

Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.