search

openhab / org.openhab.binding.zigbee

openHAB binding for ZigBee
Eclipse Public License 2.0
73 stars 111 forks source link

Add time extension support #791

Open cdjackson opened 1 year ago

cdjackson commented 1 year ago

This adds the ZigBeeTimeExtension support which should provide a time server that devices can interview to get the current system time.

This requires https://github.com/zsmartsystems/com.zsmartsystems.zigbee/pull/1371

@dschall you might like to give this a go to see if it resolves the issues you have with the Tuya device that keeps requesting the time. To build/run this, you will need to compile the SNAPSHOT of the library using the branch linked above to get the time support. I've not really done any testing on this as I've not got a device that currently requires this, so I welcome any feedback.

Signed-off-by: Chris Jackson chris@cd-jackson.com

dschall commented 1 year ago

Hey @cdjackson.

Thanks again for implementing this.

I cherry-picked your changes onto zigbee-3.3.0 and zsmartsystems-1.4.7, because that's what my test setup is on and dropped updated jars into the addons folder. I figured by cherry-picking I can avoid having to install tons of updated dependencies..

I think the update went well, but the new extension is throwing an error: Cannot add supported client cluster 000A when network state is ONLINE

I'm attaching the full log (during startup with the modified jars in place) and a shorter log with the what I think are interesting lines copied out in chronological order: full openhab.log highlights openhab.log

I could try upgading openhab to 3.4.1 (which is also using zsmartsystems-1.4.7) and retry the cherry-picking. Or do you have a guide how to safely upgrade zmartsystems to 1.4.10-SNAPSHOPT with your changes and automatically pulling in all the dependencies into OH3?

Thanks, Daniel

dschall commented 1 year ago

I realized the error Cannot add supported client cluster 000A when network state is ONLINE probably comes from the call in ZclTimeServer.java:

    protected ZclTimeServer(ZigBeeNetworkManager networkManager) {
        this.networkManager = networkManager;
        networkManager.addCommandListener(this);

        // Report that we support this cluster
        networkManager.addSupportedClientCluster(ZclTimeCluster.CLUSTER_ID);

But we do add the cluster already in ZigbeeTimeExtension::extensionInitialize, so it should be safe to remove above call to addSupportedClientCluster.

By the way, the Tuya device is asking for a server cluster: 2023-01-27 17:25:17.120 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Unsupported local server cluster 000A

So I changed the code in ZigbeeTimeExtension.java from client to server:

    public ZigBeeStatus extensionInitialize(ZigBeeNetworkManager networkManager) {
        this.networkManager = networkManager;
        networkManager.addSupportedServerCluster(ZclTimeCluster.CLUSTER_ID);
        ...

Now I'm getting farther (I think):

2023-02-03 11:13:45.189 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=000A, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=97], lastHopLqi=192, lastHopRssi=-52, sender=751D, bindingIndex=255, addressIndex=255, messageContents=00 02 00 07 00]
2023-02-03 11:13:45.189 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=751D/1, destinationAddress=0000/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=97, rssi=-52, lqi=C0, payload=00 02 00 07 00]
2023-02-03 11:13:45.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node update. NWK Address=NULL
2023-02-03 11:13:45.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node 751D is not updated from ZigBeeNode [state=ONLINE, IEEE=BC33ACFFFEEF6F95, NWK=----, endpoints=[]]
2023-02-03 11:13:45.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=02, commandId=0]
2023-02-03 11:13:45.191 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesCommand [Time: 751D/1 -> 0000/1, cluster=000A, TID=02, identifiers=[7]]
2023-02-03 11:13:45.191 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReadAttributesCommand [Time: 751D/1 -> 0000/1, cluster=000A, TID=02, identifiers=[7]] 
2023-02-03 11:13:45.192 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesResponse [Time: 0000/1 -> 751D/1, cluster=000A, TID=02, records=[ReadAttributeStatusRecord [status=null, attributeIdentifier=7]]]
2023-02-03 11:13:45.192 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - BC33ACFFFEEF6F95: Added transaction to queue, len=3, transaction=ZigBeeTransaction [ieeeAddress=BC33ACFFFEEF6F95 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesResponse [Time: 0000/0 -> 751D/1, cluster=000A, TID=02, records=[ReadAttributeStatusRecord [status=UNSUPPORTED_ATTRIBUTE, attributeIdentifier=7]]]]
2023-02-03 11:13:45.193 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=1/3
2023-02-03 11:13:45.193 [WARN ] [zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-2
java.lang.IllegalArgumentException: You cannot append null data to a stream
    at com.zsmartsystems.zigbee.serialization.DefaultSerializer.appendZigBeeType(DefaultSerializer.java:44) ~[?:?]
    at com.zsmartsystems.zigbee.zcl.field.ReadAttributeStatusRecord.serialize(ReadAttributeStatusRecord.java:118) ~[?:?]
    at com.zsmartsystems.zigbee.zcl.ZclFieldSerializer.serialize(ZclFieldSerializer.java:38) ~[?:?]
    at com.zsmartsystems.zigbee.zcl.clusters.general.ReadAttributesResponse.serialize(ReadAttributesResponse.java:109) ~[?:?]
    at com.zsmartsystems.zigbee.ZigBeeNetworkManager.sendCommand(ZigBeeNetworkManager.java:903) ~[?:?]
    at com.zsmartsystems.zigbee.app.time.ZclTimeServer.commandReceived(ZclTimeServer.java:218) ~[?:?]
    at com.zsmartsystems.zigbee.internal.ZigBeeCommandNotifier$1.run(ZigBeeCommandNotifier.java:66) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
    at java.lang.Thread.run(Thread.java:829) [?:?]

I'll keep working on it.

cdjackson commented 1 year ago

Thanks @dschall - sorry for not picking this up yesterday - it's been one of those weeks :(

But we do add the cluster already in ZigbeeTimeExtension::extensionInitialize, so it should be safe to remove above call to addSupportedClientCluster.

Agreed - much of this time code was actually written a couple of years back so I think this is probably a hangover from a change in concept wrt the lifecycle...

I'll keep working on it.

Thanks - much appreciated. Just shout if you have a question and I'll try and jump in...

dschall commented 1 year ago

sorry for not picking this up yesterday

No worries, your PR was sitting for over a month until I had time to take a look. I appreciate your work on this.

Even when changing the code to addSupportedServerCluster, it doesn't work, though.

First issue, we're getting a nullptr exception:

2023-02-03 11:13:45.189 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=000A, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=97], lastHopLqi=192, lastHopRssi=-52, sender=751D, bindingIndex=255, addressIndex=255, messageContents=00 02 00 07 00]
2023-02-03 11:13:45.189 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=751D/1, destinationAddress=0000/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=97, rssi=-52, lqi=C0, payload=00 02 00 07 00]
2023-02-03 11:13:45.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node update. NWK Address=NULL
2023-02-03 11:13:45.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node 751D is not updated from ZigBeeNode [state=ONLINE, IEEE=BC33ACFFFEEF6F95, NWK=----, endpoints=[]]
2023-02-03 11:13:45.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=02, commandId=0]
2023-02-03 11:13:45.191 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesCommand [Time: 751D/1 -> 0000/1, cluster=000A, TID=02, identifiers=[7]]
2023-02-03 11:13:45.191 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReadAttributesCommand [Time: 751D/1 -> 0000/1, cluster=000A, TID=02, identifiers=[7]] 
2023-02-03 11:13:45.192 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesResponse [Time: 0000/1 -> 751D/1, cluster=000A, TID=02, records=[ReadAttributeStatusRecord [status=null, attributeIdentifier=7]]]
2023-02-03 11:13:45.192 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - BC33ACFFFEEF6F95: Added transaction to queue, len=3, transaction=ZigBeeTransaction [ieeeAddress=BC33ACFFFEEF6F95 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesResponse [Time: 0000/0 -> 751D/1, cluster=000A, TID=02, records=[ReadAttributeStatusRecord [status=UNSUPPORTED_ATTRIBUTE, attributeIdentifier=7]]]]
2023-02-03 11:13:45.193 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=1/3
2023-02-03 11:13:45.193 [WARN ] [zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-2
java.lang.IllegalArgumentException: You cannot append null data to a stream
    at com.zsmartsystems.zigbee.serialization.DefaultSerializer.appendZigBeeType(DefaultSerializer.java:44) ~[?:?]
    at com.zsmartsystems.zigbee.zcl.field.ReadAttributeStatusRecord.serialize(ReadAttributeStatusRecord.java:118) ~[?:?]
    at com.zsmartsystems.zigbee.zcl.ZclFieldSerializer.serialize(ZclFieldSerializer.java:38) ~[?:?]
    at com.zsmartsystems.zigbee.zcl.clusters.general.ReadAttributesResponse.serialize(ReadAttributesResponse.java:109) ~[?:?]
    at com.zsmartsystems.zigbee.ZigBeeNetworkManager.sendCommand(ZigBeeNetworkManager.java:903) ~[?:?]
    at com.zsmartsystems.zigbee.app.time.ZclTimeServer.commandReceived(ZclTimeServer.java:218) ~[?:?]
    at com.zsmartsystems.zigbee.internal.ZigBeeCommandNotifier$1.run(ZigBeeCommandNotifier.java:66) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
    at java.lang.Thread.run(Thread.java:829) [?:?]

I was able to fix that by setting the status in ZclTimeServer::commandReceived:

record.setStatus(ZclStatus.SUCCESS);

Next, I believe we don't properly handle the request and send two responses. One inside ZclTimeServer, and one default response because the library didn't realize that we handled the request (?):

2023-02-03 13:01:29.106 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=000A, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=F4], lastHopLqi=184, lastHopRssi=-54, sender=751D, bindingIndex=255, addressIndex=255, messageContents=00 00 00 07 00]
2023-02-03 13:01:29.107 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=751D/1, destinationAddress=0000/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=F4, rssi=-54, lqi=B8, payload=00 00 00 07 00]
2023-02-03 13:01:29.107 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node update. NWK Address=NULL
2023-02-03 13:01:29.107 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node 751D is not updated from ZigBeeNode [state=ONLINE, IEEE=BC33ACFFFEEF6F95, NWK=----, endpoints=[]]
2023-02-03 13:01:29.108 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=00, commandId=0]
2023-02-03 13:01:29.108 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesCommand [Time: 751D/1 -> 0000/1, cluster=000A, TID=00, identifiers=[7]]
2023-02-03 13:01:29.108 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReadAttributesCommand [Time: 751D/1 -> 0000/1, cluster=000A, TID=00, identifiers=[7]] 
2023-02-03 13:01:29.109 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - BC33ACFFFEEF6F95: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=BC33ACFFFEEF6F95 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesResponse [Time: 0000/0 -> 751D/1, cluster=000A, TID=00, records=[ReadAttributeStatusRecord [status=UNSUPPORTED_ATTRIBUTE, attributeIdentifier=7]]]]
2023-02-03 13:01:29.109 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
2023-02-03 13:01:29.109 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesResponse [Time: 0000/1 -> 751D/1, cluster=000A, TID=00, records=[ReadAttributeStatusRecord [status=SUCCESS, attributeIdentifier=7, attributeDataType=UTCTIME, attributeValue=2023-02-03T13:01:29Z]]]
2023-02-03 13:01:29.109 [DEBUG] [transaction.ZigBeeTransactionManager] - 751D/1: Sending ZigBeeTransaction [ieeeAddress=BC33ACFFFEEF6F95 queueTime=1, state=WAITING, sendCnt=0, command=ReadAttributesResponse [Time: 0000/0 -> 751D/1, cluster=000A, TID=00, records=[ReadAttributeStatusRecord [status=UNSUPPORTED_ATTRIBUTE, attributeIdentifier=7]]]]
2023-02-03 13:01:29.110 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=00, commandId=1]
2023-02-03 13:01:29.110 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2023-02-03 13:01:29.110 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=751D/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=2A, rssi=--, lqi=--, payload=08 00 01 07 00 00 E2 A9 32 70 2B]
2023-02-03 13:01:29.110 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesResponse [Time: 0000/0 -> 751D/1, cluster=000A, TID=00, records=[ReadAttributeStatusRecord [status=UNSUPPORTED_ATTRIBUTE, attributeIdentifier=7]]]
2023-02-03 13:01:29.110 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=00, commandId=1]
2023-02-03 13:01:29.111 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=751D/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=2B, rssi=--, lqi=--, payload=18 00 01 07 00 86]
2023-02-03 13:01:29.126 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=48]
2023-02-03 13:01:29.147 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=49]

