Eenduidige tijdzones voor back-ups in Docker

[remb0]

Jouw omgeving

Ik draai de laatste versie van dsmr via de docker van xirixiz.

Bug, wens of iets anders

ik maakte iedere dag een automatische backup en deze werd dan ook op mijn dropbox geschreven. Nu heb ik alleen mijn docker aangepast dat de backup voortaan gezet wordt op:
/home/remb0/Docker/dsmr_backups
en in de container beschikbaar via: /dsmr/backups

de backups worden nu nog steeds wel gemaakt in de juiste folder alleen dropbox is hierna niet meer geupdate. Ik heb alleen geen idee waar ik moet kijken of wat ik moet wijzigen.
iemand een tip?

[dennissiemensma]

Je zou in de logs van dsmr_backend kunnen kijken. Daarvoor zul je wel het logging level moeten aanpassen. In de docs staat een howto, alleen heb ik niet zo snel een link voor je. Het staat onder kopje troubleshooting dacht ik. 

[remb0]

thanks dat ga ik proberen!

[dennissiemensma]

Heb je hier inmiddels meer duidelijkheid over gevonden?

[remb0]

Ik ben pas morgen thuis van vakantie, dus ga er van de week zeker mee aan de slag.

[jorkzijlstra]

Hoi Ik heb exact hetzelfde probleem en ik dacht dat #588 hiervan de oorzaak zou zijn, maar heb dit zelf ook nog niet geverifieerd.

[voipmeister]

Bij deze de link nog voor het aanpassen van het log level: https://dsmr-reader.readthedocs.io/en/latest/troubleshooting.html#logging

[dennissiemensma]

@remb0 heb je hier nog een update over?

[jorkzijlstra]

@dennissiemensma Ik heb de laatste docker container (v2.0.2) net gedeployed en zou morgen dus moeten weten of je fix werkt.

[remb0]

Ik ga morgen proberen mijn docker-compose te updaten (weet nog niet hoe) en dan te testen.
mijn plan: Dockers updaten, logging verhogen, testen.

[jorkzijlstra]

@remb0 Als je de latest tag gebruikt moet je een 'docker pull' gebruiken (in de folder van docker-compose.yaml) om de laatste versie van de tag latest binnen te halen. Anders moet het het versie nummer updaten naar v2.0.2.

Om de logging te verhogen moet je inloggen in de container en met vi de logging aanpassen. De logging op DEBUG zetten heb ik nog niet voor elkaar gekregen omdat je ook nog './post-deploy.sh' moet uitvoeren volgens de handleiding. Echter binnen de docker dontainer is er geen virtualenv beschikbaar en dit script zal dus falen.

[remb0]

thanks Jork weet wat geleerd. ik heb latest in de compose gezet en vervolgens docker compose up -d.
ik draai nu 2.0.2 :)

[xirixiz]

Goedemorgen, zelf heb ik in het verleden ook Dropbox backups gemaakt. Ik zal het aanzetten, uitzoeken en terugkoppelen wat er mis gaat en/of de oplossing is.

[jorkzijlstra]

Inmiddels zijn we een dag verder en de backup is niet geupload naar Dropbox.

@dennissiemensma wat doet de './post-deploy.sh' om de debug logging aan te zetten? De settings aan te passen en de container herstarten lijkt namelijk niet genoeg te zijn. Ik blijf alleen INFO logging zien

[xirixiz]

Je kan logging tijdelijk op debug zetten op een draaiende container, maar misschien is het handig dat je het mee kan geven als environment variable bij het starten van de Docker container. Ik zal dat ergens komende week opnemen in een nieuwe release.

Je kan iig altijd op je draaiende container inloggen met docker exec -ti <naam container> bash, de handleiding volgen voor het aanpassen van het loglevel (pad in Docker is /dsmr/dsmrreader/settings.py), en de container herstarten (zonder te verwijderen).

[jorkzijlstra]

Hoi @xirixiz,

Dit is exact wat ik het gedaan. De settings.py aangepast en de container herstart. Er komen echter alleen maar INFO loggin the de stdout (docker logs) en the log-dsmrreader.log blijft leeg. Zelf na de herstart gechecked of the log regel nog steeds niet in comment staat en dat is het geval.

De docker logs tonen alleen:

