Dsmr-reader: Dataverwerking loopt achter

[Calimerorulez]

Wat gebruik je?

• DSMR-reader versie (rechtsbovenin applicatie zichtbaar): v2.8
• Hardware (RaspberryPi 3, 4 of iets anders): Docker
• DSMR-protocol slimme meter (v2, v4 of v5): v4

Bij mij loopt de dataverwerking achter sinds 4 oktober... De enige melding die ik vinden kan is:

2019-10-27 21:20:02,377 DEBG 'dsmr_backend' stderr output:
[2019-10-27 20:20:02,377] ERROR no element found: line 1, column 0
NoneType: None

...welke zich bijna iedere seconde herhaalt.

Telegrammen komen gewoon binnen, en actueel verbruik wordt gewoon getoond, alleen zie ik sinds 4 oktober geen dag- en uurstatistieken meer...

[dennissiemensma]

Bedankt voor je melding. Het kan zijn dat er meerdere dingen spelen. Wat je sowieso mag doen is upgraden naar v2.9, wat een bug bij Buienradar oplost.

Ik hoor graag of dat ook even eventuele dataachterstand oplost (na een tijdje).

[Calimerorulez]

Ik heb geupgrade naar 2.9, twee dagen geleden, en de bug v.w.b. Buienradar is zo te zien wel weg (behalve vannacht nog eventjes een paar meldingen), maar ik heb nog steeds meldingen dat de dataverwerking achterloopt sinds 4 oktober. Ik laat hem nog wel even doorpruttelen, want ik zie geen andere errors vooralsnog (behalve dat pg_dump niet gevonden is, die heb ik zojuist in mijn docker image toegevoegd) :)

[dennissiemensma]

Dat is mooi om te horen. Kun je ook aangeven welke data exact achterloopt? Zijn dat de telegrammen of de dagtotalen/Archief?

[Calimerorulez]

Dag en uurstatistieken, dagtotalen/archief. Als ik daarin kijk, is ie exact om 0:00 gestopt; hij heeft dus zo te zien 4-10 wel gedaan.

Alles ná 4-10 is niet klikbaar.

[dennissiemensma]

Je zou nog even in de dsmr_backend log kunnen kijken: /var/log/supervisor/dsmr_backend.log

Daar zou ik fouten verwachten.

[Calimerorulez]

Ik denk omdat ik een docker image gebruik, dat die log niet wordt aangemaakt. Ik heb debug logging aangezet, maar uiteraard is dat overkill:

Ik zie de afgelopen nacht, zonder overdrijven, ongeveer 100000x dit langskomen:

[2019-11-01 03:14:29,787] DEBUG Waiting for newer readings before grouping data...

Ik speur verder :) Is er een specifiek tijdstip waar de totalen/statistieken opgemaakt worden?

[dennissiemensma]

Met die melding kan ik wel wat. Hij hangt dus hier.

• Staat de systeemtijd van je docker image goed?
• Komen er wel nieuwe metingen binnen?
• Zie je hier oplopen waardes:

sudo su - postgres
psql dsmrreader

select count(id) from dsmr_datalogger_dsmrreading where processed = false;

Edit:
En hetzelfde geldt hiervoor, wat krijg je te zien?

select timestamp from dsmr_datalogger_dsmrreading order by timestamp desc limit 10;

[Calimerorulez]

Datum/tijd klopt, en ik zie oplopende waardes:

dsmrreader=# select count(id) from dsmr_datalogger_dsmrreading where processed = false;
 count
-------
     7
(1 row)

dsmrreader=# select count(id) from dsmr_datalogger_dsmrreading where processed = false;
 count
-------
    17
(1 row)

dsmrreader=# select timestamp from dsmr_datalogger_dsmrreading order by timestamp desc limit 10;
       timestamp
------------------------
 2019-11-02 07:58:51+01
 2019-11-02 07:58:50+01
 2019-11-02 07:58:48+01
 2019-11-02 07:58:47+01
 2019-11-02 07:58:45+01
 2019-11-02 07:58:44+01
 2019-11-02 07:58:43+01
 2019-11-02 07:58:41+01
 2019-11-02 07:58:40+01
 2019-11-02 07:58:38+01
