dsmr_webinterface draait niet meer

[Jasper-GIT]

Hoi Dennis,

Afgelopen zaterdag had ik problemen met de upgrade naar 4.10 op mijn Rapsberry Pi3 B+, dit ging moeizaam maar uiteindelijk met je hulp werkend gekregen. Nu loop ik tegen een nieuw probleem aan:

pi@raspberrypi:/home/dsmr $ sudo supervisorctl status
dsmr_backend                     RUNNING   pid 2620, uptime 0:07:02
dsmr_datalogger                  RUNNING   pid 2619, uptime 0:07:02
dsmr_webinterface                FATAL     Exited too quickly (process log may have details)

In de Log van de webinterface staat het volgende:

[2021-01-18 07:33:05 +0100] [3587] [INFO] Starting gunicorn 20.0.4
Error: Already running on PID 695 (or pid file '/var/tmp/gunicorn--dsmr_webinterface.pid' is stale)

Ook is mijn Pi sinds zaterdag zo traag geworden, dat de webinterface toen hij nog werkte ongeveer 30 seconden tot 1 minuut duurde om te laden.
in top zie ik dat de CPU load van postgres enorm is. Zijn er 2!

  PID      USER       PR  NI     VIRT    RES     SHR   S    %CPU   %MEM     TIME+ COMMAND
 2023    postgres     20   0     203080  22984  17800  R    39,6   2,4      6:19.55 postgres
 2648    postgres     20   0     200892  23176  18584  D    25,1   2,4      1:23.17 postgres

Wat gaat er nog mis?

[dennissiemensma]

Je kunt de Error: Already running on PID 695 (or pid file '/var/tmp/gunicorn--dsmr_webinterface.pid' is stale) melding oplossen met:
https://dsmr-reader.readthedocs.io/en/latest/faq.html#how-do-i-fix-error-already-running-on-pid-1234

---

Wat betreft dubbele postgres processen, wellicht kun je wat meer details zien met: ps faux | grep postgres. PostgreSQL geeft namelijk dan aardig wat extra info per proces. Voorbeeld:

postgres 20321  0.0  1.1 204036 22208 ?        S     2020   8:32 /usr/lib/postgresql/11/bin/postgres -D /var/lib/postgresql/11/main -c config_file=/etc/postgresql/11/main/postgresql.conf
postgres 20325  0.0  5.1 204160 97932 ?        Ss    2020   4:28  \_ postgres: 11/main: checkpointer   
postgres 20326  0.0  0.4 204036  9444 ?        Ss    2020   2:13  \_ postgres: 11/main: background writer   
postgres 20327  0.0  0.4 204036  8216 ?        Ss    2020  23:34  \_ postgres: 11/main: walwriter   
postgres 20328  0.0  0.3 204444  6312 ?        Ss    2020   2:51  \_ postgres: 11/main: autovacuum launcher   
postgres 20329  0.0  0.1  61444  3708 ?        Ss    2020  11:07  \_ postgres: 11/main: stats collector   
postgres 20330  0.0  0.2 204332  5368 ?        Ss    2020   0:05  \_ postgres: 11/main: logical replication launcher   
postgres 29403  0.0  1.0 205688 19640 ?        Ss   Jan17   0:00  \_ postgres: 11/main: dsmrreader dsmrreader ::1(46064) idle
postgres 28103  0.0  0.8 205112 16084 ?        Ss   17:49   0:00  \_ postgres: 11/main: dsmrreader dsmrreader ::1(37980) idle
postgres 28210  0.1  0.9 205176 18176 ?        Ss   17:52   0:00  \_ postgres: 11/main: dsmrreader dsmrreader ::1(38020) idle

---

Verder kan het zijn dat DSMR-reader bezig is om met terugwerkende kracht retentie door te voeren en oude gegevens op te schonen. Dat is het eerste wat in mij opkomt.

Je kunt kijken of retentie in de configuratie aan staat. En zo ja, kijken hoever die is door deze queries uit te voeren: #1071 (comment)

[Jasper-GIT]

Dit geeft ps faux | grep postgres terug, de laatste is niet idle, maar staat op SELECT.