2019-05-05 18:09:48,810 INFO exited: dsmr_mqtt (exit status 1; not expected)
2019-05-05 18:09:48,896 INFO spawned: 'dsmr_mqtt' with pid 99
2019-05-05 18:09:50,350 INFO success: dsmr_mqtt entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

[jorkzijlstra]

Een environmental variable voor de LOGLEVEL zou idd wel een uitkomst zijn.

[jorkzijlstra]

Ik denk dat ik weet wat er bij mij lokaal aan de hand is. Wanneer ik een touch uitvoer (net om 20:23 uitgevoerd) op de backup bestanden krijg ik

Binnen de admin is de output:

Nu komt ik in de config django config TIME_ZONE = 'Europe/Amsterdam' tegen terwijl mijn system dus op UTC draait.
Het issue is nu dus dat de backup bestanden aangemaak worden met een modify date van voor de vorige sync (2 uur in het verleden) vanwege de timezone settings.

[dennissiemensma]

• ./post-deploy.shherlaadt de applicatie en past daarmee de settings opnieuw toe. Je kunt het ook handmatig doen door de Supervisor-processen te herstarten.
• Wat betreft je laatste comment, mogelijk is het dan gerelateerd aan Dropbox synchronisatie werkt alleen de eerste keer #588, hoewel ik het niet kon reproduceren qua checks. De tijdzones zouden niet moeten uitmaken.

[jorkzijlstra]

@dennissiemensma dan kijken we even verder. Is er manier om de dropbox upload handmatig te triggeren? Zodat het uurlijkse testen / debuggen wat sneller kan verlopen

[dennissiemensma]

sudo su - postgres
psql dsmrreader
update dsmr_backup_backupsettings set latest_backup = NOW() - INTERVAL '1 DAY';
update dsmr_backup_dropboxsettings set latest_sync =  NOW() - INTERVAL '1 DAY', next_sync = NOW();

Wellicht dat je de tweede query beter pas kan doen wanneer de backup daadwerkelijk gemaakt is. Kwestie van proberen.

[dennissiemensma]

In de toekomst ga ik overigens dit soort dingen in de admin interface mogelijk maken, want ik loop al een tijdje tegen dit soort beperkingen aan. Maar daarvoor moet ik eea herschrijven/handmatig maken qua admin-beheer.

[jorkzijlstra]

Ik heb die dropbox logregel uit #588 toegevoegd en dit is de output daarvan:

logger.info('DROPBOX - File: %s has not changed (last-sync: %s, file: %s)', file_path, dropbox_settings.latest_sync, last_modified)

[2019-05-05 18:46:35,349] INFO     DROPBOX - File: /dsmr/dsmrreader/../backups/dsmrreader-postgresql-backup-Tuesday.sql.gz has not changed (last-sync: 2019-05-05 17:46:34.535191+00:00, file: 2019-05-05 18:23:11.972953+02:00)
[2019-05-05 18:46:35,352] INFO     DROPBOX - File: /dsmr/dsmrreader/../backups/dsmrreader-postgresql-backup-Sunday.sql.gz has not changed (last-sync: 2019-05-05 17:46:34.535191+00:00, file: 2019-05-05 18:23:11.972953+02:00)
[2019-05-05 18:46:35,356] INFO     DROPBOX - File: /dsmr/dsmrreader/../backups/dsmrreader-postgresql-backup-Wednesday.sql.gz has not changed (last-sync: 2019-05-05 17:46:34.535191+00:00, file: 2019-05-05 18:23:11.972953+02:00)
[2019-05-05 18:46:35,358] INFO     DROPBOX - File: /dsmr/dsmrreader/../backups/dsmrreader-postgresql-backup-Friday.sql.gz has not changed (last-sync: 2019-05-05 17:46:34.535191+00:00, file: 2019-05-05 18:23:11.972953+02:00)
[2019-05-05 18:46:35,362] INFO     DROPBOX - File: /dsmr/dsmrreader/../backups/dsmrreader-postgresql-backup-Monday.sql.gz has not changed (last-sync: 2019-05-05 17:46:34.535191+00:00, file: 2019-05-05 18:23:11.972953+02:00)
[2019-05-05 18:46:35,365] INFO     DROPBOX - File: /dsmr/dsmrreader/../backups/dsmrreader-postgresql-backup-Saturday.sql.gz has not changed (last-sync: 2019-05-05 17:46:34.535191+00:00, file: 2019-05-05 18:23:11.972953+02:00)
[2019-05-05 18:46:35,368] INFO     DROPBOX - File: /dsmr/dsmrreader/../backups/dsmrreader-postgresql-backup-Thursday.sql.gz has not changed (last-sync: 2019-05-05 17:46:34.535191+00:00, file: 2019-05-05 18:23:11.972953+02:00)

