The Vera Community forums have moved!

General => Temperature Monitoring & HVAC Control => Topic started by: ajlennon on November 11, 2011, 04:28:18 pm

Title: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 11, 2011, 04:28:18 pm
Hi,

Could somebody help me with an answer to a newbie question? I've got a battery powered
Horstmann thermostat which I have kind of working thanks to the help of the people here, and
I'm trying to understand the Z-Wave paradigm.

Being a battery powered device the thermostat is going to try to be in a powered down state
as much of the time as possible, keeping the radio off and so on and so forth. There seems to
be an ongoing discussion about "waking up" Z-Wave devices and I'm wondering if it is possible
to wake up a Z-Wave device remotely or not? 

At present when I try to set a setpoint via the Vera UI it immediately tries to instruct the
thermostat and fails, I believe as the thermostat is sleeping, and then whichever Vera subsystem
it is sensibly attempts to wait until the device wakes up.

So Q. could Vera do anything at this point to force the device to wake up?

And then the other major issue is that the setpoint never actually seems to be set into the
thermostat. Can anybody comment on any code I could look at here to determine what is
going wrong?

Thanks,

Alex Lennon
Dynamic Devices Ltd
http://www.dynamicdevices.co.uk
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: utz on November 12, 2011, 10:29:06 am
I have the problem too and have not found a solution yet (I have not looked into it in too much detail yet). 
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: intveltr on November 12, 2011, 10:43:34 am
From messing around with the Horstmann thermostat, I found that setting its wakeup interval to the lowest value (256 seconds; setting it lower has no effect) will have it wake up often enough to get the setpoint value from Vera.  Vera will report failure when it first try to send the value, but when the thermostat wakes up a few minutes later, Vera will retransmit.

Not sure what it does to the battery life, and I am not sure what the  longest possible wakeup interval is that will still work reliably.
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: oTi@ on November 12, 2011, 11:17:56 am
[...] wondering if it is possible to wake up a Z-Wave device remotely or not? 
The way I understand it: in general yes, but it depends on the type of device. A lot of battery operated devices are asleep most of the time, so they cannot be talked to. They would only wake up if they need to autonomously report something (through an alarm, a report, an association, a scene, etc.). They may also support the specific wake-up feature, where the controller (i.e. Vera) can configure a wake-up interval, so the device will periodically wake up, inform the controller of that fact, so the controller gets a chance to do something (i.e. configure, request etc.) at that time. Without (further) communication from the controller, the device goes back to sleep until the next wake-up period.

Then there are devices that are battery operated, but you want to be able to talk to at any time, such as a door lock. For those devices there is the beaming feature, which allows the device to listen frequently and save battery power. These are the (battery-operated) devices that can be 'woken up' (i.e. they are not really sleeping).

Quote
So Q. could Vera do anything at this point to force the device to wake up?
I don't have this device, but from the manual it seems to rely on the wake-up feature only, i.e. it will wake up every so often (configurable by Vera) and give Vera a chance to do things.
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 12, 2011, 11:37:27 am

Thanks for the comments everybody. I have a little more information to add from my testing...

When I heat up the thermostat it seems to report temperature changes immediately (which is nice).

So I _think_ that this 256s interval is the "must wake up even if there's nothing to transmit".

I still have the problem that entering a heating setpoint in Vera 2 doesn't seem to work.

It fails to transmit, then seems to wait until the device wakes and and seems to think it's transmitted but the value doesn't change to the value I expect.

I think perhaps I need to understand more about the Vera 2 Z-Wave logging to see where the problem is here. I would really like to be able to set the setpoint from the Vera 2
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: oTi@ on November 12, 2011, 11:46:52 am
When I heat up the thermostat it seems to report temperature changes immediately (which is nice).
Makes sense. It's initiated by the t-stat.

Quote
So I _think_ that this 256s interval is the "must wake up even if there's nothing to transmit".
Right. The wake-up interval. To allow comms initiated by the controller.

Quote
It fails to transmit, then seems to wait until the device wakes and and seems to think it's transmitted but the value doesn't change to the value I expect.
Does the setpoint change in the thermostat? From @intveltr's report (http://forum.micasaverde.com/index.php/topic,4575.msg53530.html#msg53530) I got the impression that is the case, but the GUI doesn't follow along.
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 13, 2011, 06:37:17 am

"Right. The wake-up interval. To allow comms initiated by the controller."

I can't quite see how that could work. It's the thermostat that is waking up. The only way the controller could then intiiate comms to the thermostat when it woke is if they both run extremely accurate and synchronised clocks. Is that the case or does the thermostat initiate comms. when it wakes up (which I would think more likely?)
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: oTi@ on November 13, 2011, 06:52:18 am
I can't quite see how that could work.[...]
I think the way the wake-up stuff works is that the device wakes up, sends out a message saying it's awake, so that a controller that is waiting to communicate with that device then gets a chance to do so.

(I meant to contrast the device has something to say to the controller with the controller has something to say to the device. The former is possible at any time; the latter is not, as the device is asleep and the controller will have to wait for it to wake up. So comms from the device can be instant, comms to the device only every wake-up interval.)
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 13, 2011, 06:56:51 am
"Does the setpoint change in the thermostat? From @intveltr's report I got the impression that is the case, but the GUI doesn't follow along."

I've now performed a little more testing...


(1) Thermostat SP set to 21, showing 21 in the UK, my Lua code retrieving a value of 21.

NB. The Lua code uses this line to get the SP value -

local lul_sph = luup.variable_get("urn:upnp-org:serviceId:TemperatureSetpoint1_Heat", "CurrentSetpoint", 5)

(I'm still not entirely clear where this value is coming from. Presumably it is cached somewhere.)

(2) I use the UI to set the heating SP to 28

(3) The failure message comes up -

"Failed, waiting to retry when the node wakes up"

The thermostat still shows 21

(4) After a short while the error message disappears from the UI

(5) After a couple of minutes there is a message there has been a successful transmission

"Transmit was ok"

(I have the thermostat set to wake up at the circa 4 mins interval and it has presumably
 signalled it has woken up and the pending setpoint update to it has occured)

(6) Now showing 28 on thermostat

(7) I have my Lua code set to run off a timer every 4 minutes. (A hack to work around not yet having the events I need to drive it)

In my Lua code I log the retrieved values for the SetPoint and the Current temperature. The SetPoint value being retrieved is
not correct -

50      11/13/11 11:44:13.011   luup_log:0: Heating SetPoint = 21 <0x803>
50      11/13/11 11:44:13.012   luup_log:0: Temperature = 21 <0x803>

50      11/13/11 11:48:13.012   luup_log:0: Heating SetPoint = 21 <0x803>
50      11/13/11 11:48:13.012   luup_log:0: Temperature = 21 <0x803>

(8) If I then change the setpoint directly on the thermostat from 28 to 27 the thermostat correctly updates Vera 2, the SP displays in the UI correcly and the Lua code has the right value

50      11/13/11 11:55:21.365   luup_log:0: Heating SetPoint = 27 <0x803>
50      11/13/11 11:55:21.366   luup_log:0: Temperature = 21 <0x803>

...

So this appears to be more than just a UI issue. It seems more like a cached local value that isn't being correctly updated
when the pending write occurs after an initial write failure. That sound about right?

Cheers,

Alex
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: oTi@ on November 13, 2011, 07:08:59 am
So this appears to be more than just a UI issue. It seems more like a cached local value that isn't being correctly updated
when the pending write occurs after an initial write failure. That sound about right?
Sounds like Vera 'forgets' to update the setpoint value internally (i.e. the local data associated with the device) once the message goes through when the device wakes up. Consequently, the GUI shows the incorrect value as well.

Does it fix itself after the next 256 seconds?
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 13, 2011, 07:12:00 am

No I left it runnign for 3 or 4 cycles of the Lua script on the basis it might update, but it didn't fix itself. Will leave it running here again to double check
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: oTi@ on November 13, 2011, 07:24:26 am
No I left it runnign for 3 or 4 cycles of the Lua script on the basis it might update, but it didn't fix itself. Will leave it running here again to double check
I see. And within 256 seconds after an engine restart (i.e. hit the circular arrows, top right) or hitting Poll now? (I'm just wondering if Vera ever retrieves the current setpoint from the t-stat).

I'd probably file a bug at this point: http://bugs.micasaverde.com
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 13, 2011, 07:40:22 am
Here's my log. There's probably something in here if I could make sense of the Z-Wave commands.

I'll try the engine restart next, then file. Thanks for the link

Code: [Select]
I changed the thermostat to a SP or 29 directly -

07 11/13/11 12:12:18.593 Event::Evaluate 1 Setpoint Hot Change scene Heating is true <0x803>
08 11/13/11 12:12:18.593 Scene::RunScene running 3 Heating <0x803>

My logging

50 11/13/11 12:12:18.595 luup_log:0: Heating SetPoint = 29 <0x803>
50 11/13/11 12:12:18.595 luup_log:0: Temperature = 22 <0x803>
50 11/13/11 12:12:18.596 luup_log:0: Heating already on <0x803>

Here's where I used the UI to change the SP to 22

08 11/13/11 12:12:34.481 JobHandler_LuaUPnP::HandleActionRequest device: 5 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat action: SetCurrentSetpoint <0x50008>
08 11/13/11 12:12:34.482 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=5 <0x50008>
08 11/13/11 12:12:34.482 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:TemperatureSetpoint1_Heat <0x50008>
08 11/13/11 12:12:34.483 JobHandler_LuaUPnP::HandleActionRequest argument action=SetCurrentSetpoint <0x50008>
08 11/13/11 12:12:34.483 JobHandler_LuaUPnP::HandleActionRequest argument NewCurrentSetpoint=22 <0x50008>
08 11/13/11 12:12:34.484 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.5722252454170261 <0x50008>
06 11/13/11 12:12:34.485 Device_Variable::m_szValue_set device: 5 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat variable: SetpointTarget was: 28 now: 22 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x50008>
02 11/13/11 12:12:34.503 ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x50008>
02 11/13/11 12:12:34.506 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:12:34.507 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
06 11/13/11 12:12:34.661 Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 0 now: 1 #hooks: 0 upnp: 0 v:0x78ec00/NONE duplicate:0 <0x803>
06 11/13/11 12:12:34.662 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Poll failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x7b4398/NONE duplicate:0 <0x803>
02 11/13/11 12:12:34.664 ZWJob_SendData::ReceivedFrame job job#563 :Heat SP 22 node 4 (0x7957a8) N:4 P:35 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 0 <0x803>
02 11/13/11 12:12:34.668 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:12:34.669 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
02 11/13/11 12:12:34.861 ZWJob_SendData::ReceivedFrame job job#563 :Heat SP 22 node 4 (0x7957a8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 1 <0x803>
02 11/13/11 12:12:34.866 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:12:34.866 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
02 11/13/11 12:12:35.051 ZWJob_SendData::ReceivedFrame job job#563 :Heat SP 22 node 4 (0x7957a8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 2 <0x803>
02 11/13/11 12:12:35.056 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:12:35.056 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
02 11/13/11 12:12:35.201 ZWJob_SendData::ReceivedFrame job job#563 :Heat SP 22 node 4 (0x7957a8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 3 <0x803>
02 11/13/11 12:12:35.206 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:12:35.206 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
02 11/13/11 12:12:35.391 ZWJob_SendData::ReceivedFrame job job#563 :Heat SP 22 node 4 (0x7957a8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 4 <0x803>
02 11/13/11 12:12:35.396 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:12:35.396 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
02 11/13/11 12:12:35.581 ZWJob_SendData::ReceivedFrame job job#563 :Heat SP 22 node 4 (0x7957a8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 5 <0x803>
01 11/13/11 12:12:35.584 ZWJob_SendData::JobFailed job#563 :Heat SP 22 node 4 (0x7957a8) N:4 P:70 S:5 Priority 70 <0x803>

And around here we see the failure message I see on the UI

04 11/13/11 12:12:35.586 <Job ID="563" Name="Heat SP 22 node 4" Device="5" Created="11-11-13 12:12:34" Started="11-11-13 12:12:34" Completed="11-11-13 12:12:35" Duration="1.82911000" Runtime="1.79883000" Status="Aborted" LastNote="Failed, waiting to retry when the node wakes up" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02 11/13/11 12:12:54.014 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:12:54.183 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:12:54.343 <Job ID="564" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:12:54" Started="11-11-13 12:12:54" Completed="11-11-13 12:12:54" Duration="0.331173000" Runtime="0.329297000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02 11/13/11 12:14:24.017 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:14:24.343 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:14:24.493 <Job ID="565" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:14:24" Started="11-11-13 12:14:24" Completed="11-11-13 12:14:24" Duration="0.480970000" Runtime="0.477158000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
06 11/13/11 12:15:27.451 Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321186271 now: 1321186527 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02 11/13/11 12:15:27.455 ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02 11/13/11 12:15:27.456 ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02 11/13/11 12:15:27.458 ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02 11/13/11 12:15:27.472 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:15:27.473 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
06 11/13/11 12:15:27.611 Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 1 now: 0 #hooks: 0 upnp: 0 v:0x78ec00/NONE duplicate:0 <0x803>
06 11/13/11 12:15:27.613 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x7b4398/NONE duplicate:1 <0x803>


04 11/13/11 12:15:27.616 <Job ID="566" Name="send failed node 4" Device="5" Created="11-11-13 12:15:27" Started="11-11-13 12:15:27" Completed="11-11-13 12:15:27" Duration="0.160004000" Runtime="0.143333000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02 11/13/11 12:15:27.621 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:15:27.622 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>

Waking up I guess...

04 11/13/11 12:15:27.714 <Job ID="567" Name="Wakeup done 4" Device="5" Created="11-11-13 12:15:27" Started="11-11-13 12:15:27" Completed="11-11-13 12:15:27" Duration="0.255501000" Runtime="0.94364000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02 11/13/11 12:15:28.101 ZWaveNode::HandlePollUpdate_Basic_Set node 4 device 5 unhandled <0x803>
02 11/13/11 12:15:54.016 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:15:54.173 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:15:54.324 <Job ID="568" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:15:54" Started="11-11-13 12:15:54" Completed="11-11-13 12:15:54" Duration="0.311358000" Runtime="0.307779000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
08 11/13/11 12:16:13.010 Scene::RunScene running 3 Heating <0x803>
50 11/13/11 12:16:13.012 luup_log:0: Heating SetPoint = 29 <0x803>
50 11/13/11 12:16:13.012 luup_log:0: Temperature = 22 <0x803>
50 11/13/11 12:16:13.013 luup_log:0: Heating already on <0x803>
08 11/13/11 12:16:13.014 JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321186813 now 1321186573 <0x803>
06 11/13/11 12:17:18.471 Device_Variable::m_szValue_set device: 5 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: CurrentTemperature was: 22 now: 23 #hooks: 0 upnp: 0 v:0x79ea48/NONE duplicate:0 <0x803>
02 11/13/11 12:17:24.015 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:17:24.223 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:17:24.373 <Job ID="569" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:17:24" Started="11-11-13 12:17:24" Completed="11-11-13 12:17:24" Duration="0.361195000" Runtime="0.358304000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02 11/13/11 12:18:54.017 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:18:54.183 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:18:54.333 <Job ID="570" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:18:54" Started="11-11-13 12:18:54" Completed="11-11-13 12:18:54" Duration="0.321229000" Runtime="0.316529000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
06 11/13/11 12:19:43.491 Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321186527 now: 1321186783 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02 11/13/11 12:19:43.493 ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02 11/13/11 12:19:43.495 ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02 11/13/11 12:19:43.508 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:19:43.509 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
04 11/13/11 12:19:43.633 <Job ID="571" Name="Wakeup done 4" Device="5" Created="11-11-13 12:19:43" Started="11-11-13 12:19:43" Completed="11-11-13 12:19:43" Duration="0.137509000" Runtime="0.125227000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
08 11/13/11 12:19:53.072 JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: LogIpRequest <0x50008>
08 11/13/11 12:20:13.010 Scene::RunScene running 3 Heating <0x803>
50 11/13/11 12:20:13.011 luup_log:0: Heating SetPoint = 29 <0x803>
50 11/13/11 12:20:13.012 luup_log:0: Temperature = 23 <0x803>
50 11/13/11 12:20:13.013 luup_log:0: Heating already on <0x803>
08 11/13/11 12:20:13.014 JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321187053 now 1321186813 <0x803>

I don't like the look of this.. (!)

02 11/13/11 12:20:19.011 LOG_CHECK_MEMORY_LEAK pMem start 0x7ff000 now 0x80f000 last 0x808000 leaked 65536 <0x803>
02 11/13/11 12:20:24.014 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:20:24.183 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:20:24.333 <Job ID="572" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:20:24" Started="11-11-13 12:20:24" Completed="11-11-13 12:20:24" Duration="0.321273000" Runtime="0.319391000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
08 11/13/11 12:21:49.304 JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: LogIpRequest <0x51c0e>
02 11/13/11 12:21:54.015 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:21:54.154 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:21:54.453 <Job ID="573" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:21:54" Started="11-11-13 12:21:54" Completed="11-11-13 12:21:54" Duration="0.441151000" Runtime="0.438413000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02 11/13/11 12:23:24.016 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:23:24.183 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:23:24.333 <Job ID="574" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:23:24" Started="11-11-13 12:23:24" Completed="11-11-13 12:23:24" Duration="0.321028000" Runtime="0.317303000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
06 11/13/11 12:23:59.451 Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321186783 now: 1321187039 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02 11/13/11 12:23:59.453 ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02 11/13/11 12:23:59.455 ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02 11/13/11 12:23:59.468 UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02 11/13/11 12:23:59.469 ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
04 11/13/11 12:23:59.593 <Job ID="575" Name="Wakeup done 4" Device="5" Created="11-11-13 12:23:59" Started="11-11-13 12:23:59" Completed="11-11-13 12:23:59" Duration="0.137363000" Runtime="0.125011000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
08 11/13/11 12:24:13.010 Scene::RunScene running 3 Heating <0x803>

Still at 29 locally...

50 11/13/11 12:24:13.012 luup_log:0: Heating SetPoint = 29 <0x803>
50 11/13/11 12:24:13.012 luup_log:0: Temperature = 23 <0x803>
50 11/13/11 12:24:13.013 luup_log:0: Heating already on <0x803>
08 11/13/11 12:24:13.014 JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321187293 now 1321187053 <0x803>
08 11/13/11 12:24:14.234 JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: LogIpRequest <0x5240e>
08 11/13/11 12:24:14.235 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1 <0x5240e>
08 11/13/11 12:24:14.235 JobHandler_LuaUPnP::HandleActionRequest argument action=LogIpRequest <0x5240e>
08 11/13/11 12:24:14.236 JobHandler_LuaUPnP::HandleActionRequest argument IpAddress=192.168.1.105 <0x5240e>
08 11/13/11 12:24:14.236 JobHandler_LuaUPnP::HandleActionRequest argument MacAddress=00:21:5d:db:b8:d0 <0x5240e>
02 11/13/11 12:24:54.014 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:24:54.183 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:24:54.333 <Job ID="576" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:24:54" Started="11-11-13 12:24:54" Completed="11-11-13 12:24:54" Duration="0.321092000" Runtime="0.319411000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02 11/13/11 12:26:24.015 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:26:26.380 ZWaveSerial::GetFrame 0x7f3ff7d8 timed out now 0 m_listGetFramePending 0 <0xc04>
02 11/13/11 12:26:26.381 ZWaveJobHandler::SendDataAbort got m_iFrameID 0 <0xc04>
01 11/13/11 12:26:26.382 ZWJob_PollNode::Run job job#577 :pollnode #2 (0x7d1520) N:2 P:100 S:1 ZW_Send_Data to node 2 failed 1 req 0x77cc60/1 abort m_iFrameID 0 <0xc04>
02 11/13/11 12:26:26.383 ZWJob_PollNode::PollFailed job job#577 :pollnode #2 (0x7d1520) N:2 P:100 S:1 node 2 battery 0 <0xc04>
06 11/13/11 12:26:26.383 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Poll failed #hooks: 0 upnp: 0 v:0x7b4398/NONE duplicate:0 <0xc04>
04 11/13/11 12:26:26.386 <Job ID="577" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:26:24" Started="11-11-13 12:26:24" Completed="11-11-13 12:26:26" Duration="2.373942000" Runtime="2.371272000" Status="Failed" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0xc04>
02 11/13/11 12:26:26.388 JobHandler::PurgeCompletedJobs purge job#577 :pollnode #2 (0x7d1520) N:2 P:100 S:2 pollnode #2 2 cmds status 2 <0xc04>
02 11/13/11 12:27:54.015 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02 11/13/11 12:27:54.183 ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04 11/13/11 12:27:54.333 <Job ID="578" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:27:54" Started="11-11-13 12:27:54" Completed="11-11-13 12:27:54" Duration="0.321149000" Runtime="0.318319000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
08 11/13/11 12:28:13.010 Scene::RunScene running 3 Heating <0x803>

continued...
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 13, 2011, 07:41:50 am
...

Still at 29 locally...

Code: [Select]
50 11/13/11 12:28:13.012 luup_log:0: Heating SetPoint = 29 <0x803>
50      11/13/11 12:28:13.013   luup_log:0: Temperature = 23 <0x803>
50      11/13/11 12:28:13.014   luup_log:0: Heating already on <0x803>
08      11/13/11 12:28:13.014   JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321187533 now 1321187293 <0x803>
06      11/13/11 12:28:15.461   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321187039 now: 1321187295 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02      11/13/11 12:28:15.463   ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/13/11 12:28:15.464   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/13/11 12:28:15.479   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/13/11 12:28:15.479   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
04      11/13/11 12:28:15.603   <Job ID="579" Name="Wakeup done 4" Device="5" Created="11-11-13 12:28:15" Started="11-11-13 12:28:15" Completed="11-11-13 12:28:15" Duration="0.138169000" Runtime="0.124724000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
06      11/13/11 12:28:30.501   Device_Variable::m_szValue_set device: 5 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: CurrentTemperature was: 23 now: 23 #hooks: 0 upnp: 0 v:0x79ea48/NONE duplicate:1 <0x803>
06      11/13/11 12:28:30.551   Device_Variable::m_szValue_set device: 5 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: CurrentTemperature was: 23 now: 23 #hooks: 0 upnp: 0 v:0x79ea48/NONE duplicate:1 <0x803>
02      11/13/11 12:29:04.014   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:29:04.183   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:29:04.334   <Job ID="580" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:29:04" Started="11-11-13 12:29:04" Completed="11-11-13 12:29:04" Duration="0.321377000" Runtime="0.319684000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02      11/13/11 12:30:00.010   Energy::SetNextEnergyLogAlarm <0x402>
02      11/13/11 12:30:00.011   Energy::SetNextEnergyLogAlarm 2011-11-13 12:30:00 <0x402>
02      11/13/11 12:30:00.012   Energy::LogEnergyUsageOnServer starting 0 <0x402>
02      11/13/11 12:30:34.015   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:30:36.350   ZWaveSerial::GetFrame 0x7f3ff7d8 timed out now 0 m_listGetFramePending 0 <0xc04>
02      11/13/11 12:30:36.351   ZWaveJobHandler::SendDataAbort got m_iFrameID 0 <0xc04>
01      11/13/11 12:30:36.352   ZWJob_PollNode::Run job job#581 :pollnode #2 (0x773378) N:2 P:100 S:1 ZW_Send_Data to node 2 failed 1 req 0x7aa620/1 abort m_iFrameID 0 <0xc04>
02      11/13/11 12:30:36.353   ZWJob_PollNode::PollFailed job job#581 :pollnode #2 (0x773378) N:2 P:100 S:1 node 2 battery 0 <0xc04>
06      11/13/11 12:30:36.354   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Poll failed now: Poll failed #hooks: 0 upnp: 0 v:0x7b4398/NONE duplicate:1 <0xc04>
04      11/13/11 12:30:36.356   <Job ID="581" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:30:34" Started="11-11-13 12:30:34" Completed="11-11-13 12:30:36" Duration="2.343930000" Runtime="2.341156000" Status="Failed" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0xc04>
02      11/13/11 12:30:36.357   JobHandler::PurgeCompletedJobs purge job#581 :pollnode #2 (0x773378) N:2 P:100 S:2 pollnode #2 2 cmds status 2 <0xc04>
02      11/13/11 12:32:04.016   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:32:04.193   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:32:04.343   <Job ID="582" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:32:04" Started="11-11-13 12:32:04" Completed="11-11-13 12:32:04" Duration="0.331177000" Runtime="0.327628000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
08      11/13/11 12:32:13.010   Scene::RunScene running 3 Heating <0x803>

Still at 29 locally...

50      11/13/11 12:32:13.011   luup_log:0: Heating SetPoint = 29 <0x803>
50      11/13/11 12:32:13.012   luup_log:0: Temperature = 23 <0x803>
50      11/13/11 12:32:13.013   luup_log:0: Heating already on <0x803>
08      11/13/11 12:32:13.013   JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321187773 now 1321187533 <0x803>
06      11/13/11 12:32:31.501   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321187295 now: 1321187551 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02      11/13/11 12:32:31.503   ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/13/11 12:32:31.504   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/13/11 12:32:31.518   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/13/11 12:32:31.519   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
04      11/13/11 12:32:31.623   <Job ID="583" Name="Wakeup done 4" Device="5" Created="11-11-13 12:32:31" Started="11-11-13 12:32:31" Completed="11-11-13 12:32:31" Duration="0.118462000" Runtime="0.105045000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02      11/13/11 12:33:14.015   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:33:14.233   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:33:36.370   ZWaveSerial::GetFrame 0x7f3ff758 timed out now 0 m_listGetFramePending 0 <0xc04>
02      11/13/11 12:33:36.371   ZWaveJobHandler::SendDataAbort got m_iFrameID 0 <0xc04>
02      11/13/11 12:33:36.372   ZWJob_PollNode::ReturnMessageNotReceived -end- job job#584 :pollnode #2 (0x796350) N:2 P:100 S:5 node 2 didn't reply iOK 49 iBadTx 0 iNoReply 1 Abort returned m_iFrameID 0 <0xc04>
02      11/13/11 12:33:36.373   ZWJob_PollNode::PollFailed job job#584 :pollnode #2 (0x796350) N:2 P:100 S:5 node 2 battery 0 <0xc04>
06      11/13/11 12:33:36.374   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Poll failed now: Poll failed #hooks: 0 upnp: 0 v:0x7b4398/NONE duplicate:1 <0xc04>
04      11/13/11 12:33:36.376   <Job ID="584" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:33:14" Started="11-11-13 12:33:14" Completed="11-11-13 12:33:36" Duration="22.363449000" Runtime="22.361179000" Status="Failed" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0xc04>
02      11/13/11 12:33:36.377   JobHandler::PurgeCompletedJobs purge job#584 :pollnode #2 (0x796350) N:2 P:100 S:2 pollnode #2 2 cmds status 2 <0xc04>
02      11/13/11 12:34:44.015   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:34:44.193   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:34:44.423   <Job ID="585" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:34:44" Started="11-11-13 12:34:44" Completed="11-11-13 12:34:44" Duration="0.411191000" Runtime="0.408320000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
08      11/13/11 12:36:13.010   Scene::RunScene running 3 Heating <0x803>

Still at 29 locally...

50      11/13/11 12:36:13.012   luup_log:0: Heating SetPoint = 29 <0x803>
50      11/13/11 12:36:13.012   luup_log:0: Temperature = 23 <0x803>
50      11/13/11 12:36:13.013^[[A^[[5~

etc.etc.
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 13, 2011, 07:52:31 am
No, the engine restart doesn't fix it. Will file bug report now.

I'm happy to take a look at what the code is doing wrong - presumably not correctly updating a local variable after the pending write succeeds - if somebody points me to the right place to look...

Code: [Select]
03      11/13/11 12:42:25.284   LuaUPNP: starting bLogUPnP 0 <0x400>
02      11/13/11 12:42:25.298   JobHandler_LuaUPnP::Run: pid 6189 didn't exit <0x400>
09      11/13/11 12:42:25.418   UserData::ParseRooms 1 Back Room bSynced 1 <0x400>
09      11/13/11 12:42:25.419   UserData::ParseRooms 2 Kitchen bSynced 1 <0x400>
09      11/13/11 12:42:25.419   UserData::ParseRooms 3 Front Room bSynced 1 <0x400>
09      11/13/11 12:42:25.441   UserData::ParseRooms 4 Hall bSynced 1 <0x400>
03      11/13/11 12:42:25.449   UserData::LoadUserData BuildVersion: *1.1.1362* SvnVersion: *5226* Model: 2 SERCOMM NA401 flush: 0 changed: 0 resync: 9437 syncdevice:0 <0x400>
02      11/13/11 12:42:26.186   Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x400>
02      11/13/11 12:42:26.192   Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x400>
02      11/13/11 12:42:26.203   Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x400>
06      11/13/11 12:42:26.323   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastUpdate was: 1321149613 now: 1321188146 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x400>
06      11/13/11 12:42:26.325   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusID was: 2 now: 7 #hooks: 0 upnp: 0 v:0x7ab7d8/NONE duplicate:0 <0x400>
06      11/13/11 12:42:26.326   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusText was: Resetting ZWave Network now: Starting ZWave Network #hooks: 0 upnp: 0 v:0x7b4298/NONE duplicate:0 <0x400>
02      11/13/11 12:42:26.644   ZWaveJobHandler::Run connect to /dev/tts/1 -0 lock 1 <0xc04>
02      11/13/11 12:42:26.716   ZWaveJobHandler::Run connected to /dev/tts/1=1 i=0 <0xc04>
06      11/13/11 12:42:26.768   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusID was: 7 now: 7 #hooks: 0 upnp: 0 v:0x7ab7d8/NONE duplicate:1 <0xc04>
06      11/13/11 12:42:26.769   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusText was: Starting ZWave Network now: Starting ZWave Network #hooks: 0 upnp: 0 v:0x7b4298/NONE duplicate:1 <0xc04>
03      11/13/11 12:42:31.272   ZWJob_Initialize::JobDone version 3.20 type 1 role is 0 house id f937175b node id 1 suc 0 IsSecondary 0 bOnOtherNetwork 0 NodeIdServerPresent 0 IsRealPrimary 1 IsSuc 0 <0xc04>
06      11/13/11 12:42:31.279   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: VersionInfo was: 3.20 L:1 now: 3.20 L:1 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0xc04>
06      11/13/11 12:42:31.280   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: HomeID was: House: f937175b Node 1 Suc 0 now: House: f937175b Node 1 Suc 0 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0xc04>
06      11/13/11 12:42:31.281   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: Role was: Master SIS:NO PRI:YES now: Master SIS:NO PRI:YES #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0xc04>
04      11/13/11 12:42:31.284   <Job ID="0" Name="init" Device="1" Created="11-11-13 12:42:26" Started="11-11-13 12:42:26" Completed="11-11-13 12:42:31" Duration="4.438797000" Runtime="4.431230000" Status="Successful" LastNote=""/> <0xc04>
02      11/13/11 12:42:31.351   ZWave::Start reset 0 inter 0 upgrade 0 use45:1 minor:20 model:2 port:/dev/tts/1 nodes:3 <0x400>
02      11/13/11 12:42:31.355   JobHandler_LuaUPnP::StartPlugins Energy STARTED <0x400>
02      11/13/11 12:42:31.532   XXXX setinitial UpdateManualRoute node 1 = (null) <0xc04>
02      11/13/11 12:42:31.532   XXXX UpdateManualRoute setinitial node 1 m_cRoutePosition 0 <0xc04>
02      11/13/11 12:42:31.534   ZWaveNode::UpdateCommandClasses node 1 empty -- -- <0xc04>
02      11/13/11 12:42:31.535   XXXX setinitial UpdateManualRoute node 2 = 0-5x <0xc04>
02      11/13/11 12:42:31.536   UpdateManualRoute XXX1 node 2 route 0-5x <0xc04>
02      11/13/11 12:42:31.537   XXXX UpdateManualRoute setinitial node 2 m_cRoutePosition 0 <0xc04>
06      11/13/11 12:42:31.539   Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:HaDevice1 variable: Configured was: 1 now: 1 #hooks: 0 upnp: 0 v:0x78d7a0/NONE duplicate:1 <0xc04>
06      11/13/11 12:42:31.540   Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:HaDevice1 variable: Configured was: 1 now: 1 #hooks: 0 upnp: 0 v:0x78d7a0/NONE duplicate:1 <0xc04>
02      11/13/11 12:42:31.541   XXXX setinitial UpdateManualRoute node 4 = (null) <0xc04>
02      11/13/11 12:42:31.542   XXXX UpdateManualRoute setinitial node 4 m_cRoutePosition 0 <0xc04>
06      11/13/11 12:42:31.544   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: Configured was: 1 now: 1 #hooks: 0 upnp: 0 v:0x78d7a0/NONE duplicate:1 <0xc04>
06      11/13/11 12:42:31.545   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: Configured was: 1 now: 1 #hooks: 0 upnp: 0 v:0x78d7a0/NONE duplicate:1 <0xc04>
09      11/13/11 12:42:31.547   ZWaveJobHandler::UpdateNodes dongle is node 1 device 2 iExtraNodesForTest 0 <0xc04>
06      11/13/11 12:42:31.547   Device_Variable::m_szValue_set device: 2 service: urn:micasaverde-com:serviceId:SceneController1 variable: Scenes was:  now:  #hooks: 0 upnp: 0 v:0x78f1a8/NONE duplicate:1 <0xc04>
09      11/13/11 12:42:31.549   ZWaveJobHandler::UpdateNodes node 2 Device_NumTemplate D_HVAC_ZoneThermostat1.xml type ZWaveThermostat Device_Num 3 Room 2 auto-conf -1 cap 0xd2 sec 0x9c res 0x0 bas 0x4 gen 0x8 spe 0x0 config 1 secure 0 Combi Boiler classes 25,40,72,86, mfr: Horstmann Controls Limited/ mfr: 0x59 prodtype: 0x3 prodid: 0x1 notlistening: 0 list:1 rout:1 beam:1 rtsl:1 sec:0 1k:0 250:0 <0xc04>
02      11/13/11 12:42:31.550   ZWaveJobHandler::UpdateNodes not configuring node 4 because it's not listening <0xc04>
09      11/13/11 12:42:31.561   ZWaveJobHandler::UpdateNodes node 4 Device_NumTemplate D_HVAC_ZoneThermostat1.xml type ZWaveThermostat Device_Num 5 Room 1 auto-conf -1 cap 0x12 sec 0x96 res 0x0 bas 0x1 gen 0x8 spe 0x0 config 1 secure 0 _Thermostat classes 31,43,70,72,80,84,85,86, mfr: Horstmann Controls Limited/ mfr: 0x59 prodtype: 0x1 prodid: 0x3 notlistening: 1 list:0 rout:0 beam:1 rtsl:0 sec:0 1k:0 250:0 <0xc04>
06      11/13/11 12:42:31.562   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusID was: 7 now: 5 #hooks: 0 upnp: 0 v:0x7ab7d8/NONE duplicate:0 <0xc04>
06      11/13/11 12:42:31.563   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusText was: Starting ZWave Network now: Configuring ZWave devices #hooks: 0 upnp: 0 v:0x7b4298/NONE duplicate:0 <0xc04>
04      11/13/11 12:42:31.567   <Job ID="1" Name="getnodes" Device="" Created="11-11-13 12:42:31" Started="11-11-13 12:42:31" Completed="11-11-13 12:42:31" Duration="0.212695000" Runtime="0.167008000" Status="Successful" LastNote=""/> <0xc04>
02      11/13/11 12:42:31.573   JobHandler_LuaUPnP::StartUPnPServices starting with /etc/cmh-ludl/ / http://192.168.1.116:49451/luaupnp.xml <0x400>
09      11/13/11 12:42:31.703   JobHandler_LuaUPnP::Run device 3 Combi Boiler room 2 type urn:schemas-upnp-org:device:HVAC_ZoneThermostat:1 id 2 parent 1/0x756ed0 upnp: 0 <0x400>
09      11/13/11 12:42:31.704   JobHandler_LuaUPnP::Run device 2 _Scene Controller room 0 type urn:schemas-micasaverde-com:device:SceneController:1 id 1 parent 1/0x753c68 upnp: 0




 <0x400>
09      11/13/11 12:42:31.705   JobHandler_LuaUPnP::Run device 5 _Thermostat room 1 type urn:schemas-upnp-org:device:HVAC_ZoneThermostat:1 id 4 parent 1/0x773628 upnp: 0 <0x400>
09      11/13/11 12:42:31.706   JobHandler_LuaUPnP::Run device 1 ZWave room 0 type urn:schemas-micasaverde-com:device:ZWaveNetwork:1 id  parent 0/0x753518 upnp: 0 <0x400>
03      11/13/11 12:42:31.746   JobHandler_LuaUPnP::Run ready 4 devices installation 31706 missing  version *1.1.1362*  allow_evt: 1 allow_ud: 1 upnp 1 changed: 0 pMem 0x7ea000 start 7647232 diff: 651264 <0x400>
02      11/13/11 12:42:33.011   ZWaveJobHandler::SetDeviceStatus XXX2 0/0/0/0 <0x803>
06      11/13/11 12:42:34.014   Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: ManufacturerInfo was: 89,3,1 now: 89,3,1 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06      11/13/11 12:42:34.016   Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: Capabilities was: 210,156,0,4,8,0,L,R,B,RS,|37,64,114,134, now: 210,156,0,4,8,0,L,R,B,RS,|37,64,114,134, #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06      11/13/11 12:42:34.017   Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: Neighbors was: 1, now: 1, #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06      11/13/11 12:42:34.018   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: ManufacturerInfo was: 89,1,3 now: 89,1,3 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06      11/13/11 12:42:34.018   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: Capabilities was: 18,150,0,1,8,0,B,|49,67,112,114,128,132:2,133,134, now: 18,150,0,1,8,0,B,|49,67,112,114,128,132:2,133,134, #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06      11/13/11 12:42:34.019   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusID was: 5 now: 1 #hooks: 0 upnp: 0 v:0x7ab7d8/NONE duplicate:0 <0x803>
06      11/13/11 12:42:34.020   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusText was: Configuring ZWave devices now: OK #hooks: 0 upnp: 0 v:0x7b4298/NONE duplicate:0 <0x803>
02      11/13/11 12:42:46.016   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:42:46.194   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:42:46.403   <Job ID="2" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:42:46" Started="11-11-13 12:42:46" Completed="11-11-13 12:42:46" Duration="0.390921000" Runtime="0.388785000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
06      11/13/11 12:43:24.562   Device_Variable::m_szValue_set device: 5 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: CurrentTemperature was: 23 now: 24 #hooks: 0 upnp: 0 v:0x79ea48/NONE duplicate:0 <0x803>
02      11/13/11 12:44:16.014   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:44:16.173   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:44:16.343   <Job ID="3" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:44:16" Started="11-11-13 12:44:16" Completed="11-11-13 12:44:16" Duration="0.331084000" Runtime="0.329345000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02      11/13/11 12:44:35.123   UPnPCallbackEventHandler 6 start PIDLOG2 11972 <0x2009>
02      11/13/11 12:44:39.123   UPnPCallbackEventHandler 6 start PIDLOG2 11973 <0x240a>
02      11/13/11 12:45:01.011   UPnPCallbackEventHandler 7 start PIDLOG2 11976 <0x300d>
06      11/13/11 12:45:19.471   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321188063 now: 1321188319 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02      11/13/11 12:45:19.473

        ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/13/11 12:45:19.475   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/13/11 12:45:19.488   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/13/11 12:45:19.488   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
04      11/13/11 12:45:19.613   <Job ID="4" Name="Wakeup done 4" Device="5" Created="11-11-13 12:45:19" Started="11-11-13 12:45:19" Completed="11-11-13 12:45:19" Duration="0.137271000" Runtime="0.126147000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02      11/13/11 12:45:46.016   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:45:46.193   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:45:46.473   <Job ID="5" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:45:46" Started="11-11-13 12:45:46" Completed="11-11-13 12:45:46" Duration="0.461014000" Runtime="0.457381000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
08      11/13/11 12:46:26.010   Scene::RunScene running 3 Heating <0x803>
50      11/13/11 12:46:26.013   luup_log:0: Heating SetPoint = 29 <0x803>
50      11/13/11 12:46:26.013   luup_log:0: Temperature = 24 <0x803>
50      11/13/11 12:46:26.014   luup_log:0: Heating already on <0x803>
08      11/13/11 12:46:26.015   JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321188626 now 1321188386 <0x803>
02      11/13/11 12:47:16.016   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:47:16.193   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:47:16.343   <Job ID="6" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:47:16" Started="11-11-13 12:47:16" Completed="11-11-13 12:47:16" Duration="0.331161000" Runtime="0.328301000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02      11/13/11 12:48:46.016   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:48:46.243   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:48:46.394   <Job ID="7" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:48:46" Started="11-11-13 12:48:46" Completed="11-11-13 12:48:46" Duration="0.381254000" Runtime="0.377535000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
06      11/13/11 12:49:35.471   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321188319 now: 1321188575 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02      11/13/11 12:49:35.473   ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/13/11 12:49:35.474   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/13/11 12:49:35.489   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/13/11 12:49:35.490   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
04      11/13/11 12:49:35.613   <Job ID="8" Name="Wakeup done 4" Device="5" Created="11-11-13 12:49:35" Started="11-11-13 12:49:35" Completed="11-11-13 12:49:35" Duration="0.138281000" Runtime="0.124657000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02      11/13/11 12:50:16.014   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
02      11/13/11 12:50:16.363   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
04      11/13/11 12:50:16.513   <Job ID="9" Name="pollnode #2 2 cmds" Device="3" Created="11-11-13 12:50:16" Started="11-11-13 12:50:16" Completed="11-11-13 12:50:16" Duration="0.501066000" Runtime="0.499414000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
08      11/13/11 12:50:26.010   Scene::RunScene running 3 Heating <0x803>
50      11/13/11 12:50:26.011   luup_log:0: Heating SetPoint = 29 <0x803>
50      11/13/11 12:50:26.012   luup_log:0: Temperature = 24 <0x803>
50      11/13/11 12:50:26.013   luup_log:0: Heating already on <0x803
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 13, 2011, 08:27:31 am

The Mantis engine seems not to want to email me an account activation, so I guess I'll have to wait...
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: mcvflorin on November 14, 2011, 07:48:37 am
Hi ajlennon,

Vera tells the thermostat to change its setpoint, and doesn't update its internal setpoint variable until it gets confirmation from the thermostat that the setpoint successfully changed. Maybe the thermostat isn't replying back its status? In your logs you don't have Z-Wave log lines (lines starting with 41 and 42) to see the messages exchanged between Vera and the thermostat, which would help finding the cause.
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 14, 2011, 09:04:58 am
Hi mcvflorin (Florin?),

41,42 - useful to know thanks. Here's a new log of my attempt to change the SP from to 26. It updated in the thermostat but not the UI

Here's where I attempt to change the SP in the UI -

Code: [Select]
       luup_log:6: dataMine: Watching: D[5] S[urn:upnp-org:serviceId:TemperatureSensor1] V[CurrentTemperature] <0x402>
06      11/14/11 14:02:07.225   Device_Variable::m_szValue_set device: 6 service: urn:cd-jackson-com:serviceId:DataMine1 variable: ChannelCnt was: 3 now: 3 #hooks: 0 upnp: 0 v:0x7b9fd8/NONE duplicate:1 <0x402>
06      11/14/11 14:02:07.226   Device_Variable::m_szValue_set device: 6 service: urn:cd-jackson-com:serviceId:DataMine1 variable: ChannelRec was: 3 now: 3 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x402>
02      11/14/11 14:02:20.015   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.017   ZWaveSerial::Send XXXX  node 2 using route 0.0.40.137 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.018   0x1 0xd 0x0 0x19 0x2 0x2 0x25 0x2 0x5 0x0 0x0 0x0 0x0 0x1 0xc8 (#\r####%########) <0xc04>
42      11/14/11 14:02:20.041   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.041   got expected ACK <0x1406>
41      11/14/11 14:02:20.042   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.090   0x1 0x5 0x0 0x19 0x1 0x0 0xe2 (#######) <0x1406>
41      11/14/11 14:02:20.091   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.141   0x1 0x9 0x0 0x4 0x0 0x2 0x3 0x25 0x3 0x0 0xd5 (#######%###) <0x1406>
41      11/14/11 14:02:20.142   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.154   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.155   ZWaveSerial::Send XXXX  node 2 using route 0.0.40.137 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.156   0x1 0xd 0x0 0x19 0x2 0x2 0x40 0x2 0x5 0x0 0x0 0x0 0x0 0x2 0xae (#\r####@########) <0xc04>
08      11/14/11 14:02:20.168   JobHandler_LuaUPnP::HandleActionRequest device: 5 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat action: SetCurrentSetpoint <0x4408>
08      11/14/11 14:02:20.169   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=5 <0x4408>
08      11/14/11 14:02:20.170   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:TemperatureSetpoint1_Heat <0x4408>
08      11/14/11 14:02:20.171   JobHandler_LuaUPnP::HandleActionRequest argument action=SetCurrentSetpoint <0x4408>
08      11/14/11 14:02:20.171   JobHandler_LuaUPnP::HandleActionRequest argument NewCurrentSetpoint=26 <0x4408>
08      11/14/11 14:02:20.172   JobHandler_LuaUPnP::HandleActionRequest argument rand=0.631132904025657 <0x4408>
06      11/14/11 14:02:20.173   Device_Variable::m_szValue_set device: 5 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat variable: SetpointTarget was: 22 now: 26 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x4408>
42      11/14/11 14:02:20.191   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.191   got expected ACK <0x1406>
41      11/14/11 14:02:20.192   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.195   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x4408>
41      11/14/11 14:02:20.202   0x1 0x3 0x0 0x16 0xea (#####) <0xc04>
42      11/14/11 14:02:20.241   0x1 0x5 0x0 0x19 0x2 0x0 0xe1 0x18 (########) <0x1406>
41      11/14/11 14:02:20.241   ACK: 0x6 (#) <0x1406>
01      11/14/11 14:02:20.251   got CAN <0x1406>
01      11/14/11 14:02:20.252   ZWaveSerial::Send m_iFrameID 29 type 0x0 command 0x16 got repeat failure 24 iNumFailedResponse 1 time 22251 start time 22210 wait 2000 m_iSendsWithoutReceive 0 <0xc04>
01      11/14/11 14:02:20.252   ZWaveJobHandler::SendDataAbort failed <0xc04>
01      11/14/11 14:02:20.253   ZWJob_PollNode::Run job job#2 :pollnode #2 (0x798820) N:2 P:100 S:1 ZW_Send_Data to node 2 failed 4 req (nil)/-1 abort m_iFrameID 0 <0xc04>
02      11/14/11 14:02:20.254   ZWJob_PollNode::PollFailed job job#2 :pollnode #2 (0x798820) N:2 P:100 S:1 node 2 battery 0 <0xc04>
06      11/14/11 14:02:20.255   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Poll failed #hooks: 0 upnp: 0 v:0x7f5d08/NONE duplicate:0 <0xc04>
04      11/14/11 14:02:20.258   <Job ID="2" Name="pollnode #2 2 cmds" Device="3" Created="11-11-14 14:02:20" Started="11-11-14 14:02:20" Completed="11-11-14 14:02:20" Duration="0.245098000" Runtime="0.242949000" Status="Failed" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0xc04>
41      11/14/11 14:02:20.261   0x1 0x3 0x0 0x16 0xea (#####) <0x803>
42      11/14/11 14:02:20.291   0x1 0x9 0x0 0x4 0x0 0x2 0x3 0x40 0x3 0x0 0xb0 0x18 (#######@####) <0x1406>
41      11/14/11 14:02:20.292   ACK: 0x6 (#) <0x1406>
01      11/14/11 14:02:20.301   got CAN <0x1406>
01      11/14/11 14:02:20.302   ZWaveSerial::Send m_iFrameID 28 type 0x0 command 0x16 got repeat failure 24 iNumFailedResponse 1 time 22301 start time 22270 wait 2000 m_iSendsWithoutReceive 0 <0x803>
01      11/14/11 14:02:20.302   ZWJob_PollNode::Abort job job#2 :pollnode #2 (0x798820) N:2 P:100 S:2 to node 2 failed 2 <0x803>
02      11/14/11 14:02:20.304   JobHandler::PurgeCompletedJobs purge job#2 :pollnode #2 (0x798820) N:2 P:100 S:2 pollnode #2 2 cmds status 2 <0xc04>
02      11/14/11 14:02:20.307   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.308   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.310   ZWaveSerial::Send XXXX  node 4 using route 0.101.32.35 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.311   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x5 0x0 0x0 0x0 0x0 0x3 0xa9 (######C###########) <0xc04>
42      11/14/11 14:02:20.341   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.341   got expected ACK <0x1406>
41      11/14/11 14:02:20.342   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.471   0x1 0x5 0x0 0x19 0x3 0x6 0xe6 (#######) <0x1406>
41      11/14/11 14:02:20.471   ACK: 0x6 (#) <0x1406>
06      11/14/11 14:02:20.481   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 0 now: 1 #hooks: 0 upnp: 0 v:0x79e478/NONE duplicate:0 <0x803>
06      11/14/11 14:02:20.483   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Poll failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x7f5d08/NONE duplicate:0 <0x803>
02      11/14/11 14:02:20.484   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:35 S:5 to node 4 command 67/1 failed m_cTxStatus 6 retries 0 <0x803>
02      11/14/11 14:02:20.488   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.489   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.491   ZWaveSerial::Send XXXX  node 4 using route 0.58.55.48 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.492   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x4 0x8e (######C####%######) <0xc04>
42      11/14/11 14:02:20.521   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.521   got expected ACK <0x1406>
41      11/14/11 14:02:20.522   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.691   0x1 0x5 0x0 0x19 0x4 0x1 0xe6 (#######) <0x1406>
41      11/14/11 14:02:20.691   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.701   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 1 <0x803>
02      11/14/11 14:02:20.705   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.706   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.708   ZWaveSerial::Send XXXX  node 4 using route 0.58.55.48 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.709   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x5 0x8f (######C####%######) <0xc04>
42      11/14/11 14:02:20.740   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.741   got expected ACK <0x1406>
41      11/14/11 14:02:20.742   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.961   0x1 0x5 0x0 0x19 0x5 0x1 0xe7 (#######) <0x1406>
41      11/14/11 14:02:20.961   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.971   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 2 <0x803>
02      11/14/11 14:02:20.975   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.976

And here's where it actually changes when the thermostat wakes up

Code: [Select]
02      11/14/11 14:03:50.183   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
41      11/14/11 14:03:50.184   ZWaveSerial::Send XXXX  node 2 using route 0.0.44.184 autoroute: 1 direct: 0 ... <0xc04>
41      11/14/11 14:03:50.186   0x1 0xd 0x0 0x19 0x2 0x2 0x40 0x2 0x5 0x0 0x0 0x0 0x0 0xa 0xa6 (#\r####@######\n#) <0xc04>
42      11/14/11 14:03:50.221   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:03:50.221   got expected ACK <0x1406>
41      11/14/11 14:03:50.222   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:03:50.270   0x1 0x5 0x0 0x19 0xa 0x0 0xe9 (####\n##) <0x1406>
41      11/14/11 14:03:50.271   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:03:50.321   0x1 0x9 0x0 0x4 0x0 0x2 0x3 0x40 0x3 0x0 0xb0 (#######@###) <0x1406>
41      11/14/11 14:03:50.321   ACK: 0x6 (#) <0x1406>
04      11/14/11 14:03:50.333   <Job ID="4" Name="pollnode #2 2 cmds" Device="3" Created="11-11-14 14:03:50" Started="11-11-14 14:03:50" Completed="11-11-14 14:03:50" Duration="0.321132000" Runtime="0.319539000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02      11/14/11 14:04:16.123   UPnPCallbackEventHandler 6 start PIDLOG2 20580 <0x2009>
42      11/14/11 14:04:16.801   0x1 0x8 0x0 0x4 0x0 0x4 0x2 0x84 0x7 0x76 (#########v) <0x1406>
41      11/14/11 14:04:16.802   ACK: 0x6 (#) <0x1406>
06      11/14/11 14:04:16.811   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321279200 now: 1321279456 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02      11/14/11 14:04:16.814   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/14/11 14:04:16.815   ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/14/11 14:04:16.816   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/14/11 14:04:16.834   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:04:16.835   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:04:16.836   ZWaveSerial::Send XXXX  node 4 using route 0.0.49.52 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:04:16.837   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x5 0x0 0x0 0x0 0x0 0xb 0xa1 (######C###########) <0xc04>
42      11/14/11 14:04:16.851   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:04:16.851   got expected ACK <0x1406>
41      11/14/11 14:04:16.852   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:04:16.911   0x1 0x5 0x0 0x19 0xb 0x0 0xe8 (#######) <0x1406>
41      11/14/11 14:04:16.911   ACK: 0x6 (#) <0x1406>
06      11/14/11 14:04:16.921   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 1 now: 0 #hooks: 0 upnp: 0 v:0x79e478/NONE duplicate:0 <0x803>
06      11/14/11 14:04:16.922   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x7f5d08/NONE duplicate:1 <0x803>
04      11/14/11 14:04:16.925   <Job ID="5" Name="send failed node 4" Device="5" Created="11-11-14 14:04:16" Started="11-11-14 14:04:16" Completed="11-11-14 14:04:16" Duration="0.110942000" Runtime="0.103293000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02      11/14/11 14:04:16.929   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:04:16.931   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:04:16.933   ZWaveSerial::Send XXXX  node 4 using route 0.0.88.14 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:04:16.934   0x1 0xd 0x0 0x19 0x4 0x2 0x84 0x8 0x5 0x0 0x0 0x0 0x0 0xc 0x68 (#\r############h) <0xc04>
42      11/14/11 14:04:16.961   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:04:16.961   got expected ACK <0x1406>
41      11/14/11 14:04:16.962   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:04:17.011   0x1 0x5 0x0 0x19 0xc 0x0 0xef (#######) <0x1406>
41      11/14/11 14:04:17.011   ACK: 0x6 (#) <0x1406>
04      11/14/11 14:04:17.024   <Job ID="6" Name="Wakeup done 4" Device="5" Created="11-11-14 14:04:16" Started="11-11-14 14:04:16" Completed="11-11-14 14:04:17" Duration="0.206535000" Runtime="0.94609000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/>^[[5~
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 15, 2011, 06:08:28 am

All of a sudden overnight Vera 2 is no longer communicating with either the boiler actuator or the thermostat (!)

I'm getting various messages from the UI in including "unable to communicate with node" and turn heating on or off

I've tried healing the network.

The logs seem to be saying something about the actuator not being configured!

Code: [Select]
02      11/15/11 11:03:13.011   UPnPCallbackEventHandler 7 start PIDLOG2 7265 <0x300d>
08      11/15/11 11:04:38.010   Scene::RunScene running 3 Heating <0x803>
50      11/15/11 11:04:38.012   luup_log:0: Heating SetPoint = 19 <0x803>
50      11/15/11 11:04:38.013   luup_log:0: Temperature = 19 <0x803>
50      11/15/11 11:04:38.013   luup_log:0: Heating already off <0x803>
08      11/15/11 11:04:38.014   JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321355318 now 1321355078 <0x803>
08      11/15/11 11:07:17.928   JobHandler_LuaUPnP::HandleActionRequest device: 3 service: urn:upnp-org:serviceId:HVAC_UserOperatingMode1 action: SetModeTarget <0x5408>
08      11/15/11 11:07:17.929   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=3 <0x5408>
08      11/15/11 11:07:17.930   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:HVAC_UserOperatingMode1 <0x5408>
08      11/15/11 11:07:17.931   JobHandler_LuaUPnP::HandleActionRequest argument action=SetModeTarget <0x5408>
08      11/15/11 11:07:17.931   JobHandler_LuaUPnP::HandleActionRequest argument NewModeTarget=HeatOn <0x5408>
08      11/15/11 11:07:17.932   JobHandler_LuaUPnP::HandleActionRequest argument rand=0.6412345498113862 <0x5408>
02      11/15/11 11:07:17.970   ZWaveThermostat::ReceivedMessage no COMMAND_CLASS_THERMOSTAT_MODE <0x5408>
02      11/15/11 11:07:17.971   ZWaveNode::ReceivedMessage serv urn:upnp-org:serviceId:HVAC_UserOperatingMode1 action SetModeTarget unhandled <0x5408>
02      11/15/11 11:07:17.971   JobHandler_LuaUPnP::RunAction device 3 action urn:upnp-org:serviceId:HVAC_UserOperatingMode1/SetModeTarget failed with -911/ERROR Thermostat is not configured <0x5408>
08      11/15/11 11:07:21.207   JobHandler_LuaUPnP::HandleActionRequest device: 3 service: urn:upnp-org:serviceId:HVAC_UserOperatingMode1 action: SetModeTarget <0x5408>
08      11/15/11 11:07:21.208   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=3 <0x5408>
08      11/15/11 11:07:21.208   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:HVAC_UserOperatingMode1 <0x5408>
08      11/15/11 11:07:21.209   JobHandler_LuaUPnP::HandleActionRequest argument action=SetModeTarget <0x5408>
08      11/15/11 11:07:21.209   JobHandler_LuaUPnP::HandleActionRequest argument NewModeTarget=HeatOn

I'm baffled as to what changed overnight. Any ideas?
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: oTi@ on November 15, 2011, 06:30:58 am
I'm baffled as to what changed overnight. Any ideas?
Is there a repair report for 2am this morning? (Z-Wave device > Repair)
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 15, 2011, 06:41:54 am
No there's only one from later on in the morning after I initiated it to try to fix the problem -

Code: [Select]
11-11-15 10:51:36 report for HealNetwork.  Successful: Y Updated net: N  mr_only:0 Job ID: job#64 :heal network (0x785a98) P:71 S:5



=======NEIGHBOR NODE UPDATES=======
Node 2 Device 3 Combi Boiler neighbor nodes updated 0 times (incomplete 5 in a row 0), woke up 0 times configured: NO
Node 4 Device 5 _Thermostat neighbor nodes updated 0 times (incomplete 1 in a row 0), woke up 1 times configured: NO


=======STRESS TEST RESULT=======
Node 2 Device 3 Combi Boiler
  Test: NOP Sent 2 test frames and 0 succeeded (0%) with average of 0.000000 seconds and maximum of 0.000000 seconds
  Test: Basic_Get Sent 2 test frames and 0 succeeded (0%) with average of 0.000000 seconds and maximum of 0.000000 seconds
  Test: Get Node Info  Sent 2 test frames and 0 succeeded (0%) with average of 0.000000 seconds and maximum of 0.000000 seconds
  --HEALTH SCORE: 0--


=======NEIGHBOR NODE RESULT=======
Node 2 Device 3 Combi Boiler took 0.64126000 seconds to report neighbors:
Node 4 Device 5 _Thermostat took 0.36870000 seconds to report neighbors:

Inversely:


=======EDGE NODE PROFILE=======



=======DETAILED LOG=======
--Stage #1 started: 11-11-15 10:51:36 completed: 11-11-15 10:51:36 successful: N
---11-11-15 10:47:06 Job unknown
--Stage #2 started: 11-11-15 10:47:06 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:06 Pass 0/5 Updating neighbors for node 2
---11-11-15 10:47:13 Job job#65 :heal_neighbor_node 2 (0x7ea5c8) P:70 S:4 was Successful
---11-11-15 10:47:13 Pass 0/5 Updating neighbors for node 4
---11-11-15 10:47:14 Job job#66 :heal_neighbor_node 4 (0x79e218) P:70 S:4 was Successful
---11-11-15 10:47:14 Pass 1/5 Updating neighbors for node 2
---11-11-15 10:47:21 Job job#67 :heal_neighbor_node 2 (0x784680) P:70 S:4 was Successful
---11-11-15 10:47:21 Pass 2/5 Updating neighbors for node 2
---11-11-15 10:47:29 Job job#68 :heal_neighbor_node 2 (0x769fc8) P:70 S:4 was Successful
---11-11-15 10:47:29 Pass 3/5 Updating neighbors for node 2
---11-11-15 10:47:37 Job job#69 :heal_neighbor_node 2 (0x7b9f38) P:70 S:4 was Successful
---11-11-15 10:47:37 Pass 4/5 Updating neighbors for node 2
---11-11-15 10:47:45 Job job#70 :heal_neighbor_node 2 (0x8273c0) P:70 S:4 was Successful
---11-11-15 10:47:45 Neighbor Update Done
--Stage #3 started: 11-11-15 10:47:45 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:45 Routing update node 2
---11-11-15 10:47:45 Job job#71 :heal_routing_node 2 (0x7a9528) P:70 S:4 was Successful
---11-11-15 10:47:45 Routing update node 4
---11-11-15 10:47:45 Job job#72 :heal_routing_node 4 (0x828890) P:70 S:4 was Successful
---11-11-15 10:47:45 Routing update done
--Stage #4 started: 11-11-15 10:51:36 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:46 Calculate Routes Done
--Stage #5 started: 11-11-15 10:47:46 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:46 Configure node 2
---11-11-15 10:47:56 Job job#73 :conf_jh#2 (0x828bc0) P:70 S:3 was Aborted: Unable to get any information on node
---11-11-15 10:47:56 Configure node 4
---11-11-15 10:48:07 Job job#75 :conf_jh#4 (0x826680) P:70 S:3 was Aborted: Unable to get any information on node
---11-11-15 10:48:07 Configure Done
--Stage #6 started: 11-11-15 10:50:19 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:50:19 Node 4 woke up
---11-11-15 10:50:19 Pass 5/5 Updating neighbors for node 4
---11-11-15 10:51:07 Battery devices awoke
--Stage #7 started: 11-11-15 10:51:07 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:51:11 Node Details heal 2
---11-11-15 10:51:25 Node Details heal 2
---11-11-15 10:51:36 Stress test Done

That said I have rebooted the box a couple of times since then. I don't know if that would delete them?
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 15, 2011, 09:26:46 am

Very very strange. The errors from the boiler actuator were related to it not being configured (although it was fine yesterday).

After I ran the heal I was still getting those errors so I caused the UI to "configure node now" which it did.

After that it was fine! Can't understand why it thought it was no longer configured...
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: mcvflorin on November 15, 2011, 11:26:53 am
41      11/14/11 14:02:20.311   0x1 0x10 0x0 0x19 0x41 0x5 0x432 0x1 0x1 0x1 0x1a3 0x5 0x0 0x0 0x0 0x0 0x3 0xa9 (######C###########) <0xc04>

41      11/14/11 14:02:20.492   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x4 0x8e (######C####%######) <0xc04>

41      11/14/11 14:02:20.709   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x5 0x8f (######C####%######) <0xc04>

02      11/14/11 14:02:20.971   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 2 <0x803>


From what I can tell from the logs Vera sent a command of class 0x43 (http://wiki.micasaverde.com/index.php/ZWave_Command_Classes)2 with the new setpoint of 26(0x1a)3 to node 41. It sent the message once (311), then retried twice (at 492 and 709) and eventually it concluded that the new setpoint wasn't set (971). I don't know why this happened (maybe it didn't receive what it expected from the thermostat?), but it seems that this is the reason why Vera is not updating the setpoint variable. I will try to find more about this.

Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: oTi@ on November 15, 2011, 12:22:21 pm
@mcvflorin,

I think that's the sequence for when the t-stat is still sleeping. A little later (14:04:16.837) the command does seem to go through when the t-stat is awake and the comm failure is cleared, and I believe the OP was seeing 'transmit ok' and a changed setpoint on the t-stat itself.
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 15, 2011, 12:24:03 pm

Thanks Florin / oti@
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on November 15, 2011, 01:13:39 pm

Florin,

I think it as oti@ suggests. It does retry a few times then fail as the thermostat is asleep. Then it waits and retries as below -

Code: [Select]
02      11/15/11 18:05:36.724   ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/15/11 18:05:36.726   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/15/11 18:05:36.743   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/15/11 18:05:36.744   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/15/11 18:05:36.746   ZWaveSerial::Send XXXX  node 4 using route 0.32.80.58 autoroute: 1 direct: 0 <0xc04>
[color=red]41      11/15/11 18:05:36.747   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x16 0x5 0x0 0x0 0x0 0x0 0x14 0xb2 (######C###########) <0xc04>
[/color]42      11/15/11 18:05:36.791   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/15/11 18:05:36.791   got expected ACK <0x1406>
41      11/15/11 18:05:36.792   ACK: 0x6 (#) <0x1406>
42      11/15/11 18:05:36.841   0x1 0x5 0x0 0x19 0x14 0x0 0xf7 (#######) <0x1406>
41      11/15/11 18:05:36.841   ACK: 0x6 (#) <0x1406>
06      11/15/11 18:05:36.851   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 1 now: 0 #hooks: 0 upnp: 0 v:0x828b38/NONE duplicate:0 <0x803>
06      11/15/11 18:05:36.852   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x8289a8/NONE duplicate:1 <0x803>
[color=red]04      11/15/11 18:05:36.855   <Job ID="11" Name="send failed node 4" Device="5" Created="11-11-15 18:05:36" Started="11-11-15 18:05:36" Completed="11-11-15 18:05:36" Duration="0.131155000" Runtime="0.112545000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
[/color]02      11/15/11 18:05:36.861   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/15/11 18:05:36.862   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>

Going back to your earlier comment
Quote
Vera tells the thermostat to change its setpoint, and doesn't update its internal setpoint variable until it gets confirmation from the thermostat that the setpoint successfully changed. Maybe the thermostat isn't replying back its status?

We're seeing the success ACK come back I think, and Vera is updating its status to "Successful" so shouldn't it also be updating its internal setpoint at this time?

Cheers,

Alex/
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: intveltr on November 16, 2011, 05:52:50 pm
For now, I'm using a crappy workaround to get the GUI to update correctly.  It requires LUA code but I am using that anyway.  I have a virtual thermostat that holds the default day temperature; so that I can easily change the default temperature by changing the virtual device rather than going through scenes to change hardcoded values.  When I return home or in the morning when the timer fires, this scene copies the temperature set in the virtual thermostat to the actual device.  There are two commands, one to send the new temp setpoint to the thermostat, and the other to set the local setpoint (which is what Vera displays).

Code: [Select]
local DEVICE_HUISKAMER = 91
local DEFAULT_HUISKAMER = 95

local t_huis = luup.variable_get("urn:upnp-org:serviceId:TemperatureSetpoint1_Heat", "CurrentSetpoint", DEFAULT_HUISKAMER)
luup.variable_set("urn:upnp-org:serviceId:TemperatureSetpoint1_Heat", "CurrentSetpoint", t_huis, DEVICE_HUISKAMER)
luup.call_action ("urn:upnp-org:serviceId:TemperatureSetpoint1_Heat", "SetCurrentSetpoint", {NewCurrentSetpoint = t_huis}, DEVICE_HUISKAMER)

Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: utz on January 04, 2012, 04:45:03 pm
I am stuck at that point now too. Where is the code that processes the ACK so we could maybe fix this? Any idea?
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: Ap15e on January 05, 2012, 01:22:26 pm
Quote
Where is the code that processes the ACK so we could maybe fix this?

In LuaUPnP?
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: utz on January 05, 2012, 01:27:38 pm
In LuaUPnP?

Can you be a bit more precise? I am not familiar with the internal structure of vera. I know about files you need for a plugin and generally there would be an implementation file I_xxx. I am just not sure where this would be for the Thermostat device. Any pointer where to start looking (directory, filename, ...)

Thanks,

Utz
Title: Re: Waking up devices / Issue with thermostat setpoints
Post by: ajlennon on January 05, 2012, 01:30:43 pm

@utz The issue with much of this appears to be that it's handled in the closed source portion of Vera (LuaUPnP is closed I believe), for example Z-Wave Rx packet handling and I presume ACKs