(10 rows)

Overigens komt deze ook weer terug soms:

2019-11-02 03:39:01,526 DEBG 'dsmr_backend' stderr output:

[2019-11-02 03:39:01,526] ERROR    HTTPSConnectionPool(host='api.dropboxapi.com', port=443): Max retries exceeded with url: /2/files/get_metadata (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7f0e079d6460>: Failed to establish a new connection: [Errno -2] Name does not resolve'))

NoneType: None

[dennissiemensma]

Oke in dat geval klopt de Waiting for newer readings before grouping data wel. Hij is gewoon vaak snel klaar en wacht dus op nieuwe telegrammen. Dan zit het probleem verderop.

De melding van Dropbox kun je negeren, mits je ziet dat er wel nieuwe backups geupload worden.

---

Zie je hier ook recente gegevens?

sudo su - postgres
psql dsmrreader

select read_at from dsmr_consumption_electricityconsumption order by read_at desc limit 10;

En zijn de bovenste hiervan rond 4 oktober?

select hour_start from dsmr_stats_hourstatistics order by hour_start desc limit 10;

Deze ook als laatste 4 oktober?

select day from dsmr_stats_daystatistics order by day desc limit 10;

Zie je nog andere meldingen in de dsmr_backend-log met DEBUG aan, die lijken op een van deze? https://github.com/dennissiemensma/dsmr-reader/blob/v2.9.0/dsmr_stats/services.py#L60

• Stats: Unprocessed readings found for...
• Stats: No consumption found for ...
• Waiting for first gas reading on the next day...

[Calimerorulez]

1e query:

dsmrreader=# select read_at from dsmr_consumption_electricityconsumption order by read_at desc limit 10;
        read_at
------------------------
 2019-11-03 13:28:00+01
 2019-11-03 13:27:00+01
 2019-11-03 13:26:00+01
 2019-11-03 13:25:00+01
 2019-11-03 13:24:00+01
 2019-11-03 13:23:00+01
 2019-11-03 13:22:00+01
 2019-11-03 13:21:00+01
 2019-11-03 13:20:00+01
 2019-11-03 13:19:00+01
(10 rows)

2e query, antwoord: ja :)

dsmrreader=# select hour_start from dsmr_stats_hourstatistics order by hour_start desc limit 10;
       hour_start
------------------------
 2019-10-05 00:00:00+02
 2019-10-04 23:00:00+02
 2019-10-04 22:00:00+02
 2019-10-04 21:00:00+02
 2019-10-04 20:00:00+02
 2019-10-04 19:00:00+02
 2019-10-04 18:00:00+02
 2019-10-04 17:00:00+02
 2019-10-04 16:00:00+02
 2019-10-04 15:00:00+02
(10 rows)

3e query, antwoord ook ja:

dsmrreader=# select day from dsmr_stats_daystatistics order by day desc limit 10;
    day
------------
 2019-10-04
 2019-10-03
 2019-10-02
 2019-10-01
 2019-09-30
 2019-09-29
 2019-09-28
 2019-09-27
 2019-09-26
 2019-09-25
(10 rows)

Ik zie verder alleen maar dropbox errors en deze:
could not find a "pg_dump" to execute
hoewel pg_dump wel geïnstalleerd is.

Maar dat ligt denk ik aan de versie (11.5) van postgres?
pg_dump (PostgreSQL) 11.5

[dennissiemensma]

Je zou nog deze branch kunnen proberen, zit wat meer debug in: 764-stats-debug

Ik weet niet hie je in Docker wisselt, maar normaal is het:

sudo su - dsmr
git fetch
git checkout -b 764-stats-debug origin/764-stats-debug
./post-deploy.sh

Zorg wel dat je DEBUG logging aan hebt. Je zou dan iets meer moeten zien in de backend log.

[Calimerorulez]

Hiervoor moet ik even gaan knutselen aan hoe mijn Docker image wordt gegenereerd, want ik download de laatste archive van Github, en ik clone de source niet. Kan een paar dagen duren :)

[Calimerorulez]

Kleine update, ik ben er even voor gaan zitten. Ik heb de source erin gehangen (ik hoop dat ik het goed gedaan heb) en de checkout gedaan.