pi@raspberrypi:~ $ ps faux | grep postgres
pi        5740  0.0  0.0   4368   544 pts/1    S+   19:29   0:00              \_ grep --color=auto postgres
postgres   502  0.0  1.7 196236 16936 ?        S    14:56   0:01 /usr/lib/postgresql/9.6/bin/postgres -D /var/lib/postgresql/9.6/main -c config_file=/etc/postgresql/9.6/main/postgresql.conf
postgres   566  0.0 10.9 196236 103920 ?       Ss   14:56   0:05  \_ postgres: 9.6/main: checkpointer process
postgres   567  0.0  0.3 196236  3716 ?        Ss   14:56   0:00  \_ postgres: 9.6/main: writer process
postgres   568  0.0  0.7 196236  7044 ?        Ss   14:56   0:02  \_ postgres: 9.6/main: wal writer process
postgres   570  0.0  0.5 196672  4904 ?        Ss   14:56   0:00  \_ postgres: 9.6/main: autovacuum launcher process
postgres   572  0.0  0.2  53592  2580 ?        Ss   14:56   0:03  \_ postgres: 9.6/main: stats collector process
postgres  2756  0.0  1.6 197788 15512 ?        Ss   16:31   0:00  \_ postgres: 9.6/main: dsmrreader dsmrreader ::1(51590) idle
postgres  5230  0.3  1.7 197264 17052 ?        Ss   19:00   0:05  \_ postgres: 9.6/main: dsmrreader dsmrreader ::1(35680) idle
postgres  5325 29.2 14.8 203616 140480 ?       Ds   19:05   7:04  \_ postgres: 9.6/main: dsmrreader dsmrreader ::1(36972) SELECT

Het uitvoeren van de queries gaat niet helemaal top: De eerste van de 3 krijg ik na 30 min nog geen output, de andere wel:

dsmrreader=# select date_trunc('month', read_at) as month, count(id) as total from dsmr_consumption_electricityconsumption group by month order by month desc;
         month          | total
------------------------+-------
 2021-01-01 00:00:00+01 | 22564
 2020-12-01 00:00:00+01 | 44640
 2020-11-01 00:00:00+01 | 37695
 2020-10-01 00:00:00+02 | 44700
 2020-09-01 00:00:00+02 | 42922
 2020-08-01 00:00:00+02 | 44640
 2020-07-01 00:00:00+02 | 27363
 2020-06-01 00:00:00+02 | 43200
 2020-05-01 00:00:00+02 | 44640
 2020-04-01 00:00:00+02 | 42500
 2020-03-01 00:00:00+01 | 39845
 2020-02-01 00:00:00+01 | 39199
 2020-01-01 00:00:00+01 | 43117
 2019-12-01 00:00:00+01 | 43419
 2019-11-01 00:00:00+01 | 33881
 2019-10-01 00:00:00+02 | 44225
 2019-09-01 00:00:00+02 | 43200
 2019-08-01 00:00:00+02 | 44640
 2019-07-01 00:00:00+02 | 44640
 2019-06-01 00:00:00+02 | 43195
 2019-05-01 00:00:00+02 | 44637
 2019-04-01 00:00:00+02 | 43200
 2019-03-01 00:00:00+01 | 32284
 2019-02-01 00:00:00+01 |  1344
 2019-01-01 00:00:00+01 |  1488
 2018-12-01 00:00:00+01 |   968
(26 rows)

dsmrreader=# select date_trunc('month', read_at) as month, count(id) as total from dsmr_consumption_gasconsumption group by month order by month desc;
         month          | total
------------------------+-------
 2021-01-01 00:00:00+01 |  4484
 2020-12-01 00:00:00+01 |  8793
 2020-11-01 00:00:00+01 |  7254
 2020-10-01 00:00:00+02 |  8482
 2020-09-01 00:00:00+02 |  8522
 2020-08-01 00:00:00+02 |  8805
 2020-07-01 00:00:00+02 |  5446
 2020-06-01 00:00:00+02 |  8504
 2020-05-01 00:00:00+02 |  8756
 2020-04-01 00:00:00+02 |  8340
 2020-03-01 00:00:00+01 |  8001
 2020-02-01 00:00:00+01 |  7989
 2020-01-01 00:00:00+01 |  8626
 2019-12-01 00:00:00+01 |  8773
 2019-11-01 00:00:00+01 |  6889
 2019-10-01 00:00:00+02 |  8785
 2019-09-01 00:00:00+02 |  8514
 2019-08-01 00:00:00+02 |  8801
 2019-07-01 00:00:00+02 |  8795
 2019-06-01 00:00:00+02 |  8554
 2019-05-01 00:00:00+02 |  8841
 2019-04-01 00:00:00+02 |  8523
 2019-03-01 00:00:00+01 |  6705
 2019-02-01 00:00:00+01 |  1344
 2019-01-01 00:00:00+01 |  1488
 2018-12-01 00:00:00+01 |   968
