Xiaomi Gateway 3 binding (ZNDMWG03LM)

Rick999 · November 25, 2021, 1:15pm

Hello Pim Verschuuren have you managed to fix the issue ?

Pim_Verschueren · November 27, 2021, 12:14pm

Hi,

No, I gave up

Kr,

Pim

enrico.mcc · December 5, 2021, 11:02pm

Is it normal that the bridge thing is always in an “unknown” state?

Don’t know if it’s related, but the battery state of the attached door sensor is always NULL:

dexter · December 6, 2021, 1:07am

Got the log. I can see that all the XiaomiBinding requests are not accepted by the Gateway.
Can you do the following:

Check if you can telnet to the gateway device
Check if you can connect to the MQTT service which runs on the device.
Turn on debug logging for the XiaomiGatewayBinding, turn off MIIO binding, restart the XiaomiGatewayV3 binding and wait for 5-10 minutes. Then send me logs again.

Please tell me if you need any details how to do this.

I can see lots of messages from MIIO binding which probably influence on the communication.

dexter · December 6, 2021, 1:11am

No, it’s not normal. It means the binding cannot communicate with the gateway.

Have you found the token, deviceID and removed the password from the telnet?
If you answer ‘yes’ to all the questions above - please switch binding’s logs to the debug level and send me some.

enrico.mcc · December 6, 2021, 7:10am

Yes to the token and device id, but I don’t think I removed the telnet password.

Is there a procedure I could follow?

Thanks

dexter · December 6, 2021, 8:06am

Firstly, check that there is a password. Just try login admin and no password. This should be done after you turn or the binding and wait for a couple of minutes.
You should see something like this:

If there is a password - please let me know. Apparently there is already a hack to remove the password, but I need to add it to the binding.

If you share your logs that I will be able to tell more.

enrico.mcc · December 6, 2021, 11:36am

not sure how to do that, but if I use Telnet 192.168.1.24 13531 (on Windows command prompt) I get an error: connection failed.

enrico.mcc · December 6, 2021, 12:48pm

sorry I was using the wrong port:

I only used “admin” as user and no password requested

dexter · December 6, 2021, 9:28pm

Looks good. In this case I need debug level logs to investigate further.

enrico.mcc · December 7, 2021, 8:30am

Good news, here are the logs:

==> /var/log/openhab/events.log <==
2021-12-07 09:23:02.759 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:vibration_sensor:112c3d4d60:lumi_158d00039d8f0b' changed from ONLINE to UNINITIALIZED
2021-12-07 09:23:02.782 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:vibration_sensor:112c3d4d60:lumi_158d00039d8f0b' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2021-12-07 09:23:02.784 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:door_sensor:112c3d4d60:lumi_158d000522535b' changed from ONLINE to UNINITIALIZED
2021-12-07 09:23:02.797 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:door_sensor:112c3d4d60:lumi_158d000522535b' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2021-12-07 09:23:02.798 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:config:112c3d4d60' changed from UNKNOWN to UNINITIALIZED
2021-12-07 09:23:02.812 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:config:112c3d4d60' changed from UNINITIALIZED to OFFLINE (COMMUNICATION_ERROR): Bridge (broker) cannot connect to the MQTT gateway.
2021-12-07 09:23:02.825 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:config:112c3d4d60' changed from OFFLINE (COMMUNICATION_ERROR): Bridge (broker) cannot connect to the MQTT gateway. to UNINITIALIZED (DISABLED)
2021-12-07 09:23:02.828 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:vibration_sensor:112c3d4d60:lumi_158d00039d8f0b' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2021-12-07 09:23:02.835 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:door_sensor:112c3d4d60:lumi_158d000522535b' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

==> /var/log/openhab/openhab.log <==
2021-12-07 09:23:02.810 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:DISCONNECTED
2021-12-07 09:23:02.823 [DEBUG] [l.discovery.XiaomiGatewayV3Discovery] - Stop Xiaomi GatewayV3 background discovery

==> /var/log/openhab/events.log <==
2021-12-07 09:23:08.640 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:config:112c3d4d60' changed from UNINITIALIZED (DISABLED) to INITIALIZING
2021-12-07 09:23:08.651 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:config:112c3d4d60' changed from INITIALIZING to UNKNOWN
2021-12-07 09:23:08.657 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:vibration_sensor:112c3d4d60:lumi_158d00039d8f0b' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2021-12-07 09:23:08.660 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:door_sensor:112c3d4d60:lumi_158d000522535b' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2021-12-07 09:23:08.673 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:vibration_sensor:112c3d4d60:lumi_158d00039d8f0b' changed from INITIALIZING to UNKNOWN
2021-12-07 09:23:08.675 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:vibration_sensor:112c3d4d60:lumi_158d00039d8f0b' changed from UNKNOWN to ONLINE
2021-12-07 09:23:08.678 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:door_sensor:112c3d4d60:lumi_158d000522535b' changed from INITIALIZING to UNKNOWN
2021-12-07 09:23:08.680 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'xiaomigatewayv3:door_sensor:112c3d4d60:lumi_158d000522535b' changed from UNKNOWN to ONLINE

==> /var/log/openhab/openhab.log <==
2021-12-07 09:23:08.632 [INFO ] [l.discovery.XiaomiGatewayV3Discovery] - Class set
2021-12-07 09:23:08.648 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - Initializing the bridge handler 'xiaomigatewayv3:config:112c3d4d60' with thingType xiaomigatewayv3:config
2021-12-07 09:23:08.652 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - IP address: 192.168.1.24
2021-12-07 09:23:08.653 [DEBUG] [3.internal.helpers.MIIOCommunication] - No device ID defined. Retrieving Mi device ID
2021-12-07 09:23:08.658 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping  (192.168.1.24)
2021-12-07 09:23:08.662 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Starting Mi IO MessageSenderThread
2021-12-07 09:23:08.662 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Opening socket on port: 55227
2021-12-07 09:23:08.758 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping  (192.168.1.24) success
2021-12-07 09:23:08.760 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-04T17:43:42, OH time 2021-12-07T09:23:08.759990, delta -1638545966
2021-12-07 09:23:08.761 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-04T17:43:42, OH time 2021-12-07T09:23:08.761443, delta -1638545966
2021-12-07 09:23:08.763 [DEBUG] [3.internal.helpers.MIIOCommunication] - Using retrieved Mi device ID: 13D24DFE
2021-12-07 09:23:08.764 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":1,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-07 09:23:08.766 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-07 09:23:08.812 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-07 09:23:08.814 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":2,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-07 09:23:08.815 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-07 09:23:08.937 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-07 09:23:08.938 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - Creating a new instance of MqttBrokerConnection
2021-12-07 09:23:08.940 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-07 09:23:08.948 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '192.168.1.24' with clientid sgbinding1
2021-12-07 09:23:08.980 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-07 09:23:13.158 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":1,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4080}
2021-12-07 09:23:13.159 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-07 09:23:13.671 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":2,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-07 09:23:13.676 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-07 09:23:13.678 [INFO ] [l.discovery.XiaomiGatewayV3Discovery] - AutoDiscovery: creating 2 devices
2021-12-07 09:23:18.984 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to '192.168.1.24'. Next attempt in 60000ms
2021-12-07 09:23:18.989 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-07 09:23:18.995 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '192.168.1.24' with clientid sgbinding1
2021-12-07 09:23:19.015 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-07 09:23:19.019 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":3,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-07 09:23:19.022 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":4,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-07 09:23:21.326 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*287##]
2021-12-07 09:23:21.327 [INFO ] [unication.BUSConnector.message.event] - BUS-MON <<<<<<<< *#18*51*113*287##
2021-12-07 09:23:21.329 [DEBUG] [rnal.handler.OpenWebNetBridgeHandler] - ownIdFromMessage(<*#18*51*113*287##>) --> 18.51
2021-12-07 09:23:23.267 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":3,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-07 09:23:23.268 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-07 09:23:23.619 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":4,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2021-12-07 09:23:23.621 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-07 09:23:23.622 [INFO ] [l.discovery.XiaomiGatewayV3Discovery] - AutoDiscovery: creating 2 devices

dexter · December 8, 2021, 3:28am

Thanks.
The issue is in the enabling telnet command. It doesn’t respond correctly for some reason. Thus the code doesn’t go further despite the fact that telnet is working already.
I will change the code to send enable_telnet only if it doesn’t respond to the telnet connection. Otherwise it should skip it.

enrico.mcc · December 8, 2021, 12:34pm

Great, if I can support with some testing let me know

enrico.mcc · December 18, 2021, 5:13pm

Just a thought looking at the logs: should I have the MQTT binding installed to make this work?

dexter · December 20, 2021, 12:58am

Yes, please try. Let me know if it helps. I’ll add it to the readme then.

enrico.mcc · December 20, 2021, 10:20am

Ok I istalled the MQTT/Mosquito and then disabled and re-enabled the bridge thing:

2021-12-20 11:04:38.421 [DEBUG] [3.internal.helpers.MIIOCommunication] - No device ID defined. Retrieving Mi device ID
2021-12-20 11:04:38.428 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping  (192.168.1.24)
2021-12-20 11:04:38.430 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Opening socket on port: 33715 
2021-12-20 11:04:38.432 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Starting Mi IO MessageSenderThread
2021-12-20 11:04:38.565 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping  (192.168.1.24) success
2021-12-20 11:04:38.572 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:25:08, OH time 2021-12-20T11:04:38.571578, delta -1638545970
2021-12-20 11:04:38.574 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:25:08, OH time 2021-12-20T11:04:38.574112, delta -1638545970
2021-12-20 11:04:38.576 [DEBUG] [3.internal.helpers.MIIOCommunication] - Using retrieved Mi device ID: 13D24DFE
2021-12-20 11:04:38.578 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":1,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:04:38.580 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:04:38.713 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:04:38.716 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":2,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:04:38.718 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:04:42.979 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":1,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:04:42.981 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:04:42.999 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:04:43.301 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":2,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2021-12-20 11:04:43.306 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-20 11:04:53.075 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":3,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:04:53.076 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":4,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:04:57.266 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":3,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:04:57.269 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:04:57.601 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":4,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-20 11:04:57.605 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-20 11:06:02.846 [DEBUG] [3.internal.helpers.MIIOCommunication] - No device ID defined. Retrieving Mi device ID
2021-12-20 11:06:02.850 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping  (192.168.1.24)
2021-12-20 11:06:02.851 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Starting Mi IO MessageSenderThread
2021-12-20 11:06:02.852 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Opening socket on port: 39509 
2021-12-20 11:06:02.906 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping  (192.168.1.24) success
2021-12-20 11:06:02.908 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:26:32, OH time 2021-12-20T11:06:02.908246, delta -1638545970
2021-12-20 11:06:02.910 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:26:32, OH time 2021-12-20T11:06:02.910142, delta -1638545970
2021-12-20 11:06:02.912 [DEBUG] [3.internal.helpers.MIIOCommunication] - Using retrieved Mi device ID: 13D24DFE
2021-12-20 11:06:02.914 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":1,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:06:02.916 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:06:03.026 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:06:03.028 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":2,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:06:03.030 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:06:07.226 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":1,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:06:07.228 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:06:07.232 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:06:07.667 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":2,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-20 11:06:07.671 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-20 11:06:17.349 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":3,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:06:17.351 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":4,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:06:21.528 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":3,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:06:21.530 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:06:22.738 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":4,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2021-12-20 11:06:22.742 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-20 11:08:17.352 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":5,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:08:17.354 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":6,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:08:21.558 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":5,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:08:21.560 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:08:21.868 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":6,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-20 11:08:21.872 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-20 11:10:01.436 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":7,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:10:01.646 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":7,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2021-12-20 11:10:01.649 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2021-12-20 11:10:17.394 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":8,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:10:17.396 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":9,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:10:21.552 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":8,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:10:21.554 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:10:21.878 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":9,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-20 11:10:21.882 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2

not sure if it changed anything, the bridge is still in “unknown”:

enrico.mcc · December 20, 2021, 10:44am

I noticed some lines were missing from the above logs, this one should be complete:

2021-12-20 11:04:38.412 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - Initializing the bridge handler 'xiaomigatewayv3:config:112c3d4d60' with thingType xiaomigatewayv3:config
2021-12-20 11:04:38.419 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - IP address: 192.168.1.24
2021-12-20 11:04:38.421 [DEBUG] [3.internal.helpers.MIIOCommunication] - No device ID defined. Retrieving Mi device ID
2021-12-20 11:04:38.428 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping  (192.168.1.24)
2021-12-20 11:04:38.430 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Opening socket on port: 33715 
2021-12-20 11:04:38.432 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Starting Mi IO MessageSenderThread
2021-12-20 11:04:38.565 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping  (192.168.1.24) success
2021-12-20 11:04:38.572 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:25:08, OH time 2021-12-20T11:04:38.571578, delta -1638545970
2021-12-20 11:04:38.574 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:25:08, OH time 2021-12-20T11:04:38.574112, delta -1638545970
2021-12-20 11:04:38.576 [DEBUG] [3.internal.helpers.MIIOCommunication] - Using retrieved Mi device ID: 13D24DFE
2021-12-20 11:04:38.578 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":1,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:04:38.580 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:04:38.713 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:04:38.716 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":2,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:04:38.718 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:04:42.979 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":1,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:04:42.981 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:04:42.999 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:04:43.001 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - Creating a new instance of MqttBrokerConnection
2021-12-20 11:04:43.003 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:04:43.033 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:04:43.301 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":2,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2021-12-20 11:04:49.599 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*211##]
2021-12-20 11:04:53.046 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:04:53.070 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:04:53.075 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":3,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:04:53.076 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":4,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:04:57.266 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":3,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:04:57.269 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:04:57.601 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":4,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-20 11:05:00.579 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*198##]
2021-12-20 11:05:06.082 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-CMD |<--     NO DATA (size=0)
2021-12-20 11:05:06.087 [DEBUG] [nwebnet4j.communication.BUSConnector] - ##BUS-conn## Exception: Received null frame while reading responses to command
2021-12-20 11:05:06.089 [DEBUG] [nwebnet4j.communication.BUSConnector] - ##BUS-conn## Establishing CMD connection to BUS Gateway on 192.168.1.11:20000...
2021-12-20 11:05:06.091 [DEBUG] [nwebnet4j.communication.BUSConnector] - ##BUS-conn## CMD socket connected
2021-12-20 11:05:06.092 [DEBUG] [nwebnet4j.communication.BUSConnector] - (HS) starting HANDSHAKE on channel BUS-CMD... 
2021-12-20 11:05:06.094 [DEBUG] [communication.BUSConnector.handshake] - (HS) ... STEP-1: receive ACK from GW
2021-12-20 11:05:06.095 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-CMD <------- [*#*1##]
2021-12-20 11:05:06.097 [DEBUG] [communication.BUSConnector.handshake] - (HS) ... STEP-1: first ACK received
2021-12-20 11:05:06.098 [DEBUG] [communication.BUSConnector.handshake] - (HS) ... STEP-2: send session request *99*0## ... 
2021-12-20 11:05:06.101 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-CMD <------- [*98*2##]
2021-12-20 11:05:06.103 [DEBUG] [communication.BUSConnector.handshake] - (HS) ... STEP-2: HMAC_AUTH: HMAC type received: *98*2##, sending ACK ... 
2021-12-20 11:05:06.107 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-CMD <------- [*#07111208010114020507150700121211000607021011110506030007120705080203031507090005080005000911070113001004130804000811001403110405##]
2021-12-20 11:05:06.109 [DEBUG] [communication.BUSConnector.handshake] - (HS) ... STEP-3: HMAC_AUTH: Ra digits received: 07111208010114020507150700121211000607021011110506030007120705080203031507090005080005000911070113001004130804000811001403110405 ...
2021-12-20 11:05:06.110 [DEBUG] [communication.BUSConnector.handshake] - (HS) ... STEP-4: HMAC_AUTH: sending <Rb, HMAC(Ra,Rb,A,B,Kab)> ... 
2021-12-20 11:05:06.115 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-CMD <------- [*#10071310100905010605060103111411141405141005051106080105140114060512001503110905011409030609001403090208050502090415100514031014##]
2021-12-20 11:05:06.119 [DEBUG] [communication.BUSConnector.handshake] - (HS) ... STEP-4: HMAC_AUTH: final ACK sent ==HANDSHAKE COMPLETED==
2021-12-20 11:05:06.237 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-CMD <------- [*#*1##]
2021-12-20 11:05:06.239 [DEBUG] [.openwebnet4j.communication.Response] - <*#18*51*#1200#1*10##>   <<add   <*#*1##>
2021-12-20 11:05:06.241 [DEBUG] [.openwebnet4j.communication.Response] - now: <*#18*51*#1200#1*10##>   <<==    [<*#*1##>]
2021-12-20 11:05:06.242 [DEBUG] [j.communication.BUSConnector.message] - BUS-CMD   <<==   *#*1##
2021-12-20 11:05:06.246 [DEBUG] [nwebnet4j.communication.BUSConnector] - ##BUS-conn## ^^^^^^^^ USED NEW    CONNECTION    ^^^^^^^^
2021-12-20 11:05:06.271 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*1200#1*10##]
2021-12-20 11:05:06.321 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*201##]
2021-12-20 11:05:21.537 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*197##]
2021-12-20 11:05:50.401 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:DISCONNECTED
2021-12-20 11:05:50.421 [DEBUG] [l.discovery.XiaomiGatewayV3Discovery] - Stop Xiaomi GatewayV3 background discovery
2021-12-20 11:05:50.482 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*202##]
2021-12-20 11:06:02.841 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - Initializing the bridge handler 'xiaomigatewayv3:config:112c3d4d60' with thingType xiaomigatewayv3:config
2021-12-20 11:06:02.844 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - IP address: 192.168.1.24
2021-12-20 11:06:02.846 [DEBUG] [3.internal.helpers.MIIOCommunication] - No device ID defined. Retrieving Mi device ID
2021-12-20 11:06:02.850 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping  (192.168.1.24)
2021-12-20 11:06:02.851 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Starting Mi IO MessageSenderThread
2021-12-20 11:06:02.852 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Opening socket on port: 39509 
2021-12-20 11:06:02.906 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping  (192.168.1.24) success
2021-12-20 11:06:02.908 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:26:32, OH time 2021-12-20T11:06:02.908246, delta -1638545970
2021-12-20 11:06:02.910 [DEBUG] [3.internal.helpers.MIIOCommunication] - Ping response from device 13D24DFE at 192.168.1.24. Time stamp: 1970-01-17T19:26:32, OH time 2021-12-20T11:06:02.910142, delta -1638545970
2021-12-20 11:06:02.912 [DEBUG] [3.internal.helpers.MIIOCommunication] - Using retrieved Mi device ID: 13D24DFE
2021-12-20 11:06:02.914 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":1,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:06:02.916 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:06:03.026 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:06:03.028 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":2,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:06:03.030 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Sending Ping 13D24DFE (192.168.1.24)
2021-12-20 11:06:07.226 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":1,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:06:07.228 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:06:07.232 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Ping 13D24DFE (192.168.1.24) success
2021-12-20 11:06:07.234 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - Creating a new instance of MqttBrokerConnection
2021-12-20 11:06:07.236 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:06:07.280 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:06:07.667 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":2,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-20 11:06:17.295 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:06:17.342 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:06:17.349 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":3,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:06:17.351 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":4,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:06:18.426 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*207##]
2021-12-20 11:06:21.528 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":3,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:06:21.530 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:06:22.738 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":4,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2021-12-20 11:06:44.374 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*201##]
2021-12-20 11:07:11.322 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*197##]
2021-12-20 11:07:17.310 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:07:17.357 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:07:41.264 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*195##]
2021-12-20 11:08:11.203 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*198##]
2021-12-20 11:08:17.329 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:08:17.350 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:08:17.352 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":5,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:08:17.354 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":6,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:08:21.558 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":5,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:08:21.560 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:08:21.868 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":6,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}
2021-12-20 11:08:41.145 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*196##]
2021-12-20 11:09:11.085 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*200##]
2021-12-20 11:09:17.358 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:09:17.381 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:09:37.034 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*196##]
2021-12-20 11:10:00.493 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#13**#1*01*20*12*2021##]
2021-12-20 11:10:00.504 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#13**#0*11*10*00*##]
2021-12-20 11:10:01.065 [DEBUG] [nwebnet4j.communication.FrameChannel] - -FC-BUS-MON <------- [*#18*51*113*201##]
2021-12-20 11:10:01.436 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":7,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:10:01.646 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":7,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2021-12-20 11:10:17.369 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:10:17.392 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2021-12-20 11:10:17.394 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":8,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2021-12-20 11:10:17.396 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":9,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2021-12-20 11:10:21.552 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":8,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2021-12-20 11:10:21.554 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2021-12-20 11:10:21.878 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":9,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":220}

enrico.mcc · January 12, 2022, 10:18pm

Hi dexter,
do you have plans to share a new release with the above correction?
thanks

dexter · January 13, 2022, 3:59am

Hi,

Sorry for the delay, I’ve added the fix: Release beta - v07 · hubaksis/org.openhab.binding.xiaomigatewayv3 · GitHub.

In case if telnet_enable fails, the code continues to work.
Also added Honeywell Smoke Sensor (JTYJ-GD-01LM/BW).

Please try and send me new logs if something is not working.

Cheers!

enrico.mcc · January 13, 2022, 12:31pm

Thanks!

Unfortunately the status of the bridge is still yellow (unknown), those are the logs:

2022-01-13 13:30:11.534 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2022-01-13 13:30:11.537 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '192.168.1.24' with clientid sgbinding1
2022-01-13 13:30:11.612 [DEBUG] [andlers.XiaomiGatewayV3BridgeHandler] - MQTT brokers state changed to:CONNECTING
2022-01-13 13:30:11.615 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":15,"method":"enable_telnet_service","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 1).
2022-01-13 13:30:11.617 [DEBUG] [internal.miio.MiIoAsyncCommunication] - Command added to Queue {"id":16,"method":"get_device_list","params":[]} -> 192.168.1.24 (Device: 13D24DFE token: 3758466FXXXXXXXXXXXXXXXX546F414C Queue: 2).
2022-01-13 13:30:15.784 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: TELNET_ENABLE, result: null, fullresponse: {"id":15,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4070}
2022-01-13 13:30:15.786 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error received: {"code":-9999,"message":"user ack timeout"}
2022-01-13 13:30:15.787 [DEBUG] [3.internal.helpers.MIIOCommunication] - Error in response for TELNET_ENABLE command. Ignoring and continuing.
2022-01-13 13:30:15.788 [INFO ] [internal.helpers.TenletCommunication] - Connecting via telnet to 192.168.1.24
2022-01-13 13:30:15.954 [ERROR] [internal.helpers.TenletCommunication] - Error enabling external MQTT server
java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:?]
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399) ~[?:?]
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242) ~[?:?]
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224) ~[?:?]
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:?]
	at java.net.Socket.connect(Socket.java:609) ~[?:?]
	at java.net.Socket.connect(Socket.java:558) ~[?:?]
	at java.net.Socket.<init>(Socket.java:454) ~[?:?]
	at java.net.Socket.<init>(Socket.java:231) ~[?:?]
	at org.openhab.binding.xiaomigatewayv3.internal.helpers.TenletCommunication.EnableMqttExternalServer(TenletCommunication.java:49) [bundleFile:?]
	at org.openhab.binding.xiaomigatewayv3.internal.helpers.MIIOCommunication.onMessageReceived(MIIOCommunication.java:289) [bundleFile:?]
	at org.openhab.binding.xiaomigatewayv3.internal.miio.MiIoAsyncCommunication$MessageSenderThread.run(MiIoAsyncCommunication.java:257) [bundleFile:?]
2022-01-13 13:30:16.118 [DEBUG] [3.internal.helpers.MIIOCommunication] - Received response for type: GET_DEVICE_LIST, result: [{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}], fullresponse: {"code":0,"id":16,"result":[{"did":"lumi.158d00039d8f0b","model":"lumi.vibration.aq1","num":1,"total":2},{"did":"lumi.158d000522535b","model":"lumi.sensor_magnet.aq2","num":2,"total":2}],"exe_time":110}
2022-01-13 13:30:16.124 [INFO ] [3.internal.helpers.MIIOCommunication] - Found devices count: 2
2022-01-13 13:30:16.125 [INFO ] [l.discovery.XiaomiGatewayV3Discovery] - AutoDiscovery: creating 2 devices