Something seriously wrong with something - graphs/data processing

Something is seriously amiss here;

This is 2 data feeds off the same input process!

The gaps on the blue line are a timing issue (10s feed sometimes longer than that with a ‘time’ data element).

However, there should be the same number of orange line data points!

If I export the feeds directly (not from the graphs) I get exactly the same.

image

@TrystanLea - how is this possible?

This is on a PVE host using 1% CPU so it’s not running out of gas to do the processing.

What’s in the actual data files?

Not checked.

That’d be something to look at then. What happens if you change the time period? Is the problem just for this period or does it occur in other periods?

(I’m seeing similar things but not the exact same issue I think)

I can’t reproduce the effect. I think it must be down totally to the Feed Interval.

I’ve used Message Count of my emonPiCM reporting every 4.9 s, with Feed Intervals of 10 s.
OK, MessageCount.hours has no physical meaning, but I think it’s the same maths. :wink:

Input processes:

Graph:

CSV Output:. The nulls at the start and end are where the graph doesn’t fill the window:

“Unix timestamp”, “emonpiCM_5:Msg”, “emonpiCM_5:Mh”
1700491400, 64613, null
1700491410, 64615, 0.1
1700491420, 64617, 0.3
1700491430, 64619, 0.4
1700491440, 64621, 0.6
1700491450, 64623, 0.8
1700491460, 64625, 1.0
1700491470, 64627, 1.1
1700491480, 64629, 1.4
1700491490, 64632, 1.6
1700491500, 64634, 1.7
1700491510, 64636, 1.9
1700491520, 64638, 2.1
1700491530, 64640, 2.3
1700491540, 64642, 2.4
1700491550, 64644, 2.6
1700491560, 64646, 2.8
1700491570, 64648, 3.0
1700491580, 64650, 3.1
1700491590, 64652, 3.3
1700491600, 64654, 3.5
1700491610, 64656, 3.6
1700491620, 64658, 3.8
1700491630, 64660, 4.1
1700491640, 64663, 4.3
1700491650, 64665, 4.4
1700491660, 64667, 4.6
1700491670, 64669, 4.8
1700491680, 64671, 5.0
1700491690, 64673, 5.1
1700491700, 64675, 5.3
1700491710, 64677, 5.5
1700491720, 64679, 5.7
1700491730, 64681, 5.8
1700491740, 64683, 6.0
1700491750, 64685, 6.2
1700491760, 64687, 6.4
1700491770, 64689, 6.5
1700491780, 64691, 6.7
1700491790, 64693, 6.9
1700491800, 64695, 7.1
1700491810, 64698, 7.3
1700491820, 64700, 7.5
1700491830, 64702, 7.7
1700491840, 64704, 7.8
1700491850, 64706, 8.0
1700491860, 64708, 8.2
1700491870, 64710, 8.4
1700491880, 64712, 8.5
1700491890, 64714, 8.7
1700491900, 64716, 8.9
1700491910, 64718, 9.1
1700491920, 64720, 9.2
1700491930, 64722, 9.4
1700491940, 64724, 9.6
1700491950, 64726, 9.8
1700491960, 64728, 9.9
1700491970, 64731, 10.2
1700491980, 64733, 10.4
1700491990, 64735, 10.5
1700492000, 64737, 10.7
1700492010, 64739, 10.9
1700492020, 64741, 11.1
1700492030, 64743, 11.2
1700492040, 64745, 11.4
1700492050, 64747, 11.6
1700492060, 64749, 11.8
1700492070, 64751, 11.9
1700492080, 64753, 12.1
1700492090, 64755, 12.3
1700492100, 64757, 12.5
1700492110, 64759, 12.6
1700492120, 64761, 12.8
1700492130, 64764, 13.1
1700492140, 64766, 13.2
1700492150, 64768, 13.4
1700492160, 64770, 13.6
1700492170, 64772, 13.8
1700492180, 64774, 13.9
1700492190, 64776, 14.1
1700492200, 64778, 14.3
1700492210, 64780, 14.5
1700492220, 64782, 14.6
1700492230, 64784, 14.8
1700492240, 64786, 15.0
1700492250, 64788, 15.2
1700492260, 64790, 15.2
1700492270, 64793, 15.5
1700492280, 64796, 15.8
1700492290, 64798, 15.9
1700492300, 64800, 16.1
1700492310, 64802, 16.3
1700492320, 64804, 16.5
1700492330, 64806, 16.6
1700492340, 64808, 16.8
1700492350, 64810, 17.0
1700492360, 64812, 17.2
1700492370, 64814, 17.3
1700492380, 64816, 17.5
1700492390, 64818, 17.7
1700492400, 64820, 17.9
1700492410, 64822, 18.0
1700492420, 64824, 18.2
1700492430, 64826, 18.4
1700492440, 64828, 18.6
1700492450, 64831, 18.8
1700492460, 64833, 19.0
1700492470, 64835, 19.2
1700492480, 64837, 19.3
1700492490, 64839, 19.5
1700492500, 64841, 19.7
1700492510, 64843, 19.9
1700492520, 64845, 20.0
1700492530, null, null
1700492540, null, null

