Live weergave en live teller wijken af

[haijeploeg]

DSMR-reader is gemaakt om door jezelf te gebruiken en is daarom niet van buitenaf te debuggen. Daarom is het belangrijk dat je eerst deels zelf onderzoek doet en dat hieronder deelt (voor zover nodig). Dit helpt met het oplossen van jouw probleem.

https://dsmr-reader.readthedocs.io/nl/v3/troubleshooting.html

Wat gebruik je?

• DSMR-reader versie: 3.11
• Type RaspberryPi or server: RPI 3B
• Standaardinstallatie of Docker: Standaardinstallatie
• DSMR-protocol slimme meter v4/v5: v5

---

Sinds enkele dagen geleden startte de webinterface niet meer. Dit kwam omdat de socket blijkbaar niet goed was afgesloten en dus nog bekend was op het systeem. Alles gestopt en de sockets verwijderd die overbleven (web interface) daarna weer gestart en de web interface startte weer naar behoren. Echter, nu merk ik op dat de teller die bijhoud hoeveel er vandaag terug geleverd is niets laat zien. Terwijl de realtime counters laten zien dat er 0W wordt gebruikt en 1000W wordt terug geleverd. Daarnaast laat de livegrafiek ook geen teruglevering zien, terwijl dit wel echt aan de orde is.

Daarnaast valt me op dat de logging vol staat met errors, helaas zonder tijdsbepaling. Het gaat om de dsmr_backend logging.

