WARNING interface:send: MQTT Send waiting on connection.

[jimboca]

Seeing this message repeated every short poll.

2021-08-21 15:56:59,795 Thread-743 udi_interface      DEBUG    Airscape2:short_poll: ...
2021-08-21 15:56:59,796 Thread-743 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:get: Sending: url=http://192.168.86.68/status.json.cgi payload={}
2021-08-21 15:56:59,797 Thread-743 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:get: headers={}
2021-08-21 15:56:59,889 Thread-743 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:get: url=http://192.168.86.68/status.json.cgi
2021-08-21 15:56:59,890 Thread-743 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:reponse:get:  Got: code=200
2021-08-21 15:56:59,890 Thread-743 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:reponse:get:  All good!
2021-08-21 15:56:59,894 Thread-743 udi_interface      DEBUG    Airscape2:set_from_response: In: {'code': 200, 'data': {'fanspd': 0, 'doorinprocess': 0, 'timeremaining': 0, 'macaddr': '60:CB:FB:00:80:33', 'ipaddr': '192.168.86.68', 'model': '5300 WHF', 'softver': '2.15.1', 'interlock1': 0, 'interlock2': 0, 'cfm': 0, 'power': 0, 'inside': -99, 'attic': 75, 'oa': -99, 'server_response': '', 'dip_switches': '11110', 'remote_switch': '1111', 'setpoint': 0, 'dns': '192.168.86.1'}}
2021-08-21 15:56:59,896 Thread-743 udi_interface      DEBUG    Airscape2:watch_door: st=0
2021-08-21 15:56:59,897 Thread-743 udi_interface      DEBUG    Airscape2:set_from_response: Out: {'fanspd': 0, 'attic_temp': 75, 'timeremaining': 0, 'power': 0, 'doorinprocess': 0, 'cfm': 0, 'house_temp': -99, 'oa_temp': -99, 'interlock1': 0, 'interlock2': 0}
2021-08-21 15:57:02,009 MainThread udi_interface.interface WARNING  interface:send: MQTT Send waiting on connection.

[jimboca]

So the attic_temp was changed on this pass, and that change is reflected on the ISY so the values are being pushed

2021-08-21 15:59:40,055 Thread-807 udi_interface      DEBUG    Airscape2:short_poll: ...
2021-08-21 15:59:40,057 Thread-807 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:get: Sending: url=http://192.168.86.68/status.json.cgi payload={}
2021-08-21 15:59:40,057 Thread-807 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:get: headers={}
2021-08-21 15:59:40,152 Thread-807 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:get: url=http://192.168.86.68/status.json.cgi
2021-08-21 15:59:40,153 Thread-807 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:reponse:get:  Got: code=200
2021-08-21 15:59:40,153 Thread-807 udi_interface      DEBUG    pgSession:l_debug: Airscape attic_whf:reponse:get:  All good!
2021-08-21 15:59:40,157 Thread-807 udi_interface      DEBUG    Airscape2:set_from_response: In: {'code': 200, 'data': {'fanspd': 0, 'doorinprocess': 0, 'timeremaining': 0, 'macaddr': '60:CB:FB:00:80:33', 'ipaddr': '192.168.86.68', 'model': '5300 WHF', 'softver': '2.15.1', 'interlock1': 0, 'interlock2': 0, 'cfm': 0, 'power': 0, 'inside': -99, 'attic': 76, 'oa': -99, 'server_response': '', 'dip_switches': '11110', 'remote_switch': '1111', 'setpoint': 0, 'dns': '192.168.86.1'}}
2021-08-21 15:59:40,161 Thread-807 udi_interface      DEBUG    Airscape2:watch_door: st=0
2021-08-21 15:59:40,162 Thread-807 udi_interface      DEBUG    Airscape2:set_from_response: Out: {'fanspd': 0, 'attic_temp': 76, 'timeremaining': 0, 'power': 0, 'doorinprocess': 0, 'cfm': 0, 'house_temp': -99, 'oa_temp': -99, 'interlock1': 0, 'interlock2': 0}
2021-08-21 15:59:40,351 MQTT       udi_interface.interface INFO     interface:_message: Successfully set attic_whf :: CLITEMP to 76 UOM 17
2021-08-21 15:59:42,045 MainThread udi_interface.interface WARNING  interface:send: MQTT Send waiting on connection.
2021-08-21 15:59:45,063 MainThread udi_interface.interface WARNING  interface:send: MQTT Send waiting on connection.

But when a value changes I do so it reflected on the ISY but do see 2 warnings instead of just one.

[bpaauwe]

This may be caused by a problem with threads in the interface. All events are run in separate threads to prevent your node server from blocking everything in an event handler. In this case, it looks like the thread(s) that are updating the ISY are fine, but MainThread doesn't know that the MQTT connection is active and thus the message. But I don't understand why it doesn't loop there forever.

Where do you make the interface.ready() call?

Can you post the beginning lines of the node server log file? I'd like to see the order things are initializing in.