🙋 ERROR: null value in column "delivered_1" #1619
Comments
|
Bedankt voor je melding. Hoe krijg je de metingen binnen, direct via de kabel die DSMR-reader dan zelf uitleest? Je zou ook nog kunnen kijken in de tabel met metingen, of daar NULL-waardes staan: |
|
Klopt ja, direct via USB naar de DMSR-reader container. Kan het zijn dat ie twee dataloggers probeert uit te lezen en één v/d twee niet werkt waardoor je NULL waardes krijgt? Ik zou dan meer dan 1 row met null waardes verwachten. |
|
Je kunt kijken of je wat wijzer wordt met debug mode. Ik weet niet hoe het via jouw setup moet, maar wellicht is een envvar + herstart voldoende. Je zou dan in de logs ook moeten zien wat de datalogger uitleest en qua backend proces meer informatie onderwater wat die probeert te doen en wat er dan faalt. https://dsmr-reader.readthedocs.io/en/v4/how-to/troubleshooting/enabling-debug-logging.html
|
Zojuist even geprobeerd, maar zie niet direct iets heel vreemds gebeuren, jij wel? |
|
Bedankt voor je update. Ik zoek twee dingen: telegram en fouten. Het telegram staat er in en lijkt verder gewoon goede waardes te hebben, wat NULL values alleen maar vreemder maken. In principe komt er elke X seconden (of minuut) een proces langs in die backend die waardes insert in de |
|
Deze zoek ik: https://github.com/dsmrreader/dsmr-reader/blob/v5/dsmrreader/config/defaults.py#L47 In de logs kan die wel iets als |
|
Zoiets? |
|
Dit ziet er wel interessant uit: |
|
Ja precies, alleen vertekent het nog wel wat omdat je op een tijdstip grept. Als je Wellicht als je zoekt op de fout en de 20 regels ervoor en erna pakt met |
|
Hij lijkt overigens verder wel door te lopen als ik dit zo zie: Of herstart/bump je hem telkens? |
|
Oh wacht, nvm, de telegrammen zijn van een dag eerder |
|
Klopt inderdaad, had momenteel NULL values toegestaan in de database zodat het even kon doorlopen en de queue weer verdween Hieronder zie je een insert statement waar het fout gaat (even zonder code blocks, anders verdwijnt om de een of andere reden de opmaak en is het vrij onleesbaar), kun je hier wat mee? |
|
Het enige wat ik kan afleiden is dat alle velden leeg zijn, alleen de datumtijd is gevuld: Dus ik ben heel benieuwd hoe dat zit. Wat staat er in de regels daarboven? Zie je hier ook geen NULL waardes? |
|
Het mechanisme is namelijk vrij simpel. De records in de tabel met metingen worden gesplitst naar aparte tabellen voor electriciteit en gas: https://github.com/dsmrreader/dsmr-reader/blob/v5/dsmr_consumption/services.py#L62-L71
Heb je trouwens DSMR-reader en de database wel in dezelfde tijdzone staan? Het staat mij niet bekend als oorzaak voor jouw issue, maar daar kunnen altijd wel vage dingen door naar voren komen. Er zijn ook wel eens issues geweest met bepaalde packages. |
|
Sterker nog! Nu ik dat tijdzone-issue weer terug heb gezocht, zie ik wel degelijk dezelfde foutmelding! #1282Wil je eens kijken of het mogelijk daar mee te maken kan hebben? Het is echter geen recent probleem, dus ik weet niet zeker of het dezelfde oorzaak is. |
|
Bij nader inzien speelde daar twee verschillende problemen, maar dan nog is het goed om even te checken of je tijdzones kloppen. |
|
Tijdzone gecheckt, in de database en dsmr container via "date" en die staat goed, ook de postgres.conf nog gecheckt, die stond op UTC, aangepast naar Europe/Amsterdam, zijn er nog meer plekken die ik na moet lopen? Kan me zo even niets bedenken. Wat me wel direct opvalt, als ik naar de live telegram readings ga onder -> http://url:7777/admin/dsmr_datalogger/meterstatistics/ dan zie je in de "MeterStatistics @ 2022-04-27 10:48:26+00:00" een tijd van twee uur terug, maar vervolgens heeft de timestamp wel weer de jusite tijd "Timestamp: De select query die je gaf kwam niet terug met resultaten, wat me daarentegen wel opvalt, na even wat gekeken en gerommeld te hebben, is dat hij lijkt te hangen op een INSERT van 1 april (dit is tegelijkertijd ook wat je voor de INSERT ziet gebeuren zoals je vroeg): Als ik het trucje uithaal, maakt niet uit hoe vaak, door de NOT NULL te droppen en daarna de DELETE en dan weer NULL te weigeren, blijft deze INSERT statement terugkomen en ook telkens een NULL rij, heb jij een idee hoe ik die INSERT er "tussenuit" krijg? Ik denk dat we er dan misschien wel zijn? Ik snap alleen niet hoe die dan ontstaan is, behalve dan dat ik een restore heb gedaan een week of twee geleden na de problemen met TimescaleDB. |
Jazeker, want het hangt af van de tijdzone offset die erbij zit: Ik zie trouwens dat mn eerdere query niet klopte. Wil je deze eens proberen? Daarmee zie je alle onverwerkte metingen. Zie je daar wellicht NULL waardes? |
|
Niet dat mij opvalt, jou wel? Lijkt er dus trouwens op dat hij niet de hele backlog verwerkt, ondanks de niet aanwezige NULL constraint, en zodra je die weer aanzet het alsnog ineens probeert? Dat zou wel de "loop" verklaren en de INSERT statement die faalt. Wellicht die van 1 april eruit mieteren? Ik zou alleen even niet precies weten hoe... dus wellicht heb je tips, anders moet ik een postgres query gaan knutselen Mooi dat de tijd klopt en erg helder uitgelegd, dank daaroor :-) |
|
Je kunt dan deze query doen: En dan de 3 ID's die bij die records horen verwijderen, bijvoorbeeld ID's 1111, 2222 en 3333: |
|
Heel vreemd, zojuist geprobeerd: De DELETE zou zoals je schrijft vanzelfsprekend moeten werken, als ik hem zo lees, alleen als ik hem dan uitvoer, affect ie maar 1 ROW: Als je daarna weer de SELECT doet, staan de rijen er nog. Ik heb ook i.p.v. een DELETE een SELECT geprobeerd, maar dan krijg ik een lege row terug: Jij nog een idee? |
|
Ik weet niet hoe pgadmin meerdere queries afhandelt, maar als die je 3 deletes los van elkaar doet, zou het sowieso moeten werken. Verder krijg je op je SELECT-query geen resultaten omdat je geen velden opgeeft. Ik wist niet dat dat uberhaupt werkte. Probeer maar iets als: |
|
Ben even aan het spelen geweest, er lijkt iets vreemds te gebeuren in postgres zelf en ik ben er nog niet achter waardoor... Doe ik een SELECT op een willekeurige daarna, dan krijg ik netjes de row terug zoals verwacht: Doe je het op eentje van 1 april: Er moet dus haast wel iets mis zijn met die 3 rows, ik krijg ze alleen écht niet weg: Ook als je de pgadmin delete functie gebruikt, verdwijnen ze wel op het oog, doe je daarna weer alle unprocessed ophalen dan staan ze er nog (ook met DSMR reader uit, dus het zit echt in postgres), heel vreemd. |
|
Je kunt het nog buiten pgadmin proberen, direct op de command line bij de database via En ik neem aan dat je de DB ook al een keer herstart hebt? |
|
psql had ik inderdaad ook geprobeerd en heb meerdere keren herstart ja. Heb het eindelijk opgelost, besloten om de tabel te TRUNCATEN en weer opnieuw in te laden met: Toen kwam naar voren, bij het importeren, dat er sprake was van duplicate primary keys (id's), Vervolgens de tabel succesvol teruggezet weer met: Nog eenmaal gekeken met pgadmin of de onverwerkte 1 april telegrams er nog stonden... Uiteindelijk dsmr reader weer gestart en de onverwerkte telegrams weg laten werken, de tabel loopt nu netjes door zoals het zou moeten. Wat alleen wel opvalt in de DEBUG log nu is het volgende: En dan specifiek deze regel: Ik vraag me af waar die nu vandaan komt, hij loopt nu dus stuk op 1 april als die de dag statistieken wilt opmaken lijkt het, eens kijken in de tabellen... |
|
Kan het komen doordat ie een resultaat zoekt van elk uur maar deze niet kan vinden? |
|
Bedankt voor je aanvulling. Het is helaas wat lastig te duiden, gezien de foutmelding niet de locatie aangeeft. Voor de volgende release zal ik de stacktrace toevoegen, zodat duidelijk is waar die vandaan komt. Het stukje code dat de statistieken genereert heeft namelijk diverse plekken waar dit fout kan gaan. Ik denk echter wel dat het inderdaad veroorzaakt kan worden door het missen van een paar uur aan data. Is de achterstand van je onverwerkte metingen nu wel opgelost? Want dan zou voor nu een oplossing zijn om handmatig nog 2 (of 4 als je ook gas hebt) records toe te voegen in de brontabel voor dagstatistieken (voor elk missend uur). Dat is een andere tabel, namelijk |
|
Yes metingen lopen nu door dus dat is opgelost :-D De statistieken worden nu ook weer gegenereerd, er stond een row met null waardes op 1 april, deze eruit gehaald + voor 22:30 en 23:30 een waarde toegevoegd met de queries hieronder, was net iets makkelijker dan via PG-Admin, en dsmr reader gestart en hij is netjes doorgestroomd. Die twee waardes toevoegen was waarschijnlijk niet eens nodig, ben dit vergeten bij de gas tabel, en die staat ook netjes in de dagstatistieken + ik mis de data tussen 1 en 7 april, omdat ik op 7 april de backup heb teruggezet. Dat er een null row in die tabel stond kan ook prima kloppen, er zit namelijk geen constraint op die tabel zie ik, verklaard ook de Nonetype error. (id aanpassen aan een rij die je wilt kopieren, postgres creeert zelf een unieke ID, maak ook de timestamp uniek. als je dat vergeet krijg je een error en draait de query niet) Er gaat nu nog één ding fout... dat is de data rotation, alleen die Stacktrace is nog kleiner dus de debug data zegt mij niet zoveel, wat opvalt is dat het volgende continue voorkomt: en met 10 regels ervoor en erna ziet dat er zo uit: Zegt jou dit nog iets waar ik kan zoeken? |
|
Het zit in het mechanisme van opschoning. Wellicht komt die ook niet verder als er data mist, maar dat kan ik niet zo 1-2-3 zien of zeggen. De logica is dit: https://github.com/dsmrreader/dsmr-reader/blob/v5/dsmr_datalogger/services/retention.py#L39 Effectief krijg je dan wat je op een van je eerdere screenshots ook al zag: #1619 (comment) |
|
Ff aantal dingen geprobeerd, eerst data toegevoegd zoals je zei, dus op minuut 00 en 59 van elk uur, dat hielp al iets: Zoals je ziet verwerkt hij netjes de toegevoegde uren, en valt dan vervolgens weer in de herhaling, Eind goed al goed, zo zien we het graag: :-D Thanks voor alle hulp, veel geleerd en ik hoop dat het ook nog ergens meehelpt aan de ontwikkeling ooit, hoewel het hier uiteindelijk om een stukje data corruptie leek te gaan (dubbele primary keys e.d.), de vraag is natuurlijk hoe dicht je het wilt timmeren qua failsafe. Sluit jij de issue als je tevreden bent of eventueel nog iets van debug informatie wilt hebben van mij? |
|
Bedankt voor je update en fijn dat het uiteindelijk gelukt is! Het helpt zeker mee, want voor de volgende release zal ik het debuggen wat makkelijker maken met betere stacktraces en optionele query logging. |
Description
In een van de twee installaties die ik beheer loop ik tegen het volgende probleem aan:
Het volgende issue heb ik al gevonden en geprobeerd: #1288
Vervolgens wordt er 1 row verwijderd.
Als ik daarna dsmrreader weer start (ik stop dsmrreader nadat de queue is weggewerkt, zodat er niks fout gaat tijdens de delete query), geeft de runner die de statistics aanmaakt problemen, die denkt dat er nog steeds NULL waardes aanwezig zijn, dit terwijl een DELETE query 0 rows geeft en SELECT ook 0 rows...
Wel valt op dat er continue in de logging voorkomt dat er NULL waardes geprobeerd worden te inserten, wat niet mag, de TimescaleDB logs bevestigen dit:
Is er nog iets anders dat ik kan proberen? Ik heb inmiddels de stappen een aantal keer doorlopen maar ben ten einde raad, alle instellingen heb ik vergeleken met de wel werkende installatie, het enige verschil is dat de één geen teruglevering doet en de probleeminstallatie wél.
Ik draai het binnen homeassistant met de addon van sanderdw + USB P1 kabel.
De live grafieken lijken overigens prima te werken, ook is de data die binnenkomt zeker geen 0 waarde.
De tijdzones heb ik ook vergeleken, hierin is interessant dat de telegram tijd 2 uur achterloopt t.o.v. normale Nederlandse tijd, dit krijg ik alleen niet rechtgetrokken.
Gr,
David :-)
DSMR-reader version
5.1
DSMR-reader platform
No response
Debug info dump
DSMR-READER App / Python / Database v5.1 / v3.10.4 / 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.) 307908 Consumption records electricity / gas (est.) 47137 / 24012 UNRESOLVED ISSUES Too many unprocessed readings: 1339 3 weeks, 1 day ago Day statistics are lagging behind 3 weeks, 1 day agoThe text was updated successfully, but these errors were encountered: