DBLOG: Fehlermeldung im Log

[WhyTea]

Hallo,

seit heute habe ich mir nicht erklärbare Fehlermeldungen im Log.

Code Auswählen Erweitern

2021.04.06 10:58:20 2: DbLog mylogdb -> Error table history - DBD::mysql::st execute failed: Incorrect string value: '\xC2' for column `fhem`.`history`.`VALUE` at row 1 at /var/fhem/FHEM/93_DbLog.pm line 2603.

2021.04.06 10:58:50 2: DbLog mylogdb -> Error table history - DBD::mysql::st execute failed: Incorrect string value: '\xC2' for column `fhem`.`history`.`VALUE` at row 1 at /var/fhem/FHEM/93_DbLog.pm line 2603.

2021.04.06 10:59:20 2: DbLog mylogdb -> Error table history - DBD::mysql::st execute failed: Incorrect string value: '\xC2' for column `fhem`.`history`.`VALUE` at row 1 at /var/fhem/FHEM/93_DbLog.pm line 2603.

2021.04.06 10:59:50 2: DbLog mylogdb -> Error table history - DBD::mysql::st execute failed: Incorrect string value: '\xC2' for column `fhem`.`history`.`VALUE` at row 1 at /var/fhem/FHEM/93_DbLog.pm line 2603.


Die Meldung kommt immer mal wieder. Wie man sieht alle 30 Sekunden aber nicht durchgehend.
Das erste mal um 10:58:50 dann alle 30 Sekunden bis 11:04:20 dann war ruhe.
Erst um 11:58:23 kam sie wieder alle 30 Sekunden bis 12:29:40 dann war wieder ruhe.
Dann erst wieder um 15:02:03 bis 15:04:33 und dann wieder ruhe.

Hier das List von mylogdb:

Code Auswählen Erweitern

Internals:
   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
   CONFIGURATION /var/fhem/contrib/dblog/db.conf
   DEF        /var/fhem/contrib/dblog/db.conf .*:.*
   FUUID      5c46c491-f33f-a5a6-fe07-3f7291e86aafc347
   FVERSION   93_DbLog.pm:v4.11.0-s23888/2021-03-04
   MODE       asynchronous
   MODEL      MYSQL
   NAME       mylogdb
   NR         4
   NTFY_ORDER 50-mylogdb
   PID        15597
   REGEXP     .*:.*
   STATE      connected
   TYPE       DbLog
   UTF8       1
   dbconn     mysql:database=fhem;host=192.168.6.111;port=3306
   dbuser     fhemuser
   HELPER:
     COLSET     1
     DELDAYS    730
     DEVICECOL  64
     EVENTCOL   512
     OLDSTATE   connected
     PACKAGE    main
     READINGCOL 64
     TC         current
     TH         history
     TYPECOL    64
     UNITCOL    32
     VALUECOL   128
     VERSION    4.11.0
     REDUCELOG:
       mylogdb
       reduceLogNbl
       100
   READINGS:
     2021-04-06 15:55:34   CacheOverflowLastNum 0
     2021-04-06 12:30:30   CacheOverflowLastState normal
     2021-04-06 15:55:45   CacheUsage      3
     2021-04-06 15:55:34   NextSync        2021-04-06 15:56:04 or if CacheUsage 500 reached
     2021-04-06 15:55:34   background_processing_time 0.0153
     2021-04-06 02:25:00   countCurrent    11478
     2021-04-06 02:25:00   countHistory    6114688
     2021-04-06 02:00:00   lastRowsDeleted 0
     2021-04-06 15:55:45   notify_processing_time 0.0007
     2021-04-06 02:06:01   reduceLogState  reduceLogNbl finished. Rows processed: 3165080, deleted: 16421, time: 61.00sec
     2021-04-06 15:55:34   sql_processing_time 0.0042
     2021-04-06 15:55:34   state           connected
Attributes:
   DbLogExclude .*
   asyncMode  1
   bulkInsert 1
   cacheLimit 500
   room       Zentralsysteme->Logs
   showNotifyTime 1
   showproctime 1
   syncInterval 30

Und einmal Version:

Code Auswählen Erweitern

Latest Revision: 24117

File                Rev   Last Change

fhem.pl             23904 2021-03-07 09:20:31Z rudolfkoenig
60_allergy.pm       18406 2019-01-24 23:47:47Z moises
96_allowed.pm       23727 2021-02-12 20:31:37Z rudolfkoenig
42_AptToDate.pm     19639 2019-06-18 13:43:31Z CoolTux
90_at.pm            23964 2021-03-14 09:26:44Z rudolfkoenig
98_autocreate.pm    23727 2021-02-12 20:31:37Z rudolfkoenig
57_Calendar.pm      23989 2021-03-17 17:30:05Z neubert
10_CUL_HM.pm        24031 2021-03-21 09:30:57Z martinp876
93_DbLog.pm         23888 2021-03-04 19:58:00Z DS_Starter
93_DbRep.pm         23888 2021-03-04 19:58:00Z DS_Starter
98_dewpoint.pm      18846 2019-03-10 11:45:58Z hotbso
98_DOIF.pm          24100 2021-03-27 20:15:23Z Damian
98_DOIFtools.pm     22610 2020-08-15 17:21:34Z Ellert
98_dummy.pm         20665 2019-12-06 11:05:35Z rudolfkoenig
70_ENIGMA2.pm       18995 2019-03-22 20:09:53Z loredo
91_eventTypes.pm    23471 2021-01-04 19:24:21Z rudolfkoenig
01_FHEMWEB.pm       23995 2021-03-18 11:06:57Z rudolfkoenig
92_FileLog.pm       23751 2021-02-16 18:35:28Z rudolfkoenig
89_FULLY.pm         23354 2020-12-15 13:46:01Z zap
98_help.pm          23281 2020-12-02 17:55:42Z betateilchen
98_HMinfo.pm        24032 2021-03-21 09:32:15Z martinp876
00_HMUARTLGW.pm     18838 2019-03-09 20:40:14Z mgernoth
98_HTTPMOD.pm       24036 2021-03-21 12:24:36Z StefanStrobel
02_HTTPSRV.pm       20110 2019-09-05 17:30:20Z neubert
30_HUEBridge.pm     23865 2021-03-01 08:19:24Z justme1968
31_HUEDevice.pm     23912 2021-03-08 10:21:02Z justme1968
98_IF.pm            12944 2017-01-03 12:56:17Z Damian
36_JeeLink.pm       14707 2017-07-13 18:08:33Z justme1968
98_JsonList2.pm     23727 2021-02-12 20:31:37Z rudolfkoenig
36_LaCrosse.pm      20217 2019-09-21 09:53:25Z HCS
91_notify.pm        24094 2021-03-26 19:30:56Z rudolfkoenig
73_PRESENCE.pm      20782 2019-12-19 10:51:06Z markusbloch
59_PROPLANTA.pm     23449 2021-01-01 09:56:49Z tupol
70_Pushover.pm      20897 2020-01-06 12:16:20Z loredo
33_readingsGroup.pm 23844 2021-02-27 19:43:24Z justme1968
91_sequence.pm      22810 2020-09-21 10:19:17Z rudolfkoenig
36_Shelly.pm        24091 2021-03-26 09:42:09Z phenning
32_speedtest.pm     23867 2021-03-01 08:23:09Z justme1968
98_structure.pm     23818 2021-02-24 10:23:46Z rudolfkoenig
99_SUNRISE_EL.pm    23765 2021-02-18 08:14:55Z rudolfkoenig
98_SVG.pm           24097 2021-03-27 14:56:15Z rudolfkoenig
42_SYSMON.pm        23784 2021-02-20 16:03:30Z hexenmeister
32_SYSSTAT.pm       24057 2021-03-22 14:43:08Z justme1968
98_telnet.pm        23727 2021-02-12 20:31:37Z rudolfkoenig
24_TPLinkHS110.pm   21645 2020-04-12 09:11:23Z vk
59_Twilight.pm      24052 2021-03-22 06:29:38Z Beta-User
74_Unifi.pm         23500 2021-01-09 15:14:50Z wuehler
74_UnifiClient.pm   19989 2019-08-12 18:25:21Z wuehler
74_UnifiSwitch.pm   23500 2021-01-09 15:14:50Z wuehler
98_update.pm        20778 2019-12-18 17:46:44Z rudolfkoenig
99_Utils.pm         22524 2020-08-02 14:34:02Z rudolfkoenig
77_UWZ.pm           21828 2020-05-01 13:44:19Z CoolTux
98_version.pm       15140 2017-09-26 09:20:09Z markusbloch
91_watchdog.pm      23719 2021-02-11 15:53:36Z rudolfkoenig
98_weblink.pm       23597 2021-01-23 17:57:05Z rudolfkoenig

AttrTemplate.pm     22985 2020-10-18 09:04:19Z rudolfkoenig
Blocking.pm         23268 2020-12-01 11:48:48Z rudolfkoenig
Color.pm            20813 2019-12-22 18:42:10Z justme1968
DevIo.pm            23933 2021-03-12 11:01:49Z rudolfkoenig
GPUtils.pm          19666 2019-06-20 11:17:29Z CoolTux
HMConfig.pm         24033 2021-03-21 09:33:32Z martinp876
No Id found for HMConfig_SenTHPL.pm
HttpUtils.pm        23979 2021-03-15 14:00:33Z rudolfkoenig
Meta.pm             21008 2020-01-18 10:22:10Z loredo
myUtilsTemplate.pm   7570 2015-01-14 18:31:44Z rudolfkoenig
RTypes.pm           10476 2016-01-12 21:03:33Z borisneubert
SetExtensions.pm    23300 2020-12-06 11:36:24Z rudolfkoenig
SubProcess.pm       14334 2017-05-20 23:11:06Z neubert
TcpServerUtils.pm   23472 2021-01-04 19:56:38Z rudolfkoenig

doif.js                    15546 2017-12-03 09:57:42Z Ellert
fhemweb.js                 23979 2021-03-15 14:00:33Z rudolfkoenig
fhemweb_readingsGroup.js   15189 2017-10-03 17:53:27Z justme1968

Das letzte Update ist ca. eine Woche her und lief ohne Probleme bis heute.

Seit dem habe ich lediglich meine Hue-Umgebung um ein paar weitere Spots ergänzt.
Einen Zusammenhang kann ich da aber auch nicht erkennen.

Ich hoffe es kann mir jemand einen Tip geben wo ich suchen kann.

Gruß
Daniel

[KernSani]

Scheint mir ein encoding-Problem zu sein. Hast du eine Idee, wo ein "Â" geloggt werden könnte?

[DS_Starter]

Hallo Daniel,

das sind wahrscheinlich UniCode Codierungen bzw. Steuerzeichen gemäß dieser Tabelle https://www.utf8-chartable.de/unicode-utf8-table.pl?start=128&number=128&utf8=string-literal&unicodeinhtml=hex

Wenn die Meldung auftaucht siehst du die Quelle wahrscheinlich mit einem "set <> listCache".
Solltest du dort nichts sehen, hilft verbose 4 oder 5 weiter. Dann siehst du bestimmt woher diese Datensätze stammen.

Du kannst einen Filter einschalten:   useCharfilter = 1 um Steuerzeichen zu entfernen.

KernSani war schneller 

[andre07]

Mariadb oder Mysql geupdatet ? Hier hilft dann ein sql_mode=NO_ENGINE_SUBSTITUTION
im Abschnitt [mysqld]
Mit dem update wurde als Standardeinstellung  stricte mode aktiviert was zu dieser Fehlermeldung führte.... 

[WhyTea]

Mariadb oder Mysql geupdatet ? Hier hilft dann ein sql_mode=NO_ENGINE_SUBSTITUTION
im Abschnitt [mysqld]
Mit dem update wurde als Standardeinstellung  stricte mode aktiviert was zu dieser Fehlermeldung führte....

Ich habe das mal gegoogelt und versucht nachzuvollziehen.
Ich glaube das ist nicht mein Problem wenn die die Ausgabe richtig interpretiere.

Code Auswählen Erweitern

Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 86618
Server version: 10.3.27-MariaDB-0+deb10u1 Debian 10

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> SELECT @@SQL_MODE, @@GLOBAL.SQL_MODE;
+-------------------------------------------------------------------------------------------+-------------------------------------------------------------------------------------------+
| @@SQL_MODE                                                                                | @@GLOBAL.SQL_MODE                                                                         |
+-------------------------------------------------------------------------------------------+-------------------------------------------------------------------------------------------+
| STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION | STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION |
+-------------------------------------------------------------------------------------------+-------------------------------------------------------------------------------------------+
1 row in set (0.000 sec)


