Docker: (IntegrityError) null value in column "delivered_1" violates not-null constraint

[pcdiks]

Ik draai DSMR reader in docker.

Door een of andere reden is mijn database corrupt geraakt en ben ik daar pas na een paar dagen achter gekomen.
Uiteindelijk heb ik gewoon een nieuwe database container gemaakt en daarna een backup van de database terug gezet. Hiervoor het ik gebruik gemaakt van de documentatie over hoe een backup terug te zetten. Dit lijkt allemaal zonder problemen maar nu het ik de volgende twee meldingen in de 'Over' sectie:

• Te veel onverwerkte telegrammen: 11606 (3 dagen, 15 uur geleden)
• Dagstatistieken lopen achter (3 dagen, 19 uur geleden)

Na debugging aangezet te hebben zie ik in de logs soortgelijke regels voorbij komen:

[2021-02-11 19:43:03,247] ERROR    (IntegrityError) dsmr_consumption.services.run errored: null value in column "delivered_1" violates not-null constraint
DETAIL:  Failing row contains (168256, 2021-02-08 04:00:00+01, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null).

[2021-02-11 19:43:34,099] ERROR    (IntegrityError) dsmr_consumption.services.run errored: null value in column "delivered_1" violates not-null constraint
DETAIL:  Failing row contains (168257, 2021-02-08 04:00:00+01, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null).

[2021-02-11 19:44:04,708] ERROR    (IntegrityError) dsmr_consumption.services.run errored: null value in column "delivered_1" violates not-null constraint
DETAIL:  Failing row contains (168258, 2021-02-08 04:00:00+01, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null).

[2021-02-11 19:44:35,470] ERROR    (IntegrityError) dsmr_consumption.services.run errored: null value in column "delivered_1" violates not-null constraint
DETAIL:  Failing row contains (168259, 2021-02-08 04:00:00+01, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null).

Het vreemde is, dat er in de database geen regels te vinden zijn van na 2021-02-8 03:00:00 (toen is de backup gemaakt) maar pas weer vanaf 2021-02-10 11:17:51 tot aan nu toe.
De laatste regel van de import en de eerste nieuwe regel na de restore zijn deze twee:

913977 | 2021-02-08 03:00:12+01 | 17117.962 | 2330.864 | 12790.956 | 5567.440 | 0.383 | 0.000 | 2021-02-08 02:00:00+01 | 2136.173 | FALSE | 0.381 | NULL | NULL | 0.000 | NULL | NULL | NULL | NULL | NULL | 2 | NULL | NULL

913978 | 2021-02-10 11:17:51+01 | 17129.074 | 2330.864 | 12819.519 | 5567.718 | 0.000 | 0.149 | 2021-02-10 11:00:00+01 | 2178.713 | FALSE | 0.000 | NULL | NULL | 0.149 | NULL | NULL | NULL | NULL | NULL | 2 | NULL | NULL

Tussen deze twee regels zit dus geen data, die kan ik ook niet terug krijgen maar dat vind ik niet erg. Wel zou ik graag de foutmelding opgelost zien want nu werken de live grafieken en de dashboard niet goed.

[dennissiemensma]

Bedankt voor je melding! Je hebt geluk, in de zin dat er twee anderen zijn met exact hetzelfde probleem. Ik vraag me af waarom dit opeens massaal een issue is voor zoveel gebruikers.

Anyway, de oplossing staat hier, je zult zelf wat queries moeten uitvoeren: #1282 (comment)

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;

[dennissiemensma]

Voor nu sluit ik deze en pin ik deze. Dank voor jullie meldingen en de oplossingen. Ik kijk het even aan, want ik snap dus niet zo goed waarom de DB bij jullie opeens issues geeft.

[pcdiks]

Ok, die oplossing heeft geholpen maar ik heb nu nog de volgende melding in de logs:

[2021-02-11 20:22:47,296] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType' and 'decimal.Decimal'
[2021-02-11 20:23:17,666] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType' and 'decimal.Decimal'
[2021-02-11 20:23:48,731] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType' and 'decimal.Decimal'
[2021-02-11 20:24:19,888] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType' and 'decimal.Decimal'
[2021-02-11 20:24:50,863] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType' and 'decimal.Decimal'

Is daar ook een oplossing voor?

[dennissiemensma]

Staat er toevallig nog een stacktrace bij met een bestand of regelnummer?

[pcdiks]

Ja, nu je het zegt staat er een stacktrace voor:

[2021-02-11 20:18:12,461] ERROR    No recent gas reading found
Traceback (most recent call last):
  File "/dsmr/dsmr_mindergas/services.py", line 66, in export
    last_gas_reading = GasConsumption.objects.filter(
  File "/usr/local/lib/python3.9/site-packages/django/db/models/query.py", line 325, in __getitem__
    return qs._result_cache[0]
IndexError: list index out of range

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/dsmr/dsmr_mindergas/services.py", line 32, in run
    export()
  File "/dsmr/dsmr_mindergas/services.py", line 71, in export
    raise AssertionError(_('No recent gas reading found'))
AssertionError: No recent gas reading found
[2021-02-11 20:22:47,296] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType' and 'decimal.Decimal'
[2021-02-11 20:23:17,666] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType' and 'decimal.Decimal'

[dennissiemensma]

Ik denk dat dit zichzelf oplost na middernacht straks. Het systeem kan geen gasmeting vinden van gisteravond voor upload naar MinderGas.

[pcdiks]

Goeiemorgen, het probleem is er nog steeds. Op de 'Over & ondersteuning' pagina zie ik nog steeds twee problemen:

• Te veel onverwerkte telegrammen: 361 (11 seconden geleden)
• Dagstatistieken lopen achter (4 dagen, 8 uur geleden)

De meest recente trace melding is deze:
[2021-02-11 20:17:20,474] ERROR    (IntegrityError) dsmr_consumption.services.run errored: null value in column "currently_re
DETAIL:  Failing row contains (168323, 2021-02-08 04:00:00+01, null, null, null, null, null, null, null, null, null, null, nu
                                                                                                                             
[2021-02-11 20:18:12,461] ERROR    No recent gas reading found                                                               
Traceback (most recent call last):                                                                                           
  File "/dsmr/dsmr_mindergas/services.py", line 66, in export                                                                
    last_gas_reading = GasConsumption.objects.filter(                                                                        
  File "/usr/local/lib/python3.9/site-packages/django/db/models/query.py", line 325, in __getitem__                          
    return qs._result_cache[0]                                                                                               
IndexError: list index out of range                                                                                          
                                                                                                                             
During handling of the above exception, another exception occurred:                                                          
                                                                                                                             
Traceback (most recent call last):                                                                                           
  File "/dsmr/dsmr_mindergas/services.py", line 32, in run                                                                   
    export()                                                                                                                 
  File "/dsmr/dsmr_mindergas/services.py", line 71, in export                                                                
    raise AssertionError(_('No recent gas reading found'))                                                                   
AssertionError: No recent gas reading found                                                                                  
[2021-02-11 20:22:47,296] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType'
[2021-02-11 20:23:17,666] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType'
[2021-02-11 20:23:48,731] ERROR    (TypeError) dsmr_stats.services.run errored: unsupported operand type(s) for -: 'NoneType'

[dennissiemensma]

Bedankt voor je aanvulling. De meldingen uit de logs zijn nog van gisteravond, drie minuten voordat je aangaf iets opgelost te hebben.

Het kan zijn dat je last hebt van een tijdsverschil. Er is nog onderzoek gaande in #1282. Je kunt iig eerst controleren of je van hetzelfde last hebt:

• Telegram datumtijden: ⚠️ Docker only - Reading timestamp differences (1 or 2 hours off) #1282 (comment)
• Getoonde tijd moet overeen komen met huidige tijd:
  

Bij de anderen was de getoonde tijd een uur later dan het echt is, maar klopten de telegramtijden wel.

[pcdiks]

Je hebt gelijk, niet gezien. Ik dacht, ik kijk even of ik een trackback zie en post die even. Ik heb het andere issue gelezen en mijn setup is gelijk aan wat daar besproken wordt en ook bij mij staat de tijd niet goed. Ik hou het andere issue in de gaten. Th aks

[dennissiemensma]

Ter info voor anderen die dit issue vinden:

De huidige fix lijkt om (momenteel) niet-werkende PostgreSQL container 12-alpine te vervangen door 12.3-alpine.

[dennisbrouwer91]

Having the same issue here, but for whatever reason i cannot get it fixed with the above SQL statements.
When i run SELECT * FROM dsmr_consumption_electricityconsumption WHERE delivered_1 IS NULL; i also get back 0 rows, but it still isn't working. Any other ideas i might try?
Additional error found in logs :
2022-04-04 14:20:17,431 ERROR schedule execute_scheduled_processes 37 | (DatabaseError) dsmr_consumption.services.run errored: Save with update_fields did not affect any rows.

[dennissiemensma]

Please create a new issue with a debug info dump and the exact error, so it's more convenient to assist. Also, to prevent notifications to unrelated users of the previous Issue(s).