nanoCUL-Probleme nach Raspbian-Update

TheTrumpeter · 26 Oktober 2023, 10:56:49

Ich habe vor kurzem mein System neu aufgesetzt, auf dem Rasperry läuft nun Buster in der 64-bit-Version ohne GUI. FHEM-Config habe ich vom alten System übertragen, fehlende Module anhand der Fehlermeldungen nachinstalliert. Auf den ersten Blick läuft alles wunderbar, allerdings macht der nanoCUL Probleme...

Nach einiger Zeit (unterschiedlich lang, mal paar Minuten, mal paar Stunden) empfange ich keine Daten mehr.
Ab- und Anstecken hilft dann meist, aber auch ein erneutes definieren des Geräts (defmod blabla) löst das Problem.

Auszug aus dem Logfile mit "verbose 5", um 10:28:17 scheint noch eine Botschaft empfangen worden zu sein, um 10:28:27 kam dann "unknown code" und um 10:28:37 scheint nochmal was gekommen zu sein. Es gibt auch zwei passende Einträge im Syslog zu den Zeitstempeln, siehe weiter unten. Um 10:47 habe ich dann "defmod blabla" gemacht.

Zitat2023.10.26 10:28:17 5: CUL_Read: nanoCUL /b3E44A511460584707007686F7A830030057963AE000E806115322AF9D114EC4B0CA42B2AD27EAE4299BAAB446B443721EEE306FAF276EBA77423C55BB7E459A
2023.10.26 10:28:17 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A830030057963AE000E806115322AF9D114EC4B0CA42B2AD27EAE4299BAAB446B443721EEE306FAF276EBA77423C55BB7E459A/918F5AF358E05E8BAF78039

2023.10.26 10:28:17 4: CUL_Parse: nanoCUL b3E44A511460584707007686F7A830030057963AE000E806115322AF9D114EC4B0CA42B2AD27EAE4299BAAB446B443721EEE306FAF276EBA77423C55BB7E459A918F5AF358E05E8BAF78039 -45.5
2023.10.26 10:28:17 5: nanoCUL: dispatch b3E44A511460584707007686F7A830030057963AE000E806115322AF9D114EC4B0CA42B2AD27EAE4299BAAB446B443721EEE306FAF276EBA77423C55BB7E459A918F5AF358E05E8BAF780::-45.5
2023.10.26 10:28:17 5: WMBUS raw msg b3E44A511460584707007686F7A830030057963AE000E806115322AF9D114EC4B0CA42B2AD27EAE4299BAAB446B443721EEE306FAF276EBA77423C55BB7E459A918F5AF358E05E8BAF780::-45.5
2023.10.26 10:28:27 5: CUL_Read: nanoCUL /00580FBD3C167961D92A41E2973ECD14
2023.10.26 10:28:27 5: CUL_Read: nanoCUL 00580FBD3C167961D92A41E2973ECD14/062B94364BB1343C74FB6FED0A363F10
2023.10.26 10:28:27 5: CUL_Read: nanoCUL 00580FBD3C167961D92A41E2973ECD14062B94364BB1343C74FB6FED0A363F10/E9B423453A1F49DEE81B2073998367A0
2023.10.26 10:28:27 5: CUL_Read: nanoCUL 00580FBD3C167961D92A41E2973ECD14062B94364BB1343C74FB6FED0A363F10E9B423453A1F49DEE81B2073998367A0/AE287191C7BAF7F27C18036

2023.10.26 10:28:27 4: CUL_Parse: nanoCUL 00580FBD3C167961D92A41E2973ECD14062B94364BB1343C74FB6FED0A363F10E9B423453A1F49DEE81B2073998367A0AE287191C7BAF7F27C18036
2023.10.26 10:28:27 5: nanoCUL: dispatch 00580FBD3C167961D92A41E2973ECD14062B94364BB1343C74FB6FED0A363F10E9B423453A1F49DEE81B2073998367A0AE287191C7BAF7F27C18036
2023.10.26 10:28:27 3: nanoCUL: Unknown code 00580FBD3C167961D92A41E2973ECD14062B94364BB1343C74FB6FED0A363F10E9B423453A1F49DEE81B2073998367A0AE287191C7BAF7F27C18036, help me!
2023.10.26 10:28:37 5: CUL_Read: nanoCUL /b3E44A511460584707007686F7A83003
2023.10.26 10:28:37 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A83003/005F3F31CC5ACD068797CAA63E8A25B9
2023.10.26 10:28:37 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A83003005F3F31CC5ACD068797CAA63E8A25B9/08162114DC6943942CED2040D605DCE7
2023.10.26 10:28:37 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A83003005F3F31CC5ACD068797CAA63E8A25B908162114DC6943942CED2040D605DCE7/B0F8811A2E073957ABC63AB1E5B0AB2D
2023.10.26 10:28:37 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A83003005F3F31CC5ACD068797CAA63E8A25B908162114DC6943942CED2040D605DCE7B0F8811A2E073957ABC63AB1E5B0AB2D/5155BC95C9FA362BA9C8038

2023.10.26 10:28:37 4: CUL_Parse: nanoCUL b3E44A511460584707007686F7A83003005F3F31CC5ACD068797CAA63E8A25B908162114DC6943942CED2040D605DCE7B0F8811A2E073957ABC63AB1E5B0AB2D5155BC95C9FA362BA9C8038 -46
2023.10.26 10:28:37 5: nanoCUL: dispatch b3E44A511460584707007686F7A83003005F3F31CC5ACD068797CAA63E8A25B908162114DC6943942CED2040D605DCE7B0F8811A2E073957ABC63AB1E5B0AB2D5155BC95C9FA362BA9C80::-46
2023.10.26 10:28:37 5: WMBUS raw msg b3E44A511460584707007686F7A83003005F3F31CC5ACD068797CAA63E8A25B908162114DC6943942CED2040D605DCE7B0F8811A2E073957ABC63AB1E5B0AB2D5155BC95C9FA362BA9C80::-46
2023.10.26 10:47:13 3: Opening nanoCUL device /dev/serial/by-path/platform-3f980000.usb-usb-0:1.3:1.0-port0
2023.10.26 10:47:13 3: Setting nanoCUL serial parameters to 38400,8,N,1
2023.10.26 10:47:13 5: CUL_ReadAnswer nanoCUL: 005FE6AF7E3375BFF7804D7E901030CF
2023.10.26 10:47:13 5: DevIo_SimpleWrite nanoCUL: V
2023.10.26 10:47:16 5: DevIo_SimpleWrite nanoCUL: V
2023.10.26 10:47:16 5: CUL_ReadAnswer nanoCUL: V 1.67 nanoCUL868

2023.10.26 10:47:16 5: DevIo_SimpleWrite nanoCUL: ?
2023.10.26 10:47:16 5: CUL_ReadAnswer nanoCUL: ? (? is unknown) Use one of A B
2023.10.26 10:47:16 5: CUL_ReadAnswer nanoCUL: b C e F f G i K l M R T t V W X
2023.10.26 10:47:16 5: CUL_ReadAnswer nanoCUL: x

2023.10.26 10:47:16 3: nanoCUL: Possible commands: ABbCeFfGiKlMRTtVWXx
2023.10.26 10:47:16 5: DevIo_SimpleWrite nanoCUL: X21
2023.10.26 10:47:16 5: DevIo_SimpleWrite nanoCUL: T01
2023.10.26 10:47:16 5: CUL_ReadAnswer nanoCUL: 0000

2023.10.26 10:47:16 5: GOT CUL fhtid: 0000
2023.10.26 10:47:16 3: nanoCUL device opened
2023.10.26 10:47:16 5: DevIo_SimpleWrite nanoCUL: X21
2023.10.26 10:47:16 5: DevIo_SimpleWrite nanoCUL: brt
2023.10.26 10:47:16 2: Switched nanoCUL rfmode to WMBus_T
2023.10.26 10:47:16 5: CUL_Read: nanoCUL /TMODE