[dennissiemensma]

Precies, dus als ik het goed lees dan "klopt" dat dus, omdat Pythen in beide datetimes gewoon de tijdzones heeft. En dat zou die zelf moeten omrekenen. Dus voor de 'file:' is dat simpelweg de tijd -2 uur en dan lijkt die het inderdaad al gesynced te hebben.

Je kunt nog kijken of een alternatief nog werkt. Hierbij wordt alles omgezet naar de lokale tijd:
e9894a5#diff-efd6703de198519a8ad0e38a347dd660
Je hoeft alleen de drie regels uit dsmr_backup/services/dropbox.py te wijzigen en de applicatie te herladen dan.

[jorkzijlstra]

@dennissiemensma De backup zijn in ieder geval een keer geupload

De stappen die ik heb gedaan:

• fix toegepast
• update qry uitvoeren met sync now()

[dennissiemensma]

Dus begrijp ik het goed dat het omzetten naar lokale tijd wel degelijk een verschil maakt voor jou?

[jorkzijlstra]

Idd het omzetten naar de localtime zorgt er voor dat de upload id gaan werken

[MarsWarrior]

Leuk probleem om uit te zoeken, maar dit is toch een tijdscyn probleem dat je eenvoudig kunt oplossen?

• Server via NTP syncen
• Docker containers via volume binds die je toevoegt aan elke docker container. Ik heb de volgende volumes gekoppeld aan dsmr (en ook aan de postgres database overigens):
  volumes:
  - /etc/timezone:/etc/timezone:ro
  - /etc/localtime:/etc/localtime:ro

Daarmee gebruikt de docker container dus de instellingen van de host!

[jorkzijlstra]

@MarsWarrior zie de docker-compose file in de vorige comment. Die volume mappings staan er in. Binnen de containers zijn de timezones dan ook hetzelfde als de host server (mits tzdata is geinstalleerd). De hostserver staat ingesteld op UTC en Django op Europe/Amsterdam wat dus problemen lijkt te veroorzaken.

Het issue lijkt dan ook te zijn dat de Django code een locale heeft van GMT+2 en daarmee dan ook de UTC datum uitleest. Hierdoor krijgt de data dus een verkeerde offset van 2 uur extra. Gezien de sync elk uur loopt is de backup ineens van voor de laatste sync en wordt deze dus niet geupload.

[MarsWarrior]

Ah!

Dat had ik over het hoofd gezien 😄

[jorkzijlstra]

@dennis ik heb mijn server inmiddels op gmt+2 ingesteld maar zag nog steeds geen backups.

Ik ben komende week alleen niet thuis en kan niet verder debuggen. Daarna zal ik wel weer kunnen kijken.

[xirixiz]

@jorkzijlstra het zou wellicht een oplossing kunnen zijn wanneer ik het tzdata package toevoeg aan de image. Ik zal een test image bouwen en die op de hub plaatsen, dan kan je kijken of dat het issue verhelpt.

[jorkzijlstra]

Hoi Bram,

Als het goed staat er een pr voor open. Ik draai zelf dus al wel met tzdata.

Grt, jork

[xirixiz]

Ik zag het nu pas, ik heb mail gemist dat er een pr klaar stond. Ik ben de image iig aan het bijwerken nu, die zal over een uurtje beschikbaar zijn ongeveer.

Bedankt voor de bijdrage @jorkzijlstra !

[dennis]

@dennis ik heb mijn server inmiddels op gmt+2 ingesteld maar zag nog steeds geen backups.

Please dont use @dennis unless you want me to be notified, @jorkzijlstra :)

[dennissiemensma]

Bedankt voor jullie berichten. Ik kon helaas niet eerder reageren dan nu.

