EventWatcher not working after firmware update...

johnes · September 26, 2018, 4:01am

I recently upgraded my VeraPlus to the latest firmware. Now EventWatcher is not working:

every link like this:http://IP/port_3480/data_request?id=lr_EventWatcher&report=log

Returns: “No handler”

And nothing apart from reboots gets logged.

2018-09-25 22:58:42.401, E, 0, , Vera, RESTART
2018-09-25 23:57:15.157, E, 0, , Vera, RESTART,

Can anyone help?

akbooer · September 26, 2018, 7:51am

Are there any errors in the log?

johnes · September 26, 2018, 2:15pm

I didn’t see anythign that stuck out. I can try again later today.

I’m not running AltUI, so I did delete the device and the plugin and grabbed the files from github and got the same result.

akbooer · September 26, 2018, 2:33pm

No event handler, essentially means that EventWatcher hasn’t started correctly. There should be at least one error early in the logs. Clearly there should be nothing basically wrong with the plugin itself - it hasn’t been changed for quite a while. But I?m struggling to think of what it can be that Vera may now have screwed up in the upgrade.

johnes · September 27, 2018, 4:29am

This is what I found…

02 12/31/-1 19:00:40.704 Device_Service::MatchupUpnpServices no upnp service for urn:akbooer-com:serviceId:EventWatcher1 <0x77e33320>
02 12/31/-1 19:00:40.705 Device_Basic::m_eConfigured_set device 535 was 0 now 0 startup <0x77e33320>
01 12/31/-1 19:00:40.705 Device_LuaUPnP::CreateImplementations Aborting 2 because it failed to load <0x77e33320>
01 12/31/-1 19:00:40.706 JobHandler_LuaUPnP::CreateAllImplementations failed to create 2 <0x77e33320>
01 12/31/-1 19:00:40.709 Device_LuaUPnP::CreateImplementations Aborting 273 because it failed to load <0x77e33320>
01 12/31/-1 19:00:40.709 JobHandler_LuaUPnP::CreateAllImplementations failed to create 273 <0x77e33320>
01 12/31/-1 19:00:40.711 Device_LuaUPnP::CreateImplementations Aborting 372 because it failed to load <0x77e33320>
01 12/31/-1 19:00:40.711 JobHandler_LuaUPnP::CreateAllImplementations failed to create 372 <0x77e33320>
01 12/31/-1 19:00:40.973 UserData::BuildShortData bad category 666 <0x77e33320>
01 12/31/-1 19:00:40.973 UserData::BuildShortData bad category 666 <0x77e33320>
01 12/31/-1 19:00:40.973 UserData::BuildShortData bad category 666 <0x77e33320>
01 12/31/-1 19:00:40.974 UserData::BuildShortData bad category 666 <0x77e33320>
01 12/31/-1 19:00:40.974 UserData::BuildShortData bad category 666 <0x77e33320>
01 12/31/-1 19:00:40.974 UserData::BuildShortData bad category 666 <0x77e33320>
01 12/31/-1 19:00:40.974 UserData::BuildShortData bad category 666 <0x77e33320>

09 12/31/-1 19:00:46.877 JobHandler_LuaUPnP::Run device 535 ptr 0xed46b8 Event Watcher room 0 type urn:akbooer-com:device:EventWatcher:1 cat 0:-1 id parent 0/0xfb81e0 upnp: 0 plugin:0 pnp:0 mac: ip: <0x77e33320>

02 09/27/18 0:23:49.549 Device_Service::MatchupUpnpServices no upnp service for urn:akbooer-com:serviceId:EventWatcher1 <0x77e5f320>
02 09/27/18 0:23:49.549 Device_Basic::m_eConfigured_set device 535 was 0 now 0 startup <0x77e5f320>
01 09/27/18 0:23:49.549 Device_LuaUPnP::CreateImplementations Aborting 2 because it failed to load <0x77e5f320>
01 09/27/18 0:23:49.549 JobHandler_LuaUPnP::CreateAllImplementations failed to create 2 <0x77e5f320>