So then I repeated it with Feed Intervals of 5 s - still exactly the same, no intervening NULLs.

“Unix timestamp”, “emonpiCM_5:Msg2”, “emonpiCM_5:Msg2h”
1700492935, 64930, 0.0
1700492940, 64931, 0.1
1700492945, 64932, 0.2
1700492950, 64933, 0.3
1700492955, 64934, 0.4
1700492960, 64935, 0.5
1700492965, 64936, 0.5
1700492970, 64937, 0.6
1700492975, 64938, 0.7
1700492980, 64939, 0.8
1700492985, 64940, 0.9
1700492990, 64941, 1.0
1700492995, 64942, 1.1
1700493000, 64943, 1.1
1700493005, 64944, 1.2
1700493010, 64945, 1.3
1700493015, 64946, 1.4
1700493020, 64947, 1.5
1700493025, 64948, 1.6
1700493030, 64949, 1.7
1700493035, 64950, 1.7
1700493040, 64951, 1.8
1700493045, 64952, 1.9
1700493050, 64953, 2.0
1700493055, 64954, 2.1
1700493060, 64955, 2.2
1700493065, 64956, 2.3
1700493070, 64957, 2.4
1700493075, 64958, 2.5
1700493080, 64959, 2.5
1700493085, 64960, 2.6
1700493090, 64961, 2.7
1700493095, 64962, 2.8
1700493100, 64964, 3.0
1700493105, 64965, 3.1
1700493110, 64966, 3.2
1700493115, 64967, 3.2
1700493120, 64968, 3.3
1700493125, 64969, 3.4
1700493130, 64970, 3.5
1700493135, 64971, 3.6
1700493140, 64972, 3.7
1700493145, null, null

Maybe it’s specific to the calculation Brian used?

No. Msg & Msg × 0.001 still show no NULLs

“Unix timestamp”, “emonpiCM_5:Msg2hx”, “emonpiCM_5:Msg2”
1700497110, null, 65790
1700497115, null, 65791
1700497120, null, 65792
1700497125, null, 65793
1700497130, null, 65794
1700497135, null, 65795
1700497140, null, 65797
1700497145, 65.8, 65798
1700497150, 65.8, 65799
1700497155, 65.8, 65800
1700497160, 65.8, 65801
1700497165, 65.8, 65802
1700497170, 65.8, 65803
1700497175, 65.8, 65804
1700497180, 65.8, 65805
1700497185, 65.8, 65806
1700497190, 65.8, 65807
1700497195, 65.8, 65808
1700497200, 65.8, 65809
1700497205, 65.8, 65810
1700497210, 65.8, 65811
1700497215, 65.8, 65812
1700497220, 65.8, 65813
1700497225, 65.8, 65814
1700497230, 65.8, 65815
1700497235, 65.8, 65816
1700497240, 65.8, 65817
1700497245, 65.8, 65818
1700497250, 65.8, 65819
1700497255, 65.8, 65820
1700497260, 65.8, 65821
1700497265, 65.8, 65822
1700497270, 65.8, 65823
1700497275, 65.8, 65824
1700497280, 65.8, 65825
1700497285, 65.8, 65826
1700497290, 65.8, 65827
1700497295, 65.8, 65828
1700497300, 65.8, 65830
1700497305, 65.8, 65831
1700497310, 65.8, 65832
1700497315, 65.8, 65833
1700497320, 65.8, 65834
1700497325, 65.8, 65835
1700497330, 65.8, 65836
1700497335, 65.8, 65837
1700497340, 65.8, 65838
1700497345, 65.8, 65839
1700497350, 65.8, 65840
1700497355, 65.8, 65841
1700497360, 65.8, 65842
1700497365, 65.8, 65843
1700497370, 65.8, 65844
1700497375, 65.8, 65845
1700497380, 65.8, 65846
1700497385, 65.8, 65847
1700497390, 65.8, 65848
1700497395, 65.8, 65849
1700497400, 65.8, 65850
1700497405, 65.9, 65851
1700497410, 65.9, 65852
1700497415, 65.9, 65853
1700497420, 65.9, 65854
1700497425, 65.9, 65855
1700497430, 65.9, 65856
1700497435, 65.9, 65857
1700497440, 65.9, 65858
1700497445, 65.9, 65859
1700497450, 65.9, 65860
1700497455, 65.9, 65861
1700497460, 65.9, 65862
1700497465, 65.9, 65864
1700497470, 65.9, 65865
1700497475, 65.9, 65866
1700497480, 65.9, 65867
1700497485, 65.9, 65868
1700497490, 65.9, 65869
1700497495, 65.9, 65870
1700497500, 65.9, 65871
1700497505, 65.9, 65872
1700497510, 65.9, 65873
1700497515, 65.9, 65874
1700497520, 65.9, 65875
1700497525, 65.9, 65876
1700497530, 65.9, 65877
1700497535, 65.9, 65878
1700497540, 65.9, 65879
1700497545, 65.9, 65880
1700497550, 65.9, 65881
1700497555, 65.9, 65882
1700497560, 65.9, 65883

