HMLANGW mode doesn't work in 3.69.7.20230626 #2350

bronkoo · 2023-06-28T15:36:20Z

Describe the issue you are experiencing

/bin/hmlangw hangs and endless kernel messages mmd_bidcos: not enough space in buffers appears ~2,5 h after start, no lan gateway functionality at this point.

Describe the behavior you expected

stable lan gateway mode

Steps to reproduce the issue

update from release 3.69.7.20230506 to 3.69.7.20230626 via Web GUI (temporarily rm /usr/local/HMLGW)

What is the version this bug report is based on?

3.69.7.20230626

Which base platform are you running?

Raspberry Pi Zero W Rev. 1.1

Which HomeMatic/homematicIP radio module are you using?

HM-MOD-RPI-PCB

Anything in the logs that might be useful for us?

# netstat -tulpn | grep LISTEN
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      1245/sshd [listener
tcp        2      0 0.0.0.0:2000            0.0.0.0:*               LISTEN      1332/hmlangw
tcp        0      0 0.0.0.0:2001            0.0.0.0:*               LISTEN      1332/hmlangw
tcp        0      0 :::22                   :::*                    LISTEN      1245/sshd [listener

# cat /var/log/hmlangw.log 
Client 192.168.178.33 connected to BidCos port!
Client 192.168.178.33 connected to keepalive port!
Keepalive client closed connection.
BidCos client closed connection.

# tail -f /var/log/messages
Jun 28 16:54:10 homematic-raspi-hgw kern.err kernel: [15551.812456] eq3loop: eq3loop_write_master() mmd_bidcos: not enough space in buffers. free space = 15, required space = 18
Jun 28 16:54:10 homematic-raspi-hgw kern.info kernel: [15551.812513] eq3loop: eq3loop_write_master() return error: -14
.
.
. [in endless]

Additional information

Raspberry Pi Zero W is connected by WLAN.

When the issue appears, network between CCU and LAN Gateway still working, but not connected at CCU Web GUI LAN Gateway Configuration page.

On the issued LAN Gateway side the /bin/hmlangw daemon is still running without abnormal CPU load:

# top
.
 1332     1 root     S    20660   4%   1% /bin/hmlangw -n REQ0914234 -s /dev/mmd_bidcos -r -1
.

but I can't kill 1332 process, means command doesn't fulfill without any response on CLI.

The Raspberry Pi Zero W doesn't really hangs, but at issue time its responds very slowly, may be given by the system architecture combined with endless log messages...

To reboot the LAN Gateway solved the issue for next 2,5 hours without any changes on CCU, on release 3.69.7.20230626 too.

Maybe behavior looks like #2340 without any CPU load.

How can I help for further investigations?

The text was updated successfully, but these errors were encountered:

Newton1981 · 2023-06-30T05:28:26Z

I can approve the error on a Raspberry Pi3: Having trouble with the LAN Gateway since ~ 2weeks. No connections and error log full with: "LanGatewayEG kern.err kernel: [76765.505782] eq3loop: eq3loop_write_master() mmd_bidcos: not enough space in buffers. free space = 15, required space = 18
Was happy to find a fix in the changelog in the latest update (3.69.7.20230626) and after updating the Lan-Gateway was connected. Unfortunetly loosing the connection after some hours. The 2nd Lan-Gateway with the same hardware and same SW Version never had an issue.

bronkoo · 2023-06-30T07:54:13Z

After some reissue of this possible bug, my LAN Gateway is back on release 3.69.7.20230506 and it works fine since 10 hours without any suspected log messages and CCU is still on last release 3.69.7.20230626.

Newton1981 · 2023-07-12T05:57:24Z

Unfortunetly the problems on my side are still there, and yesterday evening my 2nd Lan Gatway came up with the same problem. After a reboot they work for some hours.

bronkoo · 2023-07-12T07:13:45Z

LAN Gateway here still on release 3.69.7.20230506 without any issue since 12 days...

Baxxy13 · 2023-07-25T17:21:19Z

So, jetzt habe ich mir die RM-LGW Problematik mal angesehen und kann die Probleme nachvollziehen und reproduzieren.
@jp112sdl ist auch noch fix eingesprungen um auf meinen Testsystemen die Angelegenheit zu begutachten/zu analysieren.

Die RM-OVA (.ova mit HmIP-RFUSB) und die RM-LGW (Pi2B mit HM-MOD-RPI-PCB) sind beide auf Nightly 3.71.12.20230725-5a1c60

Ausgangslage ist die frisch gebootete RM-LGW und die ausgeschaltete RM-OVA (in welcher das LGW schon eingebunden ist).

Die RM-OVA wird gebootet, und die Verbindung zur RM-LGW korrekt aufgebaut. Soweit ok.

Wenn ich jetzt aber die RM-OVA neu starte (oder nur den rfd der RM-OVA) gehen die Probleme los.
Genauer gesagt, es wird die Verbindung nicht mehr aufgebaut.

Im Log der RM-LGW kommen dann die bekannten Fehlermeldungen:
Jul 25 19:12:39 RM-LGW-Pi2B-103 kern.info kernel: [ 192.490392] eq3loop: eq3loop_write_master() return error: -14 Jul 25 19:12:39 RM-LGW-Pi2B-103 kern.err kernel: [ 192.500433] eq3loop: eq3loop_write_master() mmd_bidcos: not enough space in buffers. free space = 15, required space = 18

So wie es aussieht läuft dann der lgw in eine Art "Boot-Loop" aus dem er nicht mehr herauskommt.

2023/07/25 18:47:00.404 <Debug> A<: #20 HmBidcos RxTelegram AuthNone #A2[Ren] FFE823->A5A503 Ack: 00
2023/07/25 18:47:06.300 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.301 <Debug> A<: #0 HmSystem Response 01
2023/07/25 18:47:06.301 <Debug> A<: #21 HmSystem Identify Co_CPU_App
2023/07/25 18:47:06.311 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.312 <Debug> A<: #0 HmSystem Response 01
2023/07/25 18:47:06.312 <Debug> A<: #22 HmSystem Identify Co_CPU_App
2023/07/25 18:47:06.322 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.322 <Debug> A<: #0 HmSystem Response 01
2023/07/25 18:47:06.322 <Debug> A<: #23 HmSystem Identify Co_CPU_App
2023/07/25 18:47:06.332 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.332 <Debug> A<: #0 HmSystem Response 01
2023/07/25 18:47:06.332 <Debug> A<: #24 HmSystem Identify Co_CPU_App
2023/07/25 18:47:06.342 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.342 <Debug> A<: #0 HmSystem Response 01
2023/07/25 18:47:06.342 <Debug> A<: #25 HmSystem Identify Co_CPU_App
2023/07/25 18:47:06.352 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.352 <Debug> A<: #0 HmSystem Response 01

Möglicherweise sind die letzten Änderungen hier das Problem.

Edit:
Habe die RM-LGW jetzt mal auf 3.69.7.20230506 downgegraded.

Hier ist der Restart der RM-OVA (oder nur des rfd) kein Problem.
Die RM-LGW wirft zwar "tausende" der obigen not enough space in buffers -Fehlermeldungen, hört dann aber damit auf und die Verbindung zum LGW besteht weiterhin.

jens-maus · 2023-07-25T19:03:29Z

Danke fürs reproduzieren und die Analysen. Das sollte helfen das Problem irgendwann zeitnah dann hoffentlich final zu beheben.

Die RM-OVA wird gebootet, und die Verbindung zur RM-LGW korrekt aufgebaut. Soweit ok.

Wenn ich jetzt aber die RM-OVA neu starte (oder nur den rfd der RM-OVA) gehen die Probleme los. Genauer gesagt, es wird die Verbindung nicht mehr aufgebaut.

Ist das also das einzige Problem um das es hier geht? D.h. wenn der RM-LGW einmal in Betrieb ist darf/sollte man die normale RM nicht neustarten oder den rfd davon weil sonst die Verbindung sich nie wieder synchroniseren lässt? Hab ichd as richtig verstanden?

2023/07/25 18:47:00.404 <Debug> A<: #20 HmBidcos RxTelegram AuthNone #A2[Ren] FFE823->A5A503 Ack: 00
2023/07/25 18:47:06.300 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.301 <Debug> A<: #0 HmSystem Response 01

Wo kommen denn diese Meldungen hier her?

Möglicherweise sind die letzten Änderungen hier das Problem.

Edit: Habe die RM-LGW jetzt mal auf 3.69.7.20230506 downgegraded.

Hier ist der Restart der RM-OVA (oder nur des rfd) kein Problem. Die RM-LGW wirft zwar "tausende" der obigen not enough space in buffers -Fehlermeldungen, hört dann aber damit auf und die Verbindung zum LGW besteht weiterhin.

Danke für das analysieren. Dann müsste ich mir das selbst wohl noch einmal genauer anschauen oder jemand (@jp112sdl ?) debuggt das mal selbst mit den existierenden quellen des hmlangw daemon, denn ich werd in den nächsten Tagen/Wochen vmtl. nicht selbst dazu kommen.

jp112sdl · 2023-07-25T19:58:35Z

Hab ich das richtig verstanden?

Ja richtig.
Beim erstmaligen Verbinden des RFD -> LGW nach dem Booten des RM-LGW ist alles ok.
Verliert der RFD die Verbindung zum LGW und führt anschließend einen Reconnect durch, bzw. startet der RFD neu (sei es durch Reboot oder nur der Dienst) läuft der multimacd am LGW voll mit den Meldungen

2023/07/25 18:47:06.300 <Debug> A>: #0 HmSystem StartBootloader
2023/07/25 18:47:06.301 <Debug> A<: #0 HmSystem Response 01
2023/07/25 18:47:06.301 <Debug> A<: #21 HmSystem Identify Co_CPU_App

Die Logausgaben kommen also vom multimacd der RM-LGW.
Den hatte ich mit -c -l 0 auf der Shell gestartet.

Ich war nur kurz zwischen Tür und Angel bei Baxxy per Teamviewer auf seine Anlage verbunden.
Selbst kann ich da nicht weiter debuggen.

jp112sdl · 2023-07-26T05:32:46Z

Was mir gerade beim Morgenkaffee durch den Kopf geht:
Braucht es dieses ganze Bootloaderhandling/Resetcopro eigentlich noch?

Der multimacd stellt den CoPro beim Starten schon in den richtigen (Applikations-)Modus und ermöglicht durch das Bereitstellen der /dev/mmd_* Geräte den logischen Zugriff auf das BidCos-/HmIP-Funkmedium.

Der hmlangw muss (oder darf) sich um die physische Initialisierung (resetCoPro) dann nicht mehr kümmern.

Warum das Ganze beim 1. Connect funktioniert, weiß ich zwar auch nicht.

Aber den Absturz nach einem Reconnect führe ich gedanklich momentan darauf zurück, dass der hmlangw den CoPro hinter dem Rücken des multimacd resettet oder in den Bootloadermodus bringen will.

jens-maus · 2023-07-26T05:39:03Z

Braucht es dieses ganze Bootloaderhandling/Resetcopro eigentlich noch?

Diesen Gedanken hatte ich in der Tat auch bereits als ich das letzt mal Hand an hmlangw gelegt hatte um den anderen Bug zu fixen. Vllt könnte man diese Funktionalität ja so umbauen das diese rein optional ist und nur mit command-option aktiviert wird oder zumindest temporär einfach mal auskommentieren um dies mal zu testen.

jp112sdl · 2023-07-26T06:33:13Z

Warum das Ganze beim 1. Connect funktioniert, weiß ich zwar auch nicht.

Nun wird es klarer... bereits beim Disconnect wird sendEnterBootloader aufgerufen.
Anschließend findet keine Kommunikation zwischen RFD und HMLANGW (und somit auch dem multimacd und dem CoPro) statt, was zunächst unproblematisch ist.
Und beim nächsten Connect, wenn der RFD wieder was vom CoPro will, läuft dann alles gegen die Wand?

RaspberryMatic/buildroot-external/package/hmlangw/hmlangw.cpp

Lines 505 to 510 in 9839133

    
           fprintf( stderr,  "BidCos client closed connection.\n" ); 
        
           if( resetCoPro() == -1 && g_inBootloader == false ) 
        
           { 
        
               if( sendEnterBootloader( g_serialFd ) > 0 ) 
        
                   g_inBootloader = true; 
        
           }

Das selbe passiert auch, wenn der hmlangw Prozess beendet wird.

Ich würde sendEnterBootloader komplett als Kommandozeilenparameter abschaltbar machen.

Schaue ich mir mal an.

Newton1981 · 2023-07-26T07:14:48Z

Guten Morgen Zusammen, vorneweg schonmal vielen Dank für die viele Arbeit und Mühe die in dem ganzen Projekt steckt. Und dann auch noch für die Beschäftigung mit einem Problem das außer mir scheinbar kaum jemand hat. Wenn ich helfen kann sagt Bescheid, bin zwar die nächsten 3 Wochen im Urlaub, aber wenn ich danach was testen soll mache ich das gerne. Bin zwar nicht begabt, kann aber ganz gut Anleitungen folgen :-)

Baxxy13 · 2023-07-26T10:41:12Z

So, Lagebericht:

Haben bei einer Session am Vormittag in meine RM-LGW (Pi2B mit HM-MOD-RPI-PCB und RM-Nightly 3.71.12.20230726-4751dc) einen von @jp112sdl modifizierten hmlangw eingepflanzt.

Seitdem kann ich keine Probleme mehr feststellen.
Die Verbindung zur RM-LGW wird nach Reboots der RM-OVA oder Restarts des rfd (auf der RM-OVA) problemlos wiederhergestellt.
Auch sah ich seitdem keine der not enough space in buffers -Fehlermeldungen mehr im Log der RM-LGW.

Sieht für mich also "gefixt" aus.

jp112sdl · 2023-07-26T11:27:51Z

Ich mache den PR im Laufe des Tages noch fertig.

@jp112sdl

…self while multimacd is already doing that (#2350, @jp112sdl)

jens-maus · 2023-07-26T12:43:45Z

Ok, danke @jp112sdl. Dann am besten morgen mit dem nächsten nightly snapshot nochmal durchtesten und dann können wir dieses Thema hier hoffentlich auch endlich abhaken das die BidCos-RF LAN-Gateway Verbindungen hin- und wieder instabil sind.

Baxxy13 · 2023-07-27T16:54:38Z

So, ich habe das Testsetup (mit den heutigen Nightly's) nun ordentlich mit Verbindungsabbrüchen und Reboot's malträtiert.
Kurz und knapp. Läuft und lässt sich nicht aus dem Tritt bringen, also reconnected immer sauber ohne Fehlermeldungen oder sonstwas.
Gute Arbeit @jp112sdl !
Wird mal wieder Zeit für eine gemeinsame Portion 🐮
😉

jp112sdl · 2023-07-28T04:56:55Z

Gute Arbeit @jp112sdl !

Das Zusammenspiel hat doch mal wieder gut geklappt, dank deines aufgeräumten Testlabors (bis auf die offenen 736 Browser-Tabs^^).

Wird mal wieder Zeit für eine gemeinsame Portion 🐮

Ja müssten wir mal planen. Hab gerade bei DB geschaut und war angenehm überrascht, dass es ICE-Verbindungen nach Berlin für 9,90 EUR gibt.

jens-maus · 2023-07-28T05:34:55Z

Wird mal wieder Zeit für eine gemeinsame Portion 🐮

Ja müssten wir mal planen. Hab gerade bei DB geschaut und war angenehm überrascht, dass es ICE-Verbindungen nach Berlin für 9,90 EUR gibt.

Dann leg mal einen Zwischenstopp in Dresden ein, dann kannst du für euch auch ein Stück Eierschecke mit auf den Weg einpacken 😜

bronkoo · 2023-07-28T08:20:56Z

Ja müssten wir mal planen. Hab gerade bei DB geschaut und war angenehm überrascht, dass es ICE-Verbindungen nach Berlin für 9,90 EUR gibt.

...oder Du entscheidest Dich ab Berlin per Trampen nach Norden, macht Spaß, ist kostenlos und auf Rügen angekommen, gibt's dann Meerblick mit Zitronenbrause...

DANKE an Alle und @Newton1981 , Du bist nicht allein... ;-)
Ich teste im Release asap.

jp112sdl · 2023-07-28T08:24:03Z

Dresden liegt jetzt nicht gerade am Wegesrand in Richtung Berlin.
Aber vielleicht will @jens-maus mal raus aus der Kleinstadt und gesellt sich mit in die Berliner Runde 😉

Rügen wäre sicher auch für @Baxxy13 eine Option 😄

Baxxy13 · 2023-07-28T12:14:19Z

Ich bin ja letztes WE an Dresden vorbeigebrummt.
Die Mohnschnecke habe ich in Bad Schandau verspeist und in Pirna leckeres Softeis. 😋

Nach Rügen geht's am Sonntag, aber mit dem grünen Bus.

Ich teste im Release asap.

Na dann hoffe (und denke) ich mal das das nun läuft.

Beim Problemkind im Forum muss das Problem m.E. woanders liegen.

bronkoo added the 🐛 bug-report Something isn't working label Jun 28, 2023

jens-maus added this to the future release milestone Jul 25, 2023

jp112sdl mentioned this issue Jul 26, 2023

HMLANGW: option to prevent entering copro bootloader mode #2374

Merged

7 tasks

jens-maus linked a pull request Jul 26, 2023 that will close this issue

HMLANGW: option to prevent entering copro bootloader mode #2374

Merged

7 tasks

jens-maus closed this as completed in #2374 Jul 26, 2023

jens-maus pushed a commit that referenced this issue Jul 26, 2023

fixed issue that hmlangw puts rf-module copro into bootloader mode it…

f80ce43

…self while multimacd is already doing that (#2350, @jp112sdl)

jens-maus modified the milestones: future release, next release Jul 26, 2023

jens-maus modified the milestones: next release, 3.71.12.20230826 Aug 27, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

HMLANGW mode doesn't work in 3.69.7.20230626 #2350

HMLANGW mode doesn't work in 3.69.7.20230626 #2350

bronkoo commented Jun 28, 2023 •

edited

Loading

Newton1981 commented Jun 30, 2023

bronkoo commented Jun 30, 2023 •

edited

Loading

Newton1981 commented Jul 12, 2023

bronkoo commented Jul 12, 2023

Baxxy13 commented Jul 25, 2023 •

edited

Loading

jens-maus commented Jul 25, 2023

jp112sdl commented Jul 25, 2023 •

edited

Loading

jp112sdl commented Jul 26, 2023

jens-maus commented Jul 26, 2023

jp112sdl commented Jul 26, 2023

Newton1981 commented Jul 26, 2023

Baxxy13 commented Jul 26, 2023

jp112sdl commented Jul 26, 2023

jens-maus commented Jul 26, 2023 •

edited

Loading

Baxxy13 commented Jul 27, 2023

jp112sdl commented Jul 28, 2023

jens-maus commented Jul 28, 2023

bronkoo commented Jul 28, 2023

jp112sdl commented Jul 28, 2023

Baxxy13 commented Jul 28, 2023

HMLANGW mode doesn't work in 3.69.7.20230626 #2350

HMLANGW mode doesn't work in 3.69.7.20230626 #2350

Comments

bronkoo commented Jun 28, 2023 • edited Loading

Describe the issue you are experiencing

Describe the behavior you expected

Steps to reproduce the issue

What is the version this bug report is based on?

Which base platform are you running?

Which HomeMatic/homematicIP radio module are you using?

Anything in the logs that might be useful for us?

Additional information

Newton1981 commented Jun 30, 2023

bronkoo commented Jun 30, 2023 • edited Loading

Newton1981 commented Jul 12, 2023

bronkoo commented Jul 12, 2023

Baxxy13 commented Jul 25, 2023 • edited Loading

jens-maus commented Jul 25, 2023

jp112sdl commented Jul 25, 2023 • edited Loading

jp112sdl commented Jul 26, 2023

jens-maus commented Jul 26, 2023

jp112sdl commented Jul 26, 2023

Newton1981 commented Jul 26, 2023

Baxxy13 commented Jul 26, 2023

jp112sdl commented Jul 26, 2023

jens-maus commented Jul 26, 2023 • edited Loading

Baxxy13 commented Jul 27, 2023

jp112sdl commented Jul 28, 2023

jens-maus commented Jul 28, 2023

bronkoo commented Jul 28, 2023

jp112sdl commented Jul 28, 2023

Baxxy13 commented Jul 28, 2023

bronkoo commented Jun 28, 2023 •

edited

Loading

bronkoo commented Jun 30, 2023 •

edited

Loading

Baxxy13 commented Jul 25, 2023 •

edited

Loading

jp112sdl commented Jul 25, 2023 •

edited

Loading

jens-maus commented Jul 26, 2023 •

edited

Loading