Adapterentwicklung: Bug bei Anlage von states???

[carsten04]

Ich bin mir nicht ganz sicher, aber ich glaube es gibt noch ein Problem bei der Anlage von states durch einen Adapter. Ich versuche mich gerade selber an der Adapterentwicklung und bin dabei auf folgendes gestoßen (als Beispiel nehme ich den sonos-Adapter, da es hier für alle nachvollziehbar ist).

Bei der Anlage eines Devices über die sonos-Konfiguration wird im Log immer folgende Ausgabe erzeugt:

! ````
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.remove_from_group with {"val":"","ack":false,"ts":1490524129541,"q":0,"from":"system.adapter.sonos.0","lc":1490524129541}
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.add_to_group with {"val":"","ack":false,"ts":1490524129541,"q":0,"from":"system.adapter.sonos.0","lc":1490524129541}
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.tts with {"val":"","ack":false,"ts":1490524129541,"q":0,"from":"system.adapter.sonos.0","lc":1490524129541}
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.favorites_set with {"val":"","ack":false,"ts":1490524129541,"q":0,"from":"system.adapter.sonos.0","lc":1490524129541}
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.favorites_list with {"val":"","ack":false,"ts":1490524129541,"q":0,"from":"system.adapter.sonos.0","lc":1490524129541}
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.current_elapsed_s with {"val":"00:00","ack":false,"ts":1490524129541,"q":0,"from":"system.adapter.sonos.0","lc":1490524129541}
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.current_elapsed with {"val":0,"ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.552 info try to control id sonos.0.root.0_0_0_0.alive with {"val":null,"ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.551 info try to control id sonos.0.root.0_0_0_0.current_type with {"val":0,"ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.551 info try to control id sonos.0.root.0_0_0_0.current_duration_s with {"val":"00:00","ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.551 info try to control id sonos.0.root.0_0_0_0.current_duration with {"val":0,"ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.551 info try to control id sonos.0.root.0_0_0_0.current_cover with {"val":"","ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.551 info try to control id sonos.0.root.0_0_0_0.current_album with {"val":"","ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.551 info try to control id sonos.0.root.0_0_0_0.current_artist with {"val":"","ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.551 info try to control id sonos.0.root.0_0_0_0.current_title with {"val":"","ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.muted with {"val":false,"ack":false,"ts":1490524129540,"q":0,"from":"system.adapter.sonos.0","lc":1490524129540}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.volume with {"val":null,"ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.state with {"val":"stop","ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.seek with {"val":null,"ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.next with {"val":null,"ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.prev with {"val":null,"ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.pause with {"val":null,"ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.stop with {"val":null,"ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.550 info try to control id sonos.0.root.0_0_0_0.play with {"val":null,"ack":false,"ts":1490524129539,"q":0,"from":"system.adapter.sonos.0","lc":1490524129539}
sonos.0 2017-03-26 12:28:49.549 info try to control id sonos.0.root.0_0_0_0.state_simple with {"val":false,"ack":false,"ts":1490524129538,"q":0,"from":"system.adapter.sonos.0","lc":1490524129538}
sonos.0 2017-03-26 12:28:49.526 info http sonos server listening on port 8080
sonos.0 2017-03-26 12:28:49.490 info starting. Version 1.5.0 in E:/node_workspace/iobroker/node_modules/iobroker.sonos, node: v6.9.4
host.PC-Buero 2017-03-26 12:28:48.770 info instance system.adapter.sonos.0 started with pid 5164
host.PC-Buero 2017-03-26 12:28:46.264 info instance system.adapter.sonos.0 terminated with code null ()
host.PC-Buero 2017-03-26 12:28:46.264 warn instance system.adapter.sonos.0 terminated due to SIGTERM
host.PC-Buero 2017-03-26 12:28:46.255 info stopInstance system.adapter.sonos.0 killing pid 5796
host.PC-Buero 2017-03-26 12:28:46.255 info stopInstance system.adapter.sonos.0

Dies dürfte aber mMn. bei der Anlage der states auf keinen Fall passieren, da zu diesem Zeitpunkt die Werte der states in der Regel noch undefiniert sind und das zugehörige Gerät im schlimmsten Fall nicht gewollte Reaktionen zeigen könnte, da der verarbeitende callback in (adapter.on('stateChange,…)) mit dem übergebenen Wert (state.val) nicht zurechtkommen könnte und eine Fehlermeldung produzieren könnte und die Adapterinstanz ggf. inaktiv gesetzt würde (oder der js-controller versucht sie ständig neu zu starten).

Der zugehörige Quelltext im sonos-Adapter lautet (sonos.js):

adapter.on('stateChange', function (_id, state) {
if (!state || state.ack) return;
adapter.log.info('try to control id ' + _id + ' with ' + JSON.stringify(state));
...

Hier sieht man schon wo das Problem anscheinend liegt: natürlich wird hier völlig richtig bei state.ack == true (nur Status) sofort die Funktion verlassen. Bei der Anlage des state (mit createState(…)) wird aber anscheinend (1) ein stateChange-Event generiert (dürfte eigentlich an der Stelle glaube ich nicht passieren) und (2) state.ack == false (s. Log oben) gesetzt was zur Weiterverarbeitung im registrierten callback (adapter.on('stateChange,...)) führt und bei der Anlage der states eigentlich nicht passieren sollte.

Stehe ich hier jetzt gerade nur auf dem Schlauch und verstehe etwas grundsätzlich ber der state-Anlage nicht, oder ist das noch ein Bug für den es möglicherweise einen workaround gibt? Freue mich über jede Idee.

Grüße

Carsten

[Bluefox]

Gut gemerkt. Ich denke dass das Problem liegt an "def". Und die müssen mit ack True angelegt werden.

Werde ich checken und fixen.

[carsten04]

super, vielen Dank Bluefox. Ich habe jetzt gerade mal in adapter.js nachgesehen. Ich vermute mal hier muss gefixt werden:

alt:

 if (common.def !== undefined) {
                that.setState(id, common.def, options);
            } else {
                that.setState(id, null, false, options);
            } 

neu:

 if (common.def !== undefined) {
                that.setState(id, common.def, options);
            } else {
                that.setState(id, null, true, options);
            } 

Bin mir aber nicht 100% sicher, ob das die richtige Stelle ist.

Grüße

Carsten