Re: Setup

sarabart · August 15, 2011, 2:32pm

Wow…you guys are amazing with this alarm plugin. I don’t have any experience with coding or alarms but I thought I would give this a try knowing I will be a bit over my head. Just reading through this forum I have managed to get my NX485/NX-8 talking with vera (I think). I now get hung up in the Lua startup. I have found two different specs on the nx584 settings _10/12/10 and 12/22/10. I have tried both settings (although my locations are different because I am using the nx8 and nx584). My NX584 settings currently match the post from 12/22.The log up to the hangup is as follows:

50 08/14/11 22:30:22.223 luup_log:17: Initializing Caddx NX-584 <0x402>
50 08/14/11 22:30:22.226 luup_log:17: Sending message and waiting for response: 0x21 Interface Configuration Request <0x402>
50 08/14/11 22:30:22.228 luup_log:17: Message: Outgoing: 0x7e 0x01 0x21 0x22 0x23 <0x402>
50 08/14/11 22:30:22.381 luup_log:17: Received good message 0x01 <0x402>
50 08/14/11 22:30:22.383 luup_log:17: Message: Incoming message body: 0x32 0x2e 0x30 0x30 0xf2 0x01 0xfa 0x07 0x00 0xc8 <0x402>
50 08/14/11 22:30:22.383 luup_log:17: Handling message: 0x01 Interface Configuration <0x402>
50 08/14/11 22:30:22.384 luup_log:17: Firmware version 2.00 <0x402>
50 08/14/11 22:30:22.386 luup_log:17: All message codes are supported. <0x402>
50 08/14/11 22:30:22.386 luup_log:17: Zone Name enabled <0x402>
50 08/14/11 22:30:22.387 luup_log:17: Set Clock enabled <0x402>
50 08/14/11 22:30:22.388 luup_log:17: Secondary Keypad Function enabled <0x402>
50 08/14/11 22:30:22.388 luup_log:17: Zone bypass enabled <0x402>
50 08/14/11 22:30:22.389 luup_log:17: Sending message and waiting for response: 0x3b Set Interface Clock <0x402>
50 08/14/11 22:30:22.393 luup_log:17: Message: Outgoing: 0x7e 0x07 0xbb 0x0b 0x08 0x0e 0x16 0x1e 0x01 0x19 0x7c <0x402>
50 08/14/11 22:30:22.851 luup_log:17: Received good message 0x1d <0x402>
50 08/14/11 22:30:22.852 luup_log:17: Message: Incoming message body: <0x402>
50 08/14/11 22:30:22.852 luup_log:17: Sending message and waiting for response: 0x28 System Status Request <0x402>
50 08/14/11 22:30:22.854 luup_log:17: Message: Outgoing: 0x7e 0x01 0x28 0x29 0x2a <0x402>
50 08/14/11 22:30:23.011 luup_log:17: Received good message 0x08 <0x402>
50 08/14/11 22:30:23.013 luup_log:17: Message: Incoming message body: 0x0c 0x00 0x00 0x00 0x00 0x82 0x00 0x00 0x00 0x01 0xb3 <0x402>
50 08/14/11 22:30:23.014 luup_log:17: Handling message: 0x08 System Status <0x402>
50 08/14/11 22:30:23.014 luup_log:17: Valid partition 1 <0x402>
50 08/14/11 22:30:23.015 luup_log:17: PIN length is 4 <0x402>
50 08/14/11 22:30:23.018 luup_log:17: Getting zone name for 1 <0x402>
50 08/14/11 22:30:23.018 luup_log:17: Sending message and waiting for response: 0x23 Zone Name Request <0x402>
50 08/14/11 22:30:23.021 luup_log:17: Message: Outgoing: 0x7e 0x02 0x23 0x00 0x25 0x4c <0x402>
50 08/14/11 22:30:23.191 luup_log:17: Received inconvenient message 0x08 <0x402>
50 08/14/11 22:30:23.193 luup_log:17: Message: Unsolicited message body: 0x0c 0x00 0x00 0x00 0x00 0x82 0x00 0x00 0x00 0x01 0xb4 <0x402>
50 08/14/11 22:30:23.194 luup_log:17: Sending message: 0x1D Positive Acknowledge <0x402>
50 08/14/11 22:30:23.195 luup_log:17: Message: Outgoing: 0x7e 0x01 0x1d 0x1e 0x1f <0x402>
50 08/14/11 22:30:23.198 luup_log:17: Message: Outgoing: 0x7e 0x02 0x23 0x00 0x25 0x4c <0x402>
50 08/14/11 22:30:23.351 luup_log:17: Received inconvenient message 0x08 <0x402>
50 08/14/11 22:30:23.353 luup_log:17: Message: Unsolicited message body: 0x0c 0x00 0x00 0x00 0x00 0x82 0x00 0x00 0x00 0x01 0xb4 <0x402>
50 08/14/11 22:30:23.353 luup_log:17: Sending message: 0x1D Positive Acknowledge <0x402>
50 08/14/11 22:30:23.354 luup_log:17: Message: Outgoing: 0x7e 0x01 0x1d 0x1e 0x1f <0x402>
50 08/14/11 22:30:23.357 luup_log:17: Message: Outgoing: 0x7e 0x02 0x23 0x00 0x25 0x4c <0x402>
50 08/14/11 22:30:23.401 luup_log:17: Received inconvenient message 0x1e <0x402>
50 08/14/11 22:30:23.402 luup_log:17: Message: Unsolicited message body: <0x402>
50 08/14/11 22:30:23.403 luup_log:17: Message: Outgoing: 0x7e 0x02 0x23 0x00 0x25 0x4c <0x402>
50 08/14/11 22:30:23.451 luup_log:17: Received inconvenient message 0x1e <0x402>
50 08/14/11 22:30:23.452 luup_log:17: Message: Unsolicited message body: <0x402>
50 08/14/11 22:30:23.454 luup_log:17: Message: Outgoing: 0x7e 0x02 0x23 0x00 0x25 0x4c <0x402>
50 08/14/11 22:30:23.501 luup_log:17: Received inconvenient message 0x1e <0x402>
50 08/14/11 22:30:23.502 luup_log:17: Message: Unsolicited message body: <0x402>
this last bit just repeats itself. Any help would be appreciated!

futzle · August 15, 2011, 9:52pm

Hi sarabart,

Thanks for posting the log; it’s very helpful.

I think that one of two things is happening. It might be that the “Unsolicited message” interruptions that the plugin is seeing is putting the plugin into a state where both Vera and the NX-584 think that the other end hasn’t replied to a request. Or it might be that we’re seeing a new response 0x1e to the “Get Zone Name” request.

Can you do two things for me please?

One, see if you can ever capture a log that contains no “Unsolicited message” lines. It might take a few reload tries. Does it still devolve into the same endless loop?

Two, turn off zone name fetching by programming a zero bit into Location 3, Segment 1, bit 4. Then restart the plugin. It will choose generic names for the zones but the log should progress further. If so, and you’re still hitting problems, please post that log.

(I’m mulling over a way to save the plugin from this lengthy startup conversation with the NX-584. Often it doesn’t complete properly. My plan is that the next version will collect zones and partitions at its leisure and save the information for the next startup.)

sarabart · August 17, 2011, 12:49am

Well futzle i’ve done it now…
The partial fix was removing the zone name requests (perhaps because I have no zone names, just numbers?). Things were humming along. I could see the partition and 16 zones (because I didn’t limit the # to the 7 I have). The Lua Startup would keep going so in order to stop it I disconnected the usb between vera and NX584. :o since then they don’t want to talk. I tried to re-create the device (now #28) in an act of deperation…no good.
the new log:

09 08/16/11 20:28:36.371 JobHandler_LuaUPnP::Run device 4 Google Weather room 0 type urn:demo-micasaverde-com:device:weather:1 id parent 0/0x76c498 upnp: 0 <0x400>
09 08/16/11 20:28:36.372 JobHandler_LuaUPnP::Run device 7 High Temperature room 0 type urn:schemas-micasaverde-com:device:TemperatureSensor:1 id Weather-Forecast-HighTemperature parent 4/0x76f500 upnp: 0 <0x400>
09 08/16/11 20:28:36.373 JobHandler_LuaUPnP::Run device 8 Humidity room 0 type urn:schemas-micasaverde-com:device:HumiditySensor:1 id Weather-Current-Humidity parent 4/0x770958 upnp: 0 <0x400>
09 08/16/11 20:28:36.373 JobHandler_LuaUPnP::Run device 6 Low Temperature room 0 type urn:schemas-micasaverde-com:device:TemperatureSensor:1 id Weather-Forecast-LowTemperature parent 4/0x76cac8 upnp: 0 <0x400>
09 08/16/11 20:28:36.374 JobHandler_LuaUPnP::Run device 28 NX8 Alarm room 1 type urn:schemas-futzle-com:device:caddx-alarm:1 id parent 0/0x76cd10 upnp: 0 <0x400>
09 08/16/11 20:28:36.375 JobHandler_LuaUPnP::Run device 30 pl2303 room 0 type urn:micasaverde-org:device:SerialPort:1 id usb-00:03.0-1.2 parent 29/0x774ec0 upnp: 0 <0x400>
09 08/16/11 20:28:36.375 JobHandler_LuaUPnP::Run device 2 _Scene Controller room 0 type urn:schemas-micasaverde-com:device:SceneController:1 id 1 parent 1/0x74d138 upnp: 0 <0x400>
09 08/16/11 20:28:36.376 JobHandler_LuaUPnP::Run device 29 Serial_Portlist_2147450580 room 0 type urn:micasaverde-org:device:SerialPortRoot:1 id 16339 parent 0/0x772f60 upnp: 0 <0x400>
09 08/16/11 20:28:36.376 JobHandler_LuaUPnP::Run device 3 _SmartSwitch Energy Meter room 4 type urn:schemas-upnp-org:device:BinaryLight:1 id 2 parent 1/0x768f88 upnp: 0 <0x400>
09 08/16/11 20:28:36.377 JobHandler_LuaUPnP::Run device 5 Temperature room 0 type urn:schemas-micasaverde-com:device:TemperatureSensor:1 id Weather-Current-Temperature parent 4/0x76c7a0 upnp: 0 <0x400>
09 08/16/11 20:28:36.378 JobHandler_LuaUPnP::Run device 1 ZWave room 0 type urn:schemas-micasaverde-com:device:ZWaveNetwork:1 id parent 0/0x74c9c8 upnp: 0 <0x400>
03 08/16/11 20:28:36.408 JobHandler_LuaUPnP::Run ready 11 devices installation 16339 missing version 1.1.1245 allow_evt: 1 allow_ud: 1 upnp 1 changed: 0 pMem 0x7fa000 start 7610368 diff: 753664 <0x400>
50 08/16/11 20:28:38.013 luup_log:4: GoogleWeather Google Weather #4 starting up with id <0x402>
02 08/16/11 20:28:38.019 ZWaveJobHandler::SetDeviceStatus XXX2 0/0/0/0 <0x803>
01 08/16/11 20:28:38.024 IOPort::Connect connect -1 127.0.0.1:3481 <0x4011>
09 08/16/11 20:28:39.011 ZWaveJobHandler::FindCustomDeviceType node 2/0 has custom file class desc _SmartSwitch Energy Meter <0x803>
06 08/16/11 20:28:39.014 Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: ManufacturerInfo was: 134,3,6 now: 134,3,6 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 08/16/11 20:28:39.015 Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: Capabilities was: 210,156,0,4,16,1,L,R,B,RS,|37,39,49,50:2,112,114,133,134, now: 210,156,0,4,16,1,L,R,B,RS,|37,39,49,50:2,112,114,133,134, #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x803>
06 08/16/11 20:28:39.016 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 08/16/11 20:28:39.017 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusID was: 5 now: 1 #hooks: 0 upnp: 0 v:0x7af058/NONE duplicate:0 <0x803>
06 08/16/11 20:28:39.018 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:0x7b9ab8/NONE duplicate:0 <0x803>
50 08/16/11 20:28:42.143 luup_log:28: Initializing Caddx NX-584 <0x402>
50 08/16/11 20:28:42.146 luup_log:28: Sending message and waiting for response: 0x21 Interface Configuration Request <0x402>
50 08/16/11 20:28:42.149 luup_log:28: Message: Outgoing: 0x7e 0x01 0x21 0x22 0x23 <0x402>
50 08/16/11 20:28:43.442 luup_log:28: Ignoring byte 43 <0x402>
50 08/16/11 20:28:43.451 luup_log:28: Ignoring byte 42 <0x402>
50 08/16/11 20:28:43.461 luup_log:28: Ignoring byte c8 <0x402>
50 08/16/11 20:28:43.471 luup_log:28: Ignoring byte ff <0x402>
50 08/16/11 20:28:45.931 luup_log:28: Ignoring byte 43 <0x402>
50 08/16/11 20:28:45.941 luup_log:28: Ignoring byte 42 <0x402>
50 08/16/11 20:28:45.951 luup_log:28: Ignoring byte c8 <0x402>
50 08/16/11 20:28:45.961 luup_log:28: Ignoring byte ff <0x402>
50 08/16/11 20:28:48.431 luup_log:28: Ignoring byte 43 <0x402>
50 08/16/11 20:28:48.441 luup_log:28: Ignoring byte 42 <0x402>
50 08/16/11 20:28:48.451 luup_log:28: Ignoring byte c8 <0x402>
50 08/16/11 20:28:48.461 luup_log:28: Ignoring byte ff <0x402>
50 08/16/11 20:28:50.922 luup_log:28: Ignoring byte 43 <0x402>
50 08/16/11 20:28:50.931 luup_log:28: Ignoring byte 42 <0x402>
50 08/16/11 20:28:50.941 luup_log:28: Ignoring byte c8 <0x402>
50 08/16/11 20:28:50.951 luup_log:28: Ignoring byte ff <0x402>
I am drawn to the critical error at 20:28:38.024 regarding to i/o port.
I have tried to re-start vera and also went into programming mode for the NX584 to make sure it still existed in the the eye of the alarm…no help with either of those moves!
Ideas?

sarabart · August 17, 2011, 1:37am

my mistake…the baud rate magically changed to 9600. it only took me 2.5 hours to figure that out :-[. I will keep you posted what happens next!

sarabart · August 18, 2011, 7:06pm

We are making good progress now. After 5 or 6 restarts and 1 unplug of vera it finally took. I now have a partition 1 and 7 zones. The partition shows the ability to arm and disarm etc.
What I run into now is that each time I try to make a change and the changes are saved, the Lua startup runs for hours (usually overnight). Sometimes it will stop and sometimes it will give a failed messgage in the morning when I check it.

futzle · August 18, 2011, 9:39pm

Hours is not normal. Mine (only three zones) takes only five seconds.

Again, if I can trouble you to post logs (but not of arming/disarming, as the logs contain the PIN), I can look into it.

sarabart · August 21, 2011, 3:58am

Here is the log- I really appreciate the help. My wife is starting to think I have an addiction to this thing!
I did manage to get it to complete the Lua startup once, not sure what was different at that time.

futzle · August 21, 2011, 10:15am

Thanks sarabart. That log is incomplete. It just stops after an outgoing message to the panel. Was there more?

Perhaps this is always what happens: the log stops after an outgoing message, and the plugin is waiting forever for a reply to a request that the panel never got. Is that consistent with your logs?

When this happens, try walking around tripping sensors and see if the panel is still able to talk to the plugin.

What I’m thinking is that there’s an intermittent failure in the wire(s) connecting the Vera’s transmit to the panel’s receive pins. Perhaps a short. In the log you just posted, the panel is repeating packets back to the plugin that the plugin has already acknowledged. When that acknowledgment is lost, the panel re-sends the packet, and that’s what’s happening…

Whatever you’ve got connected between the two (a USB-to-serial adapter, I’d guess), try to swap it out for another one. A dodgy USB-to-serial adapter was the problem for a previous user on this forum topic.

You may already be doing this: you can increase the success rate of startup by making sure that no one is moving around the house, tripping sensors, while startup is happening. There’s still some bugs in the plugin’s handling of unexpected messages, so minimizing them is best.

sarabart · August 22, 2011, 1:38am

I only sent part of the log because the entire file was too big to attach. The 6 lines of communication continue to repeat for each zone until the log tail is terminated:
50 08/19/11 6:32:10.284 luup_log:28: Setting up zone 1 <0x402>
50 08/19/11 6:32:10.285 luup_log:28: Sending message and waiting for response: 0x24 Zone Status Request <0x402>
50 08/19/11 6:32:10.286 luup_log:28: Message: Outgoing: 0x7e 0x02 0x24 0x00 0x26 0x4e <0x402>
50 08/19/11 6:32:10.421 luup_log:28: Received good message 0x04 <0x402>
50 08/19/11 6:32:10.423 luup_log:28: Message: Incoming message body: 0x06 0x01 0x00 0x1b 0xf2 0x00 0x00 0x00 0x00 <0x402>
50 08/19/11 6:32:10.423 luup_log:28: Handling message: 0x04 Zone Status <0x402>
I will try to replace the usb-serial adapter and see if that helps.
Thanks again for the help-

futzle · August 22, 2011, 4:24am

Thanks sarabart. I’m working on the plugin code today. The plan is to replace auto-discovery with a manual configuration step. It should be a lot more stable, and honestly, people don’t change their setups that often.