search

alladdin / node-lox-mqtt-gateway

Gateway for Loxone™ miniserver to communicate with mqtt broker
MIT License
27 stars 20 forks source link

Large amount of duplicate events #3

Open ludekvodicka opened 7 years ago

ludekvodicka commented 7 years ago

I'm not sure if this is bug or intended behaviour but I see a lot of duplicate events in the log

https://dl.dropboxusercontent.com/u/11355235/ShareX/2017/01/2017-01-08_22-09-31.png or https://dl.dropboxusercontent.com/u/11355235/ShareX/2017/01/2017-01-08_22-10-29.png

And also when I'm subscribed for any topic I receive several messages. For the example one switch press causes about 30 events - https://dl.dropboxusercontent.com/u/11355235/ShareX/2017/01/2017-01-08_22-18-19.png

Is this correct behaviour?

alladdin commented 7 years ago

It's weird. I have no problem like that. I'll try to enhance debug logging for better diagnostics.

ludekvodicka commented 7 years ago

I'm using Mosquitto MQTT provider together with your plugin and latest Loxone config. I'm running it inside the Docker images.

alladdin commented 7 years ago

I'm also using Mosquitto and latest Loxone config on windows and raspberry pi. On both platforms without duplicate events. I added some debug messages. Please send me similar logs as previous.

ludekvodicka commented 7 years ago

I tried to rebuild docker machines but it seems that logs and behaviors are still the same. Should I configure anythig to be able to see new logs?

This is how I'm creating docker machine with your app


FROM node

RUN npm install -g node-lox-mqtt-gateway
RUN apt-get update
RUN apt-get --assume-yes install mosquitto-clients

ENTRYPOINT node /usr/local/lib/node_modules/node-lox-mqtt-gateway/bin/lox-mqtt-gateway.js --NODE_CONFIG_DIR='/data'

and this is my complet cfg file located in /data directory

{
    "winston": [{
        "Console": {
            "level": "silly",
            "colorize": true,
            "timestamp": true
        }
    }],
    "mqtt": {
        "host": "mqtt://dum-mosquitto:1883",
        "options": {
            "rejectUnauthorized": false,
            "clientId": "lox_to_mqtt_gateway"
        }
    },
    "miniserver": {
        "host": "loxone.dum:80",
        "username": "xxxxx",
        "password": "xxxx",
        "readonly": false,
        "encrypted" : true,
        "mqtt_prefix": "lox"
    }
}

and these are first lines from log:

dum-loxone-mqtt    | 2017-01-10T08:57:56.695Z - info: Loxone to MQTT gateway started
dum-loxone-mqtt    | 2017-01-10T08:57:56.718Z - info: MQTT - connect cmd=connack, retain=false, qos=0, dup=false, length=2, topic=null, payload=null, sessionPresent=false, returnCode=0
dum-loxone-mqtt    | 2017-01-10T08:57:56.747Z - info: WebSocketAPI - connect

Is there any version info I can check?

ludekvodicka commented 7 years ago

I tried it once more time. These seem to be the log lines (it's one click on switch button)

dum-loxone-mqtt    | 2017-01-10T09:12:33.706Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.707Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.707Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.714Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.714Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.717Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.718Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.719Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.720Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.732Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.732Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.733Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.733Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.737Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.737Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.737Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.738Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.738Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.738Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.748Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.748Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.749Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.749Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.750Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.750Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.751Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.751Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.752Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.752Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.752Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.752Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.753Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.753Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.753Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.753Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.770Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.771Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.771Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.771Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.772Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.772Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.784Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.784Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.785Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.785Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.794Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.794Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.794Z - debug: WebSocketAPI - received update event:  uuid=0e3b4ddb-00c9-e76d-ffffba26796ac754, event=3837.21125
dum-loxone-mqtt    | 2017-01-10T09:12:33.794Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/mereni/elektromer_celkem/state, data={"total":3837.21125}
dum-loxone-mqtt    | 2017-01-10T09:12:33.804Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.804Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.805Z - debug: WebSocketAPI - received update event:  uuid=0e3b4ddb-00c9-e76d-ffffba26796ac754, event=3837.21125
dum-loxone-mqtt    | 2017-01-10T09:12:33.805Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/mereni/elektromer_celkem/state, data={"total":3837.21125}
dum-loxone-mqtt    | 2017-01-10T09:12:33.805Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.805Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.805Z - debug: WebSocketAPI - received update event:  uuid=0e3b4ddb-00c9-e76d-ffffba26796ac754, event=3837.21125
dum-loxone-mqtt    | 2017-01-10T09:12:33.805Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/mereni/elektromer_celkem/state, data={"total":3837.21125}
dum-loxone-mqtt    | 2017-01-10T09:12:33.806Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.806Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.806Z - debug: WebSocketAPI - received update event:  uuid=0e3b4ddb-00c9-e76d-ffffba26796ac754, event=3837.21125
dum-loxone-mqtt    | 2017-01-10T09:12:33.806Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/mereni/elektromer_celkem/state, data={"total":3837.21125}
dum-loxone-mqtt    | 2017-01-10T09:12:33.810Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.810Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.810Z - debug: WebSocketAPI - received update event:  uuid=0e3b4ddb-00c9-e76d-ffffba26796ac754, event=3837.21125
dum-loxone-mqtt    | 2017-01-10T09:12:33.810Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/mereni/elektromer_celkem/state, data={"total":3837.21125}
dum-loxone-mqtt    | 2017-01-10T09:12:33.811Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.811Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.811Z - debug: WebSocketAPI - received update event:  uuid=0e3b4ddb-00c9-e76d-ffffba26796ac754, event=3837.21125
dum-loxone-mqtt    | 2017-01-10T09:12:33.811Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/mereni/elektromer_celkem/state, data={"total":3837.21125}
dum-loxone-mqtt    | 2017-01-10T09:12:33.811Z - debug: WebSocketAPI - received update event:  uuid=0eec80eb-007d-f7aa-ffff10b04d6bdd13, event=1
dum-loxone-mqtt    | 2017-01-10T09:12:33.811Z - debug: MQTT Adaptor - for mqtt:  topic=lox/[technologie]/neprirazeno/tlacitko_rele1/state, data={"active":"on"}
dum-loxone-mqtt    | 2017-01-10T09:12:33.811Z - debug: WebSocketAPI - received update event:  uuid=0e3b4ddb-00c9-e76d-ffffba26796ac754, event=3837.21125

And these are received mqtt messages:

root@2ee70ea8ad6f:/# mosquitto_sub -h dum-mosquitto -t "lox/[technologie]/neprirazeno/tlacitko_rele1/state"
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
{"active":"on"}
alladdin commented 7 years ago

which version is in /usr/local/lib/node_modules/node-lox-mqtt-gateway/package.json? New logging is in 0.2.9

ludekvodicka commented 7 years ago

You're right. It's 0.2.8.

But I'm not sure why. It seems that npm is returning old version

RUN npm install -g node-lox-mqtt-gateway

I also tried to replace content of /usr/local/lib/node_modules/node-lox-mqtt-gateway/ with content directly from GitHub but then I'm receiving following error:

dum-loxone-mqtt    | module.js:472
dum-loxone-mqtt    |     throw err;
dum-loxone-mqtt    |     ^
dum-loxone-mqtt    |
dum-loxone-mqtt    | Error: Cannot find module 'unidecode'
dum-loxone-mqtt    |     at Function.Module._resolveFilename (module.js:470:15)
dum-loxone-mqtt    |     at Function.Module._load (module.js:418:25)
dum-loxone-mqtt    |     at Module.require (module.js:498:17)
dum-loxone-mqtt    |     at require (internal/module.js:20:19)
dum-loxone-mqtt    |     at Object.<anonymous> (/usr/local/lib/node_modules/node-lox-mqtt-gateway/lib/Adaptor.js:3:19)
dum-loxone-mqtt    |     at Module._compile (module.js:571:32)
dum-loxone-mqtt    |     at Object.Module._extensions..js (module.js:580:10)
dum-loxone-mqtt    |     at Module.load (module.js:488:32)
dum-loxone-mqtt    |     at tryModuleLoad (module.js:447:12)
dum-loxone-mqtt    |     at Function.Module._load (module.js:439:3)
alladdin commented 7 years ago

After replacing content you must run "npm install" in node-lox-mqtt-gateway diretory

alladdin commented 7 years ago

I wrote the testing script https://github.com/alladdin/node-lox-ws-api-testing. Please could you try it? Is there a duplicit events?