I finally played around with your changes in com.zsmartsystems.zigbee and removed the ZclTimeServer and related classes, so the library stops responding to time commands, but still contains the time types. I modified my own prototype of org.openhab.binding.zigbee and used your newly added UTCTIME type to add a local attribute to my Tuya devide that always returns the current UTC time:

public class TuyaLocalTimeAttribute extends ZclAttribute {

    public TuyaLocalTimeAttribute(ZclCluster parent) {
        super(parent, ZclTimeCluster.ATTR_LOCALTIME, "Local Time", ZclDataType.UTCTIME, false, true, false, false);
    }

    @Override
    public Object getLastValue() {
        updateLastValue();
        return super.getLastValue();
    }

    private void updateLastValue() {        
        updateValue(ZigBeeUtcTime.now());
    }
}
    public synchronized boolean initializeConverter(ZigBeeThingHandler thing) {
        [...]
            timeCluster = endpoint.getOutputCluster(ZclTimeCluster.CLUSTER_ID);

            Set<ZclAttribute> attributes = new HashSet<ZclAttribute>();
            ZclAttribute localTimeAttribute = new TuyaLocalTimeAttribute(timeCluster);

            attributes.add(localTimeAttribute);
            timeCluster.addLocalAttributes(attributes);
        [...]

The good news: It sorta worked, OH is responding to the Tuya device's request for time:

2023-02-03 16:24:59.346 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - BC33ACFFFEEF6F95: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=BC33ACFFFEEF6F95 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesResponse [Time: 0000/0 -> 751D/1, cluster=000A, TID=00, records=[ReadAttributeStatusRecord [status=SUCCESS, attributeIdentifier=7, attributeDataType=UTCTIME, attributeValue=2023-02-03T16:24:59Z]]]]

