Author Topic: Issues changing alarm panel state through Vera  (Read 2750 times)

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Issues changing alarm panel state through Vera
« on: December 11, 2016, 01:29:04 pm »
Hi all,
I have been using Veralite and the AD2USB for a few years now with a few small hiccups.  This last hiccup has turned into me losing some hair in trying to solve the issue. 
In the Vera?s current state I cannot successfully arm my Visa 20P via the AD2USB connection.  Clicking on arm or any other buttons in the Vera devices doesn?t report and error messages or change the color of the button to green.  In the past this generally meant that my pin code wasn?t stored.  I do get a success when I store the pin. 
My scenes that involve the sensors are all working so there is communication between vera and the panel.  I have been able to randomly disarm the system through the vera interface.  I?ll arm my house and then click disarm in vera and sometimes it disarms right away.  Other times I have to click the button multiple times and it finally disarms.  It will never arm in this fashion. 

Steps I?ve tried:
-   Restored a backup to a date where I knew things were working. 
-   Power cycled the vera unit
-   Connected to the AD2USB interface via their GUI app and have full control through my PC
I?ve posted the log below from the unit when I try and run the stay scene.  This is with verbose logging and debug turned on for the Ademco Vista Partition?

Code: [Select]
0 12/11/16 10:10:03.020 luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '[1000000110000000----],008,[f70000071008001c28020000000000]," DISARMED CHIME   Ready to Arm  "'. <0x2e6ec680>
50 12/11/16 10:10:03.021 luup_log:18: (VistaAlarmPanel::getStatusFlags) Active flags: READY, CHIME_MODE <0x2e6ec680>
50 12/11/16 10:10:03.022 luup_log:18: (VistaAlarmPanel::getPartitionState) Got Alarm='None' for partition 1 (device #19). <0x2e6ec680>
50 12/11/16 10:10:03.022 luup_log:18: (VistaAlarmPanel::getPartitionState) Got ArmMode='Disarmed' for partition 1 (device #19). <0x2e6ec680>
50 12/11/16 10:10:03.023 luup_log:18: (VistaAlarmPanel::getPartitionState) Got DetailedArmMode='Ready' for partition 1 (device #19). <0x2e6ec680>
50 12/11/16 10:10:05.955 luup_log:18: (VistaAlarmPanel::requestArmMode) Request new arm mode: 'Stay', device #19. <0x2f16b680>
50 12/11/16 10:10:05.955 luup_log:18: (VistaAlarmPanel::requestArmMode) partNo = 1 <0x2f16b680>
50 12/11/16 10:10:05.956 luup_log:18: (VistaAlarmPanel::getPinCode) Using the stored PIN code. <0x2f16b680>
50 12/11/16 10:10:05.957 luup_log:18: (VistaAlarmPanel::requestArmMode) Current arm mode = 'Ready'. <0x2f16b680>
50 12/11/16 10:10:14.349 luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '!Sending.....done'. <0x2e6ec680>
50 12/11/16 10:10:14.360 luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '[1000000110000000----],008,[f70000071008001c28020000000000]," DISARMED CHIME   Ready to Arm  "'. <0x2e6ec680>
50 12/11/16 10:10:14.360 luup_log:18: (VistaAlarmPanel::getStatusFlags) Active flags: READY, CHIME_MODE <0x2e6ec680>
50 12/11/16 10:10:14.361 luup_log:18: (VistaAlarmPanel::getPartitionState) Got Alarm='None' for partition 1 (device #19). <0x2e6ec680>
50 12/11/16 10:10:14.362 luup_log:18: (VistaAlarmPanel::getPartitionState) Got ArmMode='Disarmed' for partition 1 (device #19). <0x2e6ec680>
50 12/11/16 10:10:14.363 luup_log:18: (VistaAlarmPanel::getPartitionState) Got DetailedArmMode='Ready' for partition 1 (device #19). <0x2e6ec680>
My last step would be to clear out the plugin, but then I might have to go and setup my scenes and triggers.  Thought I would post here first to see if anyone has experienced something similar.  If the whole device wasn?t working I?d start from scratch, but I have a lot of things still functioning. Help please!

Offline peterv

  • Sr. Newbie
  • *
  • Posts: 25
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #1 on: December 13, 2016, 11:47:52 am »
I am experiencing the same issue and I believe it happens when you send change state request without a PIN. For some reason the last PIN (which is now blank) is remembered and all buttons (arm, disarm, stay, etc.) stop working. This could happen for different reasons. An app that does not prompt for PIN or prompts, but no PIN is entered. Or as in my case I was trying to set up a scene to overcome limitation of ImperiHome, which does not let me set panel to StayInstant. I stumbled up on it by chance trying not to store PIN in a scene Luup code. This is what the Luup looked like:

Code: [Select]
luup.call_action("urn:micasaverde-com:serviceId:AlarmPartition2", "RequestArmMode", { State="StayInstant", PINCode=""} , 6)

And this is what I believe the relevant log entries are:

Code: [Select]
08      12/13/16 10:26:07.835   JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: RunScene <0x733d3520>
08      12/13/16 10:26:07.835   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1 <0x733d3520>
08      12/13/16 10:26:07.835   JobHandler_LuaUPnP::HandleActionRequest argument action=RunScene <0x733d3520>
08      12/13/16 10:26:07.835   JobHandler_LuaUPnP::HandleActionRequest argument SceneNum=20 <0x733d3520>
08      12/13/16 10:26:07.836   JobHandler_LuaUPnP::HandleActionRequest argument rand=0.780057339117279 <0x733d3520>
08      12/13/16 10:26:07.836   Scene::RunScene running 20 Stay <0x733d3520>
08      12/13/16 10:26:07.836   JobHandler_LuaUPnP::HandleActionRequest device: 6 service: urn:micasaverde-com:serviceId:AlarmPartition2 action: RequestArmMode <0x733d3520>
08      12/13/16 10:26:07.836   JobHandler_LuaUPnP::HandleActionRequest argument State=StayInstant <0x733d3520>
08      12/13/16 10:26:07.837   JobHandler_LuaUPnP::HandleActionRequest argument PINCode= <0x733d3520>
01      12/13/16 10:26:10.960   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 14 <0x76fd3520>
01      12/13/16 10:26:12.020   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 14 <0x76fd3520>
01      12/13/16 10:26:12.056   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 14 <0x76fd3520>
01      12/13/16 10:26:12.096   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 22 <0x76fd3520>
01      12/13/16 10:26:12.132   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 22 <0x76fd3520>
01      12/13/16 10:26:12.168   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 22 <0x76fd3520>
01      12/13/16 10:26:12.216   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 22 <0x76fd3520>
01      12/13/16 10:26:12.380   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 14 <0x76fd3520>
01      12/13/16 10:26:17.364   ZWJob_PollNode::ReceivedFrame job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 6 got 15 <0x76fd3520>
02      12/13/16 10:26:30.100   ZWaveJobHandler::AlarmCallback skipping check because of jobs <0x76fd3520>
02      12/13/16 10:26:32.329   ZWaveSerial::GetFrame 0x767d2c98 timed out now 0 m_listGetFramePending 0 <0x767d3520>
02      12/13/16 10:26:32.329   ZWaveJobHandler::SendDataAbort got m_iFrameID 0 <0x767d3520>
02      12/13/16 10:26:32.330   ZWJob_PollNode::ReturnMessageNotReceived -end- job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 node 6 didn't reply iOK 0 iBadTx 0 iNoReply 1 Abort returned m_iFrameID 0 <0x767d3520>
02      12/13/16 10:26:32.330   ZWJob_PollNode::PollFailed job job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:5 node 6 battery 0 notlist:0 <0x767d3520>
04      12/13/16 10:26:32.370   <Job ID="5" Name="pollnode #6 1 cmds" Device="49" Created="2016-12-13 10:26:10" Started="2016-12-13 10:26:10" Completed="2016-12-13 10:26:32" Duration="22.259183000" Runtime="22.258341000" Status="Failed" LastNote="" Node="6" NodeType="ZWaveNonDimmableLight" NodeDescription="Garage Door Opener 1"/> <0x767d3520>
02      12/13/16 10:26:32.371   JobHandler::PurgeCompletedJobs purge job#5 :pollnode #6 dev:49 (0x14c98d8) N:6 P:100 S:2 pollnode #6 1 cmds status 2 <0x767d3520>

To restore button functionality you need to issue a valid request to alarm mode change with a good PIN.

I am not sure if this is working as intended or is some kind of a bug.
« Last Edit: December 14, 2016, 02:48:48 pm by peterv »

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #2 on: December 14, 2016, 02:25:37 pm »
So a commonality here is I was using Imperihome as well and found that if I armed or changed modes through the app, my vera seemed to lose the PIN code and I couldn't change alarm states until I went into vera a re-entered the code.  I can't recall if I had been in the app or not before the issue happened so I don't know if it's directly related or not.

I do know that I broke my AD2USB in the process of troubleshooting.  My last ditch effort at troubleshooting was to unplug the AD2USB device from my alarm panel to try and reset it.  As I was unscrewing the power wires, my USB cord fell out, and upon further inspection the mini USB port has come off the board internally.  So now I'm without a functioning board.  I have a new one on order and it will be interesting to see if I have the same problem or not.  Maybe there was a pin loose?   

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #3 on: December 21, 2016, 10:15:40 pm »
My new AD2USB showed up in the mail yesterday.  Hooked it up and had to reconfigure a few things (had to readd the serial port).  The same issue still was happening even with the new device.  After HOURS of configurations I finally got it to work.  I'm not sure how this happened, but I think my keypad address for the ad2usb was not on partition 1.  On my vista 20p I went into programming mode and entered *191 and then 1.  After doing this (this was the last thing I did.  I must have done 1000 other things in between) I was immediately able to change the status through Vera.  PHEW.  I was going to break something! :)

The log still looks fairly similar, but you can see now it goes into the stay mode:

Code: [Select]
50      12/21/16 19:05:47.736   luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '[1000000110000000----],008,[f700000f1008001c28020000000000]," DISARMED CHIME   Ready to Arm  "'. <0x2e7ee680>
50      12/21/16 19:05:47.737   luup_log:18: (VistaAlarmPanel::getStatusFlags) Active flags: READY, CHIME_MODE <0x2e7ee680>
50      12/21/16 19:05:47.737   luup_log:18: (VistaAlarmPanel::getPartitionState) Got Alarm='None' for partition 1 (device #19). <0x2e7ee680>
50      12/21/16 19:05:47.738   luup_log:18: (VistaAlarmPanel::getPartitionState) Got ArmMode='Disarmed' for partition 1 (device #19). <0x2e7ee680>
50      12/21/16 19:05:47.739   luup_log:18: (VistaAlarmPanel::getPartitionState) Got DetailedArmMode='Ready' for partition 1 (device #19). <0x2e7ee680>
50      12/21/16 19:05:54.173   luup_log:18: (VistaAlarmPanel::requestArmMode) Request new arm mode: 'Stay', device #19. <0x2dfee680>
50      12/21/16 19:05:54.174   luup_log:18: (VistaAlarmPanel::requestArmMode) partNo = 1 <0x2dfee680>
50      12/21/16 19:05:54.174   luup_log:18: (VistaAlarmPanel::getPinCode) Using the stored PIN code. <0x2dfee680>
50      12/21/16 19:05:54.175   luup_log:18: (VistaAlarmPanel::requestArmMode) Current arm mode = 'Ready'. <0x2dfee680>
50      12/21/16 19:05:54.454   luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '!Sending.done'. <0x2e7ee680>
50      12/21/16 19:05:54.945   luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '[0011030110000000----],045,[f700000b1045038028020000000000],"ARMED ***STAY***May Exit Now  45"'. <0x2e7ee680>
50      12/21/16 19:05:54.946   luup_log:18: (VistaAlarmPanel::getStatusFlags) Active flags: ARMED_STAY, CHIME_MODE, BEEP <0x2e7ee680>

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #4 on: December 24, 2016, 03:06:12 pm »
Issue came back after a day or so working.  I don't think it has to do with the AD2USB or my alarm panel since I didn't touch a thing.  I noticed my disarm scene didn't run this morning so I tried to run it through the UI in vera and the same thing was happening where I would click on disarm and the color would not change to green.  It's stuck on stay. 

I have found after some testing that if the system is in Stay I can click on the disarm 3-4 times and it will sometimes actually disarm the system and other times it will disarm the system 3-4 times in a row.  I can't get it to go to any other states that way.

Anyone know what I can do to make this work the way it used to for the last few years? 

Offline kevinnutech

  • Jr. Member
  • **
  • Posts: 55
  • Karma: +2/-0
Re: Issues changing alarm panel state through Vera
« Reply #5 on: December 30, 2016, 01:18:05 pm »
Your ad2usb isn't conflicting addresses with another keypad on the bus is it?

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #6 on: December 31, 2016, 12:02:29 pm »
I have the following keypads

*190 - 01 00 Address 17 - Main Keypad
*191 - 01 00 Address 18 - Ad2usb
*192 - 00 00
*193 - 00 00
*194 - 00 00
*195 - 00 00
*196 - 00 00

When I am in the AD2USB configuration I have the option of selecting multiple addresses.  If I have 17 and or 18 selected the behavior is still the same.  A review of my settings is much appreciated!


Offline kevinnutech

  • Jr. Member
  • **
  • Posts: 55
  • Karma: +2/-0
Re: Issues changing alarm panel state through Vera
« Reply #7 on: January 02, 2017, 01:20:44 pm »
My next question is does it work standalone properly hooked to a PC?

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #8 on: January 02, 2017, 02:21:35 pm »
Yes.  It functions through the AD2USB control without issue.

My scenes through Vera that are linked to the controller function as well.  Example: I have a scene where when the door opens my outside lights turn on at night.  This runs without issue.  I can also see when I manually go to the keypad and change the alarm state it updates in the Vera interface to the new state. 

Offline peterv

  • Sr. Newbie
  • *
  • Posts: 25
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #9 on: January 03, 2017, 11:18:17 am »
I have not had a problem since I realized that The VistaAlarmPanel plugin is storing the last entered PIN. So if you aren't able to change state from the main devices tab, go into your Alarm -> Alarm Partition, enter your PIN in the PIN Code text box and without clicking on Store, click one of the states. This will remember the PIN code until the next time you send a wrong/empty PIN code, or maybe LUA restart/whole unit reboot - I am not sure about that one.

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #10 on: January 04, 2017, 12:48:37 pm »
I have not had a problem since I realized that The VistaAlarmPanel plugin is storing the last entered PIN. So if you aren't able to change state from the main devices tab, go into your Alarm -> Alarm Partition, enter your PIN in the PIN Code text box and without clicking on Store, click one of the states. This will remember the PIN code until the next time you send a wrong/empty PIN code, or maybe LUA restart/whole unit reboot - I am not sure about that one.

I tried doing that and it didn't seem to make a difference whether I had the pincode there or not. 

Offline peterv

  • Sr. Newbie
  • *
  • Posts: 25
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #11 on: January 05, 2017, 12:25:38 pm »
Ok, let's try something else. Here is a sample of all that I believe is related to me trying to change the alarm unsuccessfully:

Code: [Select]
10      01/05/17 8:52:48.235    mg_callback from IP:127.0.0.1:46835 /port_3480/data_request id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay start id: 37 <0x73f9b520>
12      01/05/17 8:52:48.235    luvd_get_info_data_request starting /data_request?id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
10      01/05/17 8:52:48.235    JobHandler_LuaUPnP::HandleRequest id lu_action request pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
10      01/05/17 8:52:48.236    sbrk JobHandler_LuaUPnP::HandleActionRequest from IP:192.93.110.88 pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
08      01/05/17 8:52:48.236    JobHandler_LuaUPnP::HandleActionRequest device: 6 service: urn:micasaverde-com:serviceId:AlarmPartition2 action: RequestArmMode <0x73f9b520>
08      01/05/17 8:52:48.236    JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=6 <0x73f9b520>
08      01/05/17 8:52:48.236    JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:AlarmPartition2 <0x73f9b520>
08      01/05/17 8:52:48.237    JobHandler_LuaUPnP::HandleActionRequest argument action=RequestArmMode <0x73f9b520>
08      01/05/17 8:52:48.237    JobHandler_LuaUPnP::HandleActionRequest argument State=Stay <0x73f9b520>
25      01/05/17 8:52:48.237    luup_io_write 3 size: 5 <0x73f9b520>
51      01/05/17 8:52:48.238    0x30 0x30 0x30 0x30 0x33 0xd 0xa (00003\r\n) <0x73f9b520>
25      01/05/17 8:52:48.238    luup_io_write 3 result: 1 <0x73f9b520>
35      01/05/17 8:52:48.238    ImplAction::HandleActionRequest SAlarmPartition2_AlarmPartition2_RequestArmMode_run returned 0 <0x73f9b520>
10      01/05/17 8:52:48.239    luvd_get_info_data_request creating file buffer /data_request?id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
10      01/05/17 8:52:48.240    luvd_get_info_data_request done /data_request?id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay ret 0 size 46 pMem 0x1839000/25399296 diff: 8257536 took 0 info (nil) <0x73f9b520>
10      01/05/17 8:52:48.240    mg_callback /data_request stop id: 37 <0x73f9b520>
10      01/05/17 8:52:48.241    GlobalLog: mongoose get_socket: 0x126c4b0 idle: 0 threads: 2 max: 100 head: 17 tail: 17 s: d:30516 <0x73f9b520>
52      01/05/17 8:52:48.421    0x21 0x53 0x65 0x6e 0x64 0x69 0x6e 0x67 0x2e 0x64 0x6f 0x6e 0x65 (!Sending.done) <0x73932520>
52      01/05/17 8:52:48.607    0x5b 0x31 0x30 0x30 0x31 0x30 0x30 0x30 0x31 0x31 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x2d 0x2d 0x2d 0x2d 0x5d 0x2c 0x30 0x30 0x38 0x2c 0x5b 0x66 0x37 0x30 0x30 0x30 0x30 0x31 0x66 0x31 0x30 0x30 0x38 0x30 0x30 0x31 0x63 0x32 0x38 0x30 0x32 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x5d 0x2c 0x22 0x20 0x44 0x49 0x53 0x41 0x52 0x4d 0x45 0x44 0x20 0x43 0x48 0x49 0x4d 0x45 0x20 0x20 0x20 0x52 0x65 0x61 0x64 0x79 0x20 0x74 0x6f 0x20 0x41 0x72 0x6d 0x20 0x20 0x22 ([1001000110000000----],008,[f700001f1008001c28020000000000]," DISARMED CHIME   Ready to Arm  ") <0x73932520>

and here is a successful one:
Code: [Select]
10      01/05/17 8:53:25.560    mg_callback from IP:127.0.0.1:46844 /port_3480/data_request id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 start id: 44 <0x73f9b520>
12      01/05/17 8:53:25.561    luvd_get_info_data_request starting /data_request?id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
10      01/05/17 8:53:25.561    JobHandler_LuaUPnP::HandleRequest id lu_action request pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
10      01/05/17 8:53:25.562    sbrk JobHandler_LuaUPnP::HandleActionRequest from IP:229.93.110.88 pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
08      01/05/17 8:53:25.563    JobHandler_LuaUPnP::HandleActionRequest device: 6 service: urn:micasaverde-com:serviceId:AlarmPartition2 action: RequestArmMode <0x73f9b520>
08      01/05/17 8:53:25.563    JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=6 <0x73f9b520>
08      01/05/17 8:53:25.563    JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:AlarmPartition2 <0x73f9b520>
08      01/05/17 8:53:25.564    JobHandler_LuaUPnP::HandleActionRequest argument action=RequestArmMode <0x73f9b520>
08      01/05/17 8:53:25.564    JobHandler_LuaUPnP::HandleActionRequest argument State=Stay <0x73f9b520>
08      01/05/17 8:53:25.564    JobHandler_LuaUPnP::HandleActionRequest argument PINCode=1234 <0x73f9b520>
25      01/05/17 8:53:25.565    luup_io_write 3 size: 5 <0x73f9b520>
51      01/05/17 8:53:25.565    0x31 0x32 0x33 0x34 0x33 0xd 0xa (12343\r\n) <0x73f9b520>
25      01/05/17 8:53:25.573    luup_io_write 3 result: 1 <0x73f9b520>
35      01/05/17 8:53:25.574    ImplAction::HandleActionRequest SAlarmPartition2_AlarmPartition2_RequestArmMode_run returned 0 <0x73f9b520>
10      01/05/17 8:53:25.575    luvd_get_info_data_request creating file buffer /data_request?id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 pMem 0x1839000/25399296 diff: 8257536 <0x73f9b520>
10      01/05/17 8:53:25.577    luvd_get_info_data_request done /data_request?id=lu_action&output_format=json&DeviceNum=6&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 ret 0 size 46 pMem 0x1839000/25399296 diff: 8257536 took 0 info (nil) <0x73f9b520>
10      01/05/17 8:53:25.578    mg_callback /data_request stop id: 44 <0x73f9b520>
10      01/05/17 8:53:25.578    GlobalLog: mongoose get_socket: 0x126c4b0 idle: 0 threads: 2 max: 100 head: 4 tail: 4 s: d:30516 <0x73f9b520>
52      01/05/17 8:53:25.706    0x21 0x53 0x65 0x6e 0x64 0x69 0x6e 0x67 0x2e 0x64 0x6f 0x6e 0x65 (!Sending.done) <0x73932520>
52      01/05/17 8:53:26.225    0x5b 0x30 0x30 0x31 0x31 0x30 0x33 0x30 0x31 0x31 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x2d 0x2d 0x2d 0x2d 0x5d 0x2c 0x30 0x36 0x30 0x2c 0x5b 0x66 0x37 0x30 0x30 0x30 0x30 0x31 0x66 0x31 0x30 0x36 0x30 0x30 0x33 0x38 0x30 0x32 0x38 0x30 0x32 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x5d 0x2c 0x22 0x41 0x52 0x4d 0x45 0x44 0x20 0x2a 0x2a 0x2a 0x53 0x54 0x41 0x59 0x2a 0x2a 0x2a 0x4d 0x61 0x79 0x20 0x45 0x78 0x69 0x74 0x20 0x4e 0x6f 0x77 0x20 0x20 0x36 0x30 0x22 ([0011030110000000----],060,[f700001f1060038028020000000000],"ARMED ***STAY***May Exit Now  60") <0x73932520>
06      01/05/17 8:53:26.226    Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:AlarmPartition2 variable: DetailedArmMode was: Ready now: ExitDelay #hooks: 5 upnp: 0 skip: 0 v:0x11f5fc0/NONE duplicate:0 <0x73932520>

Apparently I only had verbose logging turned on, even though I set the debug to 1 inside the alarm panel settings. I guess I need to reload after.

As you can see log entries 51 are showing what exactly is being sent to the AD2USB. I would include 51 and 52 in your research.

Note: I don't know where the IP addresses in the log come from. I have modified the second log to put in bogus PIN.

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #12 on: January 07, 2017, 12:43:31 pm »
Alright.  Digging back in.  I opened up the log to be wide open, verbose, and debug on for my device.

I noticed my logs weren't totally matching.  Your logs showed the pincode being used whereas mine showed USING STORED PINCODE.  In the log below I hit STAY, then changed the pin code.  I've changed mine to 1234

Code: [Select]
10 01/07/17 9:20:04.954 mg_callback from IP:127.0.0.1:55327 /port_3480/data_request id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay start id: 67 <0x2f569680>
12 01/07/17 9:20:04.955 luvd_get_info_data_request starting /data_request?id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
10 01/07/17 9:20:04.956 JobHandler_LuaUPnP::HandleRequest id lu_action request pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
10 01/07/17 9:20:04.957 sbrk JobHandler_LuaUPnP::HandleActionRequest from IP:0.0.0.0 pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
08 01/07/17 9:20:04.957 JobHandler_LuaUPnP::HandleActionRequest device: 19 service: urn:micasaverde-com:serviceId:AlarmPartition2 action: RequestArmMode <0x2f569680>
08 01/07/17 9:20:04.958 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=19 <0x2f569680>
08 01/07/17 9:20:04.959 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:AlarmPartition2 <0x2f569680>
08 01/07/17 9:20:04.959 JobHandler_LuaUPnP::HandleActionRequest argument action=RequestArmMode <0x2f569680>
08 01/07/17 9:20:04.960 JobHandler_LuaUPnP::HandleActionRequest argument State=Stay <0x2f569680>
50 01/07/17 9:20:04.961 luup_log:18: (VistaAlarmPanel::requestArmMode) Request new arm mode: 'Stay', device #19. <0x2f569680>
50 01/07/17 9:20:04.961 luup_log:18: (VistaAlarmPanel::requestArmMode) partNo = 1 <0x2f569680>
50 01/07/17 9:20:04.962 luup_log:18: (VistaAlarmPanel::getPinCode) Using the stored PIN code. <0x2f569680>
50 01/07/17 9:20:04.962 luup_log:18: (VistaAlarmPanel::requestArmMode) Current arm mode = 'Ready'. <0x2f569680>
25 01/07/17 9:20:04.963 luup_io_write 18 size: 5 <0x2f569680>
51 01/07/17 9:20:04.964 0x31 0x32 0x33 0x34 0x33 0xd 0xa (12343\r\n) <0x2f569680>
25 01/07/17 9:20:04.965 luup_io_write 18 result: 1 <0x2f569680>
35 01/07/17 9:20:04.966 ImplAction::HandleActionRequest SAlarmPartition2_AlarmPartition2_RequestArmMode_run returned 0 <0x2f569680>
10 01/07/17 9:20:04.967 luvd_get_info_data_request creating file buffer /data_request?id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
10 01/07/17 9:20:04.969 luvd_get_info_data_request done /data_request?id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay ret 0 size 46 pMem 0x138c000/20496384 diff: 9142272 took 0 info (nil) <0x2f569680>
10 01/07/17 9:20:04.970 mg_callback /data_request stop id: 67 <0x2f569680>
10 01/07/17 9:20:04.971 GlobalLog: mongoose get_socket: 0xb89c38 idle: 0 threads: 3 max: 100 head: 7 tail: 7 s: d:2155 <0x2f569680>
31 01/07/17 9:20:06.100 AlarmManager::Run 0xad64b0 notified of a change entry 0x115d5d0 id 160 deleted 0 <0x2bd69680>
31 01/07/17 9:20:06.101 AlarmManager::Run callback for alarm 0xad64b0 entry 0x115d5d0 type 52 id 160 param=(nil) entry->when: 1483809606 time: 1483809606 tnum: 1 slow 0 tardy 0 <0x2bd69680>
10 01/07/17 9:20:06.101 UserData::SetTag LuaUPnPAlive=1483809606 <0x2bd69680>
10 01/07/17 9:20:06.102 AlarmManager::AddRelativeAlarm current time 1483809606 delay 5 type 52 <0x2bd69680>
10 01/07/17 9:20:06.103 AlarmManager::AddAbsoluteAlarm alarm 0xad64b0 entry 0x10c0c78 id 161 type 52 param=(nil) entry->when: 1483809611 time: 1483809606 bCancelFirst 0=0 <0x2bd69680>
31 01/07/17 9:20:06.103 AlarmManager::Run finish callback for alarm 0xad64b0 entry 0x115d5d0 type 52 id 160 param=(nil) entry->when: 1483809606 time: 1483809606 tnum: 1 slow 0 duration 0 <0x2bd69680>
31 01/07/17 9:20:06.104 AlarmManager::Run 0xba5408 notified of a change entry 0xc892b8 id 1 deleted 0 <0x2cd69680>
31 01/07/17 9:20:06.105 AlarmManager::Run callback for alarm 0xba5408 entry 0xc892b8 type 7 id 1 param=0xb800a8 entry->when: 1483809606 time: 1483809606 tnum: 0 slow 1 tardy 0 <0x2cd69680>
35 01/07/17 9:20:06.105 LuaInterface::CallFunction_Timer func:checkConnection device:18 <0x2cd69680>
31 01/07/17 9:20:06.106 AlarmManager::Run 0xad64b0 notified of a change entry 0xd21d88 id 150 deleted 0 <0x2bf69680>
50 01/07/17 9:20:06.107 luup_log:18: (VistaAlarmPanel::checkConnection) Connection up. <0x2cd69680>
10 01/07/17 9:20:06.107 AlarmManager::AddRelativeAlarm current time 1483809606 delay 180 type 7 <0x2cd69680>
10 01/07/17 9:20:06.108 AlarmManager::AddAbsoluteAlarm alarm 0xba5408 entry 0x1152d10 id 37 type 7 param=0x11f7218 entry->when: 1483809786 time: 1483809606 bCancelFirst 0=0 <0x2cd69680>
31 01/07/17 9:20:06.109 AlarmManager::Run finish callback for alarm 0xba5408 entry 0xc892b8 type 7 id 1 param=0xb800a8 entry->when: 1483809606 time: 1483809606 tnum: 0 slow 1 duration 0 <0x2cd69680>
31 01/07/17 9:20:06.109 AlarmManager::Run callback for alarm 0xba5408 entry 0x10d74d8 type 7 id 36 param=0x10aed08 entry->when: 1483809606 time: 1483809606 tnum: 0 slow 1 tardy 0 <0x2cd69680>
35 01/07/17 9:20:06.110 LuaInterface::CallFunction_Timer func:ttlCountdownTimer device:18 <0x2cd69680>
10 01/07/17 9:20:06.111 AlarmManager::AddRelativeAlarm current time 1483809606 delay 5 type 7 <0x2cd69680>
10 01/07/17 9:20:06.111 AlarmManager::AddAbsoluteAlarm alarm 0xba5408 entry 0x115f4c8 id 38 type 7 param=0xc2c1a8 entry->when: 1483809611 time: 1483809606 bCancelFirst 0=0 <0x2cd69680>
31 01/07/17 9:20:06.112 AlarmManager::Run finish callback for alarm 0xba5408 entry 0x10d74d8 type 7 id 36 param=0x10aed08 entry->when: 1483809606 time: 1483809606 tnum: 0 slow 1 duration 0 <0x2cd69680>
10 01/07/17 9:20:09.890 GlobalLog: mongoose put_socket: idle: 1 threads: 3 max: 100 s: d:2155 <0x2f369680>
10 01/07/17 9:20:09.891 GlobalLog: mongoose get_socket2: 0xb89c38 idle: 0 threads: 3 max: 100 head: 8 tail: 7 s: d:2155 <0x2f569680>
10 01/07/17 9:20:09.892 GlobalLog: mongoose get_socket3: 0xb89c38 idle: 0 threads: 3 max: 100 head: 8 tail: 8 s: d:2155 <0x2f569680>
10 01/07/17 9:20:09.892 GlobalLog: mongoose ctx: 0xb89c38 idle: 0 threads: 3 max: 100 pthread_self: 794203776 s: d:2155 <0x2f569680>
10 01/07/17 9:20:09.893 mg_callback from IP:127.0.0.1:55328 /port_3480/data_request id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:VistaAlarmPanel1&action=StorePinCode&PINCode=1234 start id: 68 <0x2f569680>
12 01/07/17 9:20:09.894 luvd_get_info_data_request starting /data_request?id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:VistaAlarmPanel1&action=StorePinCode&PINCode=1234 pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
10 01/07/17 9:20:09.895 JobHandler_LuaUPnP::HandleRequest id lu_action request pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
10 01/07/17 9:20:09.896 sbrk JobHandler_LuaUPnP::HandleActionRequest from IP:0.0.0.0 pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
08 01/07/17 9:20:09.897 JobHandler_LuaUPnP::HandleActionRequest device: 19 service: urn:micasaverde-com:serviceId:VistaAlarmPanel1 action: StorePinCode <0x2f569680>
08 01/07/17 9:20:09.897 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=19 <0x2f569680>
08 01/07/17 9:20:09.898 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:VistaAlarmPanel1 <0x2f569680>
08 01/07/17 9:20:09.898 JobHandler_LuaUPnP::HandleActionRequest argument action=StorePinCode <0x2f569680>
08 01/07/17 9:20:09.899 JobHandler_LuaUPnP::HandleActionRequest argument PINCode=1234 <0x2f569680>
50 01/07/17 9:20:09.900 luup_log:18: (VistaAlarmPanel::storePinCode) Store PIN code, device #19. <0x2f569680>
50 01/07/17 9:20:09.901 luup_log:18: (VistaAlarmPanel::storePinCode) partNo = 1 <0x2f569680>
50 01/07/17 9:20:09.902 luup_log:18: (VistaAlarmPanel::storePinCode) SUCCESS: PIN code stored. <0x2f569680>
50 01/07/17 9:20:09.902 luup_log:18: (VistaAlarmPanel::task) PIN code stored. <0x2f569680>
10 01/07/17 9:20:09.903 UserData::m_iDataVersion_Variables_incr startup user data 809416006 variables 809416142 <0x2f569680>

After the pin code change my log starts to look like yours.  Still behaving badly!

Code: [Select]


10 01/07/17 9:20:12.747 mg_callback from IP:127.0.0.1:55332 /port_3480/data_request id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 start id: 71 <0x2e369680>
12 01/07/17 9:20:12.747 luvd_get_info_data_request starting /data_request?id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 pMem 0x138c000/20496384 diff: 9142272 <0x2e369680>
10 01/07/17 9:20:12.750 luvd_get_info_data_request creating file buffer /data_request?id=lu_status&DataVersion=809416142&MinimumDelay=1000&Timeout=60&LoadTime=1483809416&rand=0.824902236040026 pMem 0x138c000/20496384 diff: 9142272 <0x2f7e8680>
10 01/07/17 9:20:12.752 luvd_get_info_data_request done /data_request?id=lu_status&DataVersion=809416142&MinimumDelay=1000&Timeout=60&LoadTime=1483809416&rand=0.824902236040026 ret 0 size 525 pMem 0x138c000/20496384 diff: 9142272 took 0 info (nil) <0x2f7e8680>
10 01/07/17 9:20:12.753 mg_callback /data_request stop id: 71 <0x2f7e8680>
10 01/07/17 9:20:12.755 GlobalLog: mongoose get_socket: 0xb89c38 idle: 1 threads: 3 max: 100 head: 11 tail: 11 s: d:2155 <0x2f7e8680>
10 01/07/17 9:20:12.758 JobHandler_LuaUPnP::HandleRequest id lu_action request pMem 0x138c000/20496384 diff: 9142272 <0x2e369680>
10 01/07/17 9:20:12.759 sbrk JobHandler_LuaUPnP::HandleActionRequest from IP:0.0.0.0 pMem 0x138c000/20496384 diff: 9142272 <0x2e369680>
08 01/07/17 9:20:12.760 JobHandler_LuaUPnP::HandleActionRequest device: 19 service: urn:micasaverde-com:serviceId:AlarmPartition2 action: RequestArmMode <0x2e369680>
08 01/07/17 9:20:12.760 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=19 <0x2e369680>
08 01/07/17 9:20:12.761 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:AlarmPartition2 <0x2e369680>
08 01/07/17 9:20:12.761 JobHandler_LuaUPnP::HandleActionRequest argument action=RequestArmMode <0x2e369680>
08 01/07/17 9:20:12.762 JobHandler_LuaUPnP::HandleActionRequest argument State=Stay <0x2e369680>
08 01/07/17 9:20:12.762 JobHandler_LuaUPnP::HandleActionRequest argument PINCode=1234 <0x2e369680>
50 01/07/17 9:20:12.774 luup_log:18: (VistaAlarmPanel::requestArmMode) Request new arm mode: 'Stay', device #19. <0x2e369680>
50 01/07/17 9:20:12.774 luup_log:18: (VistaAlarmPanel::requestArmMode) partNo = 1 <0x2e369680>
50 01/07/17 9:20:12.775 luup_log:18: (VistaAlarmPanel::getPinCode) Using supplied PIN code. <0x2e369680>
50 01/07/17 9:20:12.776 luup_log:18: (VistaAlarmPanel::requestArmMode) Current arm mode = 'Ready'. <0x2e369680>
25 01/07/17 9:20:12.776 luup_io_write 18 size: 5 <0x2e369680>
51 01/07/17 9:20:12.777 0x31 0x32 0x33 0x34 0x33 0xd 0xa (12343\r\n) <0x2e369680>
25 01/07/17 9:20:12.778 luup_io_write 18 result: 1 <0x2e369680>
35 01/07/17 9:20:12.779 ImplAction::HandleActionRequest SAlarmPartition2_AlarmPartition2_RequestArmMode_run returned 0 <0x2e369680>
10 01/07/17 9:20:12.780 luvd_get_info_data_request creating file buffer /data_request?id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 pMem 0x138c000/20496384 diff: 9142272 <0x2e369680>
10 01/07/17 9:20:12.782 luvd_get_info_data_request done /data_request?id=lu_action&output_format=json&DeviceNum=19&serviceId=urn:micasaverde-com:serviceId:AlarmPartition2&action=RequestArmMode&State=Stay&PINCode=1234 ret 0 size 46 pMem 0x138c000/20496384 diff: 9142272 took 0 info (nil) <0x2e369680>
10 01/07/17 9:20:12.783 mg_callback /data_request stop id: 71 <0x2e369680>
10 01/07/17 9:20:12.784 GlobalLog: mongoose get_socket: 0xb89c38 idle: 2 threads: 3 max: 100 head: 11 tail: 11 s: d:2155 <0x2e369680>
10 01/07/17 9:20:13.108 GlobalLog: mongoose put_socket: idle: 3 threads: 3 max: 100 s: d:2155 <0x2f369680>
10 01/07/17 9:20:13.109 GlobalLog: mongoose get_socket2: 0xb89c38 idle: 2 threads: 3 max: 100 head: 12 tail: 11 s: d:2155 <0x2f569680>
10 01/07/17 9:20:13.110 GlobalLog: mongoose get_socket3: 0xb89c38 idle: 2 threads: 3 max: 100 head: 12 tail: 12 s: d:2155 <0x2f569680>
10 01/07/17 9:20:13.111 GlobalLog: mongoose ctx: 0xb89c38 idle: 2 threads: 3 max: 100 pthread_self: 794203776 s: d:2155 <0x2f569680>
10 01/07/17 9:20:13.111 mg_callback from IP:127.0.0.1:55333 /port_3480/data_request id=lu_status&DataVersion=809416143&MinimumDelay=1000&Timeout=60&LoadTime=1483809416&rand=0.7446639324072231 start id: 72 <0x2f569680>
12 01/07/17 9:20:13.112 luvd_get_info_data_request starting /data_request?id=lu_status&DataVersion=809416143&MinimumDelay=1000&Timeout=60&LoadTime=1483809416&rand=0.7446639324072231 pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
10 01/07/17 9:20:13.113 JobHandler_LuaUPnP::HandleRequest id lu_status request pMem 0x138c000/20496384 diff: 9142272 <0x2f569680>
52 01/07/17 9:20:13.467 0x21 0x53 0x65 0x6e 0x64 0x69 0x6e 0x67 0x2e 0x2e 0x2e 0x2e 0x2e 0x64 0x6f 0x6e 0x65 (!Sending.....done) <0x2f169680>
50 01/07/17 9:20:13.467 luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '!Sending.....done'. <0x2f169680>
52 01/07/17 9:20:13.478 0x5b 0x31 0x30 0x30 0x30 0x30 0x30 0x30 0x31 0x31 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x2d 0x2d 0x2d 0x2d 0x5d 0x2c 0x30 0x30 0x38 0x2c 0x5b 0x66 0x37 0x30 0x30 0x30 0x30 0x30 0x37 0x31 0x30 0x30 0x38 0x30 0x30 0x31 0x63 0x32 0x38 0x30 0x32 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x5d 0x2c 0x22 0x20 0x44 0x49 0x53 0x41 0x52 0x4d 0x45 0x44 0x20 0x43 0x48 0x49 0x4d 0x45 0x20 0x20 0x20 0x52 0x65 0x61 0x64 0x79 0x20 0x74 0x6f 0x20 0x41 0x72 0x6d 0x20 0x20 0x22 ([1000000110000000----],008,[f70000071008001c28020000000000]," DISARMED CHIME   Ready to Arm  ") <0x2f169680>
50 01/07/17 9:20:13.478 luup_log:18: (VistaAlarmPanel::processIncoming) Incoming data = '[1000000110000000----],008,[f70000071008001c28020000000000]," DISARMED CHIME   Ready to Arm  "'. <0x2f169680>
50 01/07/17 9:20:13.479 luup_log:18: (VistaAlarmPanel::getStatusFlags) Active flags: READY, CHIME_MODE <0x2f169680>
50 01/07/17 9:20:13.480 luup_log:18: (VistaAlarmPanel::getPartitionState) Got Alarm='None' for partition 1 (device #19). <0x2f169680>
50 01/07/17 9:20:13.481 luup_log:18: (VistaAlarmPanel::getPartitionState) Got ArmMode='Disarmed' for partition 1 (device #19). <0x2f169680>
50 01/07/17 9:20:13.482 luup_log:18: (VistaAlarmPanel::getPartitionState) Got DetailedArmMode='Ready' for partition 1 (device #19). <0x2f169680>

« Last Edit: February 11, 2017, 07:05:20 pm by alien8er »

Offline alien8er

  • Sr. Newbie
  • *
  • Posts: 28
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #13 on: January 07, 2017, 01:26:17 pm »
Also, just went and plugged into my AD2USB directly and changed statuses about 15 times with no failure or delays.  This stuff drives me crazy. 

Offline peterv

  • Sr. Newbie
  • *
  • Posts: 25
  • Karma: +0/-0
Re: Issues changing alarm panel state through Vera
« Reply #14 on: January 09, 2017, 12:15:04 pm »
One thing I noticed is that my requests and replies are around 100ms apart:
Code: [Select]
51      01/05/17 8:52:48.238    0x30 0x30 0x30 0x30 0x33 0xd 0xa (00003\r\n) <0x73f9b520>
52      01/05/17 8:52:48.421    0x21 0x53 0x65 0x6e 0x64 0x69 0x6e 0x67 0x2e 0x64 0x6f 0x6e 0x65 (!Sending.done) <0x73932520>

51      01/05/17 8:53:25.565    0x31 0x32 0x33 0x34 0x33 0xd 0xa (12343\r\n) <0x73f9b520>
52      01/05/17 8:53:25.706    0x21 0x53 0x65 0x6e 0x64 0x69 0x6e 0x67 0x2e 0x64 0x6f 0x6e 0x65 (!Sending.done) <0x73932520>

where yours, if it responds at all, is almost a second:
Code: [Select]
51 01/07/17 9:20:12.777 0x31 0x32 0x33 0x34 0x33 0xd 0xa (12343\r\n) <0x2e369680>
52 01/07/17 9:20:13.467 0x21 0x53 0x65 0x6e 0x64 0x69 0x6e 0x67 0x2e 0x2e 0x2e 0x2e 0x2e 0x64 0x6f 0x6e 0x65 (!Sending.....done) <0x2f169680>


Do you have the serial port configured right?

One thing you could try is to manually send the request from vera's shell. I will look it up and add a link here.

Note: I believe I entered the Path in the serial port configuration manually. I don't think it makes any difference.

*Edit: Here are instructions on how to enter alarm panel commands from vera's shell http://forum.micasaverde.com/index.php/topic,14923.msg180234.html#msg180234. I know this used to work with UI5 firmwares, because I actually used it to configure my alarm panel. This procedure will shut down Vera. You might have to change the path to the ad2usb (/dev/ttyUSB0) in step 3 to match your system. You should be then able to use 12343<eneter> to arm your system stay and 12341<enter> to disarm. where 1234 is your PIN.
« Last Edit: January 09, 2017, 12:32:26 pm by peterv »