Something not quite right @TrystanLea

Remember here, I am specifying the time as well.

Looking at a more recent gap (just one data point) I can see from the logs it was written to the feed and that both feeds are written with exactly the same timestamp.

2023-11-20 15:28:23.430|INFO|emoncms_mqtt.php|emon/glow {"time":1700494103,"electric":132783}
2023-11-20 15:28:23.431|INFO|feed_model.php|post() feedid=151 updatetime=1700494103 feedtime=1700494103 value=132783 padding_mode=
2023-11-20 15:28:23.431|INFO|feed_model.php|post() feedid=153 updatetime=1700494103 feedtime=1700494103 value=132.783 padding_mode=
2023-11-20 15:28:33.450|INFO|emoncms_mqtt.php|Valid time in seconds used 1700494113
2023-11-20 15:28:33.450|INFO|emoncms_mqtt.php|emon/glow {"time":1700494113,"electric":132790}
2023-11-20 15:28:33.451|INFO|feed_model.php|post() feedid=151 updatetime=1700494113 feedtime=1700494113 value=132790 padding_mode=
2023-11-20 15:28:33.452|INFO|feed_model.php|post() feedid=153 updatetime=1700494113 feedtime=1700494113 value=132.79 padding_mode=
2023-11-20 15:28:43.470|INFO|emoncms_mqtt.php|Valid time in seconds used 1700494125
2023-11-20 15:28:43.470|INFO|emoncms_mqtt.php|emon/glow {"time":1700494125,"electric":132798}
2023-11-20 15:28:43.471|INFO|feed_model.php|post() feedid=151 updatetime=1700494125 feedtime=1700494125 value=132798 padding_mode=
2023-11-20 15:28:43.471|INFO|feed_model.php|post() feedid=153 updatetime=1700494125 feedtime=1700494125 value=132.798 padding_mode=
2023-11-20 15:28:53.497|INFO|emoncms_mqtt.php|Valid time in seconds used 1700494133
2023-11-20 15:28:53.497|INFO|emoncms_mqtt.php|emon/glow {"time":1700494133,"electric":132803}
2023-11-20 15:28:53.498|INFO|feed_model.php|post() feedid=151 updatetime=1700494133 feedtime=1700494133 value=132803 padding_mode=
2023-11-20 15:28:53.499|INFO|feed_model.php|post() feedid=153 updatetime=1700494133 feedtime=1700494133 value=132.803 padding_mode=
2023-11-20 15:29:03.-478|INFO|emoncms_mqtt.php|Valid time in seconds used 1700494143
2023-11-20 15:29:03.-478|INFO|emoncms_mqtt.php|emon/glow {"time":1700494143,"electric":132810}
2023-11-20 15:29:03.-477|INFO|feed_model.php|post() feedid=151 updatetime=1700494143 feedtime=1700494143 value=132810 padding_mode=
2023-11-20 15:29:03.-477|INFO|feed_model.php|post() feedid=153 updatetime=1700494143 feedtime=1700494143 value=132.81 padding_mode=

(ignore the different line angles, had to do something to split them up!)

image

image

CSV from graph.

"Unix timestamp", "glow:electric_kWh", "glow:electric_Wh"
1700494090, 131.4, 132776
1700494100, 131.5, 132783
1700494110, 131.5, 132790
1700494120, null, 132798
1700494130, 131.5, 132803
1700494140, 131.5, 132810
1700494150, 131.5, 132817