Skip to content

Debugging #19

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
7wells opened this issue Oct 13, 2022 · 38 comments
Closed

Debugging #19

7wells opened this issue Oct 13, 2022 · 38 comments

Comments

@7wells
Copy link
Contributor

7wells commented Oct 13, 2022

Hier möchte ich gerne ein paar Debugging-Outputs liefern.

pi@pi4:~ $ DEBUG_LIN=1 truma_service

pi@pi4:~ $ DEBUG_PROTOCOL=1 truma_service

pi@pi4:~ $ DEBUG_APP=1 truma_service

Heute Abend schaffe ich es leider nicht mehr, weil ich den Output aus der ConnectBot App auf meinem Handy nicht vernünftig kopieren kann.

Gibt's evtl. die Möglichkeit, den Debugging-Ouput direkt und ausschließlich in eine Log-Datei umzuleiten und diese dann hier anzufügen?

DEBUG_LIN=1 truma_service > lin.log erzeugt eine leere Datei. Vermutlich mache ich es falsch oder es geht nicht.

Wie lange soll der Debug laufen?

Sollte ich während der Debug läuft, am CP+ etwas verändern (z.B. die Lüfterstufe)? Auch das kann ich erst morgen machen.

@7wells 7wells mentioned this issue Oct 13, 2022
@danielfett
Copy link
Owner

danielfett commented Oct 13, 2022

DEBUG_LIN=1 DEBUG_PROTOCOL=1 DEBUG_APP=1 truma_service > lin.log 2>&1 sollte es tun.

Änderungen sind nicht nötig, sollte aber min. 2 Minuten laufen.

@7wells
Copy link
Contributor Author

7wells commented Oct 13, 2022

Können sicherheitsrelevante Daten im Log erhalten sein? Mein MQTT PW ist hier schon bekannt. Das werde ich aber noch ändern.

@danielfett
Copy link
Owner

Nö, da sollte nichts drin sein.

@7wells
Copy link
Contributor Author

7wells commented Oct 13, 2022

Log ist auf dem RPi, aber leider weiß ich nicht, wie ich das jetzt schnell auf's Handy bekomme. 😊

Es geht wohl auch über ssh (ConnectBot App), aber dazu fehlen mir leider die Kenntnisse, sorry. Morgen reiche ich es nach.

Gute Nacht! :)

@7wells
Copy link
Contributor Author

7wells commented Oct 14, 2022

@danielfett
Hier der Log von DEBUG_LIN=1 DEBUG_PROTOCOL=1 DEBUG_APP=1 truma_service > lin.log 2>&1 über knapp 9 Minuten: lin.log.gz

@mc0110
Copy link

mc0110 commented Oct 14, 2022

Super, danke für Deine Mühe. Ich habe aber zwei Fragen:

  1. Ich sehe keine "out <" Zeilen
  2. Ich sehe auch keine NAD=0x03 Nachrichten

@7wells
Copy link
Contributor Author

7wells commented Oct 14, 2022

Sorry, ich habe keine Ahnung, was Du damit meinst bzw. welche Bedeutung die von Dir genannten Begriffe haben.

Ich kann nur meine Beobachtung beschreiben, dass ich momentan zwar Werte angezeigt bekomme, aber im MQTT Broker nicht der Teil angezeigt wird, wo es um das Setzen von Werten geht (so zumindest mein laienhaftes Verständnis).

Tut mir leid, dass ich Deine Frage nicht beantworten kann.

Aber falls Du, Daniel oder sonst jemand Vorschläge hat, was ich noch ausprobieren bzw. hier posten kann, mache ich das sehr gerne.

@mc0110
Copy link

mc0110 commented Oct 14, 2022

Hi, das war keine Kritik an Dir oder Deiner Mühe - mich wundert es nur, weil ich das in _send_answer als log-Eintrag gesehen habe. Die Frage geht also an Daniel.

BG Magnus

@7wells
Copy link
Contributor Author