The bad news is that this doesn't stop the Tuya device from waking up and asking again every ~12 minutes: openhab.log

cdjackson commented 1 year ago

First issue, we're getting a nullptr exception:

Thanks - I've fixed that now in the library branch.

Next, I believe we don't properly handle the request and send two responses. One inside ZclTimeServer, and one default response because the library didn't realize that we handled the request (?):

I'll take a look at this. It's caused by the way that the commands are processed in this server class - again - this is something that changed since this was written.

The bad news is that this doesn't stop the Tuya device from waking up and asking again every ~12 minutes:

I guess I'm not super surprised by this since it is not mandatory for a network to handle these commands it would be a bit silly to implement it in a way that requires it. That said, I guess these devices aren't really just mean to be used in "any old zigbee network", but are designed to be used with the Tuya gateway which means they don't "need" to stick to the standards.

Anyway, I guess other than that you're still kind of at square one in understanding the poor battery performance? :(

dschall commented 1 year ago

they don't "need" to stick to the standards

Yeah :( I was hoping by giving them what they want (a response to their time requests), they'd be happy and shut up for a longer period and stop draining the battery. Since they don't work properly, I'm about to give up on them. Too much time wasted, already.

But if you want to check in your time changes, let me know. I'd be happy to help get that in, so it wasn't all for nothing :)

PS: I'm wondering if the Tuya devices expect something from this message, unrelated to time, but also send repeatedly every ~12 minutes:

2023-02-03 16:49:03.175 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0002, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=7C], lastHopLqi=192, lastHopRssi=-52, sender=751D, bindingIndex=255, addressIndex=255, messageContents=82 00 00]
2023-02-03 16:49:03.176 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=751D/0, destinationAddress=0000/0, profile=0000, cluster=0002, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=7C, rssi=-52, lqi=C0, payload=82 00 00]
2023-02-03 16:49:03.176 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node update. NWK Address=NULL
2023-02-03 16:49:03.177 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - BC33ACFFFEEF6F95: Node 751D is not updated from ZigBeeNode [state=ONLINE, IEEE=BC33ACFFFEEF6F95, NWK=----, endpoints=[]]
2023-02-03 16:49:03.178 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NodeDescriptorRequest [751D/0 -> 0000/0, cluster=0002, TID=82, nwkAddrOfInterest=0000]
2023-02-03 16:49:03.178 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NodeDescriptorRequest [751D/0 -> 0000/0, cluster=0002, TID=82, nwkAddrOfInterest=0000] 
2023-02-03 16:49:03.451 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspZigbeeKeyEstablishmentHandler [networkId=0, partner=BC33ACFFFEEF6F95, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]

But since it's unrelated to time, we can maybe tal about that on the Tuya thread..

cdjackson commented 1 year ago

But if you want to check in your time changes, let me know. I'd be happy to help get that in, so it wasn't all for nothing :)

Thanks - let me take a look and try and update this as it would be good to get it working :)

PS: I'm wondering if the Tuya devices expect something from this message, unrelated to time, but also send repeatedly every ~12 minutes:

Do you have a sniffer? OI think that the Ember NCP should send a response to that, but I'm not 100% sure.

dschall commented 1 year ago

Do you have a sniffer?

Isn't OH3 sniffing all the communication, or are there additional packets exchanged that OH3 doesn't see? I don't have other devices in this test setup, only the zigbee stick and the Tuya.

cdjackson commented 1 year ago

No - you won't see some traffic. You don't see any of the lower layer stuff (ie all the ACKs that are going on at network level) and other network traffic. I can't remember if these commands will be reflected back on the serial link or not if the NCP responds, but I believe that it should be (but again, I might be wrong).