Sonoff-Adapter - ungültige Zeichen in Logmessages

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

MartinP

Die Lösung gefällt mir.

Verstehe ich das richtig, Du machst direkt einen Pull-Request?

MartinP

Noch ein Nachtrag: Die Farbgebung des Log-Levels finde ich eher hinderlich. Das Suchen nach einem Pattern "error: 0.<adaptername> wird dadurch z. B. kompliziert

MartinP

Ich habe mir sowohl das Repository des js-controllers, als auch des Sonoff-Adapters angeschaut. Die Änderungen würden meine Fähigkeiten deutlich übersteigen.

@andreas67-0 hast Du Dir die Änderung im js-controller auf die To-Do Liste gesetzt, oder soll ich einen Issue schreiben?

MartinP

Habe mal einen Issue erstellt, und Gegenwind bekommen ;-)

https://github.com/ioBroker/ioBroker.js-controller/issues/3397

Ein kleiner Ersatz sind vielleicht folgende beiden Skripte - die habe ich aber mal eben aus den Ärmeln geschüttelt, nicht besonders flexible:

my_grep.sh (usage my_grep.sh <pattern> <file>)

#!/bin/bash
#
# usage my_grep.sh <pattern> <file>
#
# prototype line zcat iobroker.current.log |sed  's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F\x7F-\x9F]//g' |grep button

patt=$1
shift
while [ "$#" -gt 0 ]; do
    cat "$1" |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"
    shift
done

my_zgrep.sh (usage my_zgrep.sh <pattern> <file>)

#!/bin/bash
#
# usage my_zgrep.sh <pattern> <file>
#
# prototype line zcat iobroker.current.log |sed  's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F\x7F-\x9F]//g' |grep button
patt=$1
#echo "pattern =" $patt
shift
while [ "$#" -gt 0 ]; do
    zcat "$1" |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"
    shift
done

#echo "searchpattern =" $patt

Dann noch eins, um in allen Logs zu suchen:

#!/bin/bash
patt=$1
zcat *.log.gz |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"
cat *.log |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"

Wenn man will, dass der eingeloggte User sie aus allen Verzeichnissen aufrufen kann, muss man noch an das File ~/.profile eine Zeile anhängen mit dem Pfad, in dem die Shellscripte liegen

PATH="$HOME/gitea/iobroker_shellscripte:$PATH"

EDIT Scripte angepasst, nun funktionieren auch Suchtexte aus mehreren Wörtern (Gänsefüße)

martin@iobroker-test-sicher:~/gitea/iobroker_shellscripte$ my_zgrep.sh "unexpected response" *.gz
2026-07-02 01:55:30.964  - error: tradfri.0 (633) Error: unexpected response (4.00) to observeDevice(65545): [object Object]
2026-07-02 01:55:33.534  - error: tradfri.0 (633) Error: unexpected response (4.00) to observeDevice(65545): [object Object]

MartinP

Habe eine einfachere Lösung gefunden:

das Tool "ansifilter" ist anscheinend auch im normalen regulären debian repository...

martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$ apt install ansifilter
[sudo] Passwort für martin:       
Paketlisten werden gelesen… Fertig
Abhängigkeitsbaum wird aufgebaut… Fertig
Statusinformationen werden eingelesen… Fertig
Die folgenden NEUEN Pakete werden installiert:
  ansifilter
0 aktualisiert, 1 neu installiert, 0 zu entfernen und 0 nicht aktualisiert.
Es müssen 68,3 kB an Archiven heruntergeladen werden.
Nach dieser Operation werden 200 kB Plattenplatz zusätzlich benutzt.

Zur Erinnerung der nicht hilfreiche Output von grep:

martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$ grep "Bad control" iobroker.2026-06-23.log
grep: iobroker.2026-06-23.log: Übereinstimmungen in Binärdatei

Aber....

martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$ ansifilter -i iobroker.2026-06-23.log |grep "Bad control"
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)
martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$

Aufgrund des "Strippens" der Farbcodierung kann man auch in einem Schritt nach Warnungen des sonoff-Adapters suchen.

martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$ ansifilter -i iobroker.2026-06-23.log |grep "warn: sonoff"
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)
2026-06-23 11:38:24.661  - warn: sonoff.0 (213567) Client [Bewaesserung] received pubrel on Bewaesserung for unknown messageId 19823
....

Alles verfügbare Logging nach einem Text durchsuchen geht so:

#!/bin/bash
patt=$1
zcat *.log.gz |ansifilter |grep "$patt"
cat *.log |ansifilter |grep "$patt"

Beispiel

martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$ bash my_logsearch.sh "warn: sonoff"
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)
2026-06-23 11:38:24.661  - warn: sonoff.0 (213567) Client [Bewaesserung] received pubrel on Bewaesserung for unknown messageId 19823
2026-06-23 11:38:24.662  - warn: sonoff.0 (213567) Client [Bewaesserung] received pubrel on Bewaesserung for unknown messageId 28257
2026-06-23 12:18:34.304  - warn: sonoff.0 (213567) Old client Bewaesserung with secret 1782209331543_5611 sends publish. Ignore! Actual se
....

Nachtrag: ansifilter scheint langsamer zu sein, als sed

Ausführungszeit ein paar Sekunden für das Durchsuchen der vergangenen Woche ist aber nicht so gravierend...

Trotzdem mal interessehalber gemessen

Hier der alte Code mit sed

#!/bin/bash
starttime=$(date +'%s%3N')
patt=$1
zcat *.log.gz |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"
cat *.log |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"
#zcat *.log.gz |ansifilter |grep "$patt"
#cat *.log |ansifilter |grep "$patt"
echo Laufzeit $(($(date +'%s%3N') - $starttime)) ms

ca 185 ms....

martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$ bash my_logsearch.sh "Bad control"
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)
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)
Laufzeit 185 ms

Mit ansifilter statt sed vergeht fast die zehnfache Zeit....

martin@martin-D2836-S1:~/gitea/iobroker_shellscripte$ bash my_logsearch.sh "Bad control"
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)
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)
Laufzeit 1603 ms

Andreas67 0

@martinp Sehr gute Lösung

MartinP

Hier noch eine Erweiterung.
Durch Angabe des absoluten Pfades auf die Log-Files muss man das Script nicht mehr im Verzeichnis /opt/iobroker/log/ ausführen.

#!/bin/bash
starttime=$(date +'%s%3N')
patt=$1
#zcat *.log.gz |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"
#cat /opt/iobroker/log/iobroker.current.log |sed 's/[\x00-\x08\x0B\x0C\x0E-\x1A\x1C-\x1F]//g' |grep "$patt"
zcat /opt/iobroker/log/*.log.gz |ansifilter |grep "$patt"
cat /opt/iobroker/log/iobroker.current.log |ansifilter |grep "$patt"
echo Laufzeit $(($(date +'%s%3N') - $starttime)) ms

Daneben heißt das script nun logsearch - die Umbenennung von "my_logsearch.sh" beschleunigt den Aufruf durch weniger tipparbeit ;-)
Es gibt bei mir nun auch logsearchf (f=fast) mit der sed-Version des filterns ...

Community Forum

NEWS

Sonoff-Adapter - ungültige Zeichen in Logmessages

Support us

404

33.0k

83.4k

1.3m