7wells commented Oct 14, 2022

Hi! Ich hatte das auch nicht als Kritik aufgefasst! :-) Mir ist es eher peinlich, dass ich nichts dazu weiß. 😊

@danielfett
Copy link
Owner

Die Beobachtungen von Magnus teile ich - da fehlen Nachrichten. Die Kommunikation sieht so aus, als ob gar keine inetbox da wäre. Es gibt auch keine unbeantworteten Nachrichten. Daher gehe ich davon aus, dass während der Initialisierung schon was schief gegangen ist.

Kannst du bitte mal ein Logfile des Init-Vorgangs machen?

Und danach: Schau mal im Settings-Menü der CP Plus nach, wenn du dort auf "Index" gehst und dann das Rad drehst - welche Versionsnummern kommen da (bitte alle auflisten).

@7wells
Copy link
Contributor Author

7wells commented Oct 14, 2022

Ok, mache ich am Samstag.

Ich frage mich, woher dann die Werte kommen, die ich bei den MQTT-Nachrichten sehe - vom CP+ oder von der Truma Combi selbst?

@danielfett
Copy link
Owner

Die kommen vom CP Plus, das ist aber ein separates Set von Nachrichten, die vermutlich nicht originär für die iNet-Box bestimmt sind. Auf jeden Fall kann man damit keine Einstellungen vornehmen.

@7wells
Copy link
Contributor Author

7wells commented Oct 15, 2022

@danielfett
Meinst Du mit "Logfile des Init-Vorgang" folgende Schritte?

  1. DEBUG_LIN=1 DEBUG_PROTOCOL=1 DEBUG_APP=1 truma_service > lin.log 2>&1 ausführen
  2. Am CP+ Bedienteil in den EInstellungen RESET => PR SET ausführen
  3. Nach 1 Minute (ich vermute, dass das reicht) das Logging beenden

INDEX zeigt übrigens folgende Infos:
C4.03.00
H1.02.00

@7wells
Copy link
Contributor Author

7wells commented Oct 15, 2022

Anbei der Log kurz vor, während und nach RESET => PR SET:
lin_init.log.gz

Hoffentlich hilft das weiter!

PS: Danke, Daniel, auch für die Erklärung, woher die Daten vermutlich kommen etc. Das erklärt ja auch, weshalb ich keine Werte ändenr kann.

@7wells
Copy link
Contributor Author

7wells commented Oct 15, 2022

Sorry, bitte löschen/ignorieren. Den vorherigen Inhalt habe ich nach #11 (comment) verschoben, da er hier OT war.

@7wells
Copy link
Contributor Author

7wells commented Oct 15, 2022

Super, danke für Deine Mühe. Ich habe aber zwei Fragen:

1. Ich sehe keine "out <" Zeilen

2. Ich sehe auch keine NAD=0x03 Nachrichten

Jetzt sind auch solche Zeilen drin, die vorher fehlten, z.B.:

2022-10-15 11:47:13,753  inet-lin  DEBUG 	Received read by identifier request.
2022-10-15 11:47:13,793  lin  DEBUG 	in < 00 55 7d → checking if answer required
2022-10-15 11:47:13,807  lin  DEBUG 	out > 03 06 f2 17 46 00 1f 00 87
2022-10-15 11:47:13,808  lin  DEBUG 	→ → sent answer

Bzgl. NAD finde ich im aktuellen Log z.B. diese Zeilen:

2022-10-15 11:47:14,634  lin  DEBUG 	TRANSPORTLAYER FRAME master → slave
2022-10-15 11:47:14,634  lin  DEBUG 	   node address: broadcast
2022-10-15 11:47:14,634  lin  DEBUG 	   single frame, expected bytes: 5
2022-10-15 11:47:14,634  lin  DEBUG 	   payload: 17 46 40 03 01
2022-10-15 11:47:14,635  lin  DEBUG 	   service id: Assign NAD
2022-10-15 11:47:14,635  lin  DEBUG 	   → potentially handled by protocol!
2022-10-15 11:47:14,685  lin  DEBUG 	in < 00 55 7d 01 01 f0 ff ff ff ff ff 0d → processing
2022-10-15 11:47:14,686  lin  DEBUG 	→ → identified as transportlayer SLAVE → MASTER
2022-10-15 11:47:14,686  lin  DEBUG 	TRANSPORTLAYER FRAME slave → master
2022-10-15 11:47:14,686  lin  DEBUG 	   node address: 01
2022-10-15 11:47:14,686  lin  DEBUG 	   single frame, expected bytes: 0
2022-10-15 11:47:14,687  lin  DEBUG 	   payload: 
2022-10-15 11:47:14,687  lin  DEBUG 	   positive response to Assign NAD
2022-10-15 11:47:14,793  lin  DEBUG 	in < 00 55 3c 7f 06 b2 00 17 46 07 0c 57 → processing
2022-10-15 11:47:14,794  lin  DEBUG 	→ → identified as transportlayer MASTER → SLAVE

Ist es das, was Ihr erwarten würdet?

Allerdings sehe ich in meinem Log keine "NAD=0x03 Nachrichten". Was sollten diese bedeuten?

@mc0110
Copy link

mc0110 commented Oct 15, 2022

Hi,
sorry für meine Abkürzung - die NAD ist die node address. Ja, die 0x03 taucht auf, die Init-Meldung ist auch im LOG. Sieht sehr gut aus. Es müsste jetzt auch das Einstellen funktionieren. Vielleicht versuchst Du mal, etwas zu ändern.
Also jetzt nochmals Glückwunsch!

@7wells
Copy link
Contributor Author

7wells commented Oct 15, 2022

❤️en Dank!

Da sich dieses "Issue" hier mit dem Debug Log beschäftigt, werde ich meine weiteren Schritte wieder beim Thema "Truma D6e" beschreiben (auch wenn ich die Truma Combi 6 ohne E habe). Also geht es dort weiter: #11 (comment) (mit meiner Frage zum Setzen/Ändern von Werten)

Euch allen ein schönes Wochenende! 🙂

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

Moin zusammen!

Sorry, @danielfett ich sehe gerade auf einem meiner Fotos, dass ich die Truma Combi 4 (nicht 6) habe. Bisher schrieb ich überall von 6, aber das dürfte wohl eh keinen Unterschied machen. Ich erwähne das hier, falls doch. D.h. die Werte im CP+ unter INDEX beziehen sich auf die Truma Combi 4:

C4.03.00
H1.02.00

@mc0110
Copy link

mc0110 commented Oct 17, 2022

Hallo zusammen,

@7wells : Im Index müsste nach der Aktivierung der iNetbox ein dritter Eintrag kommen.

Kurzes Update von meiner eigenen TRUMA: Dank der tollen Beschreibung klappt der LIN-Anschluss mit einem Adapter gut, nachdem ich festgestellt habe, dass im Adapter die Anschlüsse links und rechts getauscht sind - also Pin 1-6, 2-5, 3-4. Mit einer sauberen Masseverbindung braucht man nur das LIN-Signal (also in Daniels Abbildung den grünen Pin und daher reicht auch eine RJ11-Verbindung).

Damit konnte ich die LIN-Frames der CPplus / TRUMA mit einem UART-TCP-Server sehr gut sehen und auch die Checksum verifizieren, allerdings wollte der aufgesetzte RPI3 sich nicht auf die 0x00/0x55-Blöcke synchronisieren und der Log zeigte nur "Datenmüll". Um es kurz zu machen: Es gibt wohl auf dem UART (Besonderheit beim RPI3) ein Timing-Problem bei den neueren Softwareversionen. Abhilfe schaffte der Hinweis von Prof. Plate. Nachdem ich das Bluetooth abgeschaltet hatte, kamen auch nach dem Rebooten die ersten korrekten Meldungen im truma_service Log.

Kleiner Hinweis noch zum INIT auf dem CPplus. Ich musste das INIT mehrfach anstossen, bis die ersehnte Meldung in den Logs kam. Im Debug-Mode ist es leicht zu erkennen, denn erst mit der Initialisierung fängt der RPI3 an zu antworten. Es gibt also mit DEBUG_LIN=1 danach erst "out >" Meldungen, aber diese auch sehr regelmässig.

Danach lässt dich die TRUMA steuern - echt toll und Danke an @danielfett und alle anderen, die daran beteiligt gewesen sind. Eine echt tolle Erweiterung des smarten RV.

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

@mc0110
Vielen Dank für Deine Hinweise!

Was bedeutet denn der 3. Eintrag auf dem CP+ Display unter INDEX? Wie lauten die bei Dir?

Ich habe dort tatsächlich nur 2 Einträge.

Auch @danielfett
Das mit den out > Meldungen habe ich jetzt nicht ganz verstanden: Das, was ich hier aus meinem Debug-Log nach PR SET => INIT gepostet hatte, enthielt doch solche Meldungen. Falls dort etwas fehlen sollte, was genau wäre das?

@mc0110
Copy link

mc0110 commented Oct 17, 2022

@7wells
T23.70.0

Der Eintrag ist erst nach der Initialisierung des Inet-Simulators aufgetaucht. Ich vermute C steht für die Version des CPPlus, H für die Version der TRUMA und T dann für die "Version", die die Box hätte.

Die out-Meldungen hattest Du auch erst nach der Initialisierung. Wegen Deiner Beschreibung habe ich es auch mehrfach versucht, das INIT zu machen. Erst beim 3. oder 4. Versuch hat die iNet-Box angefangen zu antworten.

Kannst Du denn jetzt die TRUMA steuern? Heizung an/aus Wasser an/aus hat gestern bei mir geklappt.

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

@mc0110
Danke, ich probiere nochmal das INIT. Bisher versuchte ich nur, die Lüfterstufe zu ändern (siehe anderes Issue), da ich das Gas momentan nicht angeschlossen habe

Sollte der miqro_truma Service vor dem INIT gestoppt werden?

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

Interessant, denn jetzt sehe ich unter INDEX noch einen 3. Wert, ohne dass ich nochmals INIT gemacht oder sonst etwas verändert habe:
C4.03.00 H1.02.00 T23.700

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

Interessant, denn jetzt sehe ich unter INDEX noch einen 3. Wert, ohne dass ich nochmals INIT gemacht oder sonst etwas verändert habe:

C4.03.00
H1.02.00
T23.700

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

@danielfett @mc0110
Jetzt ist der 3. Eintrag (beim Weiterdrehen des CP+ Rads) wieder weg, obwohl der Service lief.

Außerdem bemerke ich jetzt erst, dass man beim Drücken auf das Rad noch mehr Werte anzeigen kann:

C4.03.00 => 0050.00
H1.02.00 => 0340.02

Der dritte Wert fehlt momentan. Ich mache nochmal einen INIT. Jetzt ist er wieder da:
T23.700 => 1F00.00

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

@danielfett
Ich habe nochmal Debug-Logs gemacht, und zwar beim Ändern der Lüftung am CP+. Zuerst lief die Lüftung auf Stufe 10 von 10 (noch vor dem Start des Debug-Log).

Beim Herunterdrehen von Stufe 10 auf Stufe 9:
vent10-9.log.gz

Beim Herunterdrehen von Stufe 9 auf Stufe 1:
vent9-1.log.gz

Beim Einstellen der Lüfterstufe von Stufe 1 auf "Off" (siehe auch Anmerkungen unten dazu):
vent1-0.log.gz

Ich sehe in keinem der 3 Logs eine out > Meldung (nach mehrfachem PR SET => INIT zuvor). Schlechtes Zeichen?

Außerdem habe ich folgende Beobachtung bzw. Fragen:

Wenn ich am CP+ Rad gegen den Uhrzeigersinn drehe, wird die Lüfterstufe schrittweise heruntergesetzt, also z.B. von 10 auf 9, ohne dass ich dafür auf den Rad-Knopf drücken muss. Wie ist das, wenn Dein miqro_truma Service läuft? Muss die Bedienung am CP+ 1:1 simuliert werden, also auch das Hangeln durch's Menü etc., oder werden die Werte sofort verändert? Denn wenn ich am CP+ die Lüftung ganz ausschalten will, geht das nicht mit weiterem Drehen gegen den Uhrzeigersinn, sondern dann muss ich eine Ebene hoch/raus, um dann in der VENT Anzeige auf Off zu drehen. Wie ist das mit Deinem Service? Einfaches Setzen, oder womöglich doch komplexer?

Ich weiß, dass Du das mit der Lüftung noch nicht herausgefunden hast, hoffe aber, dass ich evtl. etwas dazu beitragen kann, gerne auch mit noch mehr Logs.

@danielfett
Copy link
Owner

@mc0110 Danke für den Hinweis auf das Timing-Problem. Was genau hast du denn jetzt eingestellt?

@7wells Die Log-Files helfen leider nicht. Ich bräuchte die von einer inet-Box, bei der die Einstellungen geändert werden - falls es denn dort geht!

Davon abgesehen, klingt deine Problembeschreibung wirklich wie ein Timing-Problem - mal klappts und mal nicht. Die Tatsache, dass du OUT-Meldungen siehst, heißt, dass sich inetbox.py angesprochen gefühlt hat (es kamen also Nachrichten rein). Aber möglicherweise sind die Antworten nicht (zeitgerecht) angekommen. Das lässt sich leider ohne Oszilloskop oder Logic Analyzer nur schwer feststellen.

@mc0110
Copy link

mc0110 commented Oct 17, 2022

In /boot/config.txt die Zeilen ergänzt:
core_freq=250
enable_uart=1
dtoverlay=pi3-miniuart-bt

und dann noch als sudo
sudo systemctl disable hciuart

Nach einem Reboot war das Timing dann okay und die Syncs (0x00, 0x55) funktionierten.

@7wells
Copy link
Contributor Author

7wells commented Oct 17, 2022

Vielen Dank! Ich habe zwar einen RPi 3, werde aber trotzdem schauen, ob diese Einstellungen bei meinem RPi 4 positive Effekte haben.

@danielfett
Ich habe eine iNet-Box und hatte sie auch schon angeschlossen und erfolgreich (nur über Bluetooth, nicht über SMS) benutzt. Wegen der Experimente jetzt habe ich sie wieder eingepackt.

Wie kann/sollte ich sie anschließen, um nützliche Infos hier zur Verfügung stellen zu können? Muss ich sie parallel zum LIN-UART Board anschließen? Gibt's dann keine "Kollisionen"?

@7wells
Copy link
Contributor Author

7wells commented Oct 20, 2022

@danielfett
Weißt Du, ob ich die iNet Box parallel zum LIN-UART Board anschließen kann? Würde es überhaupt etwas nutzen zum Herausfinden noch unbekannter Daten/Werte?

@danielfett
Copy link
Owner

Man könnte es in der Software abklemmen, aber das ist derzeit nicht eingebaut. Du könntest einfach RX am Pi trennen, dann solltest du alles zusammen betreiben können.

@7wells
Copy link
Contributor Author

7wells commented Oct 20, 2022

Wenn ich Rx am RPi trenne, kann Dein Tool aber nichts mehr lesen, korrekt?

Welche Möglichkeiten habe ich zum weiteren Suchen nach bestimmten Daten/Werten/Steuercodes mithilfe der iNet Box? Wie hast Du die herausgefunden? Anhand der Logs vom WomoLIN Projekt? Aber ohne die Box, richtig?

Wie gesagt bin ich mir gar nicht darüber klar, ob mir die Box überhaupt helfen kann.

@7wells
Copy link
Contributor Author

7wells commented Oct 23, 2022

In /boot/config.txt die Zeilen ergänzt:
core_freq=250
enable_uart=1
dtoverlay=pi3-miniuart-bt

und dann noch als sudo
sudo systemctl disable hciuart

Nach einem Reboot war das Timing dann okay und die Syncs (0x00, 0x55) funktionierten.

Für interessierte Mitbastler und auch für mich, damit ich diese Info später schneller finde - könnte hier nützlich sein bzgl. evtl. Timing-Probleme mit dem Raspberry Pi:

raspberrypi/linux#4123

PiSupply/IoTLoRaRange#32 (comment)

https://www.raspberrypi.org/documentation/configuration/uart.md

Es ist zu beachten, dass beim Pi 4 ein paar Unterschiede zum Pi 3 bei den Einstellungen bestehen, aber beiden ist offenbar gemeinsam: Das Timing des UART-Bauteils hängt vom Timing der GPU ab, d.h. ändert letztere bei wechselnden Lasten entsprechend die Frequenz, so wechselt auch die Frequenz des UART-Bauteils. Und das wollen wir bei unserem Setup vermeiden, weshalb die Core-Frequenz stabil auf den minimal möglichen Wert von 250 auch beim Pi 4 gesetzt werden sollte. Ich habe es noch nicht probiert, werde aber darüber hier noch berichten, wenn ich mehr weiß.

Nochmals herzlichen Dank an @mc0110 für den sehr hilfreichen Hinweis! 👍

PS (Quelle):

Read /boot/overlays/README for the up-to-date documentation, rather than old unreferenced posts.

The Pi4 has a totally new peripheral module, and older documentation no longer is relevant.

If it was me, I would leave BT alone and use one of the other 4 fully featured UART.

See Raspberry Pi4 UART

@7wells
Copy link
Contributor Author

7wells commented Oct 23, 2022

@danielfett @mc0110
Nachdem ich die core_freq auf 250 gesetzt habe, scheinen mir die Messungen bzw. Datenübertragungen immer noch etwas lückenhaft zu sein:

service/truma/display_status/current_temp_room
service/truma/display_status/current_temp_water

temp.jpg

Sollte ich hier regelmäßigere Messpunkte erwarten? Sollten die beiden Variablen stets zum selben Zeitpunkt übermittelt werden? Wie sieht das bei Euch aus?

Es geht mir hier erstmal nur um die Werte von display_status.

Danke für Eure Rückmeldung!

@skrebber
Copy link

Aber ich dachte, die Timing-Geschichte bezieht sich nur auf den miniUART. Und daher sollte man auch den PL011 nehmen, weil der viel stabileres timing hat, weil vom GPU-Takt unabhängige Hardware-Lösung.
Wenn du über dtoverlay=disable-bt bluetooth ausschaltest, dann wird auf den GPIO pins der PL011 gelegt und es dürfte eigentlich nichts mit dem GPU-Takt zu tun haben.

Oder liege ich falsch?

@7wells
Copy link
Contributor Author

7wells commented Oct 23, 2022

Sorry, das weiß ich leider nicht. Es gibt bzgl. Pi 4 und UART viele Fragen in diversen Foren, allerdings habe ich nicht darauf geachtet, ob es um mini-UART/BT ging. Womöglich habe ich nicht aufmerksam genug gelesen oder es schlicht falsch verstanden. 😊

Ich bin immer noch am rätseln, woran meine hier beschriebenen Probleme liegen. Vielleicht sollte ich auch noch das Thema der unzureichenden Stromversorgung überprüfen.

@7wells
Copy link
Contributor Author

7wells commented Oct 24, 2022

Update: Trotz der Reduzierung von core_freq auf 250 tauchen immer wieder Lücken auf:

temp2.jpg

Und hier geht es erstmal nur um Werte aus display_status (nicht control_status).

@7wells 7wells closed this as completed Apr 10, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants