NEWS
[gelöst] js-controller 1.2.0 und sql 1.5.6 funktioniert nicht
-
Hallo,
habe heute den Host auf js-controller 1.2.0 aktualisiert und danach festgestellt, dass der sql-Adapter abstürzt (rotes Icon). Nach einem Restart des sql-Adapters dauert es max. 2 Minuten und er ist wieder deaktiviert.
Nach dem Rückspielen auf die js-controller 1.0.3 Version funktioniert der sql-Adapter wieder korrekt.
Viele Grüße Gerd. `
Was sagt LOG? Die Version js-controller 1.2.0 kann jetzt mehr über Abstürze sagen. -
Log ist nötig, ich benutze auch sql 1.5.6 und kann das Problem nicht nachvollziehen
–-----------------------
Send from mobile device
-
Hallo,
Fehler tritt auch auf, wenn ich auf sql1.5.4 downgrade. Fehler ist eindeutig bei js-controller 1.2.0, bzw. dadurch wird der Fehler ausgelöst.
Loddatei````
2017-09-26 19:37:43.944 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.sql.0 started with pid 11292
2017-09-26 19:37:45.709 - [32minfo[39m: sql.0 starting. Version 1.5.6 in C:/Program Files/ioBroker/node_modules/iobroker.sql, node: v6.11.2
2017-09-26 19:37:45.974 - [32minfo[39m: sql.0 Connected to mysql
2017-09-26 19:37:46.006 - [32minfo[39m: sql.0 enabled logging of hm-rpc.0.updated
2017-09-26 19:38:19.209 - [32minfo[39m: javascript.0 script.js.common.YR: file written
2017-09-26 19:39:16.444 - [32minfo[39m: host.DauerlaufLaptop object change system.adapter.sql.0
2017-09-26 19:39:16.444 - [32minfo[39m: host.DauerlaufLaptop stopInstance system.adapter.sql.0
2017-09-26 19:39:16.444 - [32minfo[39m: host.DauerlaufLaptop stopInstance system.adapter.sql.0 killing pid 11292
2017-09-26 19:39:16.491 - [33mwarn[39m: host.DauerlaufLaptop instance system.adapter.sql.0 terminated due to SIGTERM
2017-09-26 19:39:16.491 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.sql.0 terminated with code null ()
2017-09-26 19:39:18.959 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.sql.0 started with pid 9732
2017-09-26 19:39:20.615 - [32minfo[39m: sql.0 starting. Version 1.5.6 in C:/Program Files/ioBroker/node_modules/iobroker.sql, node: v6.11.2
2017-09-26 19:39:20.911 - [32minfo[39m: sql.0 enabled logging of hm-rpc.0.updated
2017-09-26 19:40:00.022 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.yr.0 started with pid 9692
2017-09-26 19:40:00.053 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.dwd.0 started with pid 3152
2017-09-26 19:40:01.881 - [32minfo[39m: yr.0 starting. Version 1.0.6 in C:/Program Files/ioBroker/node_modules/iobroker.yr, node: v6.11.2
2017-09-26 19:40:02.037 - [32minfo[39m: yr.0 got weather data from yr.no
2017-09-26 19:40:02.099 - [32minfo[39m: dwd.0 starting. Version 2.2.1 in C:/Program Files/ioBroker/node_modules/iobroker.dwd, node: v6.11.2
2017-09-26 19:40:02.913 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.dwd.0 terminated with code 0 (OK)
2017-09-26 19:40:07.131 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.yr.0 terminated with code 0 (OK)
2017-09-26 19:42:56.899 - [32minfo[39m: host.DauerlaufLaptop object change system.adapter.sql.0
2017-09-26 19:42:56.899 - [32minfo[39m: host.DauerlaufLaptop stopInstance system.adapter.sql.0
2017-09-26 19:42:56.899 - [32minfo[39m: host.DauerlaufLaptop stopInstance system.adapter.sql.0 killing pid 9732
2017-09-26 19:42:56.930 - [33mwarn[39m: host.DauerlaufLaptop instance system.adapter.sql.0 terminated due to SIGTERM
2017-09-26 19:42:56.930 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.sql.0 terminated with code null ()
2017-09-26 19:42:59.415 - [32minfo[39m: host.DauerlaufLaptop instance system.adapter.sql.0 started with pid 11572
2017-09-26 19:43:01.274 - [32minfo[39m: sql.0 starting. Version 1.5.6 in C:/Program Files/ioBroker/node_modules/iobroker.sql, node: v6.11.2 -
host.DauerlaufLaptop object change system.adapter.sql.0
Hast du Skripte laufend?
Wer ändert das Objekt?
-
Es laufen Skripte, aber keines das mit dem sql-Adapter Aktionen durchführt oder manipuliert. Die ändern nur indirekt durch Werteänderungen die sql-Adapter speichert und durch Abragen von history Informationen.
Kann sein, dass ich in dem Moment den Adapter über die iobroker Admin-Oberfläche neu gestartet hatte, da er dort wieder als deaktiviert angezeigt wurde
-
Dann stoppe mal den Adapter und Starte ihn an der kommandozeile direkt: im iobroker Verzeichnis ein: node node_modules/iobroker.sql/main.js —force —logs
Was kommt dann als Ausgabe?
-
Dann stoppe mal den Adapter und Starte ihn an der kommandozeile direkt: im iobroker Verzeichnis ein: node node_modules/iobroker.sql/main.js —force —logs
Was kommt dann als Ausgabe? `
Das klappt irgendwie nicht:````
C:\Program Files\ioBroker>node node_modules/iobroker.sql/main.js -force -logs
Cannot find module 'pg-native'
2017-09-27 21:18:39.532 - error: sql.0 adapter disabledC:\Program Files\ioBroker>node node_modules/iobroker.sql/main.js -force -logs
Cannot find module 'pg-native'
2017-09-27 21:19:17.156 - error: sql.0 already runningHabe jetzt mal sauber protokolliert, zwischen Restart und Deaktivierung :```` sql.0 2017-09-27 21:21:36.579 info enabled logging of hm-rpc.0.updated sql.0 2017-09-27 21:21:36.548 info Connected to mysql sql.0 2017-09-27 21:21:36.548 debug Response: {'code':'ER_TABLE_EXISTS_ERROR','errno':1050,'sqlMessage':'Table 'ts_bool' already exists','sqlState':'42S01','index':0,'sql':'CREATE TABLE `iobroker`.ts_bool (id INTEGER, ts BIGINT, val BOOLEAN, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts));'} sql.0 2017-09-27 21:21:36.548 debug CREATE TABLE `iobroker`.ts_bool (id INTEGER, ts BIGINT, val BOOLEAN, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); sql.0 2017-09-27 21:21:36.532 debug Response: {'code':'ER_TABLE_EXISTS_ERROR','errno':1050,'sqlMessage':'Table 'ts_string' already exists','sqlState':'42S01','index':0,'sql':'CREATE TABLE `iobroker`.ts_string (id INTEGER, ts BIGINT, val TEXT, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts));'} sql.0 2017-09-27 21:21:36.532 debug CREATE TABLE `iobroker`.ts_string (id INTEGER, ts BIGINT, val TEXT, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); sql.0 2017-09-27 21:21:36.517 debug Response: {'code':'ER_TABLE_EXISTS_ERROR','errno':1050,'sqlMessage':'Table 'ts_number' already exists','sqlState':'42S01','index':0,'sql':'CREATE TABLE `iobroker`.ts_number (id INTEGER, ts BIGINT, val REAL, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts));'} sql.0 2017-09-27 21:21:36.517 debug CREATE TABLE `iobroker`.ts_number (id INTEGER, ts BIGINT, val REAL, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); sql.0 2017-09-27 21:21:36.517 debug Response: {'code':'ER_TABLE_EXISTS_ERROR','errno':1050,'sqlMessage':'Table 'datapoints' already exists','sqlState':'42S01','index':0,'sql':'CREATE TABLE `iobroker`.datapoints (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT, type INTEGER);'} sql.0 2017-09-27 21:21:36.517 debug CREATE TABLE `iobroker`.datapoints (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT, type INTEGER); sql.0 2017-09-27 21:21:36.501 debug Response: {'code':'ER_TABLE_EXISTS_ERROR','errno':1050,'sqlMessage':'Table 'sources' already exists','sqlState':'42S01','index':0,'sql':'CREATE TABLE `iobroker`.sources (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT);'} sql.0 2017-09-27 21:21:36.501 debug CREATE TABLE `iobroker`.sources (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT); sql.0 2017-09-27 21:21:36.486 debug Response: {'code':'ER_DB_CREATE_EXISTS','errno':1007,'sqlMessage':'Can't create database 'iobroker'; database exists','sqlState':'HY000','index':0,'sql':'CREATE DATABASE `iobroker` DEFAULT CHARACTER SET utf8 DEFAULT COLLATE utf8_general_ci;'} sql.0 2017-09-27 21:21:36.486 debug CREATE DATABASE `iobroker` DEFAULT CHARACTER SET utf8 DEFAULT COLLATE utf8_general_ci; sql.0 2017-09-27 21:21:36.220 info starting. Version 1.5.6 in C:/Program Files/ioBroker/node_modules/iobroker.sql, node: v6.11.2 sql.0 2017-09-27 21:21:36.189 debug statesDB connected sql.0 2017-09-27 21:21:36.173 debug objectDB connected host.DauerlaufLaptop 2017-09-27 21:21:34.517 info instance system.adapter.sql.0 started with pid 8548 host.DauerlaufLaptop 2017-09-27 21:21:32.049 info instance system.adapter.sql.0 terminated with code null () host.DauerlaufLaptop 2017-09-27 21:21:32.049 warn instance system.adapter.sql.0 terminated due to SIGTERM
-
Und nach 21:21:36:579 kommt direkt wieder ein "terminated due to SIGTERM "?
-
Und nach 21:21:36:579 kommt direkt wieder ein "terminated due to SIGTERM "? `
Nein, da kommt gar nichts, das ist das seltsame. Das SIGTERM kommt erst wenn ich es wieder neu starte. Das Log zeigt den kompletten Inhalt zwischen Restart und auf der Oberfläche die Umschaltung auf rot=Deaktiviert, d.h. ich habe da nicht weggeschnitten oder rausgelöscht -
Also um 21:21:36:579 ging der Adapter wieder auf Rot?
jetzt wird es komisch. hast Du überhaupt Datenpunkte für SQL-History aktiviert?
-
Also um 21:21:36:579 ging der Adapter wieder auf Rot?
jetzt wird es komisch. hast Du überhaupt Datenpunkte für SQL-History aktiviert? `
Ja, 1351 Stück und die funktionieren auch wenn ich wieder den alten js-controller verwende, dann ist das Log voller Einträge von sql.0 wenn der Adapter auf Debug steht
-
Also um 21:21:36:579 ging der Adapter wieder auf Rot?
jetzt wird es komisch. hast Du überhaupt Datenpunkte für SQL-History aktiviert? `
Ja, 1351 Stück und die funktionieren auch wenn ich wieder den alten js-controller verwende, dann ist das Log voller Einträge von sql.0 wenn der Adapter auf Debug steht `
Ergänzung: Aktuell habe ich das Verzeichnis von js-controller 1.2.0 gesichert und ebenso mit 1.0.3, dadurch kann ich schnell zwischen diesen beiden Versionen umschalten und der Effekt ist, wenn ich das 1.0.3 verwende wird alles sauber in sql gespeichert und der Adapter läuft, im anderen Fall nicht. Die restlichen installierten Adapter funktionieren soweit mit beiden Versionen -
Hallöchen,
hat sich hier zufällig etwas bewegt? Mit dem Update auf js-controller 1.2.0 hab ich die gleichen Probleme mit dem SQL-Adapter.
Kann ich noch etwas zusteuern?
Grüße
Jakob
-
Naja ein Log im Debug Modus mit 1.2.0 wäre echt hilfreich.
Ich kann bisher keine Probleme nachvollziehen
-
Einmal Debug-Log:
sql.0 2017-10-18 21:49:58.715 info enabled logging of hm-rpc.0.updated sql.0 2017-10-18 21:49:58.637 info Connected to mysql sql.0 2017-10-18 21:49:58.636 debug Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'ts_bool' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.ts_bool (id INTEGER, ts BIGINT, val sql.0 2017-10-18 21:49:58.635 debug CREATE TABLE `iobroker`.ts_bool (id INTEGER, ts BIGINT, val BOOLEAN, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); sql.0 2017-10-18 21:49:58.631 debug Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'ts_string' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.ts_string (id INTEGER, ts BIGINT, v sql.0 2017-10-18 21:49:58.629 debug CREATE TABLE `iobroker`.ts_string (id INTEGER, ts BIGINT, val TEXT, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); sql.0 2017-10-18 21:49:58.626 debug Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'ts_number' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.ts_number (id INTEGER, ts BIGINT, v sql.0 2017-10-18 21:49:58.624 debug CREATE TABLE `iobroker`.ts_number (id INTEGER, ts BIGINT, val REAL, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); sql.0 2017-10-18 21:49:58.620 debug Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'datapoints' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.datapoints (id INTEGER NOT NULL PRI sql.0 2017-10-18 21:49:58.618 debug CREATE TABLE `iobroker`.datapoints (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT, type INTEGER); sql.0 2017-10-18 21:49:58.613 debug Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'sources' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.sources (id INTEGER NOT NULL PRIMAR sql.0 2017-10-18 21:49:58.610 debug CREATE TABLE `iobroker`.sources (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT); sql.0 2017-10-18 21:49:58.593 debug Response: {"code":"ER_DB_CREATE_EXISTS","errno":1007,"sqlMessage":"Can't create database 'iobroker'; database exists","sqlState":"HY000","index":0,"sql":"CREATE DATABASE `iobroker` DEFAULT CHARACTER sql.0 2017-10-18 21:49:58.574 debug CREATE DATABASE `iobroker` DEFAULT CHARACTER SET utf8 DEFAULT COLLATE utf8_general_ci; sql.0 2017-10-18 21:49:58.191 info starting. Version 1.5.6 in C:/ioBroker/node_modules/iobroker.sql, node: v4.5.0 sql.0 2017-10-18 21:49:58.108 debug statesDB connected sql.0 2017-10-18 21:49:58.050 debug objectDB connected
Der Adapter geht dann wieder auf Rot aber keine weiteren Log-Einträge mehr.
Was ich jetzt kurios finde - sobald ich direkt im Anschluss über die Kommandozeile (wie weiter oben beschrieben) den Adapter mit "… -force -logs" starte, läuft er in der shell sauber und logged auch im iobroker Browser-Log los und macht seinen Job mit seinen x-Einträgen
:?:
Wo könnte ich ansetzen, eine Idee? Ich weiß, ich müsste mal mein NodeJs updaten... lief bisher ohne murren.
-
Die Kombi läuft bei mir ohne Probleme.
Vielleicht reicht mal ein einfacher Reboot des ioBroker Servers.
Gruß
Rainer
-
Versuche erst mal den Reboot … tut fast immer gut.
Was mich etwas irritiert, ist der Hinweis im Log, das alle Tabellen neu angelegt werden sollen, was dann natürlich so nicht geht.
Wo läuft denn Dein SQL-Server und was für ein Server ist es (MySQL, MS SQL, ....)?
Gruß,
Eric
PS: Läuft bei mir ach ohne Probleme.
Von unterwegs getippert
-
Wenn er läuft und rot ist … wenn DU dann einen weiteren Datenpunkt zum logging dazu konfigurierst kommt die meldung das er enabled wurde?
Wie sieht denn das Log aus wenn du es per Kommandozeile startest?
@Eric: Das neu anlegen ist immer so.
-
Danke fürs Feedback.
Reboots hab ich einige hinter mir, leider nicht die Lösung.
Ich fahre auf dem gleichen Host MySQL (okay MariaDB, ein Problem?) und funktionierte in der Vergangenheit, aktuell auch über die Kommandozeile kopfkratz.
Wenn er Rot ist und ich einen weiteren Datenpunkt aktiviere, regt sich leider in keinem Log etwas und es gibt auch kein negatives Feedback beim Einrichten.
So sieht das Log aus der Kommandozeile aus (nur ein Ausschnitt):
C:\ioBroker>node node_modules/iobroker.sql/main.js -force -logs Cannot find module 'pg-native' 2017-10-18 22:27:02.579 - info: sql.0 starting. Version 1.5.6 in C:/ioBroker/node_modules/iobroker.sql, node: v4.5.0 2017-10-18 22:27:02.962 - debug: sql.0 CREATE DATABASE `iobroker` DEFAULT CHARACTER SET utf8 DEFAULT COLLATE utf8_general_ci; 2017-10-18 22:27:02.982 - debug: sql.0 Response: {"code":"ER_DB_CREATE_EXISTS","errno":1007,"sqlMessage":"Can't create database 'iobroker'; database exists","sqlState":"HY000","index":0,"sql":"CREATE DATABASE `iobroker` DEFAULT CHARACTER SET utf8 DEFAULT COLLATE utf8_general_ci;"} 2017-10-18 22:27:03.002 - debug: sql.0 CREATE TABLE `iobroker`.sources (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT); 2017-10-18 22:27:03.008 - debug: sql.0 Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'sources' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.sources (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT);"} 2017-10-18 22:27:03.015 - debug: sql.0 CREATE TABLE `iobroker`.datapoints (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT, type INTEGER); 2017-10-18 22:27:03.018 - debug: sql.0 Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'datapoints' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.datapoints (id INTEGER NOT NULL PRIMARY KEY AUTO_INCREMENT, name TEXT, type INTEGER);"} 2017-10-18 22:27:03.025 - debug: sql.0 CREATE TABLE `iobroker`.ts_number (id INTEGER, ts BIGINT, val REAL, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); 2017-10-18 22:27:03.029 - debug: sql.0 Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'ts_number' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.ts_number (id INTEGER, ts BIGINT, val REAL, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts));"} 2017-10-18 22:27:03.035 - debug: sql.0 CREATE TABLE `iobroker`.ts_string (id INTEGER, ts BIGINT, val TEXT, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); 2017-10-18 22:27:03.039 - debug: sql.0 Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'ts_string' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.ts_string (id INTEGER, ts BIGINT, val TEXT, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts));"} 2017-10-18 22:27:03.047 - debug: sql.0 CREATE TABLE `iobroker`.ts_bool (id INTEGER, ts BIGINT, val BOOLEAN, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts)); 2017-10-18 22:27:03.052 - debug: sql.0 Response: {"code":"ER_TABLE_EXISTS_ERROR","errno":1050,"sqlMessage":"Table 'ts_bool' already exists","sqlState":"42S01","index":0,"sql":"CREATE TABLE `iobroker`.ts_bool (id INTEGER, ts BIGINT, val BOOLEAN, ack BOOLEAN, _from INTEGER, q INTEGER, PRIMARY KEY(id, ts));"} 2017-10-18 22:27:03.054 - info: sql.0 Connected to mysql 2017-10-18 22:27:03.142 - info: sql.0 enabled logging of hm-rpc.0.updated 2017-10-18 22:27:03.144 - info: sql.0 enabled logging of hm-rpc.1.updated 2017-10-18 22:27:03.145 - info: sql.0 enabled logging of hm-rpc.0.BidCoS-RF.0.INSTALL_MODE 2017-10-18 22:27:03.146 - info: sql.0 enabled logging of hm-rpc.0.BidCoS-RF.1.LEVEL 2017-10-18 22:27:03.147 - info: sql.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_LONG 2017-10-18 22:27:03.148 - info: sql.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_SHORT 2017-10-18 22:27:03.149 - info: sql.0 enabled logging of hm-rpc.0.BidCoS-RF.2.LEVEL 2017-10-18 22:27:03.151 - info: sql.0 enabled logging of hm-rpc.0.BidCoS-RF.2.PRESS_LONG ....... usw.
-
@Eric: Das neu anlegen ist immer so. `
Ah, ok. Hatte es im Log gesehen und mich gewundert.Gruß,
Eric