Traceback (most recent call last):
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/urllib3/connectionpool.py", line 677, in urlopen
    chunked=chunked,
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/urllib3/connectionpool.py", line 381, in _make_request
    self._validate_conn(conn)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/urllib3/connectionpool.py", line 976, in _validate_conn
    conn.connect()
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/urllib3/connection.py", line 308, in connect
    conn = self._new_conn()
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/urllib3/connection.py", line 172, in _new_conn
    self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x7368d510>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/urllib3/connectionpool.py", line 725, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/urllib3/util/retry.py", line 439, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='data.buienradar.nl', port=443): Max retries exceeded with url: /2.0/feed/json (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7368d510>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/dsmr/dsmr-reader/dsmr_weather/services.py", line 37, in get_temperature_from_api
    response = requests.get(settings.DSMRREADER_BUIENRADAR_API_URL)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/requests/api.py", line 76, in get
    return request('get', url, params=params, **kwargs)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/requests/api.py", line 61, in request
    return session.request(method=method, url=url, **kwargs)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/requests/sessions.py", line 530, in request
    resp = self.send(prep, **send_kwargs)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/requests/sessions.py", line 643, in send
    r = adapter.send(request, **kwargs)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='data.buienradar.nl', port=443): Max retries exceeded with url: /2.0/feed/json (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7368d510>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/dsmr/dsmr-reader/dsmr_weather/services.py", line 20, in run
    temperature_reading = get_temperature_from_api()
  File "/home/dsmr/dsmr-reader/dsmr_weather/services.py", line 40, in get_temperature_from_api
    raise AssertionError(_('Failed to connect to or read from Buienradar API'))
AssertionError: Failed to connect to or read from Buienradar API
The current logging level only logs warnings and errors, to reduce I/O. More information can be found here: https://dsmr-reader.readthedocs.io/en/v3/troubleshooting.html#logging
[2020-06-22 15:29:04,566] ERROR    (OperationalError) dsmr_consumption.services.run errored: terminating connection due to administrator command
SSL connection has been closed unexpectedly

[2020-06-22 15:29:05,335] ERROR    dsmr_backend.management.commands.dsmr_backend: [!] Exception raised. Traceback (most recent call last):
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/utils.py", line 86, in _execute
    return self.cursor.execute(sql, params)
psycopg2.errors.AdminShutdown: terminating connection due to administrator command
SSL connection has been closed unexpectedly


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/dsmr/dsmr-reader/dsmr_backend/services/schedule.py", line 35, in execute_scheduled_processes
    current.execute()
  File "/home/dsmr/dsmr-reader/dsmr_backend/models/schedule.py", line 60, in execute
    return service(self)
  File "/home/dsmr/dsmr-reader/dsmr_consumption/services.py", line 28, in run
    for current_reading in DsmrReading.objects.unprocessed()[0:settings.DSMRREADER_COMPACT_MAX]:
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/query.py", line 276, in __iter__
    self._fetch_all()
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/query.py", line 1261, in _fetch_all
    self._result_cache = list(self._iterable_class(self))
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/query.py", line 57, in __iter__
    results = compiler.execute_sql(chunked_fetch=self.chunked_fetch, chunk_size=self.chunk_size)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 1152, in execute_sql
    cursor.execute(sql, params)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/utils.py", line 68, in execute
    return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/utils.py", line 77, in _execute_with_wrappers
    return executor(sql, params, many, context)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/utils.py", line 86, in _execute
    return self.cursor.execute(sql, params)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/utils.py", line 90, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/utils.py", line 86, in _execute
    return self.cursor.execute(sql, params)
django.db.utils.OperationalError: terminating connection due to administrator command
SSL connection has been closed unexpectedly


During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/base/base.py", line 238, in _cursor
    return self._prepare_cursor(self.create_cursor(name))
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/utils/asyncio.py", line 26, in inner
    return func(*args, **kwargs)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/postgresql/base.py", line 231, in create_cursor
    cursor = self.connection.cursor()
psycopg2.InterfaceError: connection already closed

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/dsmr/dsmr-reader/dsmr_backend/mixins.py", line 90, in run_once
    self.run(data=self.data, **options)
  File "/home/dsmr/dsmr-reader/dsmr_backend/management/commands/dsmr_backend.py", line 18, in run
    dsmr_backend.services.schedule.execute_scheduled_processes()  # Future
  File "/home/dsmr/dsmr-reader/dsmr_backend/services/schedule.py", line 45, in execute_scheduled_processes
    current.delay(timezone.timedelta(seconds=30))
  File "/home/dsmr/dsmr-reader/dsmr_backend/models/schedule.py", line 67, in delay
    self.reschedule(planned_at=timezone.now() + delta)
  File "/home/dsmr/dsmr-reader/dsmr_backend/models/schedule.py", line 71, in reschedule
    self.update(planned=planned_at)
  File "/home/dsmr/dsmr-reader/dsmr_backend/mixins.py", line 180, in update
    self.save(update_fields=updated_fields.keys())
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/base.py", line 746, in save
    force_update=force_update, update_fields=update_fields)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/base.py", line 784, in save_base
    force_update, using, update_fields,
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/base.py", line 865, in _save_table
    forced_update)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/base.py", line 917, in _do_update
    return filtered._update(values) > 0
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/query.py", line 771, in _update
    return query.get_compiler(self.db).execute_sql(CURSOR)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 1500, in execute_sql
    cursor = super().execute_sql(result_type)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 1150, in execute_sql
    cursor = self.connection.cursor()
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/utils/asyncio.py", line 26, in inner
    return func(*args, **kwargs)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/base/base.py", line 260, in cursor
    return self._cursor()
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/base/base.py", line 238, in _cursor
    return self._prepare_cursor(self.create_cursor(name))
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/utils.py", line 90, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/base/base.py", line 238, in _cursor
    return self._prepare_cursor(self.create_cursor(name))
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/utils/asyncio.py", line 26, in inner
    return func(*args, **kwargs)
  File "/home/dsmr/.virtualenvs/dsmrreader/lib/python3.7/site-packages/django/db/backends/postgresql/base.py", line 231, in create_cursor
    cursor = self.connection.cursor()
django.db.utils.InterfaceError: connection already closed

The current logging level only logs warnings and errors, to reduce I/O. More information can be found here: https://dsmr-reader.readthedocs.io/en/v3/troubleshooting.html#logging
The current logging level only logs warnings and errors, to reduce I/O. More information can be found here: https://dsmr-reader.readthedocs.io/en/v3/troubleshooting.html#logging

Heb dsmr gisteren nog geüpdatet. Daarnaast lijkt het er sterk op dat de tijd enkele uren achter loopt. Ik zie nu namelijk de waardes van 6 uur vanochtend, maar niet de huidige waardes van nu op dit moment (16:15u). Toen de webinterface niet meer startte was er voor 5 dagen geen data meer in de web interface, maar de backend stond wel aan, kan het zijn dat de applicatie alle niet verwerkte telegrammen nu aan het verwerken is? Waardoor ik nu geen realtime data meer zie in de interface? De load van de raspberry pi is namelijk ook vrij hoog.

[dennissiemensma]

Bedankt voor je melding. Ik denk dat je als eerste even op de Status-pagina moet kijken om te zien wat er aan de hand is. Als er een achterstand is in de verwerking, dan zul je dat daar ook terugzien. Je kunt aan de tijden in de grafiek ook goed zien dat het niet het huidige moment is en dat er (toen) geen teruglevering was midden in de nacht.

---

Qua performance is het mogelijk dat DSMR-reader de snelheid van je v5-meter niet aankan qua telegrammen. Dit is namelijk afhankelijk van zowel hardware en software en bij hoge load is dit (bij gebruikers met een v5-meter) meestal de oorzaak.

Je kunt eens proberen om de 'datalogger sleep' in de admin-interface onder datalogger-configuratie te verhogen naar bijvoorbeeld 5 of 10 seconden.
Hierdoor neemt DSMR-reader even een pauze na het uitlezen en dat helpt aanzienlijk in zowel de performance als de grootte van je (data)opslag. Voor het nauwkeurig uitlezen van je meterstand is namelijk enkele telegrammen per minuut al voldoende, ipv de standaard 60 per minuut van je meter. Daarnaast slijt je SD-kaart er ook (wat) minder snel door.

---

De foutmeldingen in de logs lijken op foutmeldingen die ooit hebben gespeeld met externe diensten, zoals Buienradar. Het is bekend dat die API er soms (kort) uitligt of niet reageert, maar dat is prima. DSMR-reader logt het en probeert het later nogmaals.
Als je die psycopg2 of DB-errors nog heel vaak krijgt, is het goed om even te kijken in de logs van PostgreSQL. Maar als het systeem het verder goed lijkt te doen is dat niet nodig. Zorg wel dat je regelmatig een backup buiten je SD-kaart maakt, want die gaan vroeg of laat stuk.

[dennissiemensma]

Ik zal trouwens verduidelijken in de interface dat de gegevens van de teller het laatste (onverwerkte) telegram is en de gegevens in de grafieken zijn de verwerkte gegevens. Als daar een achterstand in is, krijg je dus dit en dat is wat minder transparant.

[haijeploeg]

Hoi Dennis,

Bedankt voor je snelle reactie. Aan het tijdspad te zien is de data inmiddels weer bij met realtime. Wat mij echter wel opvalt is dat de applicatie ontzettend traag werkt nu, dit was tot een week geleden niet zo. Daarnaast kan ik de status pagina niet bereiken. Ik krijg hier contstant een 504 error. In de nginx logging vind ik dit:

2020/06/22 22:02:11 [error] 552#552: *1687 upstream timed out (110: Connection timed out) while reading response header from upstream, client: ip.add.rr.ess, server: host.example.com, request: "GET /status HTTP/1.1", upstream: "http://unix:///var/tmp/gunicorn--dsmr_webinterface.socket/status", host: "host.example.com"

Rond dat zelfde tijdstip zie ik ook contstant het volgende verschijnen in de dsmr_webinterface.log

[2020-06-22 21:59:04 +0200] [4233] [INFO] Booting worker with pid: 4233
[2020-06-22 22:03:13 +0200] [4227] [CRITICAL] WORKER TIMEOUT (pid:4233)

Ik heb nog de gunicorn timeout waarde geprobeerd op te hogen naar 120 seconden, maar dit mocht ook niet baten. Ik kan er maar niet achter komen waarom de applicatie het nu opeens zo druk heeft en een week geleden totaal niet. De load van de RPI staat gemiddeld op 2, en als top process zie ik postgresql contstant stampen. Komt dat omdat de database nu te groot aan het worden is?

Ik heb de datalogger sleep opgehoogd naar 10 seconden, maar hier merk ik tot dusver nog niets van in de performance.

Heb je dit toevallig eerder gezien? Ik heb alles al meerdere malen herstart, en heb ook nog eens deploy.sh uitgevoerd om zeker te zijn dat ik op de laatste versie zit.

[dennissiemensma]

Het kan zijn dat je dataset te groot is. Heb je de instellingen voor retentie ingeschakeld? Standaard bewaart DSMR-reader alle metingen, maar je kunt instellen dat die na een X-periode de metingen opschoont (uitgezonderd het Archief).
Je kunt dit inschakelen door even op 'retentie' te zoeken in de 'tussenpagina' voor configuratie (/configuration).