Ik krijg inderdaad veel meer logging, iedere seconde (dit zijn er drie):

[2019-11-03 17:48:20,416] DEBUG    Calling 0 backend service(s)
[2019-11-03 17:48:20,434] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,439] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,443] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,447] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,451] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,456] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,460] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,464] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,467] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,471] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,476] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,480] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,484] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,488] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,492] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,496] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,500] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,504] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,508] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,512] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,516] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,519] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,523] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,527] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,531] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,535] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,539] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,543] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,547] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,550] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,554] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,558] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,562] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,566] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:20,624] DEBUG    Waiting for first gas reading on the next day...
[2019-11-03 17:48:20,627] DEBUG    Sleeping 1 sec(s)
[2019-11-03 17:48:21,644] DEBUG    Calling 0 backend service(s)
[2019-11-03 17:48:21,672] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,679] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,686] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,691] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,696] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,700] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,704] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,709] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,714] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,718] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,722] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,726] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,730] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,734] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,738] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,742] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,747] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,751] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,755] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,759] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,763] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,767] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,771] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,775] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,780] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,784] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,788] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,792] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,796] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,800] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,804] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,808] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,812] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,817] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,821] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:21,877] DEBUG    Waiting for first gas reading on the next day...
[2019-11-03 17:48:21,880] DEBUG    Sleeping 1 sec(s)
[2019-11-03 17:48:22,895] DEBUG    Calling 0 backend service(s)
[2019-11-03 17:48:22,915] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,920] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,924] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,928] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,932] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,936] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,941] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,945] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,949] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,953] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,958] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,962] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,966] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,970] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,974] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,978] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,983] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,988] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,992] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:22,996] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,003] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,009] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,015] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,020] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,025] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,029] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,033] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,037] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,041] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,045] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,050] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,054] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,058] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,062] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,066] DEBUG    Waiting for newer readings before grouping data...
[2019-11-03 17:48:23,123] DEBUG    Waiting for first gas reading on the next day...
[2019-11-03 17:48:23,126] DEBUG    Sleeping 1 sec(s)

[dennissiemensma]

Ik zie nu waar het probleem ligt, het gaat om: Waiting for first gas reading on the next day....

Dit stopt de verwerking als er op een dag geen gas gemeten is (of als de applicatie een dag heeft uitgestaan). Ik weet niet of dat ook bij jou het geval is, maar het is in ieder geval een bug.

Ik heb een wijziging gedaan in de branch. Kun je hem eens bijwerken en kijken of dat het oplost?

sudo su - dsmr
git pull
./post-deploy.sh

De melding Waiting for newer readings before grouping data... is trouwens ongerelateerd.

[dennissiemensma]

Ik zal trouwens er ook voor zorgen dat Waiting for newer readings before grouping data.. minder vaak voorkomt. Het is verspilling van systeem resources zie ik nu, vooral bij DSMR v5. Maar dat is dus ongerelateerd aan jouw issue.

[Calimerorulez]

Ik krijg nu dit enkele malen per seconde, met een telegram er tussendoor:

[2019-11-03 18:36:06,802] DEBUG    Queued message for dsmr/reading/id
[2019-11-03 18:36:06,846] DEBUG    Ignoring dsmr/day-totals/electricity1 due to cache
[2019-11-03 18:36:06,848] DEBUG    Ignoring dsmr/day-totals/electricity2 due to cache
[2019-11-03 18:36:06,850] DEBUG    Ignoring dsmr/day-totals/electricity1_returned due to cache
[2019-11-03 18:36:06,852] DEBUG    Ignoring dsmr/day-totals/electricity2_returned due to cache
[2019-11-03 18:36:06,855] DEBUG    Ignoring dsmr/day-totals/electricity_merged due to cache
[2019-11-03 18:36:06,857] DEBUG    Ignoring dsmr/day-totals/electricity_returned_merged due to cache
[2019-11-03 18:36:06,859] DEBUG    Ignoring dsmr/day-totals/electricity1_cost due to cache
[2019-11-03 18:36:06,861] DEBUG    Ignoring dsmr/day-totals/electricity2_cost due to cache
[2019-11-03 18:36:06,863] DEBUG    Ignoring dsmr/day-totals/electricity_cost_merged due to cache
[2019-11-03 18:36:06,865] DEBUG    Ignoring dsmr/day-totals/total_cost due to cache
[2019-11-03 18:36:06,867] DEBUG    Ignoring dsmr/day-totals/gas due to cache
[2019-11-03 18:36:06,869] DEBUG    Ignoring dsmr/day-totals/gas_cost due to cache
[2019-11-03 18:36:06,871] DEBUG    Ignoring dsmr/day-totals/energy_supplier_price_electricity_delivered_1 due to cache
[2019-11-03 18:36:06,873] DEBUG    Ignoring dsmr/day-totals/energy_supplier_price_electricity_delivered_2 due to cache
[2019-11-03 18:36:06,876] DEBUG    Ignoring dsmr/day-totals/energy_supplier_price_electricity_returned_1 due to cache
[2019-11-03 18:36:06,878] DEBUG    Ignoring dsmr/day-totals/energy_supplier_price_electricity_returned_2 due to cache
[2019-11-03 18:36:06,880] DEBUG    Ignoring dsmr/day-totals/energy_supplier_price_gas due to cache
[2019-11-03 18:36:06,888] DEBUG    Ignoring dsmr/meter-stats/dsmr_version due to cache
[2019-11-03 18:36:06,891] DEBUG    Ignoring dsmr/meter-stats/electricity_tariff due to cache
[2019-11-03 18:36:06,893] DEBUG    Ignoring dsmr/meter-stats/power_failure_count due to cache
[2019-11-03 18:36:06,895] DEBUG    Ignoring dsmr/meter-stats/long_power_failure_count due to cache
[2019-11-03 18:36:06,897] DEBUG    Ignoring dsmr/meter-stats/voltage_sag_count_l1 due to cache
[2019-11-03 18:36:06,899] DEBUG    Ignoring dsmr/meter-stats/voltage_sag_count_l2 due to cache
[2019-11-03 18:36:06,901] DEBUG    Ignoring dsmr/meter-stats/voltage_sag_count_l3 due to cache
[2019-11-03 18:36:06,903] DEBUG    Ignoring dsmr/meter-stats/voltage_swell_count_l1 due to cache
[2019-11-03 18:36:06,905] DEBUG    Ignoring dsmr/meter-stats/voltage_swell_count_l2 due to cache
[2019-11-03 18:36:06,907] DEBUG    Ignoring dsmr/meter-stats/voltage_swell_count_l3 due to cache
[2019-11-03 18:36:06,909] DEBUG    Ignoring dsmr/meter-stats/rejected_telegrams due to cache
[2019-11-03 18:36:06,919] DEBUG    Sleeping 0.5 sec(s)

[cyberjunky]

Ik heb exact hetzelfde issue zoals in ander ticket vermeld;
Mijn output:

dsmrreader=# select day from dsmr_stats_daystatistics order by day desc limit 10;
    day
------------
 2019-10-04
 2019-10-03
 2019-10-02
 2019-10-01
 2019-09-30
 2019-09-29
 2019-09-28
 2019-09-27
 2019-09-26
 2019-09-25
(10 rows)\

Ik heb nog wel gas verbruik reading, althans laatste dagen.
Het kan trouwens wel zijn dat de applicatie een dag of langer niet heeft gedraait, de connectie tussen dsmr en dsmrdb containers was weg.

[Calimerorulez]

@cyberjunky Ik denk dat wij dezelfde setup hebben draaien ;)

[cyberjunky]

@Calimerorulez lijkt er op ja.
Ik lees de smartmeter waardes vanaf een gerootte Toon, en push ze elke 10 sec naar de DSMR API met een crontab scriptje.

[dennissiemensma]

@Calimerorulez die meldingen gaan over MQTT. Krijg je helemaal geen andere meldingen meer? Niets mbt Stats: ... ?

[dennissiemensma]

@Calimerorulez en begrijp ik goed dat de laatste versie van de branch dus de statistieken nog steeds niet genereert? Als hij ergens op hangt, zou ik sowieso nog een melding verwachten.

[Calimerorulez]

@dennissiemensma Sorry, ik zat met mijn suffe hoofd in de datalogger log te kijken.

Ik zie nog steeds in de backend log:

[2019-11-04 19:12:58,159] DEBUG Waiting for first gas reading on the next day...

iedere twee seconden. Een grep op Stats of stats vindt niks

/edit: ik zal de source opnieuw pullen zodadelijk. Ik maak een denkfout vermoed ik. Ik moet namelijk iedere keer een nieuwe Docker image maken, als je de source wijzigt. De image die ik gebruik maakt namelijk geen gebruik van virtualenv, dus werkt ./post-deploy.sh niet.

[Calimerorulez]

Updateje:

[2019-11-04 19:57:13,439] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:57:13,988] DEBUG     - Creating day & hour statistics for: 2019-10-31
[2019-11-04 19:57:14,416] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:57:15,438] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:57:15,453] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:57:16,020] DEBUG     - Creating day & hour statistics for: 2019-11-01
[2019-11-04 19:57:16,439] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:57:17,460] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:57:17,475] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:57:18,028] DEBUG     - Creating day & hour statistics for: 2019-11-02
[2019-11-04 19:57:18,460] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:57:19,479] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:57:19,494] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:57:20,061] DEBUG     - Creating day & hour statistics for: 2019-11-03
[2019-11-04 19:57:20,496] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:57:21,516] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:57:21,532] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:57:22,037] DEBUG     - Creating new notification containing daily usage.
[2019-11-04 19:57:22,530] DEBUG    Stats: Waiting for day to pass: 2019-11-04
[2019-11-04 19:57:22,532] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:57:23,548] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:57:23,564] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:57:23,595] DEBUG    Stats: Waiting for day to pass: 2019-11-04
[2019-11-04 19:57:23,598] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:58:12,957] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:58:13,973] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:58:13,988] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:58:14,016] DEBUG    Stats: Waiting for day to pass: 2019-11-04
[2019-11-04 19:58:14,019] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:58:15,030] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:58:15,045] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:58:15,072] DEBUG    Stats: Waiting for day to pass: 2019-11-04
[2019-11-04 19:58:15,075] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:58:16,088] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:58:16,108] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:58:16,136] DEBUG    Stats: Waiting for day to pass: 2019-11-04
[2019-11-04 19:58:16,139] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:58:17,159] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:58:17,177] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:58:17,203] DEBUG    Stats: Waiting for day to pass: 2019-11-04
[2019-11-04 19:58:17,207] DEBUG    Sleeping 1 sec(s)
[2019-11-04 19:58:18,227] DEBUG    Calling 0 backend service(s)
[2019-11-04 19:58:18,246] DEBUG    Compact: Waiting for newer readings before grouping data...
[2019-11-04 19:58:18,274] DEBUG    Stats: Waiting for day to pass: 2019-11-04
[2019-11-04 19:58:18,277] DEBUG    Sleeping 1 sec(s)

Volgens mij klopt ie nu :-)

Archief is bij en ik ben blij, dank je wel!

[dennissiemensma]

Bedankt voor je terugkoppeling. Ik vermoed dat er dan ergens een gat was qua gas en dat bleef onterecht hangen.

Je kunt nu de debug-info weer uitzetten. Ik neem de fix mee voor de volgende release, dus vanaf dan hoef je niet meer handmatig code uit te checken.

[dennissiemensma]

@cyberjunky voor jou geldt hetzelfde. Je kunt ofwel handmatig een revisie uitchecken of wachten op de release later deze week.

[dennissiemensma]

Uitgebracht in v2.10

[cyberjunky]

Top! Nu even wachten op nieuw docker image.

[Martijn02]

De docker image is uit.

@dennissiemensma Perfect! Bij mij liep de dataverwerking achter sinds 7 september (Ik heb toen database backup heb moeten terugzetten en miste waarschijnlijk een dag aan data). Ik had al een paar keer gekeken of ik de oorzaak zelf kon vinden, en vanmorgen liep ik tegen deze thread en bijbehorende fix aan. Na de een update worden de dag- en uurstatistieken weer netjes bijgewerkt. 👍