Zoals aangegeven zal ik kijken of ik komende tijd even een momentje kan pakken om dit zelf te reproduceren met Docker en het lokaal kan oplossen. Ik heb het idee dat het namelijk iets heel kleins is uiteindelijk. Tot zover heb ik er dus nog niet inhoudelijk naar gekeken.

[xirixiz]

For both the DSMR and DSMRDB container I've added the following:

    volumes:
    - /etc/localtime:/etc/localtime:ro

    environment:
      - TZ=Europe/Amsterdam

As tzdata is now part of the Docker image the Dropbox backups are working fine for me (host CEST).
Maybe you can try TZ=UTC-2 or something?

[jorkzijlstra]

Heren,

Uiteindelijk heb ik het nu werkend gekregen. Het zijn een aantal settings / issues die het probleem veroorzaken.

@xirixiz de TZ environmental variable werkt niet op de ARM based images (zie bijvoorbeeld: gliderlabs/docker-alpine#310). Wanneer je de TZ toevoegd gaat de docker instantie juist op UTC draaien terwijl op de X86 image dit wel werkt.

@dennissiemensma Zelf ben ik gewend om met het werken van datums altijd terug te gaan naar UTC of epoch en voor display purpose only eventueel een conversie naar een tijdzone te doen. Misschien handig om gewoon in de documentatie op te nemen dat de software vereist om in tijdzone Europe/Amsterdam te draaien?

De fixen die ik dus heb toegepast is:

• run laatste image (tzdata installed)
• configure host server to run on Europe/Amsterdam
• Use following docker-compose:

version: '3.6'

services:
  dsmrdb:
    image: postgres:10.5-alpine
    command: postgres -c config_file=/etc/postgresql.conf
    container_name: dsmrdb
    restart: always
    volumes:
      - ./postgresql.conf:/etc/postgresql.conf
      - /home/rock/dsmr-reader/dsmrdb:/var/lib/postgresql/data
      - /home/rock/dsmr-reader/dsmr_backups:/dsmr/backups
      - /etc/localtime:/etc/localtime:ro 
      - /etc/timezone:/etc/timezone:ro 
    environment:
      - POSTGRES_USER=dsmrreader
      - POSTGRES_PASSWORD=dsmrreader
      - POSTGRES_DB=dsmrreader
      - TZ=Europe/Amsterdam
      - PGTZ=Europe/Amsterdam
    ports:
       - 5433:5432
    
  dsmr:
#    build: .
    image: xirixiz/dsmr-reader-docker:arm64v8-latest 
    container_name: dsmr
    depends_on:
      - dsmrdb
    cap_add:
      - NET_ADMIN    
    links:
      - dsmrdb
    restart: always
    volumes:
      - /home/rock/dsmr-reader/dsmrdb:/var/lib/postgresql/data
      - /home/rock/dsmr-reader/dsmr_backups:/dsmr/backups
      - /etc/localtime:/etc/localtime:ro
      - /etc/timezone:/etc/timezone:ro
      - /tmp:/tmp
    environment:
      - DB_HOST=dsmrdb
      - DSMR_USER=
      - DSMR_EMAIL=root@localhost
      - DSMR_PASSWORD=
      - VIRTUAL_HOST=localhost
    ports:
      - 8080:80
    devices:
      - /dev/ttyUSB0:/dev/ttyUSB0

[dennissiemensma]

Er is net ook een ander issue gemeld over hetzelfde probleem, wat mogelijk niet gerelateerd is aan Docker. Als dat zo is dan kan ik het mogelijk wat makkelijker reproduceren en oplossen. Mits het hetzelfde probleem is.

[dennissiemensma]

Is er trouwens een kant en klare config voor Docker die ik kan proberen? Ik lijk een configfile te missen, want ik krijg:

dsmrdb    | 2019-06-11 19:14:53.144 GMT [1] LOG:  input in flex scanner failed at file "/etc/postgresql.conf" line 1
dsmrdb    | 2019-06-11 19:14:53.144 GMT [1] FATAL:  configuration file "/etc/postgresql.conf" contains errors

[jorkzijlstra]

@dennissiemensma

Ik heb een postgres aanpassing gedaan (timezone toegevoegd), vandaar dat ik een eigen postgresql.conf heb geinclude. Je kan eventueel ook de postgresql.conf regel uit de docker-compose.yaml halen.

Hierbij de docker-compose met de custom postgressq.conf
dsmr.zip

Vergeet niet de image naam aan te passen naar de processor voor jouw systeem.

[RezzZ]

Issue #657 heb ik gesloten, was idd ook een backup probleem met docker. Helaas geen recente backup die ik kan herstellen dus moet even opnieuw beginnen. Tijd om mijn backups beter te regelen

[dennissiemensma]

@jorkzijlstra bedankt, nu krijg ik hem wel draaiende. Alleen zodra ik mijn ontwikkelomgeving op mijn host probeer te mounten/mirroren in de container, werkt de database niet meer. Ik heb te weinig kaas gegeten van deze setup.

Wellicht is het dan toch handiger om voor nu dan maar TIME_ZONE in dsmrreader/settings.py op te nemen (te overschrijven) met een werkende waarde. Mits dat het voor jullie oplost. Die file staat verder niet onder versiebeheer namelijk en kan vrij aangepast worden bij provisioning. Dan laat ik het verder nu voor wat het is, voor Docker.

Zoals @RezzZ al aangeeft was zijn probleem namelijk achteraf ook in de Docker-variant.

[jorkzijlstra]

@dennissiemensma bedankt voor het checken / proberen.

De oplossing die werkt heb ik hierboven beschreven in het eerdere comment comment. De backups worden nu netjes elke nacht geupload. Het komt er op neer dat alles gewoon in tijdzone Europe/Amsterdam moet draaien.

Ik probeer zo min mogelijk settings te wijzigen in de container. Deze moet je namelijk bij elke docker image aanpassing allemaal opnieuw doen.
Mocht iemand dus de dsmrreader/settings.py willen aanpassen dan adviseer ik dit bestand te kopieren, aan te passen en als volume mapping te injecten.

Ik heb bijvoorbeeld /tmp ook toegevoegd zodat de logs niet bij elke herstart verdwijnen.

Zoals ik al aangaf is het misschien veel handiger om in de documentatie op te nemen dat de software als vereiste heeft om in de tijdzone Europe/Amsterdam te draaien. DSMR staat niet voor niets voor "Dutch Smart Meter Requirements" en het is dus ook logisch om in deze tijdzone te draaien.

Heel erg bedankt voor je tijd.

[xirixiz]

Goed werk allemaal en zoals ik al aan heb gegeven ga ik nog opnemen dat de TIME_ZONE als variabele kan worden meegegeven bij het starten van de container, zodat die wordt geïnjecteerd in de settings.py file. Ik heb het vrij druk momenteel, maar zal het proberen ergens deze week in te bouwen.

[dennissiemensma]

De tijdzone binnen DSMR-reader staat overigens standaard op Europe/Amsterdam: https://github.com/dennissiemensma/dsmr-reader/blob/master/dsmrreader/config/base.py#L123

Dus als dat goed is, dan hoeft daar niets voor te wijzigen bedenk ik me net. Dan zou het alleen nog een instelling zijn binnen de PostgreSQL container, die geprovisioned moet worden.

[jorkzijlstra]

Ik heb inderdaad niks aangepast in de settings.py. Alleen in de docker-compose.yaml TZ en PGTZ op de database toegevoegd om Postgress op Europe/Amsterdam te krijgen.

Uiteindelijk heb ik dus geen wijzigingen gedaan in jouw code om het werkend te krijgen.

[dennissiemensma]

Top, in dat geval laat ik dit (voorlopig) voor wat het is.

Voor Docker-installaties verwijs ik eigenlijk al helemaal naar derden-projecten, dus ik zal daar voor nu geen wijzigingen in doen. Helemaal wanneer nieuwe versies van de Docker-containers de tijdzone al goed meegeven.

https://dsmr-reader.readthedocs.io/en/latest/installation/docker.html

[dennissiemensma]

Ter info, in de volgende release komt er ook een refactoring mee voor de Dropbox-sync.

Voortaan kijkt de applicatie niet meer naar de tijden, maar maakt een hash van de inhoud van elk bestand en vergelijkt die met Dropbox. Als die afwijkt, uploadt de applicatie het bestand. Dit moet dergelijke issues met tijdzones ook oplossen en is tevens effectiever.