Emoncms missing data

[borpin (Brian Orpin)]

I suddenly noticed Emoncms was reporting usage that was impossible. It prompted me to check and it seems that my local server keeps missing data. It happens for all the data sent in a single HTTP put via Emonhub. This is one of the data views with the missing data

If I look at Emoncms log, it shows the data is received (good data shown either side) 12:55:29 but it appears is never logged. In some cases an mqtt data packet is received which I did wonder about, but in this instance it is ‘clean’ (i.e. nothing else happening between the emonhub data sets).

2017-06-28 12:55:17.775|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2017-06-28 12:55:17.777|INFO|PHPFina.php|post() id=1 timestamp=1498654517 value=473 padding=
2017-06-28 12:55:17.787|INFO|process_processlist.php|power_to_kwh() feedid=36 last_kwh=1072.74 kwh_inc=0.0015766666666667 new_kwh=1072.7415766667 last_time=1498654505 time_now=1498654517
2017-06-28 12:55:17.789|INFO|feed_model.php|insert_data() feedid=36 updatetime=1498654517 feedtime=1498654517 value=1072.7415766667 arg=join
2017-06-28 12:55:17.790|INFO|PHPFina.php|post() id=36 timestamp=1498654517 value=1072.7415766667 padding=join
2017-06-28 12:55:17.796|INFO|feed_model.php|insert_data() feedid=6 updatetime=1498654517 feedtime=1498654517 value=70 arg=
2017-06-28 12:55:17.800|INFO|PHPFina.php|post() id=6 timestamp=1498654517 value=70 padding=
2017-06-28 12:55:17.819|INFO|feed_model.php|insert_data() feedid=5 updatetime=1498654517 feedtime=1498654517 value=59.8 arg=
2017-06-28 12:55:17.824|INFO|PHPFina.php|post() id=5 timestamp=1498654517 value=59.8 padding=
2017-06-28 12:55:17.844|INFO|feed_model.php|insert_data() feedid=8 updatetime=1498654517 feedtime=1498654517 value=47.3 arg=
2017-06-28 12:55:17.848|INFO|PHPFina.php|post() id=8 timestamp=1498654517 value=47.3 padding=
2017-06-28 12:55:17.867|INFO|feed_model.php|insert_data() feedid=7 updatetime=1498654517 feedtime=1498654517 value=62.2 arg=
2017-06-28 12:55:17.871|INFO|PHPFina.php|post() id=7 timestamp=1498654517 value=62.2 padding=
2017-06-28 12:55:17.890|INFO|feed_model.php|insert_data() feedid=9 updatetime=1498654517 feedtime=1498654517 value=37.7 arg=
2017-06-28 12:55:17.895|INFO|PHPFina.php|post() id=9 timestamp=1498654517 value=37.7 padding=
2017-06-28 12:55:17.915|INFO|feed_model.php|insert_data() feedid=10 updatetime=1498654517 feedtime=1498654517 value=37.7 arg=
2017-06-28 12:55:17.919|INFO|PHPFina.php|post() id=10 timestamp=1498654517 value=37.7 padding=
2017-06-28 12:55:29.389|INFO|feed_model.php|insert_data() feedid=1 updatetime=1498654529 feedtime=1498654529 value=468 arg=
2017-06-28 12:55:29.394|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2017-06-28 12:55:29.395|INFO|PHPFina.php|post() id=1 timestamp=1498654529 value=468 padding=
2017-06-28 12:55:29.406|INFO|process_processlist.php|power_to_kwh() feedid=36 last_kwh=1072.74 kwh_inc=0.00156 new_kwh=1072.74156 last_time=1498654517 time_now=1498654529
2017-06-28 12:55:29.407|INFO|feed_model.php|insert_data() feedid=36 updatetime=1498654529 feedtime=1498654529 value=1072.74156 arg=join
2017-06-28 12:55:29.409|INFO|PHPFina.php|post() id=36 timestamp=1498654529 value=1072.74156 padding=join
2017-06-28 12:55:29.414|INFO|feed_model.php|insert_data() feedid=6 updatetime=1498654529 feedtime=1498654529 value=70 arg=
2017-06-28 12:55:29.419|INFO|PHPFina.php|post() id=6 timestamp=1498654529 value=70 padding=
2017-06-28 12:55:29.438|INFO|feed_model.php|insert_data() feedid=5 updatetime=1498654529 feedtime=1498654529 value=59.8 arg=
2017-06-28 12:55:29.442|INFO|PHPFina.php|post() id=5 timestamp=1498654529 value=59.8 padding=
2017-06-28 12:55:29.460|INFO|feed_model.php|insert_data() feedid=8 updatetime=1498654529 feedtime=1498654529 value=47.3 arg=
2017-06-28 12:55:29.466|INFO|PHPFina.php|post() id=8 timestamp=1498654529 value=47.3 padding=
2017-06-28 12:55:29.489|INFO|feed_model.php|insert_data() feedid=7 updatetime=1498654529 feedtime=1498654529 value=62.2 arg=
2017-06-28 12:55:29.493|INFO|PHPFina.php|post() id=7 timestamp=1498654529 value=62.2 padding=
2017-06-28 12:55:29.510|INFO|feed_model.php|insert_data() feedid=9 updatetime=1498654529 feedtime=1498654529 value=37.7 arg=
2017-06-28 12:55:29.517|INFO|PHPFina.php|post() id=9 timestamp=1498654529 value=37.7 padding=
2017-06-28 12:55:29.536|INFO|feed_model.php|insert_data() feedid=10 updatetime=1498654529 feedtime=1498654529 value=37.7 arg=
2017-06-28 12:55:29.542|INFO|PHPFina.php|post() id=10 timestamp=1498654529 value=37.7 padding=
2017-06-28 12:55:40.703|INFO|feed_model.php|insert_data() feedid=1 updatetime=1498654540 feedtime=1498654540 value=474 arg=
2017-06-28 12:55:40.709|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2017-06-28 12:55:40.710|INFO|PHPFina.php|post() id=1 timestamp=1498654540 value=474 padding=
2017-06-28 12:55:40.720|INFO|process_processlist.php|power_to_kwh() feedid=36 last_kwh=1072.74 kwh_inc=0.0014483333333333 new_kwh=1072.7414483333 last_time=1498654529 time_now=1498654540
2017-06-28 12:55:40.721|INFO|feed_model.php|insert_data() feedid=36 updatetime=1498654540 feedtime=1498654540 value=1072.7414483333 arg=join
2017-06-28 12:55:40.723|INFO|PHPFina.php|post() id=36 timestamp=1498654540 value=1072.7414483333 padding=join
2017-06-28 12:55:40.729|INFO|feed_model.php|insert_data() feedid=6 updatetime=1498654540 feedtime=1498654540 value=70 arg=
2017-06-28 12:55:40.733|INFO|PHPFina.php|post() id=6 timestamp=1498654540 value=70 padding=
2017-06-28 12:55:40.753|INFO|feed_model.php|insert_data() feedid=5 updatetime=1498654540 feedtime=1498654540 value=59.8 arg=
2017-06-28 12:55:40.757|INFO|PHPFina.php|post() id=5 timestamp=1498654540 value=59.8 padding=
2017-06-28 12:55:40.778|INFO|feed_model.php|insert_data() feedid=8 updatetime=1498654540 feedtime=1498654540 value=47.3 arg=
2017-06-28 12:55:40.782|INFO|PHPFina.php|post() id=8 timestamp=1498654540 value=47.3 padding=
2017-06-28 12:55:40.800|INFO|feed_model.php|insert_data() feedid=7 updatetime=1498654540 feedtime=1498654540 value=62.2 arg=
2017-06-28 12:55:40.806|INFO|PHPFina.php|post() id=7 timestamp=1498654540 value=62.2 padding=
2017-06-28 12:55:40.826|INFO|feed_model.php|insert_data() feedid=9 updatetime=1498654540 feedtime=1498654540 value=37.7 arg=
2017-06-28 12:55:40.830|INFO|PHPFina.php|post() id=9 timestamp=1498654540 value=37.7 padding=
2017-06-28 12:55:40.850|INFO|feed_model.php|insert_data() feedid=10 updatetime=1498654540 feedtime=1498654540 value=37.7 arg=
2017-06-28 12:55:40.854|INFO|PHPFina.php|post() id=10 timestamp=1498654540 value=37.7 padding=
2017-06-28 12:55:52.318|INFO|feed_model.php|insert_data() feedid=1 updatetime=1498654552 feedtime=1498654552 value=471 arg=
2017-06-28 12:55:52.323|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2017-06-28 12:55:52.324|INFO|PHPFina.php|post() id=1 timestamp=1498654552 value=471 padding=
2017-06-28 12:55:52.335|INFO|process_processlist.php|power_to_kwh() feedid=36 last_kwh=1072.74 kwh_inc=0.00157 new_kwh=1072.74157 last_time=1498654540 time_now=1498654552
2017-06-28 12:55:52.336|INFO|feed_model.php|insert_data() feedid=36 updatetime=1498654552 feedtime=1498654552 value=1072.74157 arg=join
2017-06-28 12:55:52.338|INFO|PHPFina.php|post() id=36 timestamp=1498654552 value=1072.74157 padding=join
2017-06-28 12:55:52.343|INFO|feed_model.php|insert_data() feedid=6 updatetime=1498654552 feedtime=1498654552 value=70 arg=
2017-06-28 12:55:52.347|INFO|PHPFina.php|post() id=6 timestamp=1498654552 value=70 padding=
2017-06-28 12:55:52.367|INFO|feed_model.php|insert_data() feedid=5 updatetime=1498654552 feedtime=1498654552 value=59.8 arg=
2017-06-28 12:55:52.371|INFO|PHPFina.php|post() id=5 timestamp=1498654552 value=59.8 padding=
2017-06-28 12:55:52.390|INFO|feed_model.php|insert_data() feedid=8 updatetime=1498654552 feedtime=1498654552 value=47.3 arg=
2017-06-28 12:55:52.394|INFO|PHPFina.php|post() id=8 timestamp=1498654552 value=47.3 padding=
2017-06-28 12:55:52.414|INFO|feed_model.php|insert_data() feedid=7 updatetime=1498654552 feedtime=1498654552 value=62.2 arg=
2017-06-28 12:55:52.418|INFO|PHPFina.php|post() id=7 timestamp=1498654552 value=62.2 padding=
2017-06-28 12:55:52.439|INFO|feed_model.php|insert_data() feedid=9 updatetime=1498654552 feedtime=1498654552 value=37.7 arg=
2017-06-28 12:55:52.443|INFO|PHPFina.php|post() id=9 timestamp=1498654552 value=37.7 padding=
2017-06-28 12:55:52.462|INFO|feed_model.php|insert_data() feedid=10 updatetime=1498654552 feedtime=1498654552 value=37.7 arg=
2017-06-28 12:55:52.466|INFO|PHPFina.php|post() id=10 timestamp=1498654552 value=37.7 padding=

Any ideas? Running V9.8.6 with Redis enabled.

[borpin (Brian Orpin)]

@TrystanLea @glyn.hudson - any help?

[pb66 (Paul)]

Can you show us the emonhub log for the same period?

What fixed interval is the phpfina?

Where is the data coming from and at what interval are the timestamps?

I do not know my way around the emoncms logs so well but it looks to me as if the data is on an interval greater than 10s, so IF you are logging to a 10s phpfina, you will get some missing data points when the 10-12s interval spans a complete 10s fixed interval, then as the 2 cycles get out of sync slightly each datapoint will be present until they next align and miss a couple again. Is the missing data happening at a regular interval and foe a similar span of time?

[Sam]

Sound like the same issue I have been having as described in this post:

Missing Data - 66% Quality

Hi Guys, I have an emonTx posting data via emonBase to my web server but have a large number of missing data points as shown in the graph below. The quality ratio is at 66% with the data feeds set at 10 seconds, is this behavior normal? [image] The emonBase is connected via wifi but ethernet connection gives the same results. The quality figure is exactly the same on the emonBase when read locally. Any ideas what could be causing the missing data? As a note, I can not seem to create a nega…

I have the phpfina interval set to 10s but still the issue persists.