Fehler?: Wide character in subroutine entry at ./FHEM/93_DbLog.pm line 1558.

Begonnen von AndreasR, 14 April 2017, 16:41:09

Vorheriges Thema - Nächstes Thema

AndreasR

Hallo zusammen,

seit gestern stürzt mein FHEM, das bisher immer vorbildlich lief, nach ca 15 min ab  .. - RASPI läuft weiter und Start via terminal ist möglich .. 

Dieser Eintrag:

Wide character in subroutine entry at ./FHEM/93_DbLog.pm line 1558.

im Log ist mir aufgefallen - ist immer die letzte Zeile vor dem Ausstieg,

Disable auf das DBLOG funktioniert - dann FHEM weiter - aber das taugt als Lösung nicht :-)

Hat jemand eine Idee was es sein könnte und was ich dagegen machen kann? 

Grüße

Andreas

rudolfkoenig

Irgendein Modul hat Daten mit Wide-Character als Event gepostet, und DbLog ist auf die Nase gefallen. Per Konvention muessen Module nicht-ASCII Daten als UTF-8 speichern und weitergeben, d.h. DbLog ist eigentlich nicht das Problem.

Um das Problem zu lokalisieren faellt mir ausser "attr global verbose 5" nichts ein.

hugomckinley

Ich muss diesen Thread nochmal aufwärmen.

Ich hab das gleiche Problem mit den wide characters, jedoch tritt es bei mir unregelmäßig in einem Abstand von 2 Wochen bis einige Monate auf.
"attr global verbose 5" ist bei mir nicht praktikabel, da ich nicht wochenlang so mitloggen kann befürchte ich.
Ich habe einige Stunden dblog auf verbose 5 gestellt, aber auch das sind schon Unmengen an Daten.

In der commandref habe ich bei dblog die trace* attribute gefunden. Könnten mir die helfen? Ich habe versuchsweise traceFlag ENC gesetzt und verbose auf 3 gestellt.

Ich bin momentan ziemlich ratlos.

Grüße,
Hugo
----------------------------------------------------
FHEM in TrueNAS-Jail
HMLGW + HM-Komponenten, alexa-fhem, Modbus/TCP, Modbus/RS485, LG-WebOS, Firmata, 1wire, ESP-RGBWW, DaikinAC per WLAN, Shellys, Denon AVR, Fronius WR, Helios Wohnraumlüftung, ...

hugomckinley

Ich habe jetzt zwei Abstürze mit verbose 5 loggen können. Ich hatte die Hoffnung, dass ich mir die letzten paar Zeilen ansehe und dann gleich sehe wer der Übeltäter ist. Dem ist leider nicht so.

Sehe ich das richtig, dass der komplette logcycle relevant ist?
Ich habe auch den Verdacht dass es die Zeilen mit:
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|location: Český Krumlov|location|Český Krumlov|
sind, da die in beiden logs vorkommen.
Das würde auch dazu passen, dass dieses Problem zu sehr unterschiedlichen Zeiten auftritt, je nachdem welchen Server das speedtest-Modul verwendet.
Es könnte auch zeitlich sehr gut passen mit dem Beginn der Probleme, als ich von script auf das ookla Binary umgestiegen bin.

Hier sind die beiden logs.

2022.02.10 01:37:23 4: DbLog logdb -> ################################################################
2022.02.10 01:37:23 4: DbLog logdb -> ###              start of new Logcycle                       ###
2022.02.10 01:37:23 4: DbLog logdb -> ################################################################
2022.02.10 01:37:23 4: DbLog logdb -> number of events received: 1 of device: logdb
2022.02.10 01:37:23 4: DbLog logdb -> check Device: logdb , Event: CacheOverflowLastNum: 0
2022.02.10 01:37:23 5: DbLog logdb -> parsed Event: logdb , Event: CacheOverflowLastNum: 0
2022.02.10 01:37:23 4: DbLog logdb -> added event - Timestamp: 2022-02-10 01:37:23, Device: logdb, Type: DBLOG, Event: CacheOverflowLastNum: 0, Reading: CacheOverflowLastNum, Value: 0, Unit:
2022.02.10 01:37:23 5: End notify loop for logdb
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|ping: 40.915|ping|40.915|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|upload: 20.6|upload|20.6|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|download: 88.0|download|88.0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|packetLoss: 0|packetLoss|0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|id: 34941|id|34941|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|name: CAP-NET s.r.o.|name|CAP-NET s.r.o.|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|location: Český Krumlov|location|Český Krumlov|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:55|24speed|SPEEDTEST|state: ok|state|ok|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:56|Wetterstation|HP1000|wind_direction_avg2m: 204|wind_direction_avg2m|204|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:36:59|at_AC_WZ_OG_control|AT|state: Next: 01:37:59|state|Next: 01:37:59|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:03|USV_Halde|NUT|state: OL|state|OL|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:03|USV_Halde|NUT|ups.power: 60|ups.power|60|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:04|Shelly_Plug_S_2|SHELLY|inttemp: 32.21|inttemp|32.21|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:07|Shelly_EG_WZ_AC|SHELLY|inttemp: 30.2|inttemp|30.2|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:08|at_AC_KZ_OG_control|AT|state: Next: 01:38:08|state|Next: 01:38:08|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:09|BM_Sued|CUL_HM|aesCommToDev: pending|aesCommToDev|pending|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:09|BM_Sued|CUL_HM|aesCommToDev: ok|aesCommToDev|ok|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:12|Wetterstation|HP1000|wind_direction: 210|wind_direction|210|°
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:12|Wetterstation|HP1000|wind_gust_direction_avg10m: 196|wind_gust_direction_avg10m|196|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:12|Wetterstation|HP1000|wind_direction_avg2m: 206|wind_direction_avg2m|206|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:13|at_AC_WZ_EG_control|AT|state: Next: 01:38:13|state|Next: 01:38:13|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:13|USV_Halde|NUT|state: OL|state|OL|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:13|USV_Halde|NUT|ups.power: 60|ups.power|60|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:14|vccu|CUL_HM|IOopen: 1|IOopen|1|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:14|vccu|CUL_HM|state: HMLAN1:dummy,HMLGW1:ok,HMLGW2:disconnected|state|HMLAN1:dummy,HMLGW1:ok,HMLGW2:disconnected|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:14|HMdebug|HMINFO|ERR_sabotageError: 0|ERR_sabotageError|0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:14|HMdebug|HMINFO|ERR_battery: 0|ERR_battery|0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:14|HMdebug|HMINFO|CRI__protocol: 0|CRI__protocol|0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:20|DG_Spielzimmer_Heizung_Clima|CUL_HM|measured-temp: 22.4|measured-temp|22.4|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:20|DG_Spielzimmer_Heizung_Weather|CUL_HM|measured-temp: 22.4|measured-temp|22.4|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:20|DG_Spielzimmer_Heizung_Weather|CUL_HM|state: 22.4|state|22.4|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:22|vccu|CUL_HM|IOopen: 1|IOopen|1|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:22|vccu|CUL_HM|state: HMLAN1:dummy,HMLGW1:ok,HMLGW2:disconnected|state|HMLAN1:dummy,HMLGW1:ok,HMLGW2:disconnected|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:22|HMdebug|HMINFO|ERR_battery: 0|ERR_battery|0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:22|HMdebug|HMINFO|ERR_sabotageError: 0|ERR_sabotageError|0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:22|HMdebug|HMINFO|CRI__protocol: 0|CRI__protocol|0|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:23|1w_RL_EG|OWTHERM|temperature: 35.5|temperature|35.5|°C
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:23|1w_RL_EG|OWTHERM|state: T: 35.50 °C ↓|data|state: T: 35.50 °C ↓|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:23|at_AC_KZ_DG_control|AT|state: Next: 01:38:23|state|Next: 01:38:23|
2022.02.10 01:37:23 5: DbLog logdb -> MemCache contains: 2022-02-10 01:37:23|logdb|DBLOG|CacheOverflowLastNum: 0|CacheOverflowLastNum|0|
Wide character in subroutine entry at ./FHEM/93_DbLog.pm line 2406.


und das

2022.02.11 16:14:18 4: DbLog logdb -> ################################################################
2022.02.11 16:14:18 4: DbLog logdb -> ###              start of new Logcycle                       ###
2022.02.11 16:14:18 4: DbLog logdb -> ################################################################
2022.02.11 16:14:18 4: DbLog logdb -> number of events received: 1 of device: logdb
2022.02.11 16:14:18 4: DbLog logdb -> check Device: logdb , Event: CacheOverflowLastNum: 0
2022.02.11 16:14:18 5: DbLog logdb -> parsed Event: logdb , Event: CacheOverflowLastNum: 0
2022.02.11 16:14:18 4: DbLog logdb -> added event - Timestamp: 2022-02-11 16:14:18, Device: logdb, Type: DBLOG, Event: CacheOverflowLastNum: 0, Reading: CacheOverflowLastNum, Value: 0, Unit:
2022.02.11 16:14:18 5: End notify loop for logdb
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:48|BM_West|CUL_HM|aesCommToDev: pending|aesCommToDev|pending|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:48|BM_West|CUL_HM|aesCommToDev: ok|aesCommToDev|ok|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:48|BM_West|CUL_HM|brightness: 158|brightness|158|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:48|d_sunlevel|DUMMY|level_west: 158|level_west|158|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|ping: 43.73|ping|43.73|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|upload: 20.4|upload|20.4|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|download: 12.5|download|12.5|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|packetLoss: 0|packetLoss|0|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|id: 34941|id|34941|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|name: CAP-NET s.r.o.|name|CAP-NET s.r.o.|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|location: Český Krumlov|location|Český Krumlov|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:53|24speed|SPEEDTEST|state: ok|state|ok|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:56|USV_Halde|NUT|state: OL|state|OL|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:56|USV_Halde|NUT|ups.power: 60|ups.power|60|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|at_AC_WZ_OG_control|AT|state: Next: 16:14:59|state|Next: 16:14:59|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|dewpoint: 0.2|dewpoint|0.2|°C
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|wind_direction: 251|wind_direction|251|°
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|wind_speed: 3.6|wind_speed|3|km
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|humidity: 73|humidity|73|%
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|wind_gust: 13.0|wind_gust|13|km
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|wind_gust_direction_avg10m: 215|wind_gust_direction_avg10m|215|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|wind_direction_avg2m: 259|wind_direction_avg2m|259|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|wind_speed_avg2m: 5.1|wind_speed_avg2m|5.1|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:13:59|Wetterstation|HP1000|state: T: 4.6 °C H: 73 %|state|T: 4.6 °C H: 73 %|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:06|USV_Halde|NUT|state: OL|state|OL|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:06|USV_Halde|NUT|ups.power: 60|ups.power|60|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:07|Shelly_EG_WZ_AC|SHELLY|inttemp: 20.98|inttemp|20.98|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:08|at_AC_KZ_OG_control|AT|state: Next: 16:15:08|state|Next: 16:15:08|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:11|vccu|CUL_HM|IOopen: 1|IOopen|1|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:11|vccu|CUL_HM|state: HMLAN1:dummy,HMLGW1:ok,HMLGW2:disconnected|state|HMLAN1:dummy,HMLGW1:ok,HMLGW2:disconnected|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:11|HMdebug|HMINFO|ERR_sabotageError: 0|ERR_sabotageError|0|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:11|HMdebug|HMINFO|ERR_battery: 0|ERR_battery|0|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:11|HMdebug|HMINFO|CRI__protocol: 0|CRI__protocol|0|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:13|at_AC_WZ_EG_control|AT|state: Next: 16:15:13|state|Next: 16:15:13|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:15|Wetterstation|HP1000|wind_direction: 233|wind_direction|233|°
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:15|Wetterstation|HP1000|wind_speed: 8.6|wind_speed|8|km
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:15|Wetterstation|HP1000|wind_gust: 11.2|wind_gust|11|km
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:15|Wetterstation|HP1000|wind_chill: 2.5|wind_chill|2.5|°C
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:15|Wetterstation|HP1000|wind_direction_avg2m: 260|wind_direction_avg2m|260|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:15|Wetterstation|HP1000|wind_speed_avg2m: 5.4|wind_speed_avg2m|5.4|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:17|USV_Halde|NUT|state: OL|state|OL|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:17|USV_Halde|NUT|ups.power: 60|ups.power|60|
2022.02.11 16:14:18 5: DbLog logdb -> MemCache contains: 2022-02-11 16:14:18|logdb|DBLOG|CacheOverflowLastNum: 0|CacheOverflowLastNum|0|
Wide character in subroutine entry at ./FHEM/93_DbLog.pm line 2406.


Ich habe jetzt mit attr 24speed event-on-change-reading download,packetLoss,ping,upload dieses reading rausgenommen und schau mal was passiert.
Seit 11.2. gab es natürlich keinen Absturz mehr ;)
----------------------------------------------------
FHEM in TrueNAS-Jail
HMLGW + HM-Komponenten, alexa-fhem, Modbus/TCP, Modbus/RS485, LG-WebOS, Firmata, 1wire, ESP-RGBWW, DaikinAC per WLAN, Shellys, Denon AVR, Fronius WR, Helios Wohnraumlüftung, ...