50 09/27/18 0:24:10.657 luup_log:535: EventWatcher: starting… <0x773ce520>
06 09/27/18 0:24:10.658 Device_Variable::m_szValue_set device: 535 service: urn:akbooer-com:serviceId:EventWatcher1 variable: LuupRestart was: 26-Sep-2018 23:37:50 now: 27-Sep-2018 00:24:10 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x773ce520>
06 09/27/18 0:24:10.659 Device_Variable::m_szValue_set device: 535 service: urn:akbooer-com:serviceId:EventWatcher1 variable: LastReboot was: 26-Sep-2018 23:36:20 now: 27-Sep-2018 00:22:18 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x773ce520>
50 09/27/18 0:24:10.660 luup_log:535: EventWatcher: defining CLI… <0x773ce520>
50 09/27/18 0:24:10.669 luup_log:535: EventWatcher: Starting Event service… <0x773ce520>
50 09/27/18 0:24:10.670 luup_log:535: EventWatcher: Server listening on port 443 <0x773ce520>
50 09/27/18 0:24:10.670 luup_log:535: EventWatcher: Starting Watch service… <0x773ce520>
01 09/27/18 0:24:10.671 LuaInterface::CallFunction_Startup-1 device 535 function init failed [string “local ABOUT = {…”]:1168: attempt to index local ‘c’ (a nil value) <0x773ce520>
01 09/27/18 0:24:10.671 LuImplementation::StartLua running startup code for 535 I_EventWatcher.xml failed <0x773ce520>

01 09/27/18 0:24:10.671 LuaInterface::CallFunction_Startup-1 device 535 function init failed [string “local ABOUT = {…”]:1168: attempt to index local ‘c’ (a nil value) <0x773ce520>
01 09/27/18 0:24:10.671 LuImplementation::StartLua running startup code for 535 I_EventWatcher.xml failed <0x773ce520>

akbooer · September 28, 2018, 10:09am

That’s helpful.

I was quite amused by the negative date in the early part of the log, but that’s by the by.

This shows that the plugin started but failed on line 1168:

50   09/27/18 0:24:10.657   luup_log:535: EventWatcher: starting... <0x773ce520>
50   09/27/18 0:24:10.660   luup_log:535: EventWatcher: defining CLI... <0x773ce520>
50   09/27/18 0:24:10.669   luup_log:535: EventWatcher: Starting Event service... <0x773ce520>
50   09/27/18 0:24:10.670   luup_log:535: EventWatcher: Server listening on port 443 <0x773ce520>
50   09/27/18 0:24:10.670   luup_log:535: EventWatcher: Starting Watch service... <0x773ce520>
01   09/27/18 0:24:10.671   LuaInterface::CallFunction_Startup-1 device 535 function init failed [string "local ABOUT = {..."]:1168: attempt to index local 'c' (a nil value) <0x773ce520>

What version are you running? Because in the one I’m looking at, around line 1168 is:

	for i = 0, #classes do
	  local c = classes[i] or {}
		selected[i] = c.symbol ~= "" and c.service and watchCategories:find (c.symbol
	end

…which means that c can’t possibly be nil.

I’m looking at version 2018.03.04, but this part of the code hasn’t changed for a long time, AFAIK.

johnes · September 29, 2018, 4:14pm

I deleted all of the devices, the app, and via ssh, all the eventwatcher files.

Then I went to the github site, re-downloaded them, and then reinstalled.

Now I am getting:

01 09/29/18 12:08:49.654 Device_LuaUPnP::LoadDeviceDoc can’t load /etc/cmh-lu//D_SceneController1.xml <0x77ef8320>
02 09/29/18 12:08:49.655 JobHandler_LuaUPnP::m_sMissingFile_set /etc/cmh-lu//D_SceneController1.xml <0x77ef8320>
01 09/29/18 12:08:49.655 JobHandler_LuaUPnP::CreateDevice_LuaUPnP failed to load 372/D_SceneController1.xml so device 372 is offline <0x77ef8320>
01 09/29/18 12:08:49.798 Device_LuaUPnP::LoadDeviceDoc can’t load /etc/cmh-lu//urn:akbooer-com:device:EventWatcher:1 <0x77ef8320>
02 09/29/18 12:08:49.798 JobHandler_LuaUPnP::m_sMissingFile_set /etc/cmh-lu//urn:akbooer-com:device:EventWatcher:1 <0x77ef8320>
01 09/29/18 12:08:49.798 JobHandler_LuaUPnP::CreateDevice_LuaUPnP failed to load 536/urn:akbooer-com:device:EventWatcher:1 so device 536 is offline <0x77ef8320>
01 09/29/18 12:08:49.828 Device_LuaUPnP::CreateServices Aborting device 2 because the topmost device has no interface <0x77ef8320>

01 09/29/18 12:09:10.367 JobHandler_LuaUPnP::CreateDevice_LuaUPnP failed to load 372/D_SceneController1.xml so device 372 is offline <0x775d5320>
01 09/29/18 12:09:10.439 Device_LuaUPnP::LoadDeviceDoc can’t load /etc/cmh-lu//urn:akbooer-com:device:EventWatcher:1 <0x775d5320>
02 09/29/18 12:09:10.439 JobHandler_LuaUPnP::m_sMissingFile_set /etc/cmh-lu//urn:akbooer-com:device:EventWatcher:1 <0x775d5320>

01 09/29/18 12:09:31.024 Device_LuaUPnP::LoadDeviceDoc can’t load /etc/cmh-lu//urn:akbooer-com:device:EventWatcher:1 <0x77987320>
02 09/29/18 12:09:31.024 JobHandler_LuaUPnP::m_sMissingFile_set /etc/cmh-lu//urn:akbooer-com:device:EventWatcher:1 <0x77987320>
01 09/29/18 12:09:31.024 JobHandler_LuaUPnP::CreateDevice_LuaUPnP failed to load 536/urn:akbooer-com:device:EventWatcher:1 so device 536 is offline <0x77987320>
01 09/29/18 12:09:31.039 Device_LuaUPnP::CreateServices Aborting device 2 because the topmost device has no interface <0x77987320>

09 09/29/18 12:09:38.160 JobHandler_LuaUPnP::Run device 536 ptr 0x111b798 room 0 type urn:akbooer-com:device:EventWatcher:1 cat 0:-1 id parent 0/0x11ff4d0 upnp: 0 plugin:0 pnp:0 mac: ip: <0x77987320>

50 09/29/18 12:09:54.349 luup_log:539: EventWatcher: starting… <0x76ef6520>
06 09/29/18 12:09:54.350 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: Version was: EMPTY now: 16.11.16 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
50 09/29/18 12:09:54.351 luup_log:539: EventWatcher: 16.11.16 <0x76ef6520>

12:09:54.349 luup_log:539: EventWatcher: starting… <0x76ef6520>
06 09/29/18 12:09:54.350 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: Version was: EMPTY now: 16.11.16 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
50 09/29/18 12:09:54.351 luup_log:539: EventWatcher: 16.11.16 <0x76ef6520>
06 09/29/18 12:09:54.352 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: LuupRestart was: EMPTY now: 29-Sep-2018 12:09:54 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.354 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: LastReboot was: EMPTY now: 29-Sep-2018 12:07:45 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.355 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: ServerKeyFile was: EMPTY now: /eventWatcher/EventWatcher.key #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.355 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: ServerCertificateFile was: EMPTY now: /eventWatcher/EventWatcher.crt #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.356 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: Syslog was: EMPTY now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.357 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: LogDirectory was: EMPTY now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.358 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: WatchCategories was: EMPTY now: XYSM #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.359 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: CacheSize was: EMPTY now: 1000 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.359 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: Debug was: EMPTY now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.361 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: ExtraVariablesFile was: EMPTY now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
06 09/29/18 12:09:54.362 Device_Variable::m_szValue_set device: 539 service: urn:akbooer-com:serviceId:EventWatcher1 variable: ExcludeVariablesFile was: EMPTY now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76ef6520>
50 09/29/18 12:09:54.362 luup_log:539: EventWatcher: defining CLI… <0x76ef6520>
50 09/29/18 12:09:54.367 luup_log:539: EventWatcher: Starting Event service… <0x76ef6520>
50 09/29/18 12:09:54.368 luup_log:539: EventWatcher: Server listening on port 443 <0x76ef6520>
50 09/29/18 12:09:54.369 luup_log:539: EventWatcher: Starting Watch service… <0x76ef6520>
01 09/29/18 12:09:54.370 LuaInterface::CallFunction_Startup-1 device 539 function init failed [string “ABOUT = {…”]:1158: attempt to index local ‘c’ (a nil value) <0x76ef6520>
01 09/29/18 12:09:54.370 LuImplementation::StartLua running startup code for 539 I_EventWatcher.xml failed <0x76ef6520>
02 09/29/18 12:09:54.371 UserData::AlarmCallback ALARM_RESYNC_DEVICES <0x76ef6520>

johnes · September 29, 2018, 4:17pm

1158 has: selected[i] = c.symbol ~= “” and c.service and watchCategories:find (c.symbol) – looking for these specific letters

akbooer · September 29, 2018, 5:01pm

Yes, but is the line before…

local c = classes[i] or {}

…?

johnes · September 30, 2018, 6:17pm

end
local selected = {}
local excluded = {}

for i = 0, #classes do     -- going from 0, so can't use ipairs
  local c = classes[i]
	selected[i] = c.symbol ~= "" and c.service and watchCategories:find (c.symbol) 		-- looking for these specific letters
end

akbooer · September 30, 2018, 7:43pm

You have an old version, then.

johnes · October 1, 2018, 3:44am

I’m using the one from: GitHub - akbooer/EventWatcher: Web, file, and syslog reporting of Vera HA Controller variables, events, devices, scenes, and more.

Is there a newer one than that?

akbooer · October 1, 2018, 6:31am

Yes, the development branch: