Setup, error log and ASCII mode

[patrick]

I just installed the plugin version 68, but it seems to be failing very early during startup:
50   10/11/12 23:16:43.266   luup_log:10: Initializing Caddx NX-584 __LEAK__ this:270336 start:270336 to 0xb5a000 <0x2c105680>
50   10/11/12 23:16:43.267   luup_log:10: Opening serial port <0x2c105680>
02   10/11/12 23:16:43.271   IOPort::Run RecvFailed 0 close 11 <0x2e105680>
02   10/11/12 23:16:48.291   IOPort::Run RecvFailed 0 close 12 __LEAK__ this:143360 start:413696 to 0xb7d000 <0x2e105680>


I configured the serial port to the default baud rate (9600) that was the default for my NX-8E.  The NX-8E is currently configured for ASCII mode, and I believe that I enabled the features correctly as listed on the hardware setup page.  If I plug the USB adapter (Prolific chipset) into my Windows machine and run Putty at 9600, it has a periodic sequence of numbers logged.  If I use the aux buttons on my keyfobs, one of the digits changes.  Based on this, I think the cabling is ok.

The configure and users tabs are stuck at "getting configuration...", so I can't enable debug logging without modifying the lua file.

Do you have any other suggestions on how to troubleshoot this, or should I assume my prolific adapter is busted under the Vera3's build of OpenWRT and get a FTDI instead?

[patrick]

I forced debug on, uploaded the file & restarted luup.   Looks like it's never getting past the luup.io.intercept call, it just hangs.

50   10/12/12 0:34:48.278   luup_log:10: Initializing Caddx NX-584 __LEAK__ this:110592 start:266240 to 0xe32000 <0x2b78d680>
50   10/12/12 0:34:48.278   luup_log:10: Opening serial port <0x2b78d680>
25   10/12/12 0:34:48.279   luup_io_intercept 10 <0x2b78d680>
20   10/12/12 0:34:48.279   LuaInterface::lu_iop_intercept_incoming 0xd499e0 mutex_lock 0xd405ac <0x2b78d680>
20   10/12/12 0:34:48.279   LuaInterface::lu_iop_intercept_incoming acquired 0xd499e0 got lock 0xd405ac <0x2b78d680>
25   10/12/12 0:34:48.280   luup_io_intercept 10 <0x2b78d680>
25   10/12/12 0:34:48.280   luup_io_write 10 size: 5 <0x2b78d680>
51   10/12/12 0:34:48.281   0x7e 0x1 0x21 0x22 0x23 (~#!"#) <0x2b78d680>
25   10/12/12 0:34:48.282   luup_io_write 10 result: 1 <0x2b78d680>
25   10/12/12 0:34:48.282   lu_io_read starting <0x2b78d680>
25   10/12/12 0:34:48.283   IOPort::GetIncomingData before wait 0x2b78c98c id 1 timeout: 10 <0x2b78d680>
02   10/12/12 0:34:48.285   IOPort::Run RecvFailed 0 close 11 <0x2d78d680>

[futzle]

Patrick, the plugin isn't receiving any bytes over the interface. It's sending the original "get config" message to the interface but getting no response.

What tests have you done on the connection to verify that it works?

[patrick]

So in putty at 9600, I initially saw repeated strings such as this.  If I use a keyfob to trigger a relay, the last 2 digits change to 80 or 81
0986006000C8606314C05181

DL900 still isn't working, not sure why, but it looks like I may be making some progress after power cycling the panel.  http://diysecurityforum.com/index.php?topic=19054.0 had someone with a similar truncated message issue in DL900.

At this point, I'm no longer hanging, it's just failing:
01      10/12/12 21:48:51.332   ^[[31;1mLuImplementation::StartLua running startup code for 13 I_CaddxNX584Security.xml failed^[[0m <0x2be4d680>
31      10/12/12 21:48:51.333   AlarmManager::Run finish callback for alarm 0xdce2e0 entry 0xe1b768 type 5 id 14 param=0xe0bb10 entry->when: 1350103691 time: 13
31      10/12/12 21:48:51.333   AlarmManager::Run callback for alarm 0xdce2e0 entry 0xe08b08 type 158 id 28 param=(nil) entry->when: 1350103694 time: 1350103731
02      10/12/12 21:48:51.334   ^[[33;1mUserData::AlarmCallback ALARM_RESYNC_DEVICES^[[0m <0x2be4d680>
10      10/12/12 21:48:51.338   FileUtils::ReadURL starting https://cms2.mios.com/sync_device?PK_AccessPoint=30003868&HW_Key=<redacted for security> <0
10      10/12/12 21:48:51.339   XXX-UpdateSystemMessagesTasks now 2=Caddx NX584 Security System[13]: Failed to set up interface <0x2bc4d680>

I double checked the settings, and was missing the set calendar command.  I fixed that, reset everything, and now it looks like it's just rejecting all bytes received:
50      10/12/12 23:03:48.273   luup_log:13: Initializing Caddx NX-584 __LEAK__ this:126976 start:299008 to 0x8b6000 <0x2b7db680>
50      10/12/12 23:03:48.273   luup_log:13: Opening serial port <0x2b7db680>
50      10/12/12 23:03:48.274   luup_log:13: Sending message and waiting for response: 0x21 Interface Configuration Request <0x2b7db680>
50      10/12/12 23:03:48.275   luup_log:13: Message: Outgoing: 0x7e 0x01 0x21 0x22 0x23 <0x2b7db680>
02      10/12/12 23:03:48.279   ^[[33;1mIOPort::Run RecvFailed 0 close 12^[[0m <0x2d9db680>
02      10/12/12 23:03:53.302   ^[[33;1mIOPort::Run RecvFailed 0 close 12^[[0m <0x2d9db680>
50      10/12/12 23:03:58.575   luup_log:13: Ignoring byte 0a <0x2b7db680>
50      10/12/12 23:03:58.586   luup_log:13: Ignoring byte 30 <0x2b7db680>
50      10/12/12 23:03:58.596   luup_log:13: Ignoring byte 42 <0x2b7db680>
50      10/12/12 23:03:58.607   luup_log:13: Ignoring byte 38 <0x2b7db680>
50      10/12/12 23:03:58.617   luup_log:13: Ignoring byte 31 <0x2b7db680>
50      10/12/12 23:03:58.628   luup_log:13: Ignoring byte 33 <0x2b7db680>
50      10/12/12 23:03:58.638   luup_log:13: Ignoring byte 35 <0x2b7db680>
50      10/12/12 23:03:58.649   luup_log:13: Ignoring byte 32 <0x2b7db680>
50      10/12/12 23:03:58.659   luup_log:13: Ignoring byte 45 <0x2b7db680>
50      10/12/12 23:03:58.670   luup_log:13: Ignoring byte 33 <0x2b7db680>
50      10/12/12 23:03:58.680   luup_log:13: Ignoring byte 33 <0x2b7db680>
50      10/12/12 23:03:58.690   luup_log:13: Ignoring byte 33 <0x2b7db680>


Last update in this post, I need to get some sleep
Ignoring byte 0a.... 0d  - those look familiar.  It looks like I needed to be in binary.
I set the panel to binary, 9600, then power cycled the panel for good measure.  Once the panel was up, I restarted luup, and got much further.  It recognized the capabilities, but appears to have hung attempting to set the time or shortly thereafter.  It eventually failed.  This log is larger, so I have attached it.

I think it's getting very close.  I'll be sure to update the wiki page with the NX-8e specifics (locations & segments to set, photo of my cable, serial settings) once its working.

[futzle]

Patrick, based on that string, you've set your panel to ASCII mode. The plugin can only speak binary mode.

Haven't looked at the attachment yet; Tapatalk isn't letting me see it, so I'll have to wait till I am near a real computer.

Edit: Ok, you figured out the binary thing yourself.  The message was truncated in Tapatalk so I didn't see that you'd switched to binary already.

The fresh_attempt log is better.  It looks like there are intermittent dropouts on the line, resulting in timeouts.  Most likely the dropouts are on the Vera-to-panel data direction, because you're not getting partial messages back from the panel.  I had exactly this happen to me early in development, where the USB port wasn't enough to power the USB-to-serial adapter, and the alarm panel would keep sending status updates, thinking I hadn't acknowledged them, and my code would send acknowledgments, unaware that they weren't getting through.  With you, it might be that reason, or it might be a different reason.  It's hard to test; moving the USB cable to a desktop computer might make the problem go away because the desktop is able to supply more power to the adapter.

Two avenues of investigation occur to me.  The easy one is to insert a powered USB hub in between.  That's what I ended up doing in my situation.  If that doesn't help, then see if you can run an IP-to-serial proxy program on your computer (I use ser2net on my Linux machine), and have Vera connect to the IP address on your computer.  That way you've got a known working physical connection and any bugs left are due to the protocol.

Also, double-check that there isn't a dropout on the physical Vera-to-panel serial connection; you can't test that without sending messages to the panel, because RS-232 is full duplex.

[patrick]

Thanks, I'll work on the physical connections and see what I can find. 

Could I substitute a wiznet for ser2net?  I don't own any machines with "real" RS-232 ports.

I'll look into these options:
- Usb hub w/ existing Prolific USB-serial converter
- A different USB-serial chipset: FTDI232
- Wiznet WIZ110SR - has a separate power supply and MAX232 buffer on it, so it should be pretty much on-spec

[futzle]

Could I substitute a wiznet for ser2net?  I don't own any machines with "real" RS-232 ports.

Yeah, you could. I've got one I bought for that purpose but never commissioned.

[patrick]

Could I substitute a wiznet for ser2net?  I don't own any machines with "real" RS-232 ports.

Yeah, you could. I've got one I bought for that purpose but never commissioned.

Ftdi synced up just fine.  It detects partition 1 status and the last event ok.

A few things aren't working as expected though.  I'll dig into the logs more as I have time to see what I can find.
- event view doesn't list any past events
- zone detection is not working.  I tried the max supported in my system (56 - 8 wired plus 48 wireless), and also the max zone number I use (24).   no luck

[increa]

RS-232 and the NX-8E.  Cable. Protocol. Voltages. Pinout. Etc.

http://www.intrepidcreativity.com/reverse/nx-8e/