Plugin loses connection to Elk Panel (Serial to USB)

salilathalye · October 16, 2015, 11:39pm

Hi everyone,

I have a Vera Lite now running 1.7.690 and version 2.19 of the Elk Alarm Panel Plugin. Prior to upgrading to this level of firmware I had a stable connection between the Vera and the Elk M1-Gold using a serial to USB cable. The Vera went into a boot loop for some unknown reason and so I had to reset everything and start over. During the recovery process I decided to update the firmware to the latest, and I had to install the latest versions of all the plugins.

After upgrading the system does not appear to be stable: very frequently all sensors etc hooked up to the Elk will go offline and I get the message “27 devices are no longer connected…” in the dashboard. In order to rectify this I go into the Apps section and reload LUUP. The system will come up and hold the connection for a few minutes and then we are back in the same situation.

The baud rate is set to 115200 and Used by Device is set to Elk Alarm Panel []. Everything else is set to default.

Please point me to how to set up logging so that I can capture what is going on.

Thanks in advance,

sal

zoot1612 · October 19, 2015, 2:13am

@salilathalye
Please check here [url=http://wiki.micasaverde.com/index.php/Logs]http://wiki.micasaverde.com/index.php/Logs[/url]

This is a guide on how to access logs on the Vera. Once you have that you can post relevant data.

salilathalye · January 1, 2016, 2:47pm

Here is an excerpt from the log:

50 01/01/16 9:33:51.389 luup_log:211: ElkPlugin::checkConnectionType: Running on Serial. <0x2be08680>
01 01/01/16 9:33:51.389 lu_io_connected 0x103ab28 args 1 0xac0e40 <0x2be08680>
06 01/01/16 9:33:51.390 Device_Variable::m_szValue_set device: 211 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 1 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0xafb9d8/NONE duplicate:1 <0x2be08680>
01 01/01/16 9:33:51.390 LuaInterface::CallFunction_Startup-2 device 211 function elkStartup failed Elk Alarm Panel with return false <0x2be08680>
01 01/01/16 9:33:51.392 LuImplementation::StartLua running startup code for 211 I_ElkAlarmPanel1.xml failed <0x2be08680>

Any thoughts on what might be causing this? The connection seems very flaky: sometimes reloading LuuP works for a while (8-10 hours) and other times multiple reloads of LuuP still results in not connecting to the Panel.

salilathalye · January 1, 2016, 3:10pm

I uninstalled the Plugin, reloaded Luup and then installed version 2.19 of the plugin. Then went into Develop Apps and set the serial port to use Elk Panel. Here is the log filtered for “Elk”

09 01/01/16 10:08:35.080 JobHandler_LuaUPnP::Run device 236 Elk Alarm Panel room 10 type urn:schemas-micasaverde-com:device:ElkAlarmPanel:1 cat 22:-1 id parent 0/0xe10658 upnp: 0 plugin:938 pnp:0 mac: ip: <0x2b5e3000>
50 01/01/16 10:08:48.254 luup_log:62: device # 236: supports HVAC_UserOperatingMode1; set watch on variable ‘ModeTarget’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.255 luup_log:62: device # 236: supports HVAC_UserOperatingMode1; set watch on variable ‘ModeStatus’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.256 luup_log:62: device # 236: supports HVAC_UserOperatingMode1; set watch on variable ‘EnergyModeTarget’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.256 luup_log:62: device # 236: supports HVAC_UserOperatingMode1; set watch on variable ‘EnergyModeStatus’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.257 luup_log:62: device # 236: supports HVAC_FanOperatingMode1; set watch on variable ‘Mode’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.258 luup_log:62: device # 236: supports HVAC_FanOperatingMode1; set watch on variable ‘FanStatus’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.259 luup_log:62: device # 236: supports TemperatureSetpoint1_Heat; set watch on variable ‘CurrentSetpoint’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.259 luup_log:62: device # 236: supports TemperatureSetpoint1_Heat; set watch on variable ‘SetpointTarget’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.260 luup_log:62: device # 236: supports TemperatureSetpoint1_Cool; set watch on variable ‘CurrentSetpoint’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.261 luup_log:62: device # 236: supports TemperatureSetpoint1_Cool; set watch on variable ‘SetpointTarget’ for Elk Alarm Panel <0x2bd34680>
50 01/01/16 10:08:48.892 luup_log:236: ElkPlugin:::M1 Panel Plugin version 2.19. <0x2bd34680>
50 01/01/16 10:08:48.894 luup_log:236: ElkPlugin::getDebugMode: Debug mode disabled. <0x2bd34680>
50 01/01/16 10:08:52.905 luup_log:236: ElkPlugin::checkConnectionType: Running on Serial. <0x2bd34680>
01 01/01/16 10:08:52.907 LuaInterface::CallFunction_Startup-2 device 236 function elkStartup failed Elk Alarm Panel with return false <0x2bd34680>
01 01/01/16 10:08:52.919 LuImplementation::StartLua running startup code for 236 I_ElkAlarmPanel1.xml failed <0x2bd34680>

salilathalye · January 1, 2016, 3:49pm

In this scenario I am capturing logs including the install of 2.19 of the plugin:

root@MiOS_…:/tmp/log/cmh# tail -f LuaUPnP.log | grep “Elk*”
7703 root 1672 S grep Elk*
7703 root 1672 S grep Elk*
7703 root 1672 S grep Elk*
02 01/01/16 10:44:13.696 JobHandler_LuaUPnP::FetchMissingFiles need to download D_ElkAlarmPanel1.json <0x2ad6c000>
02 01/01/16 10:44:13.697 JobHandler_LuaUPnP::m_sMissingFile_set D_ElkAlarmPanel1.json <0x2ad6c000>
02 01/01/16 10:44:13.698 JobHandler_LuaUPnP::FetchMissingFiles need to download D_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.699 JobHandler_LuaUPnP::m_sMissingFile_set D_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.699 JobHandler_LuaUPnP::FetchMissingFiles need to download D_ElkAlarmPartition1.json <0x2ad6c000>
02 01/01/16 10:44:13.700 JobHandler_LuaUPnP::m_sMissingFile_set D_ElkAlarmPartition1.json <0x2ad6c000>
02 01/01/16 10:44:13.701 JobHandler_LuaUPnP::FetchMissingFiles need to download D_ElkAlarmPartition1.xml <0x2ad6c000>
02 01/01/16 10:44:13.702 JobHandler_LuaUPnP::m_sMissingFile_set D_ElkAlarmPartition1.xml <0x2ad6c000>
02 01/01/16 10:44:13.702 JobHandler_LuaUPnP::FetchMissingFiles need to download L_ElkAlarmPanel1.lua <0x2ad6c000>
02 01/01/16 10:44:13.703 JobHandler_LuaUPnP::m_sMissingFile_set L_ElkAlarmPanel1.lua <0x2ad6c000>
02 01/01/16 10:44:13.704 JobHandler_LuaUPnP::FetchMissingFiles need to download I_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.705 JobHandler_LuaUPnP::m_sMissingFile_set I_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.705 JobHandler_LuaUPnP::FetchMissingFiles need to download S_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.706 JobHandler_LuaUPnP::m_sMissingFile_set S_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.707 JobHandler_LuaUPnP::FetchMissingFiles need to download J_ElkAlarmPanel1.js <0x2ad6c000>
02 01/01/16 10:44:13.708 JobHandler_LuaUPnP::m_sMissingFile_set J_ElkAlarmPanel1.js <0x2ad6c000>
02 01/01/16 10:44:13.709 JobHandler_LuaUPnP::FetchMissingFiles need to download D_ElkAlarmPanel1_UI7.json <0x2ad6c000>
02 01/01/16 10:44:13.710 JobHandler_LuaUPnP::m_sMissingFile_set D_ElkAlarmPanel1_UI7.json <0x2ad6c000>
02 01/01/16 10:44:13.710 JobHandler_LuaUPnP::FetchMissingFiles need to download D_ElkAlarmPartition1_UI7.json <0x2ad6c000>
02 01/01/16 10:44:13.711 JobHandler_LuaUPnP::m_sMissingFile_set D_ElkAlarmPartition1_UI7.json <0x2ad6c000>
02 01/01/16 10:44:13.712 JobHandler_LuaUPnP::FetchMissingFiles need to download J_ElkAlarmPanel1_UI7.js <0x2ad6c000>
02 01/01/16 10:44:13.713 JobHandler_LuaUPnP::m_sMissingFile_set J_ElkAlarmPanel1_UI7.js <0x2ad6c000>
01 01/01/16 10:44:13.917 Device_LuaUPnP::LoadDeviceDoc can’t load /etc/cmh-lu//D_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.917 JobHandler_LuaUPnP::m_sMissingFile_set /etc/cmh-lu//D_ElkAlarmPanel1.xml <0x2ad6c000>
02 01/01/16 10:44:13.918 JobHandler_LuaUPnP::CreateDevice_LuaUPnP failed to load 237/D_ElkAlarmPanel1.xml so device 237 is offline while waiting for download the file <0x2ad6c000>
09 01/01/16 10:44:18.359 JobHandler_LuaUPnP::Run device 237 room 0 type urn:schemas-micasaverde-com:device:ElkAlarmPanel:1 cat 0:-1 id parent 0/0xa47440 upnp: 0 plugin:938 pnp:0 mac: ip: <0x2ad6c000>
03 01/01/16 10:44:18.483 JobHandler_LuaUPnP::Run ready 62 devices oem:1 skin:1-mios installation 35014080 missing /etc/cmh-lu//D_ElkAlarmPanel1.xml version 1.7.730 allow_evt: 1 allow_ud: 1 upnp 0 netpnp: 1 reprovision: 0 secure: 0 tz:18000 tnow:1451663058 dst: 0 gmt:-18000 tz:EST / EDT fahr:1 changed: 0 pMem 0x1175000 start 9228288 diff: 9076736 <0x2ad6c000>
7703 root 1672 S grep Elk*
7703 root 1672 S grep Elk*
7703 root 1672 S grep Elk*
09 01/01/16 10:44:33.944 JobHandler_LuaUPnP::Run device 237 Elk Alarm Panel room 0 type urn:schemas-micasaverde-com:device:ElkAlarmPanel:1 cat 22:-1 id parent 0/0xc3ae08 upnp: 0 plugin:938 pnp:0 mac: ip: <0x2b8a2000>
50 01/01/16 10:44:49.062 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘ModeTarget’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.063 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘ModeStatus’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.063 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘EnergyModeTarget’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.064 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘EnergyModeStatus’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.065 luup_log:62: device # 237: supports HVAC_FanOperatingMode1; set watch on variable ‘Mode’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.066 luup_log:62: device # 237: supports HVAC_FanOperatingMode1; set watch on variable ‘FanStatus’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.066 luup_log:62: device # 237: supports TemperatureSetpoint1_Heat; set watch on variable ‘CurrentSetpoint’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.067 luup_log:62: device # 237: supports TemperatureSetpoint1_Heat; set watch on variable ‘SetpointTarget’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.068 luup_log:62: device # 237: supports TemperatureSetpoint1_Cool; set watch on variable ‘CurrentSetpoint’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.069 luup_log:62: device # 237: supports TemperatureSetpoint1_Cool; set watch on variable ‘SetpointTarget’ for Elk Alarm Panel <0x2c1f2680>
50 01/01/16 10:44:49.742 luup_log:237: ElkPlugin:::M1 Panel Plugin version 2.19. <0x2c1f2680>
06 01/01/16 10:44:49.743 Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: DebugMode was: EMPTY now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x2c1f2680>
50 01/01/16 10:44:49.744 luup_log:237: ElkPlugin::getDebugMode: Debug mode disabled. <0x2c1f2680>
50 01/01/16 10:44:53.758 luup_log:237: ElkPlugin::checkConnectionType: Running on Serial. <0x2c1f2680>
01 01/01/16 10:44:53.763 LuaInterface::CallFunction_Startup-2 device 237 function elkStartup failed Elk Alarm Panel with return false <0x2c1f2680>
01 01/01/16 10:44:53.765 LuImplementation::StartLua running startup code for 237 I_ElkAlarmPanel1.xml failed <0x2c1f2680>

salilathalye · January 1, 2016, 4:23pm

01 01/01/16 11:11:07.409 LuImplementation::StartLua running startup code for 237 I_ElkAlarmPanel1.xml failed <0x2c0ec680>
7703 root 1676 S grep Elk*
7703 root 1676 S grep Elk*
7703 root 1676 S grep Elk*
09 01/01/16 11:12:04.993 JobHandler_LuaUPnP::Run device 237 Elk Alarm Panel room 0 type urn:schemas-micasaverde-com:device:ElkAlarmPanel:1 cat 22:-1 id parent 0/0xa35df8 upnp: 0 plugin:938 pnp:0 mac: ip: <0x2ab89000>
50 01/01/16 11:12:15.592 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘ModeTarget’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.593 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘ModeStatus’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.594 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘EnergyModeTarget’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.594 luup_log:62: device # 237: supports HVAC_UserOperatingMode1; set watch on variable ‘EnergyModeStatus’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.595 luup_log:62: device # 237: supports HVAC_FanOperatingMode1; set watch on variable ‘Mode’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.596 luup_log:62: device # 237: supports HVAC_FanOperatingMode1; set watch on variable ‘FanStatus’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.596 luup_log:62: device # 237: supports TemperatureSetpoint1_Heat; set watch on variable ‘CurrentSetpoint’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.597 luup_log:62: device # 237: supports TemperatureSetpoint1_Heat; set watch on variable ‘SetpointTarget’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.598 luup_log:62: device # 237: supports TemperatureSetpoint1_Cool; set watch on variable ‘CurrentSetpoint’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:15.599 luup_log:62: device # 237: supports TemperatureSetpoint1_Cool; set watch on variable ‘SetpointTarget’ for Elk Alarm Panel <0x2b4da680>
50 01/01/16 11:12:16.217 luup_log:237: ElkPlugin:::M1 Panel Plugin version 2.33. <0x2b4da680>
06 01/01/16 11:12:16.218 Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: PluginVersion was: 2.33 now: 2.33 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b4da680>
50 01/01/16 11:12:16.219 luup_log:237: ElkPlugin::getDebugMode: Debug mode disabled. <0x2b4da680>
50 01/01/16 11:12:20.229 luup_log:237: ElkPlugin::checkConnectionType: Running on Serial. <0x2b4da680>
01 01/01/16 11:12:20.231 LuaInterface::CallFunction_Startup-2 device 237 function elkStartup failed Elk Alarm Panel with return false <0x2b4da680>
01 01/01/16 11:12:20.232 LuImplementation::StartLua running startup code for 237 I_ElkAlarmPanel1.xml failed <0x2b4da680>
50 01/01/16 11:13:54.548 luup_log:237: ElkPlugin:::M1 Panel Plugin version 2.33. <0x2bc2a680>
06 01/01/16 11:13:54.580 Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: PluginVersion was: 2.33 now: 2.33 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2bc2a680>
50 01/01/16 11:13:54.581 luup_log:237: ElkPlugin::getDebugMode: Debug mode disabled. <0x2bc2a680>
50 01/01/16 11:13:58.612 luup_log:237: ElkPlugin::checkConnectionType: Running on Serial. <0x2bc2a680>
01 01/01/16 11:13:58.614 LuaInterface::CallFunction_Startup-2 device 237 function elkStartup failed Elk Alarm Panel with return false <0x2bc2a680>
01 01/01/16 11:13:58.615 LuImplementation::StartLua running startup code for 237 I_ElkAlarmPanel1.xml failed <0x2bc2a680>
02 01/01/16 11:14:22.551 JobHandler_LuaUPnP::REQ_Handler no handler for lr_ElkCustom <0x3006b680>
02 01/01/16 11:14:31.983 JobHandler_LuaUPnP::REQ_Handler no handler for lr_ElkCounters <0x3026b680>
08 01/01/16 11:14:52.662 JobHandler_LuaUPnP::HandleActionRequest device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 action: ClearTask <0x3026b680>
08 01/01/16 11:14:52.663 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:ElkAlarmPanel1 <0x3026b680>
02 01/01/16 11:14:52.665 JobHandler_LuaUPnP::RunAction device 237 action urn:micasaverde-com:serviceId:ElkAlarmPanel1/ClearTask failed with -911/Device not ready <0x3026b680>

zoot1612 · January 3, 2016, 9:20am

@salilathalye
In the advanced tab set debug to 1 in the plugin to get more details in log.

salilathalye · January 3, 2016, 2:37pm

Connection seems to be very flaky for whatever reason. Every once in a while, I can connect to the Elk board, but the connection can can go out at any time.

I was able to turn on detailed logging, so I will send you some more logs when the connection fails

The logs below (with detailed logging off)

50 01/03/16 9:19:41.255 06 01/03/16 9:19:41.255 50 01/03/16 9:19:41.257 50 01/03/16 9:19:45.272 50 01/03/16 9:19:45.294 06 01/03/16 9:19:45.295 50 01/03/16 9:19:45.295 50 01/03/16 9:19:45.323 50 01/03/16 9:19:45.623 50 01/03/16 9:19:45.674 50 01/03/16 9:19:45.704 50 01/03/16 9:19:45.763 50 01/03/16 9:19:45.783 50 01/03/16 9:19:45.803 50 01/03/16 9:19:45.823 50 01/03/16 9:19:45.853 50 01/03/16 9:19:45.873 50 01/03/16 9:19:45.893 50 01/03/16 9:19:45.904 50 01/03/16 9:19:45.923 50 01/03/16 9:19:45.953 50 01/03/16 9:19:45.973 50 01/03/16 9:19:45.993 50 01/03/16 9:19:46.013 50 01/03/16 9:19:46.033 50 01/03/16 9:19:46.053 50 01/03/16 9:19:46.073 50 01/03/16 9:19:46.084 50 01/03/16 9:19:46.103 50 01/03/16 9:19:46.124 50 01/03/16 9:19:46.143 50 01/03/16 9:19:46.183 06 01/03/16 9:19:46.676 06 01/03/16 9:19:46.676 06 01/03/16 9:19:46.677 06 01/03/16 9:19:46.678 06 01/03/16 9:19:46.679 06 01/03/16 9:19:46.679 50 01/03/16 9:19:51.124 50 01/03/16 9:19:51.124 06 01/03/16 9:19:51.146 06 01/03/16 9:19:56.101 50 01/03/16 8:10:37.367 06 01/03/16 8:10:37.368 50 01/03/16 8:10:37.372 50 01/03/16 8:10:41.382 50 01/03/16 8:10:51.385 50 01/03/16 8:10:51.386 50 01/03/16 8:11:02.988 50 01/03/16 8:11:02.989 50 01/03/16 8:11:15.394 50 01/03/16 8:11:15.395 01 01/03/16 8:11:15.396 01 01/03/16 8:11:15.398 luup_log:237: ElkPlugin:::M1 Panel Plugin version 2.33. <0x2b62e680>
Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: PluginVersion was: 2.33 now: 2.33 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
luup_log:237: ElkPlugin::getDebugMode: Debug mode disabled. <0x2b62e680>
luup_log:237: ElkPlugin::checkConnectionType: Running on Serial. <0x2b62e680>
luup_log:237: ElkPlugin:::M1 version 5.2.4 <0x2b62e680>
Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: FirmwareVersion was: 5.2.4 now: 5.2.4 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
luup_log:237: ElkPlugin::(ElkPlugin::getOutputs) No output controls. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Output Name No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Task Name No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Thermostat Names No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Keypad Name No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Counter Names No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
luup_log:237: ElkPlugin::processLabels: Label type: Custom Settings No processing. <0x2b62e680>
Device_Variable::m_szValue_set device: 245 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: zone_type was: Non Alarm now: Non Alarm #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
Device_Variable::m_szValue_set device: 246 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: zone_type was: Non Alarm now: Non Alarm #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
Device_Variable::m_szValue_set device: 247 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: zone_type was: Non Alarm now: Non Alarm #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
Device_Variable::m_szValue_set device: 248 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: zone_type was: Non Alarm now: Non Alarm #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
Device_Variable::m_szValue_set device: 249 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: zone_type was: Non Alarm now: Non Alarm #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
Device_Variable::m_szValue_set device: 250 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: zone_type was: Non Alarm now: Non Alarm #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b62e680>
luup_log:237: ElkPlugin::TROUBLE: Low Battery Control Trouble <0x2de2e680>
luup_log:237: ElkPlugin::task: Low Battery Control Trouble <0x2de2e680>
Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: TroubleReport was: Low Battery Control Trouble now: Low Battery Control Trouble #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2de2e680>
Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: Heartbeat was: 8 now: 10 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x2de2e680>
luup_log:237: ElkPlugin:::M1 Panel Plugin version 2.33. <0x2bc18680>
Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: PluginVersion was: 2.33 now: 2.33 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2bc18680>
luup_log:237: ElkPlugin::getDebugMode: Debug mode disabled. <0x2bc18680>
luup_log:237: ElkPlugin::checkConnectionType: Running on Serial. <0x2bc18680>
luup_log:237: ElkPlugin::checkMessage: ERROR: Empty message. <0x2bc18680>
luup_log:237: ElkPlugin::getVersion: ERROR: Failed to get version. <0x2bc18680>
luup_log:237: ElkPlugin::checkMessage: ERROR: Empty message. <0x2bc18680>
luup_log:237: ElkPlugin::getVersion: ERROR: Failed to get version. <0x2bc18680>
luup_log:237: ElkPlugin::checkMessage: ERROR: Empty message. <0x2bc18680>
luup_log:237: ElkPlugin::getVersion: ERROR: Failed to get version. <0x2bc18680>
LuaInterface::CallFunction_Startup-2 device 237 function elkStartup failed Elk Alarm Panel with return false <0x2bc18680>
LuImplementation::StartLua running startup code for 237 I_ElkAlarmPanel1.xml failed <0x2bc18680>

salilathalye · January 4, 2016, 12:43am

Connection just failed. UI showed 26 devices not connected but the plugin was logging the following (I used to have an M1XEP but no longer have it anymore. I wonder if the Elk M1 still thinks it is connected):

root@MiOS_…:/tmp/log/cmh# tail -f LuaUPnP.log | grep “Elk*”
02 01/03/16 19:34:47.413 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:34:47.414 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:34:55.003 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘3927191030116010’, misc=00, checksum=6A <0x2f98b680>
02 01/03/16 19:34:55.004 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:35:16.533 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:35:16.534 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:35:25.013 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘0928191030116010’, misc=00, checksum=6C <0x2f98b680>
02 01/03/16 19:35:25.014 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:35:45.653 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:35:45.654 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:35:55.033 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘3828191030116010’, misc=00, checksum=6A <0x2f98b680>
02 01/03/16 19:35:55.034 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:36:14.207 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:36:14.207 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:36:25.053 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘0829191030116010’, misc=00, checksum=6C <0x2f98b680>
02 01/03/16 19:36:25.054 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:36:43.253 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:36:43.254 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:36:55.073 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘3829191030116010’, misc=00, checksum=69 <0x2f98b680>
02 01/03/16 19:36:55.074 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:37:12.493 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:37:12.494 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:37:25.093 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘0930191030116010’, misc=00, checksum=73 <0x2f98b680>
02 01/03/16 19:37:25.094 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:37:41.623 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:37:41.624 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:37:55.113 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘3930191030116010’, misc=00, checksum=70 <0x2f98b680>
02 01/03/16 19:37:55.114 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:38:10.962 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:38:10.986 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>
02 01/03/16 19:38:31.269 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘0931191030116010’, misc=00, checksum=72 <0x2f98b680>
02 01/03/16 19:38:31.270 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f98b680>
02 01/03/16 19:38:48.767 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f98b680>
02 01/03/16 19:38:49.454 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f98b680>

salilathalye · January 4, 2016, 12:49am

Without any intervention other than refreshing the dashboard, the connection came back again:

02 01/03/16 19:44:48.473 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘3937191030116010’, misc=00, checksum=69 <0x2f63d680>
02 01/03/16 19:44:48.473 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f63d680>
02 01/03/16 19:44:49.602 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f63d680>
02 01/03/16 19:44:49.603 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f63d680>
02 01/03/16 19:44:49.604 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f63d680>
02 01/03/16 19:44:59.202 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘005A’, misc=00, checksum=BC <0x2f63d680>
02 01/03/16 19:44:59.203 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:44:59.204 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #5, status = Violated. <0x2f63d680>
02 01/03/16 19:44:59.204 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘1’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:02.233 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0053’, misc=00, checksum=CA <0x2f63d680>
02 01/03/16 19:45:02.233 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:02.234 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #5, status = Normal. <0x2f63d680>
02 01/03/16 19:45:02.235 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Armed’ = ‘1’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:02.236 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘0’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:02.962 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘005A’, misc=00, checksum=BC <0x2f63d680>
02 01/03/16 19:45:02.963 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:02.964 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #5, status = Violated. <0x2f63d680>
02 01/03/16 19:45:02.965 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘1’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:05.172 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f63d680>
02 01/03/16 19:45:05.173 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:05.174 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Violated. <0x2f63d680>
02 01/03/16 19:45:05.175 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘1’ for zone 1 (device 245). <0x2f63d680>
02 01/03/16 19:45:05.370 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f63d680>
02 01/03/16 19:45:05.371 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f63d680>
02 01/03/16 19:45:06.012 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0053’, misc=00, checksum=CA <0x2f63d680>
02 01/03/16 19:45:06.013 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:06.014 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #5, status = Normal. <0x2f63d680>
02 01/03/16 19:45:06.015 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Armed’ = ‘1’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:06.016 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘0’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:06.582 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘005A’, misc=00, checksum=BC <0x2f63d680>
02 01/03/16 19:45:06.583 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:06.584 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #5, status = Violated. <0x2f63d680>
02 01/03/16 19:45:06.584 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘1’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:06.672 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f63d680>
02 01/03/16 19:45:06.673 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f63d680>
02 01/03/16 19:45:08.072 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f63d680>
02 01/03/16 19:45:08.073 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:08.074 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Normal. <0x2f63d680>
02 01/03/16 19:45:08.074 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Armed’ = ‘1’ for zone 1 (device 245). <0x2f63d680>
02 01/03/16 19:45:08.076 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘0’ for zone 1 (device 245). <0x2f63d680>
02 01/03/16 19:45:09.612 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0053’, misc=00, checksum=CA <0x2f63d680>
02 01/03/16 19:45:09.613 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:09.614 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #5, status = Normal. <0x2f63d680>
02 01/03/16 19:45:09.615 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Armed’ = ‘1’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:09.616 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘0’ for zone 5 (device 249). <0x2f63d680>
02 01/03/16 19:45:10.772 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f63d680>
02 01/03/16 19:45:10.773 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:10.774 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Violated. <0x2f63d680>
02 01/03/16 19:45:10.774 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘1’ for zone 1 (device 245). <0x2f63d680>
02 01/03/16 19:45:10.792 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f63d680>
02 01/03/16 19:45:10.793 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f63d680>
02 01/03/16 19:45:12.272 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f63d680>
02 01/03/16 19:45:12.273 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f63d680>
02 01/03/16 19:45:13.672 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f63d680>
02 01/03/16 19:45:13.673 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:45:13.674 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Normal. <0x2f63d680>
02 01/03/16 19:45:13.674 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Armed’ = ‘1’ for zone 1 (device 245). <0x2f63d680>
02 01/03/16 19:45:13.675 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘0’ for zone 1 (device 245). <0x2f63d680>
02 01/03/16 19:45:18.492 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘0938191030116010’, misc=00, checksum=6B <0x2f63d680>
02 01/03/16 19:45:18.493 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f63d680>
02 01/03/16 19:45:18.522 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f63d680>
02 01/03/16 19:45:18.523 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f63d680>
02 01/03/16 19:45:18.524 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f63d680>
02 01/03/16 19:45:47.653 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f63d680>
02 01/03/16 19:45:47.653 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f63d680>
02 01/03/16 19:45:47.654 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f63d680>
02 01/03/16 19:45:48.512 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘3938191030116010’, misc=00, checksum=68 <0x2f63d680>
02 01/03/16 19:45:48.513 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f63d680>
02 01/03/16 19:46:16.933 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f63d680>
02 01/03/16 19:46:16.933 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f63d680>
02 01/03/16 19:46:16.934 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f63d680>
02 01/03/16 19:46:18.522 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘0939191030116010’, misc=00, checksum=6A <0x2f63d680>
02 01/03/16 19:46:18.523 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f63d680>
02 01/03/16 19:46:30.732 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f63d680>
02 01/03/16 19:46:30.733 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f63d680>
02 01/03/16 19:46:30.734 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Violated. <0x2f63d680>
02 01/03/16 19:46:30.735 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘1’ for zone 1 (device 245). <0x2f63d680>
02 01/03/16 19:46:30.922 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f63d680>
02 01/03/16 19:46:30.933 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f63d680>
Terminated

salilathalye · January 4, 2016, 1:57am

UI is telling me that 25 devices are not connected as of 20:27:00, but the plugin is still recording all the sensor changes. Not sure why this is happening. So even when the plugin can see the sensors trigger, Vera is acting like it cant see any of the Elk M1 inputs.

02 01/03/16 20:50:41.090 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 20:50:43.129 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f469680>
02 01/03/16 20:50:43.130 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 20:50:43.149 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f469680>
02 01/03/16 20:50:43.150 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f469680>
02 01/03/16 20:50:43.639 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0053’, misc=00, checksum=CA <0x2f469680>
02 01/03/16 20:50:43.640 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 20:50:44.659 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f469680>
02 01/03/16 20:50:44.660 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f469680>
02 01/03/16 20:50:46.029 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f469680>
02 01/03/16 20:50:46.030 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 20:50:51.970 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4143201030116010’, misc=00, checksum=7B <0x2f469680>
02 01/03/16 20:50:51.971 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>
02 01/03/16 20:51:06.299 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 20:51:06.300 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 20:51:21.979 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1144201030116010’, misc=00, checksum=7D <0x2f469680>
02 01/03/16 20:51:21.980 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>
02 01/03/16 20:51:35.470 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 20:51:35.470 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 20:51:52.010 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4144201030116010’, misc=00, checksum=7A <0x2f469680>
02 01/03/16 20:51:52.010 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>
02 01/03/16 20:52:04.640 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 20:52:04.640 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 20:52:22.019 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1145201030116010’, misc=00, checksum=7C <0x2f469680>
02 01/03/16 20:52:22.020 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>
02 01/03/16 20:52:33.050 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 20:52:33.050 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 20:52:52.039 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4145201030116010’, misc=00, checksum=79 <0x2f469680>
02 01/03/16 20:52:52.040 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>
02 01/03/16 20:53:02.080 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 20:53:02.081 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 20:53:08.889 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f469680>
02 01/03/16 20:53:08.890 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 20:53:08.909 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f469680>
02 01/03/16 20:53:08.910 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f469680>
02 01/03/16 20:53:10.339 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f469680>
02 01/03/16 20:53:10.340 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f469680>

salilathalye · January 4, 2016, 2:30am

Now there are no more sensor changes coming through even though I am moving in front of the sensor.

02 01/03/16 21:27:50.140 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f469680>
02 01/03/16 21:27:51.440 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 21:27:51.441 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 21:27:51.559 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f469680>
02 01/03/16 21:27:51.560 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 21:27:52.269 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f469680>
02 01/03/16 21:27:52.270 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 21:27:52.289 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f469680>
02 01/03/16 21:27:52.290 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f469680>
02 01/03/16 21:27:53.359 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4220211030116010’, misc=00, checksum=7E <0x2f469680>
02 01/03/16 21:27:53.360 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>
02 01/03/16 21:27:53.739 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f469680>
02 01/03/16 21:27:53.740 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f469680>
02 01/03/16 21:27:55.169 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f469680>
02 01/03/16 21:27:55.170 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f469680>
02 01/03/16 21:28:20.459 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 21:28:20.460 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 21:28:23.379 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1221211030116010’, misc=00, checksum=80 <0x2f469680>
02 01/03/16 21:28:23.380 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>
02 01/03/16 21:28:49.549 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f469680>
02 01/03/16 21:28:49.550 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f469680>
02 01/03/16 21:28:53.390 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4221211030116010’, misc=00, checksum=7D <0x2f469680>
02 01/03/16 21:28:53.390 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f469680>

salilathalye · January 4, 2016, 2:52am

The only way to recover was to reboot the Vera from Settings / Net and WiFi.
Once I did this, the Elk devices report back again, sensor changes are coming in.

02 01/03/16 21:46:13.116 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f175680>
02 01/03/16 21:46:13.116 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Normal. <0x2f175680>
02 01/03/16 21:46:13.117 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Armed’ = ‘1’ for zone 1 (device 245). <0x2f175680>
02 01/03/16 21:46:13.119 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘0’ for zone 1 (device 245). <0x2f175680>
02 01/03/16 21:46:13.691 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:46:13.692 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:46:13.693 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:46:13.821 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f175680>
02 01/03/16 21:46:13.822 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f175680>
02 01/03/16 21:46:13.822 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Violated. <0x2f175680>
02 01/03/16 21:46:13.823 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘1’ for zone 1 (device 245). <0x2f175680>
02 01/03/16 21:46:13.841 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f175680>
02 01/03/16 21:46:13.841 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f175680>
02 01/03/16 21:46:15.331 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f175680>
02 01/03/16 21:46:15.332 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f175680>
02 01/03/16 21:46:16.681 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f175680>
02 01/03/16 21:46:16.681 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f175680>
02 01/03/16 21:46:16.682 luup_log:237: ElkPlugin::processZoneChangeUpdate: Zone #1, status = Normal. <0x2f175680>
02 01/03/16 21:46:16.683 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Armed’ = ‘1’ for zone 1 (device 245). <0x2f175680>
02 01/03/16 21:46:16.684 luup_log:237: ElkPlugin::setZoneState: Set variable ‘Tripped’ = ‘0’ for zone 1 (device 245). <0x2f175680>
02 01/03/16 21:46:23.231 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1239211030116010’, misc=00, checksum=77 <0x2f175680>
02 01/03/16 21:46:23.232 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:46:42.951 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:46:42.952 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:46:42.953 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:46:53.251 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4239211030116010’, misc=00, checksum=74 <0x2f175680>
02 01/03/16 21:46:53.252 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:47:11.421 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:47:11.422 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:47:11.423 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:47:23.271 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1240211030116010’, misc=00, checksum=7F <0x2f175680>
02 01/03/16 21:47:23.272 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:47:40.581 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:47:40.582 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:47:40.583 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:47:53.281 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4240211030116010’, misc=00, checksum=7C <0x2f175680>
02 01/03/16 21:47:53.282 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:48:09.701 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:48:09.702 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:48:09.703 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:48:23.311 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1241211030116010’, misc=00, checksum=7E <0x2f175680>
02 01/03/16 21:48:23.312 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:48:38.871 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:48:38.872 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:48:38.873 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:48:53.331 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4241211030116010’, misc=00, checksum=7B <0x2f175680>
02 01/03/16 21:48:53.332 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:49:08.051 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:49:08.052 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:49:08.053 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:49:23.341 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1242211030116010’, misc=00, checksum=7D <0x2f175680>
02 01/03/16 21:49:23.342 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:49:36.471 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:49:36.472 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:49:36.473 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:49:53.371 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4242211030116010’, misc=00, checksum=7A <0x2f175680>
02 01/03/16 21:49:53.372 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:50:05.611 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:50:05.612 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:50:05.613 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
01 01/03/16 21:50:22.101 luup_log:237: ElkPlugin::getHeartbeat: OK 29 sec since last ping. <0x2e534680>
06 01/03/16 21:50:22.101 Device_Variable::m_szValue_set device: 237 service: urn:micasaverde-com:serviceId:ElkAlarmPanel1 variable: Heartbeat was: 29 now: 29 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2e534680>
02 01/03/16 21:50:23.381 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1243211030116010’, misc=00, checksum=7C <0x2f175680>
02 01/03/16 21:50:23.382 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:50:34.891 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:50:34.892 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:50:34.893 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:50:53.401 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4343211030116010’, misc=00, checksum=78 <0x2f175680>
02 01/03/16 21:50:53.402 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:51:04.001 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:51:04.002 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:51:04.003 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:51:23.421 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1244211030116010’, misc=00, checksum=7B <0x2f175680>
02 01/03/16 21:51:23.422 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:51:32.451 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:51:32.452 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:51:32.452 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>
02 01/03/16 21:51:53.441 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘4244211030116010’, misc=00, checksum=78 <0x2f175680>
02 01/03/16 21:51:53.442 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f175680>
02 01/03/16 21:52:01.581 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f175680>
02 01/03/16 21:52:01.582 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f175680>
02 01/03/16 21:52:01.583 luup_log:237: ElkPlugin::setPartitionState: Set variable ‘ChimeEnabled’ = ‘0’ for partition 1 (device 244). <0x2f175680>

zoot1612 · January 4, 2016, 11:42pm

@salilathalye
I can’t see anything wrong in the log.

Can you try using the attached lua file. It has more debugging statements and will hopefully provide more feedback.

salilathalye · January 4, 2016, 11:59pm

I am up and running with your file. Elk and Vera are connected. Will send you log fragments as things transpire.

Thanks for your help.

salilathalye · January 5, 2016, 12:16pm

Connection lost this morning.

02 01/05/16 7:12:54.842 luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>
02 01/05/16 7:12:54.860 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f9ad680>
02 01/05/16 7:12:54.861 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f9ad680>
02 01/05/16 7:12:56.280 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f9ad680>
02 01/05/16 7:12:56.281 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f9ad680>
02 01/05/16 7:12:57.680 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f9ad680>
02 01/05/16 7:12:57.681 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f9ad680>
02 01/05/16 7:12:57.681 luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>
02 01/05/16 7:13:00.611 luup_log:237: ElkPlugin::checkMessage: length=25(0x19), message type=KC, data=‘0100000000001111111’, misc=00, checksum=10 <0x2f9ad680>
02 01/05/16 7:13:00.612 luup_log:237: ElkPlugin::handlerFunc Message type description: Keypad KeyChange Update <0x2f9ad680>
02 01/05/16 7:13:11.870 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f9ad680>
02 01/05/16 7:13:11.871 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f9ad680>
02 01/05/16 7:13:11.872 luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>
02 01/05/16 7:13:11.890 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f9ad680>
02 01/05/16 7:13:11.891 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f9ad680>
02 01/05/16 7:13:13.400 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f9ad680>
02 01/05/16 7:13:13.401 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f9ad680>
02 01/05/16 7:13:14.771 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f9ad680>
02 01/05/16 7:13:14.771 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f9ad680>
02 01/05/16 7:13:14.772 luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>
02 01/05/16 7:13:18.100 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f9ad680>
02 01/05/16 7:13:18.101 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f9ad680>
02 01/05/16 7:13:18.101 luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>
02 01/05/16 7:13:18.120 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f9ad680>
02 01/05/16 7:13:18.121 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f9ad680>
02 01/05/16 7:13:19.610 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0501’, misc=00, checksum=94 <0x2f9ad680>
02 01/05/16 7:13:19.611 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f9ad680>
02 01/05/16 7:13:20.600 luup_log:237: ElkPlugin::checkMessage: length=22(0x16), message type=XK, data=‘1006073050116010’, misc=00, checksum=77 <0x2f9ad680>
02 01/05/16 7:13:20.601 luup_log:237: ElkPlugin::handlerFunc Message type description: Ethernet Module Test <0x2f9ad680>
02 01/05/16 7:13:20.960 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘0013’, misc=00, checksum=CE <0x2f9ad680>
02 01/05/16 7:13:20.961 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f9ad680>
02 01/05/16 7:13:20.962 luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>
02 01/05/16 7:13:22.590 luup_log:237: ElkPlugin::checkMessage: length=10(0x0A), message type=ZC, data=‘001A’, misc=00, checksum=C0 <0x2f9ad680>
02 01/05/16 7:13:22.591 luup_log:237: ElkPlugin::handlerFunc Message type description: Zone Change Update <0x2f9ad680>
02 01/05/16 7:13:22.592 luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>
02 01/05/16 7:13:22.620 luup_log:237: ElkPlugin::checkMessage: length=11(0x0B), message type=PC, data=‘A0301’, misc=00, checksum=96 <0x2f9ad680>
02 01/05/16 7:13:22.621 luup_log:237: ElkPlugin::processMessage: Unhandled message type ‘PC’ <0x2f9ad680>

salilathalye · January 5, 2016, 1:25pm

Without any intervention on my part, the connection was reestablished a few minutes later. Here is a log file.

zoot1612 · January 5, 2016, 1:26pm

@salilathalye

At some point the plugin sets INITIALIZED = false. I have looked through the code and cannot see anywhere that this should happen (but it obviously does) can you check before this line.

02      01/05/16 7:12:54.842    luup_log:237: ElkPlugin::Zone Change Update:Plugin not initialized <0x2f9ad680>

to see if there are any lines that may contain anything that mentions connection or heartbeat.

salilathalye · January 5, 2016, 1:31pm

I will check this evening, though the log may have wrapped. I’ve seen some heartbeat messages in red saying the ping time was 4 seconds.

I’m using tail -f | grep “Elk*”

Is there a better way to capture the logs to prevent wrapping?

Thanks

zoot1612 · January 5, 2016, 3:55pm

@salilathalye
Everything going via log and debug should be picked up but I can’t see the issue so trying to chase more info.

heartbeat uses the XK response to ensure that the links stays active. If it doesn’t get an XK packet in a five minute interval the plugin should check the connection and if it has failed try to set it up again.

I think it must be failing in there somewhere but still at a loss to understand how.