Dennoch vielen Dank für die Info!

[WhyTea]

Scheint mir ein encoding-Problem zu sein. Hast du eine Idee, wo ein "Â" geloggt werden könnte?

Wow, kein Plan wo so ein Zeichen herkommen könnte. Sieht für mich wie ein fehlerhafter Wert aus. 
Danke Dir! Ich werde mal den Lösungsansatz von DS_Starter probieren und berichten.

das sind wahrscheinlich UniCode Codierungen bzw. Steuerzeichen gemäß dieser Tabelle https://www.utf8-chartable.de/unicode-utf8-table.pl?start=128&number=128&utf8=string-literal&unicodeinhtml=hex

Wenn die Meldung auftaucht siehst du die Quelle wahrscheinlich mit einem "set <> listCache".
Solltest du dort nichts sehen, hilft verbose 4 oder 5 weiter. Dann siehst du bestimmt woher diese Datensätze stammen.

Du kannst einen Filter einschalten:   useCharfilter = 1 um Steuerzeichen zu entfernen.

Danke das werde ich so Probieren.

[WhyTea]

Hallo,
ich wärme das Thema noch einmal auf.
Da das Problem immer nur sehr sporadisch auftaucht ist die Analyse leider nicht einfach gewesen da ich leider immer den Moment verpasst habe wo es auftrat.

Eher durch Zufall bin ich nun auf eine Idee gekommen wo das Problem liegen könnte.

Ich frage wie hier https://wiki.fhem.de/wiki/Departure beschrieben den Busfahrplan ab.

Code Auswählen Erweitern

defmod Busplan_Knappule HTTPMOD none 0
attr Busplan_Knappule get01Name Knappule
attr Busplan_Knappule get01Regex (\[\[.*\]\]).*
attr Busplan_Knappule get01URL https://transport.stefan-biermann.de/publictransportapi/rest/departure/FHEM?from=20000759&provider=Vrr
attr Busplan_Knappule room Zentralsysteme->Busplan
attr Busplan_Knappule timeout 30

Zum einen passt der Timeout von 30 Sekunden zum dem Logeinträgen und zum Anderen sehe ich bei der Ausgabe eben solche angemerkten Steuerzeichen.

Code Auswählen Erweitern


[["442","Dortmund Höchsten","2"],["442","Dortmund Hörde Bf","10"],["442","Dortmund Reichsmark","22"],["442","Dortmund Hörde Bf","30"],["442","Dortmund Syburg","42"],["442","Dortmund Hörde Bf","50"],["442","Dortmund Höchsten","62"],["442","Dortmund Hörde Bf","70"],["442","Dortmund Reichsmark","82"],["442","Dortmund Hörde Bf","90"]]

Wenn ich die Seite im Browser aufrufe sieht die Rückgabe allerdings in Ordnung aus:

Code Auswählen Erweitern

[["442","Dortmund Hörde Bf","4"],["442","Dortmund Höchsten","16"],["442","Dortmund Hörde Bf","24"],["442","Dortmund Reichsmark","36"],["442","Dortmund Hörde Bf","44"],["442","Dortmund Syburg","56"],["442","Dortmund Hörde Bf","64"],["442","Dortmund Höchsten","76"],["442","Dortmund Hörde Bf","84"],["442","Dortmund Reichsmark","96"]]

Ich denke ich habe ein Zeichensatzproblem aber ich weis nicht wie ich das korrigieren kann und hoffe auf Hilfe.

Gruß
Daniel

[WhyTea]

Ich habe jetzt mal das Attr showBody aktiviert und sehe auch dort das die erhaltenden Daten korrekt sind.

Hiermal ein komplettes List von dem Device:

Code Auswählen Erweitern

