Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

⚠️ Docker only - Reading timestamp differences (1 or 2 hours off) #1282

Closed
8uurg opened this issue Feb 10, 2021 · 117 comments
Closed

⚠️ Docker only - Reading timestamp differences (1 or 2 hours off) #1282

8uurg opened this issue Feb 10, 2021 · 117 comments
Labels
Milestone

Comments

@8uurg
Copy link

8uurg commented Feb 10, 2021

Oplossing

Verwijder deze mount:

/etc/localtime:/etc/localtime:ro

Alternatief

Gebruik postgres:12.4-alpine

#1282 (comment)


Oorspronkelijk issue:

Server error tussen 23:00 en 00:00: LookupError: No electricity readings found for: 2021-02-11

Omgeving
Ik draai DSMR reader in Docker, met een remote datalogger.


DSMR-READER
    App / Python / Database                                                       v4.11 / v3.9.1 / postgresql
    BE sleep / DL sleep / Retention / Override                                     1.0s / 5.0s / 672h / False
    Latest telegram version read / Parser settings                                                 "50" / "4"

DATA
    Telegrams total (est.)                                                                             209017
    Consumption records electricity / gas (est.)                                                 38752 / 8479

UNRESOLVED ISSUES
    Too many unprocessed readings: 1937                                                          a minute ago

(voor unprocessed readings heb ik de reportagesnelheid al op 5s gezet, ipv de standaardwaarde van 0.5s.)

Probleemomschrijving
Na terugzetten van een backup probeert DSMR na opstarten herhaaldelijk rijen toe te voegen waarin waardes voorkomen met null:

dsmrdb_1  | 2021-02-10 22:29:00.344 CET [38] ERROR:  null value in column "delivered_1" violates not-null constraint
dsmrdb_1  | 2021-02-10 22:29:00.344 CET [38] DETAIL:  Failing row contains (70779, 2021-02-09 04:00:00+01, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null).
dsmrdb_1  | 2021-02-10 22:29:00.344 CET [38] STATEMENT:  INSERT INTO "dsmr_consumption_electricityconsumption" ("read_at", "delivered_1", "returned_1", "delivered_2", "returned_2", "currently_delivered", "currently_returned", "phase_currently_delivered_l1", "phase_currently_delivered_l2", "phase_currently_delivered_l3", "phase_currently_returned_l1", "phase_currently_returned_l2", "phase_currently_returned_l3", "phase_voltage_l1", "phase_voltage_l2", "phase_voltage_l3", "phase_power_current_l1", "phase_power_current_l2", "phase_power_current_l3") VALUES ('2021-02-09T03:00:00+00:00'::timestamptz, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL) RETURNING "dsmr_consumption_electricityconsumption"."id"

Dit herhaalt zich zo ongeveer iedere 30s, ondertussen update de live grafiek niet.

Verder heb ik tussen 23:00 en 24:00 geen toegang tot het dashboard en krijg ik het volgende bericht (om 23:18):


Server Error
Sorry, something unexpected happened.
Exception:

LookupError: No electricity readings found for: 2021-02-11

