[quote=“micasaverde, post:10, topic:170311”]
MiOS does not seem to have any concept of saying, this is a battery powered device and I just heard from it so now would be a great time to try sending a message to it because it is probably awake.
Not true. This is the ONLY way that battery-operated devices work. Otherwise nobody would get any battery operated devices to work.
Regarding the new change in the last release, we have ALWAYS sent queued commands when a battery device wakes up.[/quote]
It is really the thermostats that are the major problem for me rather than the HSM100. Here is an example I have a thermostat that is device_id 93 and node 43 (0x2b). I know the device is about to wake up in the next few seconds, so here are some bits of your logs:
08 02/06/12 9:21:02.013 JobHandler_LuaUPnP::HandleActionRequest device: 93 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat action: SetCurrentSetpoint <0x402>
08 02/06/12 9:21:02.013 JobHandler_LuaUPnP::HandleActionRequest argument NewCurrentSetpoint=10 <0x402>
06 02/06/12 9:21:02.014 Device_Variable::m_szValue_set device: 93 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat variable: SetpointTarget was: 13 now: 10 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x402>
02 02/06/12 9:21:02.016 ZWJob_SendData UPDATE MANUAL ROUTE 43=(nil) <0x402>
06 02/06/12 9:21:09.984 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryDate was: 1328519772 now: 1328520069 #hooks: 1 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
06 02/06/12 9:21:09.987 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryLevel was: 60 now: 60 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.033 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryDate was: 1328520069 now: 1328520070 #hooks: 1 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
06 02/06/12 9:21:10.036 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryLevel was: 60 now: 60 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.083 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryDate was: 1328520070 now: 1328520070 #hooks: 1 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.084 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryLevel was: 60 now: 60 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.163 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryDate was: 1328520070 now: 1328520070 #hooks: 1 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.164 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryLevel was: 60 now: 60 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.213 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryDate was: 1328520070 now: 1328520070 #hooks: 1 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.214 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryLevel was: 60 now: 60 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.263 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryDate was: 1328520070 now: 1328520070 #hooks: 1 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 02/06/12 9:21:10.264 Device_Variable::m_szValue_set device: 93 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryLevel was: 60 now: 60 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
The log file continues, but we never see a LastWakeup change for this device, although quite honestly it must clearly be awake to some extent because it is sending us battery updates. Looking at the z-Wave messages we see the following (these are the first messages after 09:21:00 so the Setpoint change has yet to generate any traffic at all)
Z 09:21:09.980 0x01 0x09 00 0x04 00 0x2b 0x03 0x80 0x03 0x3c 0x65 [battery status info as in logs]
V 09:21:09.982 0x06
Z 09:21:10.000 0x01 0x09 00 0x04 00 0x2b 0x03 0x80 0x03 0x3c 0x65 [battery status info as in logs]
V 09:21:10.031 0x06
Z 09:21:10.040 0x01 0x09 00 0x04 00 0x2b 0x03 0x80 0x03 0x3c 0x65 [battery status info as in logs]
V 09:21:10.081 0x06
Z 09:21:10.110 0x01 0x09 00 0x04 00 0x2b 0x03 0x80 0x03 0x3c 0x65 [battery status info as in logs]
V 09:21:10.161 0x06
Z 09:21:10.170 0x01 0x09 00 0x04 00 0x2b 0x03 0x80 0x03 0x3c 0x65 [battery status info as in logs]
V 09:21:10.211 0x06
Z 09:21:10.220 0x01 0x09 00 0x04 00 0x2b 0x03 0x80 0x03 0x3c 0x65 [battery status info as in logs]
V 09:21:10.261 0x06
V 09:21:14.582 0x01 0x03 00 0x16 0xea
Z 09:21:14.590 0x06
Z 09:21:14.890 0x01 0x05 00 0x19 0x85 0x01 0x67
V 09:21:14.891 0x06
V 09:21:16.660 0x01 0x10 00 0x19 0x2b 0x05 0x43 0x01 0x01 0x01 0x0a 0x05 00 00 00 00 0x86 0x13 [hooray MiOS is talking to my device, 6 seconds after the battery info, rather too late in the day I suspect]
Z 09:21:16.670 0x06 0x01 0x04 0x01 0x19 0x01 0xe2
V 09:21:16.711 0x06
Z 09:21:19.290 0x01 0x09 00 0x04 00 0x12 0x03 0x80 0x03 0x35 0x55
V 09:21:19.341 0x06
Z 09:21:19.350 0x01 0x0c 00 0x04 00 0x12 0x06 0x43 0x03 0x01 0x42 0x03 0xe8 0x0b
V 09:21:19.391 0x06
Z 09:21:19.400 0x01 0x0a 00 0x04 00 0x12 0x04 0x46 0x08 00 0x7f 0xd6
V 09:21:19.441 0x06
V 09:21:27.723 0x01 0x03 00 0x16 0xea
Z 09:21:27.730 0x06
Z 09:21:28.170 0x01 0x05 00 0x19 0x86 0x01 0x64
V 09:21:28.172 0x06
V 09:21:29.748 0x01 0x10 00 0x19 0x2b 0x05 0x43 0x01 0x01 0x01 0x0a 0x25 00 00 00 00 0x87 0x32 [MiOS tries again, but it must be asleep by now!]
Z 09:21:29.760 0x06 0x01 0x04 0x01 0x19 0x01 0xe2
V 09:21:29.781 0x06
Z 09:21:35.980 0x01 0x09 00 0x04 00 0x17 0x03 0x80 0x03 0x31 0x54 [here comes a different thermostat, battery report]
V 09:21:35.982 0x06
Z 09:21:36.000 0x01 0x0c 00 0x04 00 0x17 0x06 0x43 0x03 0x01 0x42 0x03 0xe8 0x0e [setpoint reporting]
V 09:21:36.031 0x06
Z 09:21:36.060 0x01 0x0a 00 0x04 00 0x17 0x04 0x46 0x08 00 0x7f 0xd3 [control schedule override report]
V 09:21:36.081 0x06
Z 09:21:36.090 0x01 0x08 00 0x04 00 0x17 0x02 0x81 0x05 0x62 [clock request]
V 09:21:36.131 0x06
V 09:21:40.141 0x01 0x03 00 0x16 0xea
Z 09:21:40.150 0x06
Z 09:21:40.440 0x01 0x05 00 0x19 0x87 0x01 0x65
V 09:21:40.461 0x06
V 09:21:42.201 0x01 0x0f 00 0x19 0x17 0x04 0x81 0x06 0x29 0x15 0x05 00 00 00 00 0x88 0xcc [hooray MiOS responds 6 seconds later again to tell the thermostat the time]
Z 09:21:42.210 0x06 0x01 0x04 0x01 0x19 0x01 0xe2
V 09:21:42.242 0x06
Z 09:21:42.370 0x01 0x05 00 0x19 0x88 0x01 0x6a
V 09:21:42.372 0x06
V 09:21:42.381 0x01 0x0f 00 0x19 0x17 0x04 0x81 0x06 0x29 0x15 0x25 00 00 00 00 0x89 0xed [sorry MiOS you really won’t get through now]
Z 09:21:42.390 0x06 0x01 0x04 0x01 0x19 0x01 0xe2
Now this is a more interesting log because this is a device that does show a change in LastWakeup
Z 09:23:54.970 0x01 0x09 00 0x04 00 0x36 0x03 0x80 0x03 0x3c 0x78 [another battery report]
V 09:23:54.972 0x06
Z 09:23:54.990 0x01 0x0c 00 0x04 00 0x36 0x06 0x43 0x03 0x01 0x42 0x03 0xe8 0x2f [setpoint report]
V 09:23:55.035 0x06
V 09:23:55.036 0x01 0x11 00 0x19 0x31 0x06 0x60 0x0d 0x01 0x01 0x25 0x02 0x05 00 00 00 00 0x95 0x1a [different device]
Z 09:23:55.040 0x01 0x0a 00 0x04 00 0x36 0x04 0x46 0x08 00 0x7f 0xf2 0x18 [climate control schedule]
V 09:23:55.071 0x06
Z 09:23:55.080 0x01 0x08 00 0x04 00 0x36 0x02 0x81 0x05 0x43 [clock request]
V 09:23:55.121 0x06
V 09:23:56.080 0x01 0x11 00 0x19 0x31 0x06 0x60 0x0d 0x01 0x01 0x25 0x02 0x05 00 00 00 00 0x95 0x1a [different device]
Z 09:23:56.090 0x06 0x01 0x04 0x01 0x19 0x01 0xe2
V 09:23:56.096 0x01 0x03 00 0x16 0xea
Z 09:23:56.100 0x18 [Got a CAN]
V 09:23:56.112 0x06
Z 09:23:56.120 0x01 0x05 00 0x19 0x95 00 0x76
V 09:23:56.121 0x01 0x03 00 0x16 0xea
Z 09:23:56.130 0x18 [Got a CAN]
V 09:23:56.151 0x06
Z 09:23:56.160 0x01 0x0d 00 0x04 00 0x31 0x07 0x60 0x0d 0x01 0x01 0x25 0x03 00 0x8b [different device]
V 09:23:56.191 0x06
V 09:23:58.160 0x01 0x0f 00 0x19 0x36 0x04 0x81 0x06 0x29 0x17 0x05 00 00 00 00 0x96 0xf1 [hooray MiOS got there in 3-4 seconds with clock info so the device is still awake!]
Z 09:23:58.171 0x06 0x01 0x04 0x01 0x19 0x01 0xe2
V 09:23:58.211 0x06
Z 09:23:58.220 0x01 0x05 00 0x19 0x96 00 0x75
V 09:23:58.261 0x06
Z 09:23:58.270 0x01 0x08 00 0x04 00 0x36 0x02 0x84 0x07 0x44 [device responds - this appears to update LastWakeup]
V 09:23:58.311 0x06
V 09:23:58.323 0x01 0x0d 00 0x19 0x36 0x02 0x46 0x07 0x05 00 00 00 00 0x97 0x0c [climate control message]
Z 09:23:58.330 0x06 0x01 0x04 0x01 0x19 0x01 0xe2
V 09:23:58.361 0x06
Z 09:23:58.370 0x01 0x05 00 0x19 0x97 00 0x74
V 09:23:58.411 0x06
Z 09:23:58.420 0x01 0x0a 00 0x04 00 0x36 0x04 0x46 0x08 00 0x7f 0xf2
V 09:23:58.461 0x06
V 09:23:58.474 0x01 0x0d 00 0x19 0x36 0x02 0x84 0x08 0x05 00 00 00 00 0x98 0xce
Now with the best will in the world waiting 3-4 seconds to respond to a battery powered device isn’t a great performance. MiOS clearly isn’t rushing to respond to battery powered devices.
Looking at these logs it is of little surprise to me that my devices aren’t working very well and the batteries are running flat very quickly. Ideally all messages to a battery powered device would be sent within a fraction of a second of any messages being received from the device and the same would be true of any responses to requests for information. If this happened I could also send a message to the device to tell it to go back to sleep as suggested by Danfoss.
Looking at the logs my radiator thermostats must stay awake for around 5 seconds every time they communicate with MiOS, whereas in the ideal world they would receive my messages and then be sent a command to go back to sleep. This appears to explain why Danfoss say batteries in their thermostats last a couple of years whilst with MiOS they last a couple of months.