Om te zien of het echt de grootte is, kun je dit uitvoeren:

sudo su - postgres
psql dsmrreader

SELECT nspname || '.' || relname AS "relation",
    pg_size_pretty(pg_total_relation_size(C.oid)) AS "total_size"
  FROM pg_class C
  LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace)
  WHERE nspname NOT IN ('pg_catalog', 'information_schema')
    AND C.relkind <> 'i'
    AND nspname !~ '^pg_toast'
  ORDER BY pg_total_relation_size(C.oid) DESC
  LIMIT 20;

Ter vergelijking, mijn database met de kortste retentie:

                      relation                      | total_size 
----------------------------------------------------+------------
 public.dsmr_datalogger_dsmrreading                 | 48 MB
 public.dsmr_consumption_electricityconsumption     | 40 MB
 public.dsmr_stats_hourstatistics                   | 4368 kB
 public.dsmr_consumption_gasconsumption             | 4064 kB
 public.dsmr_weather_temperaturereading             | 3688 kB
 public.dsmr_stats_daystatistics                    | 336 kB
 public.dsmr_backend_scheduledprocess               | 120 kB
 public.django_admin_log                            | 88 kB
 public.django_session                              | 88 kB
 public.dsmr_backend_scheduledcall                  | 72 kB
 public.auth_user                                   | 64 kB
 public.dsmr_backup_dropboxsettings                 | 56 kB
 public.dsmr_notification_statusnotificationsetting | 56 kB
 public.auth_permission                             | 56 kB
 public.dsmr_consumption_energysupplierprice        | 40 kB
 public.django_content_type                         | 40 kB
 public.django_migrations                           | 40 kB
 public.dsmr_stats_note                             | 40 kB
 public.dsmr_backend_emailsettings                  | 32 kB
 public.dsmr_datalogger_meterstatistics             | 32 kB

Een database van honderden MB's tot een GB zal wel schalen op een SD-kaart. Maar als het (veel) meer is is denk ik (automatische) opschoning wel nodig. Zoals hierboven beschreven.

[haijeploeg]

Hoi Dennis,

Bedankt voor je antwoord! Was me niet bewust dat er een retentie optie was. Denk dat het probleem zich wel hierin vind :)

                    relation                    | total_size
------------------------------------------------+------------
 public.dsmr_datalogger_dsmrreading             | 3496 MB
 public.dsmr_consumption_electricityconsumption | 97 MB
 public.dsmr_consumption_gasconsumption         | 5184 kB
 public.dsmr_stats_hourstatistics               | 528 kB
 public.dsmr_weather_temperaturereading         | 440 kB
 public.dsmr_datalogger_meterstatistics         | 368 kB
 public.dsmr_backend_scheduledprocess           | 120 kB
 public.dsmr_stats_daystatistics                | 96 kB
 public.dsmr_frontend_notification              | 80 kB
 public.dsmr_backup_backupsettings              | 64 kB
 public.django_session                          | 64 kB
 public.django_admin_log                        | 64 kB
 public.django_migrations                       | 64 kB
 public.auth_user                               | 64 kB
 public.dsmr_stats_electricitystatistics        | 56 kB
 public.auth_permission                         | 56 kB
 public.dsmr_consumption_energysupplierprice    | 40 kB
 public.django_content_type                     | 40 kB
 public.dsmr_stats_note                         | 40 kB
 public.auth_user_groups                        | 32 kB

3.5GB aan metingen vind de PI waarschijnlijk niet heel leuk. Ik heb de retentie op een maand gezet, even kijken aankijken hoe dit gaat in de komende dagen.

[dennissiemensma]

Bedankt voor de update. Ik denk dat als je nu opnieuw kijkt dat er al flink opgeschoond is.

En anders kun je DEBUG-logging tijdelijk aanzetten en in de log van dsmr_backend kijken waar die momenteel is bij opschonen: https://dsmr-reader.readthedocs.io/en/latest/troubleshooting.html#logging

[haijeploeg]

Hoi Dennis,

Inmiddels is de pi weer helemaal bij en is de database opgeschoond! Bedankt voor je hulp!