Internals:
   BUSY       0
   CFGFN      /var/fhem/FHEM/busplan.cfg
   DEF        none 0
   FUUID      5c46c497-f33f-a5a6-8cc4-25934dbb6f9f5178
   Interval   0
   MainURL   
   ModuleVersion 4.1.10 - 6.7.2021
   NAME       Busplan_Knappule
   NOTIFYDEV  global
   NR         1767
   NTFY_ORDER 50-Busplan_Knappule
   STATE      ???
   TYPE       HTTPMOD
   httpbody   [["442","Dortmund Reichsmark","13"],["442","Dortmund Hörde Bf","19"],["442","Dortmund Syburg","31"],["442","Dortmund Hörde Bf","39"],["442","Dortmund Höchsten","51"],["442","Dortmund Hörde Bf","59"],["442","Dortmund Reichsmark","71"],["442","Dortmund Hörde Bf","79"],["442","Dortmund Syburg","91"],["442","Dortmund Hörde Bf","99"]]
   value     
   CompiledRegexes:
   Helper:
     DBLOG:
       Knappule:
         mylogdb:
           TIME       1646147710.51431
           VALUE      [["442","Dortmund Reichsmark","13"],["442","Dortmund Hörde Bf","19"],["442","Dortmund Syburg","31"],["442","Dortmund Hörde Bf","39"],["442","Dortmund Höchsten","51"],["442","Dortmund Hörde Bf","59"],["442","Dortmund Reichsmark","71"],["442","Dortmund Hörde Bf","79"],["442","Dortmund Syburg","91"],["442","Dortmund Hörde Bf","99"]]
   HttpUtils:
     NAME       
     addr       https://transport.stefan-biermann.de:443
     auth       0
     buf       
     code       200
     conn       
     data       
     displayurl https://transport.stefan-biermann.de/publictransportapi/rest/departure/FHEM?from=20000759&provider=Vrr
     header     
     host       transport.stefan-biermann.de
     httpheader HTTP/1.0 200 OK
Content-Length: 337
Content-Type: application/json
Date: Tue, 01 Mar 2022 15:15:10 GMT
Strict-Transport-Security: max-age=31536000; includeSubDomains; preload
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
X-Robots-Tag: noindex,nofollow,nosnippet,noarchive,notranslate,noimageindex
X-Xss-Protection: 1; mode=block
     httpversion 1.0
     hu_blocking 0
     hu_filecount 1
     hu_port    443
     hu_portSfx
     hu_proxy   1
     ignoreredirects 1
     loglevel   4
     path       /publictransportapi/rest/departure/FHEM?from=20000759&provider=Vrr
     protocol   https
     redirects  0
     timeout    30
     url        https://transport.stefan-biermann.de/publictransportapi/rest/departure/FHEM?from=20000759&provider=Vrr
     sslargs:
   QUEUE:
   READINGS:
     2022-03-01 16:15:10   Knappule        [["442","Dortmund Reichsmark","13"],["442","Dortmund Hörde Bf","19"],["442","Dortmund Syburg","31"],["442","Dortmund Hörde Bf","39"],["442","Dortmund Höchsten","51"],["442","Dortmund Hörde Bf","59"],["442","Dortmund Reichsmark","71"],["442","Dortmund Hörde Bf","79"],["442","Dortmund Syburg","91"],["442","Dortmund Hörde Bf","99"]]
   REQUEST:
     context    get
     data       
     header     
     ignoreredirects 0
     num        01
     retryCount 0
     type       get01
     url        https://transport.stefan-biermann.de/publictransportapi/rest/departure/FHEM?from=20000759&provider=Vrr
     value     
   defptr:
     readingBase:
       Knappule   get
     readingNum:
       Knappule   01
     readingOutdated:
     requestReadings:
       get01:
         Knappule   get 01
Attributes:
   get01Name  Knappule
   get01Regex (\[\[.*\]\]).*
   get01URL   https://transport.stefan-biermann.de/publictransportapi/rest/departure/FHEM?from=20000759&provider=Vrr
   room       Zentralsysteme->Busplan
   showBody   1
   timeout    30

Hier sieht man sehr schön das aus einem "ö" ein "ö" wird. Aber warum und was kann ich tun?

[Guybrush]

probier das mal

Code Auswählen Erweitern

attr Busplan_Knapulle getDecode UTF-8

[WhyTea]

Das sieht gut aus! Danke!