Button pressed once after a period of time does not include payload "action" for Legrand Switch (067773)

Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨

https://www.zigbee2mqtt.io

GNU General Public License v3.0

11.73k stars 1.64k forks source link

Button pressed once after a period of time does not include payload "action" for Legrand Switch (067773) #14256

Closed celestianx closed 1 year ago

celestianx commented 1 year ago

What happened?

With a Legrand Remote Switch (067773, after a certain period of time when the light is off, pressing the button once will not send a message with the proper format, i.e. the action attribute is missing from the payload resulting in the light not being toggled on. If button is pressed twice in a row, send message will include the correct payload. If button is not pressed twice in a row, but then pressed a minute after, same wrong behavior is observed (wrong payload)

What did you expect to happen?

Switch to toggle "on" my light after a single press on the button (i.e. first press after a long period of time to send message with the "action" payload)

How to reproduce it (minimal and precise)

Press the switch to toggle off the light Wait a few minutes Press the switch to toggle on the light

Zigbee2MQTT version

1.27.2 commit: 7dc48fb

Adapter firmware version

20220219

Adapter

zStack3x0

Debug log

info  2022-09-30 05:50:31: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 05:50:31: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":100,"linkquality":102,"voltage":3000}'
info  2022-09-30 05:51:35: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 05:51:35: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":100,"linkquality":91,"voltage":3000}'
info  2022-09-30 05:51:39: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"action":"toggle","battery":100,"linkquality":94,"voltage":3000}'
info  2022-09-30 05:51:39: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387/action', payload 'toggle'
info  2022-09-30 05:57:34: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 05:57:34: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"action":"brightness_move_down","action_rate":100,"battery":100,"linkquality":43,"voltage":3000}'
info  2022-09-30 05:57:34: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387/action', payload 'brightness_move_down'
info  2022-09-30 05:57:35: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":100,"linkquality":29,"voltage":3000}'
info  2022-09-30 05:57:36: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"action":"brightness_stop","battery":100,"linkquality":54,"voltage":3000}'
info  2022-09-30 05:57:36: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387/action', payload 'brightness_stop'
info  2022-09-30 06:13:36: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"action":"toggle","battery":100,"linkquality":65,"voltage":3000}'
info  2022-09-30 06:13:36: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387/action', payload 'toggle'
info  2022-09-30 06:13:37: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 06:13:37: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":80,"linkquality":65,"voltage":2900}'
info  2022-09-30 06:21:18: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 06:21:18: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":80,"linkquality":87,"voltage":2900}'
info  2022-09-30 06:22:04: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 06:22:04: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":100,"linkquality":98,"voltage":3000}'
info  2022-09-30 06:29:29: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 06:29:29: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":100,"linkquality":54,"voltage":3000}'
info  2022-09-30 06:36:02: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
info  2022-09-30 06:36:04: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"action":"toggle","battery":100,"linkquality":94,"voltage":3000}'
info  2022-09-30 06:36:04: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387/action', payload 'toggle'

celestianx commented 1 year ago

Similar issue reports back in January for 067774. As for 067773 with Firmware build date: 20181022 and Firmware version: 003c, the fix does not work. I have tried adding it to a dummy group, and it does seem to fix it. Nonetheless, it is still an issue because we shouldn't have. to do so in my opinion :)

celestianx commented 1 year ago

So it might be a repeat of all the threads but: 1. Unsupported message. Why would a Legrand switch send a "manuSpecificUbisysDimmerSetup"? And if so, isn't there some kind of response we can provide to the switch so that it stops doing that?

Received Zigbee message from '0x0004740000a93387', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[5,33,16,1,9,135,51,169,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0

2. After further reviewing the logs, it seems that the Legrand switch always announce itself on the network after some time of inactivity. Whenever, it does so, we do see the that herdsmann receive the commandToggle but it seems z2m ignores it:

Zigbee2MQTT:debug 2022-10-02 10:09:34: No converter available for '067773' with cluster 'manuSpecificUbisysDimmerSetup' and type 'raw' and data '{"data":[5,33,16,0,9,135,51,169,0,0,116,4,0,1],"type":"Buffer"}'
Zigbee2MQTT:debug 2022-10-02 10:09:35: Received Zigbee message from '0x0004740000a93387', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2022-10-02 10:09:35: Device '0x0004740000a93387' announced itself
Zigbee2MQTT:info  2022-10-02 10:09:35: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
Zigbee2MQTT:debug 2022-10-02 10:09:35: Received Zigbee message from '0x0004740000a93387', type 'readResponse', cluster 'genPowerCfg', data '{"batteryVoltage":29}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2022-10-02 10:09:35: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":80,"linkquality":83,"voltage":2900}'
Zigbee2MQTT:debug 2022-10-02 10:09:37: Retrieving state of '0x0004740000a93387' after reconnect`

Also, when binding the switch to the bulb directly, we do see that z2m captures the commandToggle and send it properly:

Zigbee2MQTT:debug 2022-10-02 10:23:11: Received Zigbee message from '0x0004740000a93387', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[5,33,16,0,9,135,51,169,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2022-10-02 10:23:11: No converter available for '067773' with cluster 'manuSpecificUbisysDimmerSetup' and type 'raw' and data '{"data":[5,33,16,0,9,135,51,169,0,0,116,4,0,1],"type":"Buffer"}'
Zigbee2MQTT:debug 2022-10-02 10:23:11: Received Zigbee message from '0x0004740000a93387', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2022-10-02 10:23:11: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"action":"toggle","battery":80,"linkquality":72,"voltage":2900}'
Zigbee2MQTT:info  2022-10-02 10:23:11: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387/action', payload 'toggle'
Zigbee2MQTT:debug 2022-10-02 10:23:11: Device '0x0004740000a93387' announced itself
Zigbee2MQTT:info  2022-10-02 10:23:11: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
Zigbee2MQTT:debug 2022-10-02 10:23:11: Received Zigbee message from '0x0004740000a93387', type 'readResponse', cluster 'genPowerCfg', data '{"batteryVoltage":29}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2022-10-02 10:23:11: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":80,"linkquality":76,"voltage":2900}'
Zigbee2MQTT:debug 2022-10-02 10:23:12: Received Zigbee message from '0x001788010b98965f', type 'readResponse', cluster 'genOnOff', data '{"onOff":1}' from endpoint 11 with groupID 0
Zigbee2MQTT:info  2022-10-02 10:23:12: MQTT publish: topic 'zigbee2mqtt/0x001788010b98965f', payload '{"brightness":254,"color_mode":"xy","linkquality":171,"state":"ON","update":{"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2022-10-02 10:23:12: Received Zigbee message from '0x001788010b98965f', type 'attributeReport', cluster 'genOnOff', data '{"onOff":1}' from endpoint 11 with groupID 0
Zigbee2MQTT:info  2022-10-02 10:23:12: MQTT publish: topic 'zigbee2mqtt/0x001788010b98965f', payload '{"brightness":254,"color_mode":"xy","linkquality":171,"state":"ON","update":{"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2022-10-02 10:23:12: Received Zigbee message from '0x001788010b98965f', type 'attributeReport', cluster 'genLevelCtrl', data '{"currentLevel":134}' from endpoint 11 with groupID 0
Zigbee2MQTT:info  2022-10-02 10:23:12: MQTT publish: topic 'zigbee2mqtt/0x001788010b98965f', payload '{"brightness":134,"color_mode":"xy","linkquality":171,"state":"ON","update":{"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2022-10-02 10:23:13: Retrieving state of '0x0004740000a93387' after reconnect
Zigbee2MQTT:debug 2022-10-02 10:23:17: Received Zigbee message from '0x001788010b98965f', type 'attributeReport', cluster 'genLevelCtrl', data '{"currentLevel":254}' from endpoint 11 with groupID 0
Zigbee2MQTT:info  2022-10-02 10:23:17: MQTT publish: topic 'zigbee2mqtt/0x001788010b98965f', payload '{"brightness":254,"color_mode":"xy","linkquality":167,"state":"ON","update":{"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2022-10-02 10:23:20: Received Zigbee message from '0x0004740000a93387', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,2,5,135,51,169,0,0,116,4,0],"type":"Buffer"}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2022-10-02 10:23:20: No converter available for '067773' with cluster 'manuSpecificUbisysDimmerSetup' and type 'raw' and data '{"data":[21,33,16,2,5,135,51,169,0,0,116,4,0],"type":"Buffer"}'

Effectively, the binding vs. no binding in z2m seems to have a different behaviour

celestianx commented 1 year ago

Not much success on that issue but I have investigated and understood why there is this behaviour :) The herdsman default convert is as such:

        cluster: 'genOnOff',
        type: 'commandToggle',
        convert: (model, msg, publish, options, meta) => {
            if (hasAlreadyProcessedMessage(msg)) return;
            const payload = {action: postfixWithEndpointName('toggle', msg, model, meta)};
            addActionGroup(payload, msg, model);
            return payload;
        },
    },

The hasAlreadyProcessedMessage(msg) is what cause this strange behaviour:

function hasAlreadyProcessedMessage(msg, ID=null, key=null) {
    const currentID = ID !== null ? ID : msg.meta.zclTransactionSequenceNumber;
    key = key || msg.device.ieeeAddr;
    if (transactionStore[key] === currentID) return true;
    transactionStore[key] = currentID;
    return false;
}

It seems the Legrand switch implements msg.meta.zclTransactionSequenceNumber in a non very reliable way:

It increments a number from 1 to N
It resets the transaction number upon each device announcement
It announces systematically on the network only after a few seconds of inactivity

Thus the problem mostly occur on the first press because the device would send a transaction number of 1, and if the last transaction was a single press (in most case), the stored transaction number is also 1.

Zigbee2MQTT:debug 2022-10-08 11:07:47: Received Zigbee message from '0x0004740000a93387', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
{
  type: 'commandToggle',
  device: Device {
    zh: Device {
      _events: [Object: null prototype] {},
      _eventsCount: 0,
      _maxListeners: undefined,
      ID: 3,
      _type: 'EndDevice',
      _ieeeAddr: '0x0004740000a93387',
      _networkAddress: 57796,
      _manufacturerID: 4129,
      _endpoints: [Array],
      _manufacturerName: ' Legrand\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00',
      _powerSource: 'Battery',
      _modelID: ' Remote switch\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00',
      _applicationVersion: 0,
      _stackVersion: 66,
      _zclVersion: 2,
      _hardwareVersion: 4,
      _dateCode: ' \x0020181022\x00\x00\x00\x00\x00',
      _softwareBuildID: '003c',
      _interviewCompleted: true,
      _interviewing: false,
      _skipDefaultResponse: false,
      _skipTimeResponse: false,
      meta: [Object],
      _lastSeen: 1665220067906,
      _defaultSendRequestWhen: 'active',
      _linkquality: 142,
      [Symbol(kCapture)]: true
    },
    _definition: {
      zigbeeModel: [Array],
      model: '067773',
      vendor: 'Legrand',
      description: 'Wireless remote switch',
      fromZigbee: [Array],
      exposes: [Array],
      toZigbee: [Array],
      meta: [Object],
      configure: [AsyncFunction: configure],
      onEvent: [AsyncFunction: readInitialBatteryState],
      options: [Array]
    },
    _definitionModelID: ' Remote switch\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
  },
  endpoint: Endpoint {
    _events: [Object: null prototype] {},
    _eventsCount: 0,
    _maxListeners: undefined,
    ID: 1,
    profileID: 260,
    deviceID: 260,
    inputClusters: [ 0, 3, 15, 32, 1, 64513 ],
    outputClusters: [ 3, 6, 8, 0, 64513, 25 ],
    deviceNetworkAddress: 57796,
    deviceIeeeAddress: '0x0004740000a93387',
    clusters: {
      genPowerCfg: [Object],
      genBasic: [Object],
      genPollCtrl: [Object]
    },
    _binds: [ [Object], [Object], [Object], [Object], [Object], [Object] ],
    _configuredReportings: [],
    meta: {},
    pendingRequests: [],
    [Symbol(kCapture)]: true
  },
  data: {},
  linkquality: 142,
  groupID: 0,
  cluster: 'genOnOff',
  meta: {
    zclTransactionSequenceNumber: 1,
    manufacturerCode: null,
    frameControl: {
      frameType: 1,
      manufacturerSpecific: false,
      direction: 0,
      disableDefaultResponse: true,
      reservedBits: 0
    }
  }
}
Key:
0x0004740000a93387
Transaction Store:
{ '0x0004740000a93387': 1 }
Zigbee2MQTT:debug 2022-10-08 11:07:48: Device '0x0004740000a93387' announced itself
Zigbee2MQTT:info  2022-10-08 11:07:48: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x0004740000a93387","ieee_address":"0x0004740000a93387"},"type":"device_announce"}'
Zigbee2MQTT:debug 2022-10-08 11:07:48: Received Zigbee message from '0x0004740000a93387', type 'readResponse', cluster 'genPowerCfg', data '{"batteryVoltage":28}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2022-10-08 11:07:48: MQTT publish: topic 'zigbee2mqtt/0x0004740000a93387', payload '{"battery":60,"linkquality":142,"voltage":2800}'
Zigbee2MQTT:debug 2022-10-08 11:07:50: Retrieving state of '0x0004740000a93387' after reconnect
Zigbee2MQTT:debug 2022-10-08 11:07:56: Received Zigbee message from '0x0004740000a93387', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,2,5,135,51,169,0,0,116,4,0],"type":"Buffer"}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2022-10-08 11:07:56: No converter available for '067773' with cluster 'manuSpecificUbisysDimmerSetup' and type 'raw' and data '{"data":[21,33,16,2,5,135,51,169,0,0,116,4,0],"type":"Buffer"}'

Wouldn't it be more reliable to compute this transaction id based on more attributes from the message to ensure it is unique?

Koenkk commented 1 year ago

Could you check if the issue is fixed with the following external converter:

const fz = require('zigbee-herdsman-converters/converters/fromZigbee');
const tz = require('zigbee-herdsman-converters/converters/toZigbee');
const exposes = require('zigbee-herdsman-converters/lib/exposes');
const reporting = require('zigbee-herdsman-converters/lib/reporting');
const extend = require('zigbee-herdsman-converters/lib/extend');
const ota = require('zigbee-herdsman-converters/lib/ota');
const tuya = require('zigbee-herdsman-converters/lib/tuya');
const utils = require('zigbee-herdsman-converters/lib/utils');
const e = exposes.presets;
const ea = exposes.access;

const fzLocal = {
    command_toggle: {
        cluster: 'genOnOff',
        type: 'commandToggle',
        convert: (model, msg, publish, options, meta) => {
            //if (hasAlreadyProcessedMessage(msg)) return;
            const payload = {action: postfixWithEndpointName('toggle', msg, model, meta)};
            addActionGroup(payload, msg, model);
            return payload;
        },
    },
};

const definition = {
    zigbeeModel: [
        ' Remote switch\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000'],
    model: '067773',
    vendor: 'Legrand',
    // led blink RED when battery is low
    description: 'Wireless remote switch',
    fromZigbee: [fz.identify, fz.command_on, fz.command_off, fzLocal.command_toggle, fz.command_move, fz.command_stop,
        fz.battery],
    exposes: [e.battery(), e.action(['identify', 'on', 'off', 'toggle', 'brightness_move_up',
        'brightness_move_down', 'brightness_stop'])],
    toZigbee: [],
    meta: {battery: {voltageToPercentage: '3V_2500'}},
    configure: async (device, coordinatorEndpoint, logger) => {
        const endpoint = device.getEndpoint(1);
        await reporting.bind(endpoint, coordinatorEndpoint, ['genPowerCfg', 'genOnOff', 'genLevelCtrl']);
    },
    onEvent: readInitialBatteryState,
};

module.exports = definition;

save this as file next to configuration.yaml as ext_converter.js
add it to configuration.yaml:
```
external_converters:
- ext_converter.js
```
start z2m, check if issue is fixed

jiquem commented 1 year ago

Hello, Unfortunately, it doesn't start when I add the ext_converter.js. (I am under Home Assistant, so first, I stop zigbee2mqtt, and then performed what you mentioned)

Here is the error message:

[19:40:17] INFO: Preparing to start...
[19:40:17] INFO: Socat not enabled
[19:40:18] INFO: Starting Zigbee2MQTT...
/app/dist/util/externally-loaded.js:32
    fromZigbee: [fz.identify, fz.command_on, fz.command_off, fzLocal.command_toggle, fz.legacy.cmd_move, fz.legacy.cmd_stop,
                                                                                               ^
TypeError: Cannot read properties of undefined (reading 'cmd_move')
    at /app/dist/util/externally-loaded.js:32:96
    at Script.runInContext (node:vm:139:12)
    at Script.runInNewContext (node:vm:144:17)
    at Object.runInNewContext (node:vm:298:38)
    at loadModuleFromText (/app/lib/util/utils.ts:148:8)
    at loadModuleFromFile (/app/lib/util/utils.ts:155:12)
    at Object.getExternalConvertersDefinitions (/app/lib/util/utils.ts:165:25)
    at getExternalConvertersDefinitions.next (<anonymous>)
    at new ExternalConverters (/app/lib/extension/externalConverters.ts:12:20)
    at new Controller (/app/lib/controller.ts:84:58)

I've tried to bind the Legrand 067773 to a test group, but I've got this error message:

error 2022-10-09 19:26:19: Failed to bind cluster 'genOnOff' from 'legrand_switch_cagibi' to 'test' (Error: Bind 0x0004740000c43729/1 genOnOff from '13' failed (AREQ - ZDO - bindRsp after 10000ms))
error 2022-10-09 19:26:29: Failed to bind cluster 'genLevelCtrl' from 'legrand_switch_cagibi' to 'test' (Error: Bind 0x0004740000c43729/1 genLevelCtrl from '13' failed (AREQ - ZDO - bindRsp after 10000ms))
info  2022-10-09 19:26:29: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/bind', payload '{"data":{"clusters":[],"failed":["genOnOff","genLevelCtrl"],"from":"legrand_switch_cagibi/1","to":"test"},"error":"Failed to bind","status":"error","transaction":"935z8-4"}'

Koenkk commented 1 year ago

Updated https://github.com/Koenkk/zigbee2mqtt/issues/14256#issuecomment-1272303031

celestianx commented 1 year ago

Hi Koenkk, Thank you for your support. I had already fixed it and was testing it since yesterday in a likely manner and was testing it since yesterday. Works perfectly. Not knowing about zigbee protocol and zclTransactionSequenceNumber, I followed an approach where I was providing an id on a timestamp to the transaction store of the hasAlreadyProcessedMessage method; From your experience, in what cases, a device sends multiple commands with the same transaction number? If there is non in the case of a light switch, then your fix is better!

Overall, while it fixes the commandToggle, this behaviour potentially impacts the command move up, down (the stop should be ok as it comes after a move up or down)

command_toggle: {
        cluster: 'genOnOff',
        type: 'commandToggle',
        convert: (model, msg, publish, options, meta) => {
            const id =  (new Date().getTime()/1000).toString()
            if (utils.hasAlreadyProcessedMessage(msg, id)) return;
            const payload = {action: utils.postfixWithEndpointName('toggle', msg, model, meta)};
            utils.addActionGroup(payload, msg, model);
            return payload;
        },
    },

celestianx commented 1 year ago

Last question from you, is it necessary to retrieve the battery state on each event? Isn't it using battery of the switch for nothing as the switch actually provides the battery state every single time it responds? Is it possible as part of the converter to publish two mqtt messages ?

jiquem commented 1 year ago

Updated #14256 (comment)

Now, I have

[21:27:33] INFO: Preparing to start...
[21:27:34] INFO: Socat not enabled
[21:27:34] INFO: Starting Zigbee2MQTT...
/app/dist/util/externally-loaded.js:42
    onEvent: readInitialBatteryState,
             ^
ReferenceError: readInitialBatteryState is not defined
    at /app/dist/util/externally-loaded.js:42:14
    at Script.runInContext (node:vm:139:12)
    at Script.runInNewContext (node:vm:144:17)
    at Object.runInNewContext (node:vm:298:38)
    at loadModuleFromText (/app/lib/util/utils.ts:148:8)
    at loadModuleFromFile (/app/lib/util/utils.ts:155:12)
    at Object.getExternalConvertersDefinitions (/app/lib/util/utils.ts:165:25)
    at getExternalConvertersDefinitions.next (<anonymous>)
    at new ExternalConverters (/app/lib/extension/externalConverters.ts:12:20)
    at new Controller (/app/lib/controller.ts:84:58)

celestianx commented 1 year ago

Could you just paste your .js file? You are clearly doing something different than what has been suggested by Koenkk

jiquem commented 1 year ago

This is what I did. my .js file, only contain the code from Koenkk.

Thanks

➜  zigbee2mqtt cat > ext_converter.js 
const fz = require('zigbee-herdsman-converters/converters/fromZigbee');
const tz = require('zigbee-herdsman-converters/converters/toZigbee');
const exposes = require('zigbee-herdsman-converters/lib/exposes');
const reporting = require('zigbee-herdsman-converters/lib/reporting');
const extend = require('zigbee-herdsman-converters/lib/extend');
const ota = require('zigbee-herdsman-converters/lib/ota');
const tuya = require('zigbee-herdsman-converters/lib/tuya');
const utils = require('zigbee-herdsman-converters/lib/utils');
const e = exposes.presets;
const ea = exposes.access;

const fzLocal = {
    command_toggle: {
        cluster: 'genOnOff',
        type: 'commandToggle',
        convert: (model, msg, publish, options, meta) => {
            //if (hasAlreadyProcessedMessage(msg)) return;
            const payload = {action: postfixWithEndpointName('toggle', msg, model, meta)};
            addActionGroup(payload, msg, model);
            return payload;
        },
    },
};

const definition = {
    zigbeeModel: [
        ' Remote switch\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000'],
    model: '067773',
    vendor: 'Legrand',
    // led blink RED when battery is low
    description: 'Wireless remote switch',
    fromZigbee: [fz.identify, fz.command_on, fz.command_off, fzLocal.command_toggle, fz.command_move, fz.command_stop,
        fz.battery],
    exposes: [e.battery(), e.action(['identify', 'on', 'off', 'toggle', 'brightness_move_up',
        'brightness_move_down', 'brightness_stop'])],
    toZigbee: [],
    meta: {battery: {voltageToPercentage: '3V_2500'}},
    configure: async (device, coordinatorEndpoint, logger) => {
        const endpoint = device.getEndpoint(1);
        await reporting.bind(endpoint, coordinatorEndpoint, ['genPowerCfg', 'genOnOff', 'genLevelCtrl']);
    },
    onEvent: readInitialBatteryState,
};

module.exports = definition;

celestianx commented 1 year ago

The method is not defined in your converter extension. You either need to define it explicitly or import it from the base code to handle Legrand devices

Add this at the beginning:

const legrand = require('zigbee-herdsman-converters/devices/legrand');

Then,

onEvent: legrand.readInitialBatteryState,

You may also have to put utils. in front of all the methods:

utils.postfixWithEndpointName('toggle', msg, model, meta)};
utils.addActionGroup(payload, msg, model);

jiquem commented 1 year ago

Thanks celestianx for your answer. It works ! However I have some automation triggered twice. I will manage it using a delay in the automation

Here for exemple, when the automation is triggered twice.

info  2022-10-10 12:30:11: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665397811316,"linkquality":51,"voltage":3000}'
info  2022-10-10 12:30:11: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665397811614,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:30:11: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":"toggle","battery":100,"last_seen":1665397811680,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:30:11: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":"","battery":100,"last_seen":1665397811680,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:30:11: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1/action', payload 'toggle'
info  2022-10-10 12:30:12: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665397812217,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:30:12: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cuisine_1","ieee_address":"0x0004740000c4372f"},"type":"device_announce"}'
info  2022-10-10 12:30:13: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665397813204,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:30:13: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":"toggle","battery":100,"last_seen":1665397813557,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:30:13: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":"","battery":100,"last_seen":1665397813557,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:30:13: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1/action', payload 'toggle'
info  2022-10-10 12:30:22: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665397822776,"linkquality":36,"voltage":3000}'

And after, the automation is triggered once

info  2022-10-10 12:47:57: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665398877655,"linkquality":36,"voltage":3000}'
info  2022-10-10 12:47:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665398878012,"linkquality":36,"voltage":3000}'
info  2022-10-10 12:47:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":"toggle","battery":100,"last_seen":1665398878015,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:47:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":"","battery":100,"last_seen":1665398878015,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:47:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1/action', payload 'toggle'
info  2022-10-10 12:47:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665398878438,"linkquality":40,"voltage":3000}'
info  2022-10-10 12:47:58: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cuisine_1","ieee_address":"0x0004740000c4372f"},"type":"device_announce"}'
info  2022-10-10 12:48:07: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cuisine_1', payload '{"action":null,"battery":100,"last_seen":1665398887421,"linkquality":40,"voltage":3000}'

Koenkk commented 1 year ago

Here for exemple, when the automation is triggered twice.

Can you provide the debug log of this?

jiquem commented 1 year ago

Just 2 minutes after activating the debug, It seems, I've got one occurence :

info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665433858085,"linkquality":65,"voltage":2900}'
debug 2022-10-10 22:30:58: Received Zigbee message from 'legrand_switch_cagibi', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[5,33,16,0,9,41,55,196,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665433858361,"linkquality":61,"voltage":2900}'
debug 2022-10-10 22:30:58: Received Zigbee message from 'legrand_switch_cagibi', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665433858438,"linkquality":65,"voltage":2900}'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665433858438,"linkquality":65,"voltage":2900}'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665433858667,"linkquality":65,"voltage":2900}'
debug 2022-10-10 22:30:58: Device 'legrand_switch_cagibi' announced itself
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cagibi","ieee_address":"0x0004740000c43729"},"type":"device_announce"}'
debug 2022-10-10 22:31:00: Received Zigbee message from 'legrand_switch_cagibi', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
info  2022-10-10 22:31:00: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665433860135,"linkquality":94,"voltage":2900}'
info  2022-10-10 22:31:00: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665433860135,"linkquality":94,"voltage":2900}'
info  2022-10-10 22:31:00: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
debug 2022-10-10 22:31:00: Received Zigbee message from 'legrand_switch_cagibi', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[5,33,16,0,9,41,55,196,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-10 22:31:00: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665433860445,"linkquality":87,"voltage":2900}'
debug 2022-10-10 22:31:00: Retrieving state of 'legrand_switch_cagibi' after reconnect
debug 2022-10-10 22:31:09: Received Zigbee message from 'legrand_switch_cagibi', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,2,5,41,55,196,0,0,116,4,0],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-10 22:31:09: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665433869643,"linkquality":94,"voltage":2900}'

All logs in the attached file log.txt

celestianx commented 1 year ago

Hi Koenkk, Thank you for your support. I had already fixed it and was testing it since yesterday in a likely manner and was testing it since yesterday. Works perfectly. Not knowing about zigbee protocol and zclTransactionSequenceNumber, I followed an approach where I was providing an id on a timestamp to the transaction store of the hasAlreadyProcessedMessage method; From your experience, in what cases, a device sends multiple commands with the same transaction number? If there is non in the case of a light switch, then your fix is better!

Overall, while it fixes the commandToggle, this behaviour potentially impacts the command move up, down (the stop should be ok as it comes after a move up or down)
command_toggle: {
        cluster: 'genOnOff',
        type: 'commandToggle',
        convert: (model, msg, publish, options, meta) => {
            const id =  (new Date().getTime()/1000).toString()
            if (utils.hasAlreadyProcessedMessage(msg, id)) return;
            const payload = {action: utils.postfixWithEndpointName('toggle', msg, model, meta)};
            utils.addActionGroup(payload, msg, model);
            return payload;
        },
    },

@Koenkk : did you get a chance to think about my questions? Thanks!

Koenkk commented 1 year ago

@jiquem yes to confirm, in your log this appears after pressing the button just once?

debug 2022-10-10 22:30:58: Received Zigbee message from 'legrand_switch_cagibi', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665433858438,"linkquality":65,"voltage":2900}'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665433858438,"linkquality":65,"voltage":2900}'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665433858667,"linkquality":65,"voltage":2900}'
debug 2022-10-10 22:30:58: Device 'legrand_switch_cagibi' announced itself
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cagibi","ieee_address":"0x0004740000c43729"},"type":"device_announce"}'
debug 2022-10-10 22:31:00: Received Zigbee message from 'legrand_switch_cagibi', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0

@celestianx I need to check the case of @jiquem first; seems in this case multiple messages are send and now also published to MQTT because we don't do the sequenceNumber check anymore.

jiquem commented 1 year ago

Hello Koenkk,

Thanks for your support ! I confirm that it appears after pressing the button just once.

jiquem commented 1 year ago

Here, I have 11 seconds between all messages related to one single push on the button.

info  2022-10-11 19:52:55: MQTT publish: topic 'zigbee2mqtt/legrand_switch_naomi', payload '{"action":null,"battery":80,"last_seen":1665510775228,"linkquality":105,"voltage":2900}'
info  2022-10-11 19:52:55: MQTT publish: topic 'zigbee2mqtt/legrand_switch_naomi', payload '{"action":"toggle","battery":80,"last_seen":1665510775319,"linkquality":109,"voltage":2900}'
info  2022-10-11 19:52:55: MQTT publish: topic 'zigbee2mqtt/legrand_switch_naomi', payload '{"action":"","battery":80,"last_seen":1665510775319,"linkquality":109,"voltage":2900}'
info  2022-10-11 19:52:55: MQTT publish: topic 'zigbee2mqtt/legrand_switch_naomi/action', payload 'toggle'
info  2022-10-11 19:52:55: MQTT publish: topic 'zigbee2mqtt/legrand_switch_naomi', payload '{"action":null,"battery":80,"last_seen":1665510775551,"linkquality":109,"voltage":2900}'
info  2022-10-11 19:52:55: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_naomi","ieee_address":"0x0004740000c43721"},"type":"device_announce"}'
info  2022-10-11 19:52:57: MQTT publish: topic 'zigbee2mqtt/legrand_switch_naomi', payload '{"action":null,"battery":80,"last_seen":1665510777069,"linkquality":105,"voltage":2900}'
info  2022-10-11 19:53:06: MQTT publish: topic 'zigbee2mqtt/legrand_switch_naomi', payload '{"action":null,"battery":80,"last_seen":1665510786275,"linkquality":102,"voltage":2900}'

Here a few elements regarding my setup

Total 53
By device type
Router: 31
End devices: 22

By power source
Mains (single phase): 31
Battery: 22

By vendor
Signify Netherlands B.V.: 21
Legrand: 19
Philips: 4
LEDVANCE: 3
LUMI: 3
IKEA of Sweden: 2
LiXee: 1

By model
Remote switch: 16
LTW013: 6
LCT010: 4
LCG002: 4
LEDVANCE DIM: 3
LWB010: 3
LCT012: 3
Connected outlet: 2
TRADFRI remote control: 2
LCA004: 2
ZLinky_TIC: 1
lumi.sensor_magnet.aq2: 1
Double gangs remote switch: 1
lumi.remote.b686opcn01: 1
lumi.remote.b1acn01: 1
LST002: 1
LCA001: 1
LCT015: 1

celestianx commented 1 year ago

@jiquem yes to confirm, in your log this appears after pressing the button just once?

debug 2022-10-10 22:30:58: Received Zigbee message from 'legrand_switch_cagibi', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665433858438,"linkquality":65,"voltage":2900}'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665433858438,"linkquality":65,"voltage":2900}'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665433858667,"linkquality":65,"voltage":2900}'
debug 2022-10-10 22:30:58: Device 'legrand_switch_cagibi' announced itself
info  2022-10-10 22:30:58: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cagibi","ieee_address":"0x0004740000c43729"},"type":"device_announce"}'
debug 2022-10-10 22:31:00: Received Zigbee message from 'legrand_switch_cagibi', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0

@celestianx I need to check the case of @jiquem first; seems in this case multiple messages are send and now also published to MQTT because we don't do the sequenceNumber check anymore.

Oh I see! Did not realize that because I don't have this issue. As I have added the timestamp of the message as a sequence number for the transaction store and the HasAlreadyProcessedMessage()

While this may not be the definitive fix, @jiquem, if you replace the function by this, do you still have duplicate message?:

command_toggle: {
        cluster: 'genOnOff',
        type: 'commandToggle',
        convert: (model, msg, publish, options, meta) => {
            const id =  (new Date().getTime()/1000).toString()
            if (utils.hasAlreadyProcessedMessage(msg, id)) return;
            const payload = {action: utils.postfixWithEndpointName('toggle', msg, model, meta)};
            utils.addActionGroup(payload, msg, model);
            return payload;
        },
    },

jiquem commented 1 year ago

@celestianx, here is what I've got after modifying the code and pushing 2 times a switch

info  2022-10-11 22:41:55: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665520915033,"linkquality":102,"voltage":2900}'
info  2022-10-11 22:41:55: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665520915338,"linkquality":58,"voltage":2900}'
info  2022-10-11 22:41:56: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665520916342,"linkquality":58,"voltage":2900}'
info  2022-10-11 22:41:56: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cagibi","ieee_address":"0x0004740000c43729"},"type":"device_announce"}'
info  2022-10-11 22:41:56: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665520916342,"linkquality":58,"voltage":2900}'
info  2022-10-11 22:41:56: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665520916342,"linkquality":58,"voltage":2900}'
info  2022-10-11 22:41:56: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-11 22:42:02: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665520922898,"linkquality":58,"voltage":2900}'
info  2022-10-11 22:42:02: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665520922898,"linkquality":58,"voltage":2900}'
info  2022-10-11 22:42:02: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-11 22:42:04: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665520924985,"linkquality":58,"voltage":2900}'

celestianx commented 1 year ago

Ok. At this point, I cannot understand why you would have a different behaviour from mine.

Can you share the detailed information about your switch? Model and firmware version?
If you go back to the original configuration (i.e. w/o the extender), what do you observe?

@Koenkk any idea?

jiquem commented 1 year ago

My switch is the 067773 in version 71 (I've updated all firmwares last Saturday) Here is what I've got just after removing the extender

info  2022-10-13 22:58:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665694738043,"linkquality":61,"voltage":2900}'
info  2022-10-13 22:58:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665694738128,"linkquality":61,"voltage":2900}'
info  2022-10-13 22:58:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665694738128,"linkquality":61,"voltage":2900}'
info  2022-10-13 22:58:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-13 22:58:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665694738488,"linkquality":61,"voltage":2900}'
info  2022-10-13 22:58:58: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cagibi","ieee_address":"0x0004740000c43729"},"type":"device_announce"}'
info  2022-10-13 22:59:04: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1665694744088,"linkquality":94,"voltage":2900}'
info  2022-10-13 22:59:04: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1665694744088,"linkquality":94,"voltage":2900}'
info  2022-10-13 22:59:04: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-13 22:59:07: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1665694747068,"linkquality":98,"voltage":2900}'

Differences are maybe linked to others elements of my setup ?

celestianx commented 1 year ago

Is this all the messages sent after a single press?

jiquem commented 1 year ago

Yes, juste after one press

celestianx commented 1 year ago

What I would recommend is to put log level in "debug". With that level, you see what messages z2m receives from the zigbee receiver.

If you receive multiple messages for some unknown reason, then it makes sens you have that many.
If you receive one, but z2m sends multiple, the problem is within z2m

With the base converter, this is what I get upon a single press:

Debug 2022-10-16 20:37:08Received Zigbee message from 'Interrupteur Dégagement (Gauche)', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Info 2022-10-16 20:37:08MQTT publish: topic 'zigbee2mqtt/Interrupteur Dégagement (Gauche)', payload '{"action":"toggle","battery":80,"linkquality":83,"voltage":2900}'
Info 2022-10-16 20:37:08MQTT publish: topic 'zigbee2mqtt/Interrupteur Dégagement (Gauche)/action', payload 'toggle'
Debug 2022-10-16 20:37:08Device 'Interrupteur Dégagement (Gauche)' announced itself
Info 2022-10-16 20:37:08MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"Interrupteur Dégagement (Gauche)","ieee_address":"0x000474000099df44"},"type":"device_announce"}'
Debug 2022-10-16 20:37:09Received Zigbee message from 'Interrupteur Dégagement (Gauche)', type 'readResponse', cluster 'genPowerCfg', data '{"batteryVoltage":27}' from endpoint 1 with groupID 0
Info 2022-10-16 20:37:09MQTT publish: topic 'zigbee2mqtt/Interrupteur Dégagement (Gauche)', payload '{"battery":40,"linkquality":83,"voltage":2700}'

By the way, z2m displays: Firmware build date: 20180730 Firmware version: 003c

jiquem commented 1 year ago

It seems you are French too ;) I will activate the debug, and let you know by tomorrow evening.

celestianx commented 1 year ago

Anyone who uses Legrand devices are likely to be french I guess ;o) @Koenkk : do you have any advice for jiquem? I am trying to help but I just got recently into the game ;o)

celestianx commented 1 year ago

One thing you may look at, this may also be one reason:

jiquem commented 1 year ago

I've set this parameter. Here is the output after one single push

info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1666018361332,"linkquality":58,"voltage":2900}'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1666018361333,"linkquality":58,"voltage":2900}'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1666018361536,"linkquality":193,"voltage":2900}'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1666018361580,"linkquality":189,"voltage":2900}'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1666018361580,"linkquality":189,"voltage":2900}'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1666018361580,"linkquality":189,"voltage":2900}'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1666018361873,"linkquality":189,"voltage":2900}'
info  2022-10-17 16:52:41: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_cagibi","ieee_address":"0x0004740000c43729"},"type":"device_announce"}'
info  2022-10-17 16:52:43: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"toggle","battery":80,"last_seen":1666018363203,"linkquality":189,"voltage":2900}'
info  2022-10-17 16:52:43: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1666018363203,"linkquality":189,"voltage":2900}'
info  2022-10-17 16:52:43: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":"","battery":80,"last_seen":1666018363203,"linkquality":189,"voltage":2900}'
info  2022-10-17 16:52:43: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-17 16:52:43: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi/action', payload 'toggle'
info  2022-10-17 16:52:43: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1666018363501,"linkquality":193,"voltage":2900}'
info  2022-10-17 16:52:52: MQTT publish: topic 'zigbee2mqtt/legrand_switch_cagibi', payload '{"action":null,"battery":80,"last_seen":1666018372780,"linkquality":193,"voltage":2900}'

FYI, I added some routers and end devices this weekend. I now have 42 routers and 30 end devices

jiquem commented 1 year ago

FYI, the double switch 067774 has the same behavior

I adapted the previous code, but it doesn't work. @celestianx and @Koenkk, do you have any idea regarding the mistakes I made please ?

const legrand = require('zigbee-herdsman-converters/devices/legrand');
const fz = require('zigbee-herdsman-converters/converters/fromZigbee');
const tz = require('zigbee-herdsman-converters/converters/toZigbee');
const exposes = require('zigbee-herdsman-converters/lib/exposes');
const reporting = require('zigbee-herdsman-converters/lib/reporting');
const extend = require('zigbee-herdsman-converters/lib/extend');
const ota = require('zigbee-herdsman-converters/lib/ota');
const tuya = require('zigbee-herdsman-converters/lib/tuya');
const utils = require('zigbee-herdsman-converters/lib/utils');
const e = exposes.presets;
const ea = exposes.access;

const fzLocal = {
    command_toggle: {
            cluster: 'genOnOff',
            type: 'commandToggle',
            convert: (model, msg, publish, options, meta) => {
                const id =  (new Date().getTime()/1000).toString()
                if (utils.hasAlreadyProcessedMessage(msg, id)) return;
                const payload = {action: utils.postfixWithEndpointName('toggle', msg, model, meta)};
                utils.addActionGroup(payload, msg, model);
                return payload;
            },
    },
};

const definition = {
    zigbeeModel: [
        ' Double remote switch\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000'],
    model: '067774',
    vendor: 'Legrand',
    // led blink RED when battery is low
    description: 'Wireless double remote switch',
    fromZigbee: [fz.identify, fz.command_on, fz.command_off, fzLocal.command_toggle, fz.command_move, fz.command_stop,
        fz.battery],
    exposes: [e.battery(), e.action(['identify', 'on', 'off', 'toggle_left', 'toggle_right', 'brightness_move_up',
        'brightness_move_down', 'brightness_stop'])],
    toZigbee: [],
    meta: {battery: {voltageToPercentage: '3V_2500'}},
    configure: async (device, coordinatorEndpoint, logger) => {
        const endpoint = device.getEndpoint(1);
        await reporting.bind(endpoint, coordinatorEndpoint, ['genPowerCfg', 'genOnOff', 'genLevelCtrl']);
    },
    onEvent: legrand.readInitialBatteryState,
};

module.exports = definition;

celestianx commented 1 year ago

Hi, not sure I understood what you did last :) @Koenkk any ideas?

Koenkk commented 1 year ago

I'm not sure what we can do here, I don't see how we can reliable determine whether an action is a duplicate or (since the transaction sequence number part is bugged)

jiquem commented 1 year ago

@Koenkk you provided a working solution for the single switch, I « just » would like to do the same for the « double » switch : any help would be much appreciated !

Koenkk commented 1 year ago

@celestianx does https://github.com/Koenkk/zigbee2mqtt/issues/14256#issuecomment-1272303031 also work for you?

celestianx commented 1 year ago

Hi both! In a nutshell, @Koenkk : yes, it solves it. I don't know if Legrand's transaction sequence number part is bugged or whether the use we make of it in z2m is not compatible. Just a quick recap. Initial issue was for me that some events were not propagated by z2m because of:

 if (hasAlreadyProcessedMessage(msg)) return;`

This function uses the last transaction sequence number sent but the way Legrand implements it is through a counter from 1:N. This counter resets after a few seconds of inactivity of the switch. In the case a switch is pressed once and stores "1" as last transaction number, the next press after a few seconds of inactivity would send "1" and z2m would consider it as already processed due to the way the hasAlreadyProcessedMessage works.

For me it was solved either by @Koenkk suggestion or mine:

Entirely remove it
Create a transaction number based on a timestamp because I did not know what I could break if I entirely removed it:
```
const id =  (new Date().getTime()/1000).toString()
if (utils.hasAlreadyProcessedMessage(msg, id)) return;
```
Then we moved on to what I had understood as being another issue of @jiquem which duplicated messages which does not occur on my side and I thought this was the ongoing discussion.

One last thing on battery state: I have also remarked something which is another topic of its own. On each event, z2m requests for battery state but battery state is contained in each response so I feel we are unnecessarily querying a battery powered device but I haven't dwelled into how I could leverage switch response to emit an additional battery state to HA, @Koenkk if you have any suggestion! Also, the battery level reported does not seem to be accurate but it seems that the way to compute battery level for this kind of battery is hard.

celestianx commented 1 year ago

My custom extender for all my switches 067773, 067774, 412170: I have also taken the initiative to remove the manuSpecificUbisysDimmerSetup with an empty return message. I don't know either why the switch emits it systematically as Ubisys is another vendor.

const fz = {...require('zigbee-herdsman-converters/converters/fromZigbee'), legacy: require('zigbee-herdsman-converters/lib/legacy').fromZigbee};
const tz = require('zigbee-herdsman-converters/converters/toZigbee');
const exposes = require('zigbee-herdsman-converters/lib/exposes');
const reporting = require('zigbee-herdsman-converters/lib/reporting');
const extend = require('zigbee-herdsman-converters/lib/extend');
const utils = require('zigbee-herdsman-converters/lib/utils');
const e = exposes.presets;
const ea = exposes.access;

const readInitialBatteryState = async (type, data, device) => {
    if (['deviceAnnounce'].includes(type)) {
        const endpoint = device.getEndpoint(1);
        const options = {manufacturerCode: 0x1021, disableDefaultResponse: true};
        await endpoint.read('genPowerCfg', ['batteryVoltage'], options);
    }
};

const fzLocal = {
    command_off: {
        cluster: 'genOnOff',
        type: 'commandOff',
        convert: (model, msg, publish, options, meta) => {
            const id =  (new Date().getTime()/1000).toString()
            if (utils.hasAlreadyProcessedMessage(msg, id)) return;
            const payload = {action: utils.postfixWithEndpointName('off', msg, model, meta)};
            utils.addActionGroup(payload, msg, model);
            return payload;
        },
    },
    on_off: {
        cluster: 'genOnOff',
        type: ['attributeReport', 'readResponse'],
        convert: (model, msg, publish, options, meta) => {
            if (msg.data.hasOwnProperty('onOff')) {
                const property = utils.postfixWithEndpointName('state', msg, model, meta);
                return {[property]: msg.data['onOff'] === 1 ? 'ON' : 'OFF'};
            }
        },
    },
    command_toggle: {
        cluster: 'genOnOff',
        type: 'commandToggle',
        convert: (model, msg, publish, options, meta) => {
            const id =  (new Date().getTime()/1000).toString()
            if (utils.hasAlreadyProcessedMessage(msg, id)) return;
            const payload = {action: utils.postfixWithEndpointName('toggle', msg, model, meta)};
            utils.addActionGroup(payload, msg, model);
            return payload;
        },
    },
    command_move: {
        cluster: 'genLevelCtrl',
        type: ['commandMove', 'commandMoveWithOnOff'],
        options: [exposes.options.simulated_brightness()],
        convert: (model, msg, publish, options, meta) => {
            const id = JSON.stringify(new Date().getTime()/1000)
            if (utils.hasAlreadyProcessedMessage(msg, id)) return;
            const direction = msg.data.movemode === 1 ? 'down' : 'up';
            const action = utils.postfixWithEndpointName(`brightness_move_${direction}`, msg, model, meta);
            const payload = {action, action_rate: msg.data.rate};
            utils.addActionGroup(payload, msg, model);

            if (options.simulated_brightness) {
                const opts = options.simulated_brightness;
                const deltaOpts = typeof opts === 'object' && opts.hasOwnProperty('delta') ? opts.delta : 20;
                const intervalOpts = typeof opts === 'object' && opts.hasOwnProperty('interval') ? opts.interval : 200;

                globalStore.putValue(msg.endpoint, 'simulated_brightness_direction', direction);
                if (globalStore.getValue(msg.endpoint, 'simulated_brightness_timer') === undefined) {
                    const timer = setInterval(() => {
                        let brightness = globalStore.getValue(msg.endpoint, 'simulated_brightness_brightness', 255);
                        const delta = globalStore.getValue(msg.endpoint, 'simulated_brightness_direction') === 'up' ?
                            deltaOpts : -1 * deltaOpts;
                        brightness += delta;
                        brightness = utils.numberWithinRange(brightness, 0, 255);
                        globalStore.putValue(msg.endpoint, 'simulated_brightness_brightness', brightness);
                        const property = utils.postfixWithEndpointName('brightness', msg, model, meta);
                        publish({[property]: brightness});
                    }, intervalOpts);

                    globalStore.putValue(msg.endpoint, 'simulated_brightness_timer', timer);
                }
            }

            return payload;
        },
    },
    command_stop: {
        cluster: 'genLevelCtrl',
        type: ['commandStop', 'commandStopWithOnOff'],
        options: [exposes.options.simulated_brightness()],
        convert: (model, msg, publish, options, meta) => {
            if (utils.hasAlreadyProcessedMessage(msg)) return;
            if (options.simulated_brightness) {
                clearInterval(globalStore.getValue(msg.endpoint, 'simulated_brightness_timer'));
                globalStore.putValue(msg.endpoint, 'simulated_brightness_timer', undefined);
            }
            const payload = {action: utils.postfixWithEndpointName(`brightness_stop`, msg, model, meta)};
            utils.addActionGroup(payload, msg, model);
            return payload;
        },
    },
    dimmer_setup: {
        cluster: 'manuSpecificUbisysDimmerSetup',
        type: 'raw',
        convert: (model, msg, publish, options, meta) => {
            return;
        },
    }
};

module.exports = [
    {
        zigbeeModel: [
            ' Remote switch\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000'],
        model: '067773',
        vendor: 'Legrand',
        // led blink RED when battery is low
        description: 'Wireless remote switch CUSTOM',
        fromZigbee: [fz.identify, fzLocal.command_toggle, fzLocal.command_move, fzLocal.command_stop, fz.battery, fzLocal.dimmer_setup],
        exposes: [e.battery(), e.action(['identify', 'on', 'off', 'toggle', 'brightness_move_up',
            'brightness_move_down', 'brightness_stop'])],
        toZigbee: [],
        meta: {battery: {voltageToPercentage: '3V_2500'}},
        configure: async (device, coordinatorEndpoint, logger) => {
            const endpoint = device.getEndpoint(1);
            await reporting.bind(endpoint, coordinatorEndpoint, ['genPowerCfg', 'genOnOff', 'genLevelCtrl']);
        },
        onEvent: readInitialBatteryState,
    },
    {
        zigbeeModel: [' Double gangs remote switch\u0000\u0000\u0000\u0000'],
        model: '067774',
        vendor: 'Legrand',
        description: 'Wireless double remote switch CUSTOM',
        fromZigbee: [fz.identify, fz.command_on, fzLocal.command_off, fzLocal.command_toggle, fzLocal.command_move, fzLocal.command_stop, fz.battery, fzLocal.dimmer_setup],
        exposes: [e.battery(),
            e.action(['identify', 'on', 'off', 'toggle', 'brightness_move_up', 'brightness_move_down', 'brightness_stop'])],
        toZigbee: [],
        meta: {multiEndpoint: true, battery: {voltageToPercentage: '3V_2500'}},
        configure: async (device, coordinatorEndpoint, logger) => {
            const endpoint = device.getEndpoint(1);
            await reporting.bind(endpoint, coordinatorEndpoint, ['genPowerCfg', 'genOnOff', 'genLevelCtrl']);
            const endpoint2 = device.getEndpoint(2);
            await reporting.bind(endpoint2, coordinatorEndpoint, ['genOnOff', 'genLevelCtrl']);
        },
        endpoint: (device) => {
            return {left: 1, right: 2};
        },
        onEvent: readInitialBatteryState,
    },
    {
        zigbeeModel: [' Teleruptor\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000'+
            '\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000'],
        model: '412170',
        description: 'DIN smart relay for light control ( Bticino FC80RC ) CUSTOM',
        vendor: 'Legrand',
        extend: extend.switch(),
        fromZigbee: [fz.identify, fzLocal.on_off, fz.electrical_measurement, fz.legrand_cluster_fc01, fz.ignore_basic_report, fz.ignore_genOta],
        toZigbee: [tz.legrand_deviceMode, tz.on_off, tz.legrand_identify, tz.electrical_measurement_power],
        exposes: [exposes.switch().withState('state', true, 'On/off (works only if device is in "switch" mode)'),
            e.power().withAccess(ea.STATE_GET), exposes.enum('device_mode', ea.ALL, ['switch', 'auto'])
                .withDescription('switch: allow on/off, auto will use wired action via C1/C2 on teleruptor with buttons')],
        configure: async (device, coordinatorEndpoint, logger) => {
            const endpoint = device.getEndpoint(1);
            await reporting.bind(endpoint, coordinatorEndpoint, ['genIdentify', 'genOnOff', 'haElectricalMeasurement']);
            await reporting.onOff(endpoint);
            await reporting.readEletricalMeasurementMultiplierDivisors(endpoint);
            await reporting.activePower(endpoint);
        },
    }
];

jiquem commented 1 year ago

Thanks @celestianx, I will try your extender beginning of next week and let you know if it works for me as well. And last but not least, I will read it to understood precisely what you did !

Koenkk commented 1 year ago

On each event, z2m requests for battery state but battery state is contained in each response so I feel we are unnecessarily querying a battery powered device but I haven't dwelled into how I could leverage switch response to emit an additional battery state to HA, @Koenkk if you have any suggestion!

Fixed this!

Regarding the actions, fixed this for both the 067773 and 067774.

Please test if it works correctly without using any external converter in the latest dev branch.

Changes will be available in the dev branch in a few hours from now. (https://www.zigbee2mqtt.io/advanced/more/switch-to-dev-branch.html)

celestianx commented 1 year ago

Thanks @Koenkk. Will test it when I get back home next week. Meanwhile: While I only started to get in the source code for this issue and does not have a full perspective on how everything works, two questions:

Is removing entirely the onEvent the right approach? Because then, we don't read it at all anymore. It is self-contained in the payload returned on each event but not sure z2m interprets it as of today.
Is there any reason you did not add the command_move or command_stop? My reasoning would be these have the hasAlreadyProcessedMessage(msg) as well. For the command_stop, I don't think this would cause an issue as it follows another command but for the command_move, it can;

Koenkk commented 1 year ago

Is removing entirely the onEvent the right approach? Because then, we don't read it at all anymore. It is self-contained in the payload returned on each event but not sure z2m interprets it as of today.

It is not needed to read it all the time, the device should report the values itself.

Is there any reason you did not add the command_move or command_stop? My reasoning would be these have the hasAlreadyProcessedMessage(msg) as well. For the command_stop, I don't think this would cause an issue as it follows another command but for the command_move, it can;

I assumed that with the external converter I posted all actions were working, is that not the case? (does the problem still occur with action stop/move?)

jiquem commented 1 year ago

Hello @Koenkk I manage to test the edge version on HA : it's working. However, I noticed a 2-3 seconds delay between the moment I press the switch and the "toggle" action is performed. It's seems that this delay is longer on double switch (067774) than on single (067773)

Debug log on double switch (067774)

debug 2022-10-30 22:20:36: Received Zigbee message from 'legrand_switch_double_escalier_bas_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,0,9,26,55,185,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-30 22:20:36: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1', payload '{"action":null,"battery":60,"last_seen":1667164836416,"linkquality":47,"voltage":2800}'
debug 2022-10-30 22:20:36: Received Zigbee message from 'legrand_switch_double_escalier_bas_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,1,9,26,55,185,0,0,116,4,0,2],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-30 22:20:36: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1', payload '{"action":null,"battery":60,"last_seen":1667164836445,"linkquality":43,"voltage":2800}'
info  2022-10-30 22:20:36: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1', payload '{"action":null,"battery":60,"last_seen":1667164836755,"linkquality":43,"voltage":2800}'
debug 2022-10-30 22:20:36: Device 'legrand_switch_double_escalier_bas_1' announced itself
info  2022-10-30 22:20:36: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_double_escalier_bas_1","ieee_address":"0x0004740000b9371a"},"type":"device_announce"}'
debug 2022-10-30 22:20:38: Received Zigbee message from 'legrand_switch_double_escalier_bas_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,0,9,26,55,185,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-30 22:20:38: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1', payload '{"action":null,"battery":60,"last_seen":1667164838180,"linkquality":51,"voltage":2800}'
debug 2022-10-30 22:20:38: Received Zigbee message from 'legrand_switch_double_escalier_bas_1', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 2 with groupID 0
info  2022-10-30 22:20:38: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1', payload '{"action":"toggle_right","battery":60,"last_seen":1667164838564,"linkquality":51,"voltage":2800}'
info  2022-10-30 22:20:38: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1', payload '{"action":"","battery":60,"last_seen":1667164838564,"linkquality":51,"voltage":2800}'
info  2022-10-30 22:20:38: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1/action', payload 'toggle_right'
debug 2022-10-30 22:20:38: Received Zigbee message from 'legrand_switch_double_escalier_bas_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,1,9,26,55,185,0,0,116,4,0,2],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-30 22:20:38: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_escalier_bas_1', payload '{"action":null,"battery":60,"last_seen":1667164838700,"linkquality":51,"voltage":2800}'
debug 2022-10-30 22:20:38: Retrieving state of 'legrand_switch_double_escalier_bas_1' after reconnect

Debug log on single switch (067773)

debug 2022-10-30 22:26:24: Received Zigbee message from 'legrand_switch_entree_cles_3', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[5,33,16,0,9,43,198,174,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":null,"battery":80,"last_seen":1667165184559,"linkquality":83,"voltage":2900}'
debug 2022-10-30 22:26:24: Device 'legrand_switch_entree_cles_3' reconnected
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3/availability', payload '{"state":"online"}'
debug 2022-10-30 22:26:24: Received Zigbee message from 'legrand_switch_entree_cles_3', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":"toggle","battery":80,"last_seen":1667165184661,"linkquality":83,"voltage":2900}'
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":"","battery":80,"last_seen":1667165184661,"linkquality":83,"voltage":2900}'
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3/action', payload 'toggle'
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":null,"battery":80,"last_seen":1667165184855,"linkquality":83,"voltage":2900}'
debug 2022-10-30 22:26:24: Device 'legrand_switch_entree_cles_3' announced itself
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_entree_cles_3","ieee_address":"0x0004740000aec62b"},"type":"device_announce"}'
debug 2022-10-30 22:26:26: Retrieving state of 'legrand_switch_entree_cles_3' after reconnect
debug 2022-10-30 22:26:33: Received Zigbee message from 'legrand_switch_entree_cles_3', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,2,5,43,198,174,0,0,116,4,0],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-10-30 22:26:33: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":null,"battery":80,"last_seen":1667165193574,"linkquality":87,"voltage":2900}'

celestianx commented 1 year ago

It is not needed to read it all the time, the device should report the values itself. Fully agree! I think I misled you with my own misunderstanding of things worked taking a look again with jiquem's logs. The switch is not sending proactively the battery level: z2m reads it on each device_announce, then z2m sends it in every message as part of its payload.

The battery-less switches from Legrand seems to have a behaviour where they would need to announce themselves even after a couple of seconds of inactivity - which seems like overkill to me as querying the battery once a day or so would avoid stressing the switch battery. We could put in place a mechanism which only does it by storing the last time the battery was read, but it's likely to be overkill as you are most likely to press the switch a couple of times a day. I thought about this when I was making some tests and as the battery level reported seems to be incorrect, I told myself this could be an optimisation. All in all, I think it's better to revert back to what it was (apologies!)

Is there any reason you did not add the command_move or command_stop? My reasoning would be these have the hasAlreadyProcessedMessage(msg) as well. For the command_stop, I don't think this would cause an issue as it follows another command but for the command_move, it can;

I assumed you had read my code :) I have remarked 2 things about the existing code:

fromZigbee: [fz.identify, fz.command_on, fzLocal.command_off, fz.command_toggle, fz.legacy.cmd_move, fz.legacy.cmd_stop,
fromZigbee: [fz.identify, fz.command_on, fzLocal.command_off, fzLocal.command_toggle, fz.legacy.cmd_move, fz.legacy.cmd_stop,

Why would the 067773 be using fz.legacy while the 067774 is not? Thus, I had moved from fz.legacy.cmd_move and cmd_stop to fz.command_move and fz.command_stop and it works perfectly on my side. Would you know if there is any reason?
In both command_move and command_stop, there is occurrences of
```
if (utils.hasAlreadyProcessedMessage(msg, id)) return;
```
So I had assumed, there should be removed as well based on my understanding:
I switch on the light after a couple of time, the switch sends a tsn "1"
After a couple of time, I want to dim-up or down, I do a long press up or down, the switch will send a tsn "1" (behaviour described earlier) and thus it will not take into account the dimming. For command_stop it's unlikely to happen as it comes straight after a command_move so I would assume the tsn is always incremented

celestianx commented 1 year ago

Hello @Koenkk I manage to test the edge version on HA : it's working. However, I noticed a 2-3 seconds delay between the moment I press the switch and the "toggle" action is performed. It's seems that this delay is longer on double switch (067774) than on single (067773)

Two questions for you:

When you revert back to the original code, you don't observe this 1-2s delay?
How do you bind the devices? In z2m or through HA automations?

We do see that z2m is sending twice the messages which is actually strange @Koenkk is my understanding from the logs is correct?:

info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":"toggle","battery":80,"last_seen":1667165184661,"linkquality":83,"voltage":2900}'
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":"","battery":80,"last_seen":1667165184661,"linkquality":83,"voltage":2900}'
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3/action', payload 'toggle'
info  2022-10-30 22:26:24: MQTT publish: topic 'zigbee2mqtt/legrand_switch_entree_cles_3', payload '{"action":null,"battery":80,"last_seen":1667165184855,"linkquality":83,"voltage":2900}'

Koenkk commented 1 year ago

@jiquem the Received Zigbee message from is immediately followed by the MQTT publish so the delay is either in your network or the device itself (can be checked by sniffing: https://www.zigbee2mqtt.io/advanced/zigbee/04_sniff_zigbee_traffic.html#with-cc2531)

@celestianx

I thought about this when I was making some tests and as the battery level reported seems to be incorrect, I told myself this could be an optimisation.

What is incorrect?

So I had assumed, there should be removed as well based on my understanding:

Did that know!

Why would the 067773 be using fz.legacy while the 067774 is not? Thus, I had moved from fz.legacy.cmd_move and cmd_stop to fz.command_move and fz.command_stop and it works perfectly on my side. Would you know if there is any reason?

Because 067773 was added way before 067774, before these converters became legacy. They are kept in order to prevent breaking change for the 067773

Changes will be available in the dev branch in a few hours from now. (https://www.zigbee2mqtt.io/advanced/more/switch-to-dev-branch.html)

jiquem commented 1 year ago

Thanks both @Koenkk and @celestianx for your feedbacks. I will have inspect my network... but what is quite strange is that it's working without delay for single switch and not for double switch. Moreover, this evening, I noticed, that for double switch, I've got new "accepting joining" messages for double switch just after using them

0x0004740000b927da & legrand_switch_double_beajeanmi_entree_1 are the same devices legrand_switch_double_beajeanmi_entree_1 is part of my setup since many days.

➜  2022-10-30.11-37-59 egrep "0x0004740000b927da|legrand_switch_double_beajeanmi_entree_1" log.txt
info  2022-11-01 00:40:58: Accepting joining not in blocklist device '0x0004740000b927da'
info  2022-11-01 00:40:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259658328,"linkquality":65,"voltage":3000}'
debug 2022-11-01 00:40:58: Received Zigbee message from 'legrand_switch_double_beajeanmi_entree_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,0,9,218,39,185,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-11-01 00:40:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259658624,"linkquality":69,"voltage":3000}'
debug 2022-11-01 00:40:58: Received Zigbee message from 'legrand_switch_double_beajeanmi_entree_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,1,9,218,39,185,0,0,116,4,0,2],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-11-01 00:40:58: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259658650,"linkquality":69,"voltage":3000}'
info  2022-11-01 00:40:59: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259659072,"linkquality":69,"voltage":3000}'
debug 2022-11-01 00:40:59: Device 'legrand_switch_double_beajeanmi_entree_1' announced itself
info  2022-11-01 00:40:59: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_double_beajeanmi_entree_1","ieee_address":"0x0004740000b927da"},"type":"device_announce"}'
debug 2022-11-01 00:40:59: Received Zigbee message from 'legrand_switch_double_beajeanmi_entree_1', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
info  2022-11-01 00:40:59: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":"toggle_left","battery":100,"last_seen":1667259659251,"linkquality":21,"voltage":3000}'
info  2022-11-01 00:40:59: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":"","battery":100,"last_seen":1667259659251,"linkquality":21,"voltage":3000}'
info  2022-11-01 00:40:59: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1/action', payload 'toggle_left'
debug 2022-11-01 00:41:01: Retrieving state of 'legrand_switch_double_beajeanmi_entree_1' after reconnect
debug 2022-11-01 00:41:15: Received Zigbee message from 'legrand_switch_double_beajeanmi_entree_1', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 2 with groupID 0
info  2022-11-01 00:41:15: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":"toggle_right","battery":100,"last_seen":1667259675492,"linkquality":43,"voltage":3000}'
info  2022-11-01 00:41:15: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":"","battery":100,"last_seen":1667259675492,"linkquality":43,"voltage":3000}'
info  2022-11-01 00:41:15: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1/action', payload 'toggle_right'
info  2022-11-01 00:41:22: Accepting joining not in blocklist device '0x0004740000b927da'
info  2022-11-01 00:41:22: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259682661,"linkquality":43,"voltage":3000}'
debug 2022-11-01 00:41:22: Received Zigbee message from 'legrand_switch_double_beajeanmi_entree_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,0,9,218,39,185,0,0,116,4,0,1],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-11-01 00:41:22: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259682950,"linkquality":43,"voltage":3000}'
debug 2022-11-01 00:41:22: Received Zigbee message from 'legrand_switch_double_beajeanmi_entree_1', type 'raw', cluster 'manuSpecificUbisysDimmerSetup', data '{"data":[21,33,16,1,9,218,39,185,0,0,116,4,0,2],"type":"Buffer"}' from endpoint 1 with groupID 0
info  2022-11-01 00:41:22: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259682989,"linkquality":43,"voltage":3000}'
info  2022-11-01 00:41:23: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":null,"battery":100,"last_seen":1667259683303,"linkquality":43,"voltage":3000}'
debug 2022-11-01 00:41:23: Device 'legrand_switch_double_beajeanmi_entree_1' announced itself
info  2022-11-01 00:41:23: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"legrand_switch_double_beajeanmi_entree_1","ieee_address":"0x0004740000b927da"},"type":"device_announce"}'
debug 2022-11-01 00:41:23: Received Zigbee message from 'legrand_switch_double_beajeanmi_entree_1', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 2 with groupID 0
info  2022-11-01 00:41:23: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":"toggle_right","battery":100,"last_seen":1667259683439,"linkquality":43,"voltage":3000}'
info  2022-11-01 00:41:23: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1', payload '{"action":"","battery":100,"last_seen":1667259683439,"linkquality":43,"voltage":3000}'
info  2022-11-01 00:41:23: MQTT publish: topic 'zigbee2mqtt/legrand_switch_double_beajeanmi_entree_1/action', payload 'toggle_right'
debug 2022-11-01 00:41:25: Retrieving state of 'legrand_switch_double_beajeanmi_entree_1' after reconnect

celestianx commented 1 year ago

@Koenkk : thanks, let me test this and report what I observe practically. Since I am away until tomorrow For the battery, it does feel that way because I have a friend working at Legrand who tells me a switch is supposed to last 5 years. I don’t think that the official app. reports the battery level and I have read this is not easy to assess battery levels. What I did observe though ever since l switched to z2m:

Reported battery level are between 40% and 60% while I have been using them for 6 months
Sometimes the reported battery levels fluctuates back to 80% or 60% with no reason

@jiquem it does feel more like a setting you enabled in z2m. As for the delay, I have noticed it myself as well but it’s either the firmware and/or the quality of the network. By re-adding the switch and optimizingyour Zigbee network with repeaters/routers it should help

jiquem commented 1 year ago

@celestianx , thanks for your message, I have plenty of routers, that's why I don't believe it could be my network. I have :

End devices: 51
Router: 51

Regarding the z2m, appart the transmit power, I didn't change a single thing.

vmishurov commented 1 year ago

May I ask you one question :) In your examples I see - MQTT publish: topic 'zigbee2mqtt/legrand_switch_xxx/action', payload 'toggle_right' But I have so - MQTT publish: topic 'zigbee2mqtt/legrand_switch_yyy/action', payload 'on_right' or if you press the opposite button -'off_right' Device 067774 (firmware 0003 2019-03-20) Why do you have 'toggle' action and I have 'on' / 'off' ?

Tonio16 commented 1 year ago

May I ask you one question :) In your examples I see - MQTT publish: topic 'zigbee2mqtt/legrand_switch_xxx/action', payload 'toggle_right' But I have so - MQTT publish: topic 'zigbee2mqtt/legrand_switch_yyy/action', payload 'on_right' or if you press the opposite button -'off_right' Device 067774 (firmware 0003 2019-03-20) Why do you have 'toggle' action and I have 'on' / 'off' ?

It depends of the firmware.

Antoine