[cyberjunky]

Top! Werkt perfect weer hier, ik heb de donate functionaliteit ook getest, die werkt ook! ;-) @dennissiemensma

[dennissiemensma]

Bedankt voor jullie input, fijn om te horen!

[swerveshot]

Eeehm sorry dat ik een beetje achter loop. Maar.... help!

_Edit: nog even een mention aan @dennissiemensma, anders leest hij dit misschien niet eens. 🤔_

Toevallig constateerde ik ook op mijn installatie hetzelfde issue. Echter het bijwerken van dsmr-reader verhelpt het in mijn geval niet.

Nu ZOU het kunnen zijn dat dit komt omdat ik verhuisd ben en gewoon mijn huidige install heb gekoppeld op de P1 poort op het nieuwe adres. Complicerende factor hierbij is ook nog eens dat ik op het nieuwe adres geen gasverbruik meer heb omdat ik hier stadsverwarming heb.

_Om exact te zijn: laatste meting in dsmr_consumption_gasconsumption is van 2019-04-25 21:40:00+02. En de eerste meting in dsmr_consumption_electricityconsumption op het nieuwe adres is van 2019-09-18 23:32:00+02._

Aanvullend, de data in de dsmr_consumption_electricityconsumption kolom is recent.

dsmrreader=# select read_at from dsmr_consumption_electricityconsumption order by read_at desc limit 10;
        read_at
------------------------
 2020-01-02 09:34:00+01
 2020-01-02 09:33:00+01
 2020-01-02 09:32:00+01
 2020-01-02 09:31:00+01
 2020-01-02 09:30:00+01
 2020-01-02 09:29:00+01
 2020-01-02 09:28:00+01
 2020-01-02 09:27:00+01
 2020-01-02 09:26:00+01
 2020-01-02 09:25:00+01
(10 rows)

Bij dsmr_stats_hourstatistics en dsmr_stats_daystatistics zie ik helaas geen recente data.

dsmrreader=# select hour_start from dsmr_stats_hourstatistics order by hour_start desc limit 10;
       hour_start
------------------------
 2019-10-09 00:00:00+02
 2019-10-08 23:00:00+02
 2019-10-08 22:00:00+02
 2019-10-08 21:00:00+02
 2019-10-08 20:00:00+02
 2019-10-08 19:00:00+02
 2019-10-08 18:00:00+02
 2019-10-08 17:00:00+02
 2019-10-08 16:00:00+02
 2019-10-08 15:00:00+02
(10 rows)

dsmrreader=# select day from dsmr_stats_daystatistics order by day desc limit 10;
    day
------------
 2019-10-08
 2019-10-07
 2019-10-06
 2019-10-05
 2019-10-04
 2019-10-03
 2019-10-02
 2019-10-01
 2019-09-30
 2019-09-29
(10 rows)

Er is wel een klein aantal readings dat niet verwerkt is, maar dat lijkt mij redelijk onschuldig.

dsmrreader=# select count(id) from dsmr_datalogger_dsmrreading where processed = false;
 count
-------
    10
(1 row)

Het enige wat me opvalt als ik de dsmr_backend.log bekijk is (los van wat dropbox en buienradar gerelateerde events) dat er heel veel keren deze log regels worden weggeschreven.

[2019-10-27 17:29:58,599] ERROR    2019-10-27 02:00:00
NoneType
[2019-10-27 17:29:58,600] ERROR    no element found: line 1, column 0
NoneType

Maar dit is alleen op 27 oktober en heeft steeds een 'echte' timestamp aan het begin van het event, maar steeds exact '2019-10-27 02:00:00' in de data. Na 27 oktober komt dit ook niet meer voor.

Als ik hier een apart issue voor moet aanmaken doe ik dat graag hoor. Maar omdat het zo leek op dit issue heb ik er ondanks dat deze gesloten is toch nog een update op gestuurd.

[dennissiemensma]

@swerveshot zou je dit comment even in een nieuw issue willen zetten? Want anders dan krijgen andere volgers van dit huidige issue ook telkens notificaties.

[swerveshot]

Absoluut! Ik noemde het al aan het einde van mijn comment. Geen probleem.