(26 rows)

[dennissiemensma]

Helder. Ik neem aan dat retentie wel ingeschakeld? Krijg je verder wel nieuwe data op je dashboard, ondanks dat die dan wellicht wat traag is?

Het opschonen zal steeds sneller gaan. Het belangrijkste is dat je gegevens blijven door lopen.

[Jasper-GIT]

sind net werkt mijn dashboard, retentie staat op een maand nu.
Het lijkt er op dat de gegevens wel doorlopen.. Grafieken lopen 25 minuten achter ongeveer.

wel zij dit de meldingen:
Ongeveer 39621400 metingen opgeslagen, overweeg dataopschoning (indien nog niet ingeschakeld) (nu)
Database groeit gestaag: 8384 MB, overweeg dataopschoning (indien nog niet ingeschakeld) (nu)
Proces loopt achter op schema: Generate consumption data (19 minuten geleden)
Te veel onverwerkte telegrammen: 133 (20 minuten geleden) Dit aantal is variabel

[dennissiemensma]

Dat verklaart een hoop! Je hebt bijna 40 miljoen metingen en vandaar dat de opschoning ook zo traag is.

Je kunt kijken of je de datalogger sleep in de configuratie wat hoger kan zetten, als die nu nog op 0,5 seconden staat. Anders blijft er veel data binnenkomen en dat helpt ook niet mee.

Zolang het aantal onverwerkte telegrammen blijft oplopen is het goed. Dat betekent dat ze wel opgeslagen zijn, maar nog niet verwerkt zijn. Verwerken kan met terugwerkende kracht. Houd het de komende uren of dagen even in de gaten.

[Jasper-GIT]

Dit is allemaal voor mij pas zichtbaar sinds V4.10. Daarvoor zag ik dit dus niet (of is me niet opgevallen), maar liep alles wel als een zonnetje.
Sinds deze update heeft hij het er moeilijk mee, ik schrok ook van zoveel data.
De sleep config had ik al op 10 gezet.

Opschoning gaat ook met terugwerkende kracht? Aangezien dit metingen zijn sinds eind 2018 en ik de retentie pas zaterdag aangezet heb, weet ik niet of hij dit ook allemaal op gaat schonen.

[dennissiemensma]

Klopt, het is inderdaad met terugwerkende kracht, daarom is het zo traag en intensief. Afhankelijk van de hardware kan het meerdere dagen duren. Zie bijvoorbeeld #1149.

Je kunt overigens zelf ervoor kiezen om retentie uit te zetten en alle gegevens te bewaren. Dit schaalt waarschijnlijk voor lange tijd prima, totdat je issues krijgt met schijfruimte of andere bijwerkingen.

[dennissiemensma]

@Jasper-GIT is het inmiddels gelukt en is je data verkleind?

[Jasper-GIT]

Hoi Dennis, De Pi is weer snel inmiddels en ik heb geen melding meer van grote hoeveelheden data.. Wel zie ik nog 1 melding en dat is deze: *Database groeit gestaag: 8402 MB, overweeg dataopschoning (indien nog niet ingeschakeld)* (*nu*) Groeten Jasper

[dennissiemensma]

@Jasper-GIT fijn!

Je kunt dit nog proberen. Hoef je maar eenmalig uit te voeren nu je dataopschoning weer 'bij' is:

sudo su - postgres
vacuumdb -f -v -z -d dsmrreader

Vermoedelijk gaat de laatste melding dan ook weg.

[Jasper-GIT]

Bedankt, Met je suggestie ook de laatste melding verdwenen! Groeten, Jasper Op do 11 feb. 2021 om 18:36 schreef Dennis Siemensma < [email protected]>:

…

Closed #1264 <#1264>. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#1264 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AA4AMOD2ZBB36VENCUWXGNDS6QIRDANCNFSM4WGZ7Z3A> .