2023.10.26 10:47:16 4: CUL_Parse: nanoCUL TMODE
2023.10.26 10:47:16 5: CUL_Parse: switched to TMODE
2023.10.26 10:47:21 5: CUL_Read: nanoCUL /b3E44A511460584707007686F7A84003
2023.10.26 10:47:21 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A84003/0052F5CCC94AAFBE12900BF668217342
2023.10.26 10:47:21 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A840030052F5CCC94AAFBE12900BF668217342/BC9E1273AC10DE3C1515C332332B8677
2023.10.26 10:47:21 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A840030052F5CCC94AAFBE12900BF668217342BC9E1273AC10DE3C1515C332332B8677/9CDC185180DCD2A249EE82659802554C
2023.10.26 10:47:21 5: CUL_Read: nanoCUL b3E44A511460584707007686F7A840030052F5CCC94AAFBE12900BF668217342BC9E1273AC10DE3C1515C332332B86779CDC185180DCD2A249EE82659802554C/8978AC6E6BC1080803D803C

2023.10.26 10:47:21 4: CUL_Parse: nanoCUL b3E44A511460584707007686F7A840030052F5CCC94AAFBE12900BF668217342BC9E1273AC10DE3C1515C332332B86779CDC185180DCD2A249EE82659802554C8978AC6E6BC1080803D803C -44
2023.10.26 10:47:21 5: nanoCUL: dispatch b3E44A511460584707007686F7A840030052F5CCC94AAFBE12900BF668217342BC9E1273AC10DE3C1515C332332B86779CDC185180DCD2A249EE82659802554C8978AC6E6BC1080803D80::-44
2023.10.26 10:47:21 5: WMBUS raw msg b3E44A511460584707007686F7A840030052F5CCC94AAFBE12900BF668217342BC9E1273AC10DE3C1515C332332B86779CDC185180DCD2A249EE82659802554C8978AC6E6BC1080803D80::-44

Im Syslog finde ich zu dem Zeitpunkt:

ZitatOct 26 10:28:20 raspberrypi kernel: [266683.996099] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
Oct 26 10:28:41 raspberrypi kernel: [266704.997070] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32

Das Gerät ist wie folgt definiert:

Code Auswählen

define nanoCUL CUL /dev/serial/by-path/platform-3f980000.usb-usb-0:1.3:1.0-port0@38400 0000
attr nanoCUL group Wasserzaehler
attr nanoCUL rfmode WMBus_T
attr nanoCUL room Sensoren
attr nanoCUL verbose 5

An der Firmware habe ich seit Jahren nichts geändert, mit dem alten System hatte ich keinerlei Probleme. (Ich könnte zu Testzwecken die SD-Karte mit dem alten System wieder einstecken, gehe aber davon aus, dass es damit problemlos läuft.)

Hat jemand eine Idee was die Ursache dafür ist und wie ich es lösen kann?

KölnSolar · 26 Oktober 2023, 11:20:37

ZitatOct 26 10:28:20 raspberrypi kernel: [266683.996099] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
Oct 26 10:28:41 raspberrypi kernel: [266704.997070] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32

Da kann dann FHEM nichts dafür.

ZitatNach einiger Zeit (unterschiedlich lang, mal paar Minuten, mal paar Stunden) empfange ich keine Daten mehr.
Ab- und Anstecken hilft dann meist, aber auch ein erneutes definieren des Geräts (defmod blabla) löst das Problem.

Ich spekuliere mal auf ein Spannungsproblem(mehr Leistungsaufnahme oder Spannungsschwankungen durch Update ?)
Besseres Netzteil oder aktiver USB-Hub... sollten das Problem lösen.

RalfRog · 26 Oktober 2023, 11:42:14

Wenn es mit der Spannungsversorgung zu tun hat könnte bei der Suche helfen:

Code Auswählen

vcgencmd get_throttled
mit Ausgabe z.B.: throttled=0x50005
wenns ok ist: throttled=0x0

Ich bin mir nicht ganz sicher aber ich glaube es steht auch im Syslog (irgenwie was von low voltage).

Google mal nach "Low Voltage Warning".

Gruß Ralf

TheTrumpeter · 26 Oktober 2023, 13:24:28

Zitat von: KölnSolar am 26 Oktober 2023, 11:20:37Ich spekuliere mal auf ein Spannungsproblem(mehr Leistungsaufnahme oder Spannungsschwankungen durch Update ?)
Besseres Netzteil oder aktiver USB-Hub... sollten das Problem lösen.

Hm... es ist richtig, dass die Prozessorlast mit dem neuen System permanent etwas höher ist als zuletzt vorher. Allerdings war die Last mit dem alten System vor diversen Optimierungen, die ich im Sommer gemacht hatte, noch höher als jetzt mit dem neuen System.
Der einzige Unterschied in der FHEM-Konfiguration ggü. dem alten System, ist, dass jetzt fhempy läuft. (Das war auch der Grund für das Update, weil ich's mit dem alten System einfach nicht zum Laufen bekommen habe.)
Ich habe nun mal fhempy deaktiviert (bzw. den Server gestoppt) und schaue, wie sich die Last in den nächsten Stunden verhält.

Zitat von: RalfRog am 26 Oktober 2023, 11:42:14Wenn es mit der Spannungsversorgung zu tun hat könnte bei der Suche helfen:
Code Auswählen Erweitern
vcgencmd get_throttled mit Ausgabe z.B.: throttled=0x50005 wenns ok ist: throttled=0x0
Ich bin mir nicht ganz sicher aber ich glaube es steht auch im Syslog (irgenwie was von low voltage).

Google mal nach "Low Voltage Warning".

Gruß Ralf

Im Syslog ist nichts zu finden, aber im kernel-Log. Blöderweise stehen da die Uhrzeiten nicht dabei, drum ist eine Zuordnung schwierig.
Allerdings hatte ich diese "trottled"-Warnungen auch mit dem alten System ohne jegliche Auswirkung...
Werd' mal schauen was ich für Netzteile herumliegen habe und mal ein anderes/stärkeres versuchen.

MadMax-FHEM · 26 Oktober 2023, 13:27:06

Wichtig ist die Spannung!

Der PI hat gern 5,2V drunter gibt's schonal die UnderVOLTAGE Warnung...

Gut genügend Strom nat. auch...

Ich hab bei so manchem PI ein StepUp-Modul davor und regle das auf ca. 5,2V

Dann war bei diesen PIs ruhe mit den Undervoltage Meldungen...
Z.B. bei meinem PI mit deConz-Aufsteck. Hab gemerkt, dass nicht mehr zuverlässig geschalten wird...
-> Undervoltage...

Dann StepUp und seither Ruhe und schaltet zuverlässig...

Gruß, Joachim

RalfRog · 26 Oktober 2023, 20:56:02

Zitat von: TheTrumpeter am 26 Oktober 2023, 13:24:28Werd' mal schauen was ich für Netzteile herumliegen habe und mal ein anderes/stärkeres versuchen.

Das mit dem Rumliegen war so eine Sache: Netzteil oder doch Ladegerät - Spannung stabil genug?

Bin dann auf ein Meanwell Hutschiene-Netzteil (15W / 4,75 bis 5,5 Volt adjust.) umgestiegen - gibts auch als Openfame bzw. Lochblechgehäuse und liegen bei 15 bis 10 EUR.

Von da an war Ruhe mit der SSD am USB, die sich gern mal weggehängt hatte.

Gruß Ralf

TheTrumpeter · 30 Oktober 2023, 09:12:16

Habe gestern Abend dann ein Netzteil mit 3A gefunden. Davor war es über ein Netzteil mit 2,4A versorgt. Seitdem ist Ruhe, die Prozessorlast ist auch deutlich gesunken, das "Throttling" ist weg.

Normalerweise ist der Raspi auch über ein Hutschienen-Netzteil mit regelbarer Spannung versorgt, das immer auf 5,4V eingestellt ist, aber da muss ich was reparieren. Drum ist schon länger die Übergangslösung mit der Steckdose mit integriertem USB-Netzteil im Einsatz ist: https://www.amazon.de/gp/product/B08PV2F6ND/

TheTrumpeter · 03 November 2023, 10:24:06

Zitat von: TheTrumpeter am 30 Oktober 2023, 09:12:16Habe gestern Abend dann ein Netzteil mit 3A gefunden. Davor war es über ein Netzteil mit 2,4A versorgt. Seitdem ist Ruhe, die Prozessorlast ist auch deutlich gesunken, das "Throttling" ist weg.

Zu früh gefreut, ,,Throttling" tritt zwar weiterhin nicht auf, aber heute Nacht wurden dann beide USB-Devices mit dem CH341 im Abstand von 4h ,,ausgeworfen".
Im Kernel-Log ist rundherum nichts eingetragen

Irgendwelche Ideen?

RalfRog · 03 November 2023, 13:48:29

Hallo

Zitat von: MadMax-FHEM am 26 Oktober 2023, 13:27:06...
Der PI hat gern 5,2V drunter gibt's schonal die UnderVOLTAGE Warnung...
Gut genügend Strom nat. auch...

Die 3A sind es ja nicht allein. Natürlich muss das Netzteil genügend Strom liefern können und dabei muss die Spannung stimmen.
5,2V dürfen es am USB-Eingang sein - daher bei vielen das regelbare Netzteil

Eine weitere Sache wäre die Zuleitung - zu lang, zu dünn => dann fällt ggfs. zuviel Spannung auf den Drähten ab.

Ich hatte mir mal extra ein USB-Kabel mit AWG20 besorgt (da sind nur die beiden Spannungspins belegt).

Die Meldung im Kernel-Log bzw. auch über dmesg:

Code Auswählen

[   67.509611] Under-voltage detected! (0x00050005)
[   73.748373] Voltage normalised (0x00000000)

Sep  1 07:05:03 raspberrypi kernel: [67.509611] Under-voltage detected! (0x00050005)
Sep  1 07:05:08 raspberrypi kernel: [73.748373] Voltage normalised (0x00000000)

Zitat von: TheTrumpeter am 30 Oktober 2023, 09:12:16Normalerweise ist der Raspi auch über ein Hutschienen-Netzteil mit regelbarer Spannung versorgt, das immer auf 5,4V eingestellt ist...

Das würde dir verraten ob es an der Stromversorgung liegt zumindest wenn das Problem weg ist.

Wenn ich mich recht erinnere hatte ich zum Thema mal gelesen, dass bei "Under-voltage detected!" der PI intern "Komponenten" wie USB abschaltet/runterfährt um den Core noch korrekt versorgen zu können.

Gruß Ralf

KölnSolar · 03 November 2023, 20:36:16

ZitatIm Kernel-Log ist rundherum nichts eingetragen

Wenn da nichts steht, dürfte es nicht an der Spannungsversorgung des RPi liegen. Vielleicht vom Nano ? Thema Levelshifter ? $:-\$

TheTrumpeter · 04 November 2023, 07:01:46

Zitat von: KölnSolar am 03 November 2023, 20:36:16Thema Levelshifter ? $:-\$

Das Teil ist jahrelang unauffällig gelaufen, nach dem OS-Update soll's plötzlich ein HW-Problem geben? Kommt mir irgendwie komisch vor.

Mir ist auch aufgefallen, dass das 2. Gerät mit dem CH341-Chip ebenfalls Probleme macht. Das ist ein simpler RS485-Dongle. Auch da fällt sporadisch die Kommunikation aus, im Log findet sich dann der gleiche Eintrag wie beim nanoCUL. Das Gerät läuft nicht in FHEM, dort kann ich das Problem beheben, indem ich das Service einfach neustarte.
Google hat zwar zahlreiche Treffer dazu, aber daraus werde ich nicht wirklich schlau. Die Suchergebnisse sind vorwiegend aus der (3D?) Druckecke. Dort wird ein Problem mit dem Treiber vermutet.

Ich helfe mir derzeit mal so, dass ich das Service für den RS485-Dongle stündlich über einen Cron-Job neu starte & den nanoCUL stündlich über ein "at" neu definiere. Momentan ist das ausreichend, aber bis zum Frühjahr brauche ich eine Lösung, mit der keine Informationen vom RS485 bzw. Wasserzähler, der vom nanoCUL abgefragt wird, verloren gehen können.