Sonoff-Adapter - ungültige Zeichen in Logmessages

MartinP

Nachträglicher EDIT: Die Escape-Formatierungen waren NICHT das Problem -> siehe Postings ab #3
@homoran bitte verschieben nach dieser späteren Erkenntnis! ich habe schon die Überschrift Korrigiert

Aus aktuellem Anlass ist mir dieses Thema mal wieder aufgepoppt ...

Die Loggings liegen folgendermaßen vor

martin@iobroker-test-sicher:/opt/iobroker/log$ ls -l             
total 3452
-rw-rwxr--+ 1 iobroker iobroker   1209 Jun 26 10:10 iobroker-audit.json
-rw-rw-r--+ 1 iobroker iobroker 672353 Jun 20 00:01 iobroker.2026-06-19.log.gz
-rw-rw-r--+ 1 iobroker iobroker 624646 Jun 21 00:00 iobroker.2026-06-20.log.gz
-rw-rw-r--+ 1 iobroker iobroker 650422 Jun 22 00:00 iobroker.2026-06-21.log.gz
-rw-rw-r--+ 1 iobroker iobroker 630390 Jun 23 00:01 iobroker.2026-06-22.log.gz
-rw-rw-r--+ 1 iobroker iobroker 484644 Jun 24 00:00 iobroker.2026-06-23.log.gz
-rw-rw-r--+ 1 iobroker iobroker 110585 Jun 25 00:00 iobroker.2026-06-24.log.gz
-rw-rw-r--+ 1 iobroker iobroker  69347 Jun 26 00:00 iobroker.2026-06-25.log.gz
-rw-rw-r--+ 1 iobroker iobroker 271086 Jun 26 10:38 iobroker.2026-06-26.log
lrwxrwxrwx  1 iobroker iobroker     23 Jun 26 10:30 iobroker.current.log -> iobroker.2026-06-26.log

Die Logfiles der Vortage nur gezippt.

Durchsuchen kann man die Zips mit zgrep oder grep. So zum Beispiel alles, was vom Email-Adapter geloggt wurde

aktueller Tag

martin@iobroker-test-sicher:/opt/iobroker/log$ grep "email" *.log
iobroker.2026-06-26.log:2026-06-26 02:01:04.965  - info: email.0 (418) Send email: {"text":"Thermostat tot 26.06.26  02:00:55","to":"Martin.Praekelt@o2online.de","subject":"[SmartHome] Thermostat tot 26.06.26  02:00:55","from":"martin.praekelt@o2online.de"}
iobroker.2026-06-26.log:2026-06-26 02:01:05.274  - info: email.0 (418) Send email: {"text":"Thermostat lebt wieder, 26.06.26 02:00:56\nNicht erreichbar für 0:0:30\nThermostat 1.2.7 13-MAR-2026 started, 3 sensors, 3C5D04572015/28, 3C610457
....

Die sieben Tage davor

martin@iobroker-test-sicher:/opt/iobroker/log$ zgrep "email" *.gz |more
iobroker.2026-06-19.log.gz:2026-06-19 02:11:44.139  - info: email.0 (435) Send email: {"text":"Gerätetedetails: \nAqara_1: OK (true)\nEnergiezaehler: OK (true)\nFritzDECT_Steckdose: OK (true)\nLidl-Fluter : ERROR (false)\nAlive EMS
-ESP : ERROR (false)\nAlive Meross 1: OK (true)\nAlive Zählerüberwachung: OK (true)\nAlive Meross 2: OK (true)\nAlive NOUS A1T (\"Bewaesserung\"): OK (true)\nAlive ESP-TORSTEUERUNG: OK (true)\nAlive FF-DO-Hilgenloh : ERROR (false)\n","to":"
martin.praekelt@o2online.de","subject":"SmartHome Gerätestatus: 3 Geräte nicht erreichbar","from":"martin.praekelt@o2online.de"}
iobroker.2026-06-19.log.gz:2026-06-19 02:11:46.543  - info: email.0 (435) sent to martin.praekelt@o2online.de
iobroker.2026-06-19.log.gz:2026-06-19 02:12:27.340  - info: email.0 (435) Send email: {"text":"Gerätetedetails: \nAqara_1: OK (true)\nEnergiezaehler: OK (true)\nFritzDECT_Steckdose: OK (true)\nLidl-Fluter : ERROR (false)\nAlive EMS
....

Was nicht klappt, ist Suchen nach "info: email"

Da sind wohl escape Formatierungen im Text der Log-Nachricht (hier ein Schnipsel von Linux-Control

00047130: 2020 2d20 1b5b 3332 6d69 6e66 6f1b 5b33    - .[32minfo.[3
00047140: 396d 3a20 6c69 6e75 782d 636f 6e74 726f  9m: linux-contro
00047150: 6c2e 3020 2836 3739 2920 7375 6363 6573  l.0 (679) succes
00047160: 7366 756c 2072 6563 6569 7665 6420 6461  sful received da
00047170: 7461 2066 726f 6d20 7072 6f78 6d6f 7820  ta from proxmox

Mein erster Versuch, nach error und warn Meldungen des Email-Adapters in den Log-Zipfiles zu suchen:

Erst mit zgrep nach Log-Zeilen "email.0" suchen, und das Suchergebnis dann noch einmal nach "error" oder "warn" durchsuchen .... funktioniert...

martin@iobroker-test-sicher:/opt/iobroker/log$ zgrep  "email.0" * |grep -E "error.|warn."
iobroker.2026-06-19.log.gz:2026-06-19 20:27:21.283  - warn: host.iobroker-test-sicher instance system.adapter.email.0 terminated due to SIGKILL
iobroker.2026-06-22.log.gz:2026-06-22 08:01:13.210  - error: email.0 (213499) Error Unexpected socket close
iobroker.2026-06-22.log.gz:2026-06-22 08:01:13.216  - error: email.0 (213499) Cannot send email: Error: Unexpected socket close
iobroker.2026-06-23.log.gz:2026-06-23 08:01:16.955  - error: email.0 (213499) Error read ECONNRESET
iobroker.2026-06-23.log.gz:2026-06-23 08:01:16.960  - error: email.0 (213499) Cannot send email: Error: read ECONNRESET
grep: iobroker.2026-06-23.log.gz: binary file matches
iobroker.2026-06-24.log.gz:2026-06-24 17:18:28.385  - warn: host.iobroker-test-sicher instance system.adapter.email.0 terminated due to SIGKILL
iobroker.2026-06-24.log.gz:2026-06-24 17:19:40.492  - warn: email.0 (42410) slow connection to objects DB. Still waiting ...
iobroker.2026-06-24.log.gz:2026-06-24 17:19:50.632  - warn: email.0 (42410) slow connection to states DB. Still waiting ...
iobroker.2026-06-24.log.gz:2026-06-24 17:29:14.710  - error: email.0 (42410) Error queryA ETIMEOUT pop.o2online.de
iobroker.2026-06-24.log.gz:2026-06-24 17:29:14.711  - error: email.0 (42410) Cannot send email: Error: queryA ETIMEOUT pop.o2online.de
iobroker.2026-06-24.log.gz:2026-06-24 17:29:35.272  - error: email.0 (42410) Error queryA ETIMEOUT pop.o2online.de
iobroker.2026-06-24.log.gz:2026-06-24 17:29:35.273  - error: email.0 (42410) Cannot send email: Error: queryA ETIMEOUT pop.o2online.de
iobroker.2026-06-24.log.gz:2026-06-24 17:29:39.222  - error: email.0 (42410) Error queryA ETIMEOUT pop.o2online.de
iobroker.2026-06-24.log.gz:2026-06-24 17:29:39.227  - error: email.0 (42410) Cannot send email: Error: queryA ETIMEOUT pop.o2online.de
iobroker.2026-06-24.log.gz:2026-06-24 17:30:29.903  - warn: host.iobroker-test-sicher instance system.adapter.email.0 terminated due to SIGKILL
iobroker.2026-06-24.log.gz:2026-06-24 17:35:30.597  - warn: email.0 (418) slow connection to objects DB. Still waiting ...
iobroker.2026-06-24.log.gz:2026-06-24 17:36:09.260  - warn: email.0 (418) slow connection to states DB. Still waiting ...
iobroker.2026-06-25.log.gz:2026-06-25 09:44:12.085  - error: email.0 (418) Error connect ENETUNREACH 91.136.8.190:465
iobroker.2026-06-25.log.gz:2026-06-25 09:44:12.093  - error: email.0 (418) Cannot send email: Error: connect ENETUNREACH 91.136.8.190:465
martin@iobroker-test-sicher:/opt/iobroker/log$

Ich finde es eigentlich ziemlich lästig, dass die Escape-Sequenzen im Log-File für das Durchsuchen mit grep im Weg stehen
Sieht hübsch aus, und die Farbliche Markierung von warn,info etc ist beim manuellen Durchforsten sicher hilfreich....

Das ist aber sicher Geschmackssache. Einen Issue traue ich mich nicht dafür auf zu machen. Was meint Ihr?

P.S. Die Warnung "binary file matches" ist auch spannend, muss ich mir ggfs. auch anschauen

MartinP

Nachtrag zur "bösen" Log-Zeile ...

Auch die habe ich gefunden

iconv -f ASCII -t ASCII -o /dev/null iobroker.2026-06-23.log 
iconv: ungültige Eingabe-Sequenz an der Stelle 780997

Dann eine Hex-Dump-Datei angelegt

xxd iobroker.2026-06-23.log >iobroker.2026-06-23.hex

780997 ist in Hex laut Linux-Taschenrechner BEAC5

000bea30: 3438 3632 397d 0a32 3032 362d 3036 2d32  48629}.2026-06-2
000bea40: 3320 3032 3a30 303a 3535 2e37 3033 2020  3 02:00:55.703  
000bea50: 2d20 1b5b 3332 6d69 6e66 6f1b 5b33 396d  - .[32minfo.[39m
000bea60: 3a20 656d 6169 6c2e 3020 2832 3133 3439  : email.0 (21349
000bea70: 3929 2053 656e 6420 656d 6169 6c3a 207b  9) Send email: {
000bea80: 2274 6578 7422 3a22 5468 6572 6d6f 7374  "text":"Thermost
000bea90: 6174 206c 6562 7420 7769 6564 6572 2c20  at lebt wieder, 
000beaa0: 3233 2e30 362e 3236 2030 323a 3030 3a33  23.06.26 02:00:3
000beab0: 375c 6e4e 6963 6874 2065 7272 6569 6368  7\nNicht erreich
000beac0: 6261 7220 66c3 bc72 2030 3a30 3a34 305c  bar f..r 0:0:40\
000bead0: 6e54 6865 726d 6f73 7461 7420 312e 322e  nThermostat 1.2.
000beae0: 3720 3133 2d4d 4152 2d32 3032 3620 7374  7 13-MAR-2026 st
000beaf0: 6172 7465 642c 2033 2073 656e 736f 7273  arted, 3 sensors

Nach "Nicht erreichbar ..." kommt irgendein Zeichen - Müll, es sieht nach einem falsch kodierten "ü" aus ..

Dieses "ü" ist es - werde es pragmatisch mal durch "ue" ersetzen - die 90er rufen an ;-)

NACHTRAG:
Das ist definitiv einen Issue wert ... Da die Mail ja "sauber" dargestellt wird, würde ich sagen, für den Email-Adapter, was das Logging angeht...

MartinP

Nachtrag 2, es war nicht der Mail-Adapter, sondern der Sonoff Adapter ... der Loggt anscheinend "kaputte" JSON-Pakete, ohne sie zu "entschärfen"!

Die Textdatei ließ sich mit der Linux-Mint-Textverarbeitung "xed" wohl einlesen, es gab aber eine Warnung...

Die geöffnete Datei enthält einige ungültige Zeichen. Wenn Sie die Bearbeitung fortsetzen, könnten Sie das Dokument unbrauchbar machen.
Sie können auch eine andere Zeichenkodierung wählen und es erneut versuchen.

Hier wahrscheinlich die problematische Stelle (grep scheint wohl etwas "Voraus" zu lesen, deshalb hatte ich den Zeitpunkt früher gesehen)

```

Habe einen Issue erstellt https://github.com/ioBroker/ioBroker.sonoff/issues/586

OliverIO

@MartinP

Hab es selbst nicht geprüft, könnte aber das trennzeichen zwischen log lesen (info:) und der Instanz (email.0) evtl. ein tabulator sein?

Greg arbeitet ja mit regulären ausdrücken
https://man7.org/linux/man-pages/man1/grep.1.html

Meine Lieblingswitze um so einen Ausdruck/pattern zu entwickeln ist

https://regex101.com/

Regex ist aber nicht ganz so handlich, aber diese Seite zeigt Dir die Ergebnis ein wenig aufbereitet.
Die am besten funktionierende Methode für mich ist, einfach die gewünschte Fundstelle markieren + markante, sich wahrscheinlich wenig wiederholende Textstellen davor und/oder danach. Das können manchmal nur wenige Zeichen sein, manchmal aber auch mehr.
Wenn man diese Fundstelle oben in das patterned kopiert müsste die Fundstelle auch markiert werden.
Dann geht man die Fundstelle durch und ersetzt alle variablen Anteile mit entsprechenden regex Befehle.

Eine weitere Möglichkeit, wäre, einen entsprechenden Ausschnitt aus mehreren Zeilen in eine KI zu kopieren und das gewünschte Ergebnis mit Nutzung von Greg verbal zu beschreiben. Dann dürfte die ki so ein pattern auswerfen.

Letzte Möglichkeit: den selben Ausschnitt aus mehreren Zeilen hier ins Forum kopieren und du erhältst dein pattern für das entsprechende Tool

MartinP

Ich glaube, das ist ein klassisches Shit In -> Shit Out Problem.

Das Tasmota-Device, was per Sonoff-Adapter ausgelesen wird, schickt ein verkrüppeltes JSON-Telegramm per MQTT.

Der Sonoff Adapter merkt, dass das Telegramm nicht "astrein" ist

"SyntaxError: Bad control character in string literal in JSON at position 118 (line 1 column 119)"

Trotzdem wird das empfangene JSON an die Log-Message WIE ES IST angehängt ...

Hier ist das nur eine Unbequemlichkeit, weil danach das Log-File nicht mehr mit grep durchsuchbar ist.

martin@martin-D2836-S1:~/Temp$ grep -n "sonoff" iobroker.2026-06-23.log
17651:2026-06-23 10:57:24.792  - info: sonoff.0 (213567) Client [Stromzaehler_B5F63F] connection closed: Error: Cannot parse topic
17652:2026-06-23 10:57:25.673  - info: sonoff.0 (213567) Client [Stromzaehler_B5F63F] connected with secret (gelöscht)
grep: iobroker.2026-06-23.log: Übereinstimmungen in Binärdatei

Wenn ich die Log-Datei im Text-Editor bereinige und als Kopie speichere (Passage aus dem Screenshot mit "...." überschreiben):

martin@martin-D2836-S1:~/Temp$ grep -n "sonoff" "iobroker.2026-06-23 (Kopie).log"
17651:2026-06-23 10:57:24.792  - info: sonoff.0 (213567) Client [Stromzaehler_B5F63F] connection closed: Error: Cannot parse topic
17652:2026-06-23 10:57:25.673  - info: sonoff.0 (213567) Client [Stromzaehler_B5F63F] connected with secret ......
18715:2026-06-23 11:34:53.713  - info: sonoff.0 (213567) Client [Bewaesserung] reconnected. Old secret ...... ==> New secret ....
18762:2026-06-23 11:36:09.637  - info: sonoff.0 (213567) Client [Bewaesserung] reconnected. Old secret ... ==> New secret ...
18847:2026-06-23 11:38:24.659  - warn: sonoff.0 (213567) Client [Bewaesserung] cannot parse data"SENSOR": _{"Time":"2026-06-23T10:36:54","ENERGY":{"TotalStartTime":"2023-07-03T14:48:02","Total":514.532,"Yesterday":0.643,"To0....tele/tasmota_17AB7E/STATE{"Time":"2026-06-23T10:37:14","Uptime":"55T00:44:43","UptimeSec":4754683,"Heap":16,"Sle_ - SyntaxError: Bad control character in string literal in JSON at position 118 (line 1 column 119)
18848:2026-06-23 11:38:24.661  - warn: sonoff.0 (213567) Client [Bewaesserung] received pubrel on Bewaesserung for unknown messageId 19823
.....

Wenn man Shit bemerkt, reicht man ihn nicht weiter ... nicht einmal an einen Logger -> https://www.trendmicro.com/de_de/what-is/apache-log4j-vulnerability.html

Nachtrag - ein Gedanke. Wenn bei der Entgegennahme der Log-Message auf "Bad control characters" geprüft und ggfs. entschärft würde, könnte nicht jeder Adapter beim Logging gepflegten Unsinn treiben ....

mcm1957

@MartinP sagte:

Nachtrag - ein Gedanke. Wenn bei der Entgegennahme der Log-Message auf "Bad control characters" geprüft und ggfs. entschärft würde, könnte nicht jeder Adapter beim Logging gepflegten Unsinn treiben ....

Bin ich im Prinzip bei dir. Mach bitte ein Issue beim js-controller auf und beschreib dein Problem.

OliverIO

@MartinP sagte:

Wenn man Shit bemerkt, reicht man ihn nicht weiter ... nicht einmal an einen Logger -> https://www.trendmicro.com/de_de/what-is/apache-log4j-vulnerability.html

ist der erwähnte logger irgendwo da im einsatz?
ist ja eher ein logger im java umfeld.
das problem da war, das ein feature defaultmäßig nicht beschränkt war und dadurch über logeinträge, die ein angreifer mit entsprechendem wissen evtl provozieren konnte, externer code nachgeladen werden konnte (sofern die firewalls das zugelassen haben)

MartinP

Es ist sicherlich keine gute Idee, sich da sicher zu fühlen. Exotische ungeprüfte Eingabedaten ist der Angriffsvektor vieler Schadsoftware ...

mcm1957

@MartinP sagte:

Nachtrag - ein Gedanke. Wenn bei der Entgegennahme der Log-Message auf "Bad control characters" geprüft und ggfs. entschärft würde, könnte nicht jeder Adapter beim Logging gepflegten Unsinn treiben ....

Bin ich im Prinzip bei dir. Mach bitte ein Issue beim js-controller auf und beschreib dein Problem.

Es macht null Sinn in zig Adaptern explizite Filter zu implementieren bzw. eigene Hüllen um log.* zu schreiben.

Andreas67 0

Es macht wenig Sinn, jeden Adapter einzeln anzupassen. Die Bereinigung sollte zentral im Logger des js-controller stattfinden, kurz bevor der String in die Datei geschrieben wird.Ein schlanker regulärer Ausdruck (Regex) kann alle schädlichen Steuerzeichen (C0- und C1-Kontrollzeichen) entfernen, ohne nennenswerten CPU-Overhead zu erzeugen. Wichtig dabei ist, dass die ANSI-Escape-Zeichen für die farbige Log-Ausgabe im Terminal erhalten bleiben.Hier ist ein konkreter JavaScript-Entwurf für die zentrale Logging-Schnittstelle:javascriptfunction sanitizeLogMessage(message) {
if (typeof message !== 'string') return message;

// Entfernt schädliche Steuerzeichen (C0 und C1),
// erlaubt aber Zeilenumbrüche (\n, \r), Tabs (\t) und das ANSI-Escape-Zeichen (\x1b) für die Farben
return message.replace(/[\x00-\x08\x0B\x0C\x0E-\x1F\x7F-\x9F]/g, '');

}
Verwende Code mit Vorsicht.Die VorteileZentral: Keine Anpassungen an den einzelnen Adaptern notwendig.Integrität: Logfiles bleiben für grep und andere Text-Tools immer vollständig durchsuchbar.Abwärtskompatibel: Die Farb-Formatierungen im Terminal funktionieren weiterhin einwandfrei, da das Escape-Zeichen (\x1b) geschützt wird.Ich würde mich über eine kurze Rückmeldung freuen, ob dieser Ansatz für euch infrage kommt, oder ob ich dazu ein offizielles GitHub-Issue eröffnen soll. Viele Grüße,Andreas

Community Forum

NEWS

Sonoff-Adapter - ungültige Zeichen in Logmessages

Support us

202

33.0k

83.3k

1.3m