Traceback:

  File "/usr/local/lib/python3.9/site-packages/django/core/handlers/base.py", line 181, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)

  File "/usr/local/lib/python3.9/site-packages/django/views/generic/base.py", line 70, in view
    return self.dispatch(request, *args, **kwargs)

  File "/dsmr/dsmr_frontend/mixins.py", line 11, in dispatch
    return super().dispatch(request, *args, **kwargs)

  File "/usr/local/lib/python3.9/site-packages/django/views/generic/base.py", line 98, in dispatch
    return handler(request, *args, **kwargs)

  File "/usr/local/lib/python3.9/site-packages/django/views/generic/base.py", line 159, in get
    context = self.get_context_data(**kwargs)

  File "/dsmr/dsmr_frontend/views/dashboard.py", line 31, in get_context_data
    context_data['consumption'] = dsmr_consumption.services.day_consumption(

  File "/dsmr/dsmr_consumption/services.py", line 248, in day_consumption
    raise LookupError("No electricity readings found for: {}".format(day))

Kanttekening
Voor als iemand anders dit tegenkomt: Ik heb dit kort opgelost door de constraints uit de tabellen te verwijderen

START TRANSACTION;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_1 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_2 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_1 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_2 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_delivered DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_returned DROP NOT NULL;
COMMIT;

Om de rijen toegevoegd te laten worden, om ze vervolgens weer te verwijderen:

DELETE FROM dsmr_consumption_electricityconsumption WHERE delivered_1 IS NULL;

En de constraints weer teruggezet:

START TRANSACTION;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_1 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_2 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_1 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_2 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_delivered SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_returned SET NOT NULL;
COMMIT;

Voor het laatste probleem heb ik echter geen oplossing... De datum en tijd in de containers (dsmr en db) zijn correct.

@dennissiemensma
Copy link
Member

Bedankt voor je melding. Toevallig had iemand soortgelijke issues in xirixiz/dsmr-reader-docker/issues/171, dus mogelijk helpt dat in het vinden van de oorzaak met die null-meldingen.

Wat betreft je andere issue over de foutmelding tussen 23:00 en 0:00, dat klinkt erg als een tijdzone issue en klinkt als een bug in DSMR-reader bij het bepalen van de datum aan de hand van de huidige tijd.

  • Welke database image/versie gebruik je in Docker?
  • Welke tijdzone-instellingen gebruik je in de Docker envvars voor DSMR-reader/DB?
  • Wat voor soort backup heb je teruggezet? Een volledige of een partial?
  • Weet je nog of de backup uit dezelfde DSMR-reader versie kwam als die je nu draait? Of heb je die tegelijkertijd geupgrade?

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

Yep. Ik had precies hetzelfde probleem als de persoon waarnaar je refereert, database was corrupt omdat de datum en tijd van de alpine docker image niet meer werkte op de Raspberry Pi 4 na een update van de containers. Dus ook hier was sprake van een update.

Een korte serie van de stappen die ik heb gezet:

  • Heb de image op postgres:12 zet
  • Losse docker-compose.yml gemaakt die alleen de database opstart en de backup directory aan de container mount,
  • Backup teruggezet (Ik heb een van de laatste 'daily' backups die de docker image automatisch maakt gebruik gemaakt, deze lijkt volledig te zijn: ik heb data van > 1 maand geleden in de interface.).
  • Terug naar de originele docker-compose
  • Na opstarten begon direct bovenstaande issue met null-waardes en met de tijd offset (en: ik realiseer me nu in de live grafiek ook).

Tijdzone in de containers, op de host, en op de remote datalogger is allemaal Europe/Amsterdam en loopt gelijk, maar ik heb bij de remote datalogger dit wel aan moeten passen (Was eerst London, dus dat verklaart 1 uur tijdsverschil). Ik heb deze ook via supervisor opnieuw opgestart, maar wellicht is een volledige reboot nodig? Update: reboot uitgevoerd op remote datalogger verhelpt het ook niet.

Ik heb trouwens sinds het volgen van mijn eigen stappen geen problemen meer ondervonden met de NULL-waardes: het was iets wat alleen voorkwam na het terugzetten van de backup.

@dennissiemensma
Copy link
Member

@8uurg dank voor de uitgebreide toelichting. @Tralapo wellicht wil je dezelfde stappen volgen als onderin bovenstaande comment: #1282 (comment) voor het oplossen van de null-waardes.

Ondertussen zal ik even kijken of ik wat kan vinden mbt de andere datumfout.

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

Ik ben zowel met Docker als SQL geen enorme pro, dus eigenlijk twee losse vragen aan @8uurg:

  • Wat doen die comments nou eigenlijk precies? Constraints zegt mij zo niets
  • Hoe voer ik ze precies uit in de Docker?

@dennissiemensma
Copy link
Member

dennissiemensma commented Feb 11, 2021

Verder heb ik tussen 23:00 en 24:00 geen toegang tot het dashboard en krijg ik het volgende bericht (om 23:18):

Het lijkt erop dat de specifieke fout komt doordat DSMR-reader de datum gebruikt van het meest recente telegram. Dat kan wellicht botsen met een paar seconden als de meter voorloopt, maar ik ga er vanuit dat jullie meter niet heel toevallig een uur voor loopt.

Helaas zie ik niet zo 1-2-3 waarom dit op deze manier gedaan is. Het is een wijziging van november 2017, dus lang geleden, voor v1.11. Ik denk dat ik het wijzig zodat die gewoon de datum pakt volgens DSMR-reader, en niet volgens de meter, en zal ik de foutafhandeling wat beter doen.

@dennissiemensma dennissiemensma changed the title Na terugzetten backup problemen. NOT NULL constraint, Server error tussen 23:00 en 00:00. Server error tussen 23:00 en 00:00: LookupError: No electricity readings found for: 2021-02-11 Feb 11, 2021
@dennissiemensma dennissiemensma added this to the 4.12 milestone Feb 11, 2021
@Tralapo
Copy link

Tralapo commented Feb 11, 2021

@dennissiemensma Ik weet niet of het relevant is, maar wat me wel opvalt wat tijden betreft:

Als ik in de Admin naar geplande processen ga en er een aanpas, kun je naast het vakje tijd op 'Nu' klikken. Dan vult hij de correcte, huidige, tijd in, maar zodra ik op opslaan druk springt hij een uur vooruit en staat er 'over 59 minuten'.

@dennissiemensma
Copy link
Member

@Tralapo dank voor de aanvulling, des te meer vermoedens ik heb dat het iets met de tijdzone is, want ik krijg dat zelf niet voor elkaar. Wat krijg je te zien als je inlogt op de docker container en date typt?

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

@dennissiemensma Ik heb zelf ook de vermoedens dat het iets met tijdzones te maken heeft gegeven het precieze uur verschil.
Aangezien mijn remote datalogger de tijdzone Europe/London had toen ik hem voor het eerst weer aanzette. Als je deze tijdzone plakt achter nederlandse tijd heb je 1 uur verschil met de huidige tijd.
Ik weet echter niet hoe DSMR Reader intern omgaat met tijdzones, dus is een hypothese gebaseerd op weinig informatie...

Desnoods kan ik kijken of het met het terugzetten van de backup te maken heeft/of het door iets wat al in de database staat, te maken heeft door een losse database en een schone installatie te bekijken.

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

Heb dit gecheckt met docker exec -t [container-id] date en DSMR loopt gelijk met de Pi zelf (18:34 CET) en Postgress zegt 06:34PM CET. Ook goed dus, maar andere vorm.

@dennissiemensma
Copy link
Member

@8uurg wat krijg je te zien op de commandline in de docker container als je date typt?

De (standaard) remote datalogger stuurt verder gewoon het telegram door, met de datumtijd van de meter, dus daar verwacht ik ook geen afwijkingen.

@dennissiemensma
Copy link
Member

dennissiemensma commented Feb 11, 2021

Ik weet echter niet hoe DSMR Reader intern omgaat met tijdzones

DSMR-reader kan overweg met tijdzones, waarbij alle datetimes in de applicatie een tijdzone hebben. Dat zeggende hebben moet DSMR-reader op sommige momenten of (zoals hier) bij het bepalen van datums wel het omzetten naar de lokale tijdzone. De lokale tijdzone zou degene moeten zijn die ingesteld is als DJANGO_TIMEZONE, die ook default naar onze NL-tijdzone.

Maar het lijkt erop dat dit toch niet in alle gevallen werkt. Want jullie geven beiden aan DJANGO_TIMEZONE=Europe/Amsterdam te gebruiken, wat ook goed zou moeten zijn.

En als ik het zelf probeer met DJANGO_TIMEZONE=UTC zie ik ook een verschil in /admin/dsmr_backend/scheduledprocess/6/change/:
Selection_001

En met DJANGO_TIMEZONE=Europe/Amsterdam:
Selection_002

Dus ik zie niet in wat jullie situatie veroorzaakt. Ik zal het sowieso vanavond hier ook even proberen na 23:00, maar ik verwacht dat ik het niet kan reproduceren.

@dennissiemensma
Copy link
Member

Wat krijgen jullie te zien als jullie in de database container dit doen? Ik weet overigens niet of het eerst command nodig is in Docker.

sudo su - postgres

psql dsmrreader -c 'select timestamp from dsmr_datalogger_dsmrreading order by timestamp desc limit 5;'

Bij mij is het:

       timestamp        
------------------------
 2021-02-11 17:47:54+00
 2021-02-11 17:47:34+00
 2021-02-11 17:47:14+00
 2021-02-11 17:46:54+00
 2021-02-11 17:46:34+00

Wat klopt, in de zin dat het 1 uur achterloopt, maar dat dat gecompenseerd wordt met +00 (UTC). In jullie geval zou ik een afwijking kunnen verwachten.

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

Hier nog even in afbeeldingen wat er gebeurt als ik een gepland proces met de hand invul op nu + 2 minuten.

image

Zodra ik op opslaan heb gedrukt, schiet hij een uur vooruit:

image

@dennissiemensma Met sudo docker exec -i dsmrdb psql dsmrreader -c "select timestamp from dsmr_datalogger_dsmrreading order by timestamp desc limit 5;" -U dsmrreader krijg ik:

       timestamp
------------------------
 2021-02-11 18:57:22+01
 2021-02-11 18:57:19+01
 2021-02-11 18:57:16+01
 2021-02-11 18:57:13+01
 2021-02-11 18:57:10+01
(5 rows)

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

@dennissiemensma
Date:
afbeelding

In de container bestaat bij mij de postgres user niet, deze stap sla ik dus over.
SQL:
afbeelding

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

@8uurg Het loopt hier allemaal wat (snel) door elkaar heen nu, maar zou jij mij nog even kunnen toelichten hoe je die acties toepast om de null fouten weg te krijgen? Ik zit nog steeds voornamelijk met dat probleem namelijk, maar begrijp niet helemaal waar/hoe ik de fix toepas.

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

@Tralapo De NULL fouten komen -- mijn inziens -- door telegrams die om een onbekende reden na verwerking overal null voor hebben (behalve de timestamp). De database faalt ze te verwerken (ze voldoen niet aan de eisen voor een valide waarde in de database), maar de verwerkingsprocedure probeert het dan opnieuw: het bericht is nog niet verwerkt.
Als je SQL kan invoeren (eg. via psql) zorgt

START TRANSACTION;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_1 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_2 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_1 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_2 DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_delivered DROP NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_returned DROP NOT NULL;
COMMIT;

ervoor dat deze eisen komen te vervallen, de database staat toe dat deze waardes worden toegevoegd.
Ondertussen worden de berichten (incl met NULL) verwerkt en in de database gestopt. De berichten met NULL moeten echter weer verwijderd worden (zie volgende commando).
(! PAS OP ! Dit commando verwijdert databaseinformatie, zorg dus dat je een backup hebt of niet om de data geeft!)

DELETE FROM dsmr_consumption_electricityconsumption WHERE delivered_1 IS NULL;

(Ik ga er van uit dat er, net zoals bij mij, er sprake is dat alle waardes null zijn, en dat dus een check for een enkele kolom die non-null is volstaat)

Vervolgens zet ik de eisen weer terug naar normaal:

START TRANSACTION;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_1 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_2 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_1 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_2 SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_delivered SET NOT NULL;
ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_returned SET NOT NULL;
COMMIT;

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

@8uurg Maar hoe kom ik 'in' docker om deze SQL acties in te voeren? Simpelweg sudo docker exec -i dsmrdb psql -U dsmrreader en dan daarachter één voor één al die regels? Ben zoals gezegd nog een redelijke beginner op zowel docker als sql vlak.

Wat bedoel je precies met het hebben van een backup? Ben ik na deze actie alle gegevens uit dsmr kwijt?
Want dit probleem ontstond juist bij het terugzetten van zo'n backup, dus ben ik dan niet terug bij af?

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

@8uurg Maar hoe kom ik 'in' docker om deze SQL acties in te voeren? Simpelweg sudo docker exec -i dsmrdb psql -U dsmrreader en dan daarachter één voor één al die regels? Ben zoals gezegd nog een redelijke beginner op zowel docker als sql vlak.

Klopt!

Wat bedoel je precies met het hebben van een backup? Ben ik na deze actie alle gegevens uit dsmr kwijt?
Want dit probleem ontstond juist bij het terugzetten van zo'n backup, dus ben ik dan niet terug bij af?

Je raakt niet alle data kwijt, maar als je in een live database data gaat verwijderen word ik altijd nerveus. Ik zorg er altijd voor en raad aan dat er een backup is: een typefout kan wel alles verwijderen...

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

Volgens mij doe ik het niet goed:

pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "START TRANSACTION;"
START TRANSACTION
pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_1 DROP NOT NULL;"
ALTER TABLE
pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN delivered_2 DROP NOT NULL;"
ALTER TABLE
pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_1 DROP NOT NULL;"
ALTER TABLE
pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN returned_2 DROP NOT NULL;"
ALTER TABLE
pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_delivered DROP NOT NULL;"
ALTER TABLE
pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "ALTER TABLE dsmr_consumption_electricityconsumption ALTER COLUMN currently_returned DROP NOT NULL;"
ALTER TABLE
pi@raspberrypi:[~] sudo docker exec -i dsmrdb psql -U dsmrreader dsmrreader -c "COMMIT;"                             
WARNING:  there is no transaction in progress
COMMIT

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

Uh. Hij heeft de aanpassingen in een keer succesvol doorgevoerd. De bedoeling was meer om

sudo docker exec -it dsmrdb psql -U dsmrreader dsmrreader 

te gebruiken om een command line te krijgen en ze daarin uit te voeren.

Het commando is correct uitgevoerd, dus je hoeft het niet opnieuw te doen...

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

Ah, bedankt. Heb voor de zekerheid de eerste reeks ALTER TABLE commando's nog een keer gedaan via die interface.

De DELETE actie lijkt alleen niet echt iets te doen daarna, klopt dat?

dsmrreader=# DELETE FROM dsmr_consumption_electricityconsumption WHERE delivered_1 IS NULL;
DELETE 0

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

Als het goed zou zijn, zou hij alle NULLs verwijderd moeten zijn, of zijn ze nog niet toegevoegd.
Je moet even wachten na het aanpassen van de tabel om het de tijd te geven.

@Tralapo
Copy link

Tralapo commented Feb 11, 2021

Ik had natuurlijk weer veel te veel haast. Heb de boel even opnieuw opgestart en de eerste reeks ALTER TABLE nogmaals gedaan.

Inmiddels, een paar minuutjes later, zie ik voor het eerst de hoeveelheid onverwerkte telegrammen omlaag gaan in plaats van omhoog! Van ruim 26000 stuks naar ruim 22000 stuks nu. Nog even geduld dus, maar er lijkt iets te gebeuren.

Update:
De DELETE leverde nu ook 5 resultaten op.
En inmiddels worden de dagstatistieken ook verwerkt!

Dat probleem is dus uit de weg! Ik kan zelf nog niet bevestigen of ik tussen 23:00 en 00:00 ook niet in de interface kan (niet getest), maar kans lijkt groot omdat ik wel vergelijkebare tijd-afwijkingen lijk te hebben.

@dennissiemensma
Copy link
Member

Dank voor jullie input, ik heb dan geen verdere ideeen meer waar het aan kan liggen qua 23:00-0:00.

Er is nu overigens een derde Docker-gebruiker die hetzelfde probleem heeft qua null-velden in #1288, dus ik ben heel benieuwd wat er in Docker of PostgreSQL gebeurd is met jullie dat dit plotseling speelt. Ik houdhet huidige issue wel voor "23:00-0:00" en zal de oplossing voor de null-velden in de andere zetten.

@8uurg
Copy link
Author

8uurg commented Feb 11, 2021

Nog een aanvulling: bij mij loopt hij nu ~600 readings achter, wat ongeveer overeen komt met 1 uur. Dit aantal loopt ook niet meer verder terug... /admin/dsmr_datalogger/meterstatistics/ en /admin/dsmr_datalogger/dsmrreading/ geven (in tegenstelling tot de database) ook de verkeerde tijd aan.

@Tralapo
Copy link

Tralapo commented Feb 13, 2021

Toch weer een kleine correctie/aanvulling hierop. 12.5 werkt goed als ik bijvoorbeeld de docker-compose-file wijzig van 12.4 naar 12.5 en dan docker-compose pull en docker-compose up -d doe. Dan lijkt alles goed te werken, zo had ik dat ook gecheckt voor de comment hierboven. Maar dat blijkt zo te zijn tót ik de Pi een keer reboot.

Dan ontstaat het andere issue weer, waarbij de containers van zowel DSMR als de DB eindeloos blijven herstarten. De log zegt dan dit (check ook de timestamps):

PostgreSQL Database directory appears to contain a database; Skipping initialization

1970-04-30 07:38:00.010 CET [1] LOG:  starting PostgreSQL 12.5 on arm-unknown-linux-musleabihf, compiled by gcc (Alpine 10.2.1_pre1) 10.2.1 20201203, 32-bit
1970-04-30 07:38:00.010 CET [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
1970-04-30 07:38:00.010 CET [1] LOG:  listening on IPv6 address "::", port 5432
1970-04-30 07:38:00.010 CET [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
1970-04-30 07:38:00.010 CET [1] LOG:  startup process (PID 21) was terminated by signal 11: Segmentation fault
1970-04-30 07:38:00.010 CET [1] LOG:  aborting startup due to startup process failure
1970-04-30 07:38:00.010 CET [1] LOG:  database system is shut down

De container blijft alleen niet eens lang genoeg online om de database te kunnen droppen (die mogelijk corrupt is geraakt) en een backup terug te zetten om te kijken wat er dan gebeurt.

Als ik dan alles verwijder, een nieuwe container maak op basis van postgres:12.4-alpine en de backup terugzet, dan blijft de boel draaien. Ook na een reboot van de Pi start alles dan weer normaal op zoals je mag verwachten.

Vreemd, maar postgres:12.4-alpine it is dus voorlopig. En vanaf nu blijf ik er voorlopig écht even vanaf.

@xirixiz
Copy link
Contributor

xirixiz commented Feb 13, 2021

Goede analyse heren, jammer dat ik niet veel bij heb kunnen dragen. Ik ben dit weekend helaas druk met andere zaken.

De DSMR image (latest) is gebaseerd op, dus het issue zit idd zoals eerder gedacht echt in de Alpine PG release.
Ik zal er iig een note van maken in de README voor nu.

bash-5.0# cat /etc/os-release
VERSION_ID=3.12.3
PRETTY_NAME="Alpine Linux v3.12"

@8uurg
Copy link
Author

8uurg commented Feb 18, 2021

Voor de mensen die afvragen wat er met de Alpine images mis is: ze zijn overgestapt naar 64 bits tijd. (Zie https://wiki.alpinelinux.org/wiki/Release_Notes_for_Alpine_3.13.0#time64_requirements)
Als je naar een nieuwere versie wil updaten, hierbij wat instructies!

Het probleem is echter dat een tussenlaag waar docker gebruik van maakt (libseccomp2) dit in de standaardversies voor de Raspberry Pi nog niet ondersteunt.

De standaarddistributie voor een Raspberry Pi is op Debian (Buster) gebaseerd, updaten van libseccomp2 naar een nieuwere versie die wel 64-bits tijd ondersteunt gaat dan als volgt.

  • De public keys van debian staan niet voorgeinstalleerd met een RPi, deze kun je als volgt installeren:
    sudo apt-key adv --keyserver keyserver.ubuntu.com --recv-keys 04EE7237B7D453EC
    sudo apt-key adv --keyserver keyserver.ubuntu.com --recv-keys 648ACFD622F3D138
    
  • Voeg vervolgens de buster-backports repository toe aan apt.
    • Open /etc/apt/sources.list in een tekstverwerker naar keuze:
      sudo nano /etc/apt/sources.list
      
    • Voeg de volgende regel toe aan de onderkant van het bestand:
      deb http://deb.debian.org/debian buster-backports main
      
  • Installeer libseccomp2 via buster-backports
    sudo apt update
    sudo apt install libseccomp2/buster-backports
    

Als het goed is zullen alle alpine images nu weer werken (incl. de nieuwe update van DSMR-reader!)


Wat betreft het tijdsverschil: dat verdwijnt als zowel DSMR-reader als de database binnen een Alpine Linux container draaien. Als je postgres:12 (of iets anders) gebruikt, is dit niet het geval.

@dennissiemensma dennissiemensma changed the title Server error tussen 23:00 en 00:00: LookupError: No electricity readings found for: 2021-02-11 ⚠️ Docker-DB timestamp issues - hour(s) offset (due to libseccomp2) Feb 18, 2021
@xirixiz
Copy link
Contributor

xirixiz commented Feb 25, 2021

Images based on Debian are now available (development tag). Please verify and let me know if eveything is working properly again so I can proceed and create a PR to the master branch and build new "production" releases.
https://hub.docker.com/r/xirixiz/dsmr-reader-docker/tags?page=1&ordering=last_updated&name=development-v4.12.0

@dennissiemensma
Copy link
Member

Thanks! Ik heb het toegevoegd aan de initiele tekst in dit issue.

@dennissiemensma
Copy link
Member

@8uurg @Tralapo zijn jullie toevallig binnenkort in de gelegenheid om dit te proberen en terug te koppelen of het werkt?

#1282 (comment)

@Tralapo
Copy link

Tralapo commented Feb 25, 2021

Ik heb vorige week naar aanleiding van de comment van @8uurg de libseccomp2 handmatig geüpdate en daarna kon ik gewoon weer switchen naar postgres:12-alpine en werkte alles weer zoals ik mag verwachten.

@martinvisser
Copy link

Na de upgrade naar v4.12 faalt de backup, omdat pg_dump nu ineens versie 11.10 heeft en de database postgres 12 is/was. Na een downgrade naar postgres 11.10 werkt de backup weer.
Ik draai ze in docker trouwens op een Raspberry Pi.

Heb dus handmatig een backup moeten maken van de database waar ik wel toegang had tot een pg_dump versie 12.

@mdr-github
Copy link

mdr-github commented Mar 15, 2021

Images based on Debian are now available (development tag). Please verify and let me know if eveything is working properly again so I can proceed and create a PR to the master branch and build new "production" releases.
https://hub.docker.com/r/xirixiz/dsmr-reader-docker/tags?page=1&ordering=last_updated&name=development-v4.12.0

Hallo, ik ben nieuw in dit topic (en zal me later uitgebreider introduceren) maar heb hetzelfde probleem met de docker image. Ik gebruik een remote datalogger op de P1 poort die de telegrammen via wifi doorstuurt. DSMR Reader draait in docker op mijn thuisserver (amd64, Debian 10 Buster, eigenlijk OpenMediaVault 5).

Het probleem is bij mij ook de timestaps van de telegrammen, die lopen 1 uur voor.

De datalogger en de server gebruiken NTP, die tijd loopt bij. In beide dockers dsmr en dsmrdb geeft commando date ook de juiste tijd aan. De log files van beide dockers hebben de juiste tijd. De web GUI van DSMR Reader geeft de juiste tijd aan in de header.

Maar onder "DSMR Meter statistics (read only)" toont de timestamp van het laatste telegram een tijd die een uur voor loopt. Vreemd genoeg doet de "live view" daar nog een schepje bovenop, die loopt 2 uur voor. Het lijkt fout te gaan met tijdzones en mogelijk DST.

Nav de genoemde oplossing heb ik de docker image aangepast naar image: xirixiz/dsmr-reader-docker:development-2021.03.02-amd64 en development-v4.12.0-amd64 om te testen. De stack (compose) aangepast in Portainer en opnieuw opgestart, maar dat lijkt het nog niet te hebben opgelost. Doe ik het verkeerd?

EDIT: problem solved, oplossing gevonden in een andere issue. In de dsmrdb container heb ik de regel met volume /etc/localtime:/etc/localtime:ro verwijderd en nu werkt het prima. Excuses.

@ronniebee
Copy link

Images based on Debian are now available (development tag). Please verify and let me know if eveything is working properly again so I can proceed and create a PR to the master branch and build new "production" releases.
https://hub.docker.com/r/xirixiz/dsmr-reader-docker/tags?page=1&ordering=last_updated&name=development-v4.12.0

Hallo, ik ben nieuw in dit topic (en zal me later uitgebreider introduceren) maar heb hetzelfde probleem met de docker image. Ik gebruik een remote datalogger op de P1 poort die de telegrammen via wifi doorstuurt. DSMR Reader draait in docker op mijn thuisserver (amd64, Debian 10 Buster, eigenlijk OpenMediaVault 5).

Het probleem is bij mij ook de timestaps van de telegrammen, die lopen 1 uur voor.

De datalogger en de server gebruiken NTP, die tijd loopt bij. In beide dockers dsmr en dsmrdb geeft commando date ook de juiste tijd aan. De log files van beide dockers hebben de juiste tijd. De web GUI van DSMR Reader geeft de juiste tijd aan in de header.

Maar onder "DSMR Meter statistics (read only)" toont de timestamp van het laatste telegram een tijd die een uur voor loopt. Vreemd genoeg doet de "live view" daar nog een schepje bovenop, die loopt 2 uur voor. Het lijkt fout te gaan met tijdzones en mogelijk DST.

Nav de genoemde oplossing heb ik de docker image aangepast naar image: xirixiz/dsmr-reader-docker:development-2021.03.02-amd64 en development-v4.12.0-amd64 om te testen. De stack (compose) aangepast in Portainer en opnieuw opgestart, maar dat lijkt het nog niet te hebben opgelost. Doe ik het verkeerd?

EDIT: problem solved, oplossing gevonden in een andere issue. In de dsmrdb container heb ik de regel met volume /etc/localtime:/etc/localtime:ro verwijderd en nu werkt het prima. Excuses.

yes.. het verwijderen van etc/local ... hielp.Geen idee wat ik heb gedaan maar ik krijg weer data binnen...

@xirixiz
Copy link
Contributor

xirixiz commented Mar 20, 2021

Ik heb de regel uit het docker-compose voorbeeld verwijderd, en daarnaast heb ik "common issues" opgenomen in de README en dit issue benoemd.

Overiges kan je nu ook gewoon weer deze tag/release gebruiken: xirixiz/dsmr-reader-docker

Goed werk verricht, daar hou ik van zelf ook gedegen onderzoek verrichten 👍 !

@ronniebee
Copy link

Ik heb de regel uit het docker-compose voorbeeld verwijderd, en daarnaast heb ik "common issues" opgenomen in de README en dit issue benoemd.

Overiges kan je nu ook gewoon weer deze tag/release gebruiken: xirixiz/dsmr-reader-docker

Goed werk verricht, daar hou ik van zelf ook gedegen onderzoek verrichten 👍 !

Hoi Bram, thx!!
7 uur aan het proberen geweest maar uiteindelijk gelukt :-).

groet,

Ronald

@dennissiemensma dennissiemensma changed the title ⚠️ Docker-DB timestamp issues - hour(s) offset (due to libseccomp2) ⚠️ Docker - Timestamp issues - Hour(s) offset (due to libseccomp2) Mar 20, 2021
@dennissiemensma dennissiemensma changed the title ⚠️ Docker - Timestamp issues - Hour(s) offset (due to libseccomp2) ⚠️ Docker only - Reading timestamp differences (1 or 2 hours off) Mar 30, 2021
@dennissiemensma dennissiemensma unpinned this issue Aug 12, 2021
@dennissiemensma dennissiemensma pinned this issue Jun 14, 2022
@marcovtr
Copy link

Uh. Hij heeft de aanpassingen in een keer succesvol doorgevoerd. De bedoeling was meer om

sudo docker exec -it dsmrdb psql -U dsmrreader dsmrreader 

te gebruiken om een command line te krijgen en ze daarin uit te voeren.

Het commando is correct uitgevoerd, dus je hoeft het niet opnieuw te doen...

Ik probeer dit command uit te voeren maar krijg deze fout melding
psql: error: connection to server on socket "/run/postgresql/.s.PGSQL.5432" failed: No such file or directory
Is the server running locally and accepting connections on that socket?
Mijn harde schijf is gecrasht heb een backup terug gezet op een nieuwe schijf maar nu heb ik een paar null regels die ik er niet uit krijg.
Ik ben hier nog maar een beginner mee. kan mij iemand helpen?

@dennissiemensma
Copy link
Member

@marcovtr je kunt het beste even een nieuw issue openen en vermelden wat je allemaal gebruikt

@dsmrreader dsmrreader locked and limited conversation to collaborators Oct 31, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

9 participants