The continuing frustrations of Vera

clippermiami · March 31, 2015, 8:06pm

C’est la vie

I actually did this on “the other Vera” the one with the alarm and camera system as it was behaving similarly. My “primary” (ZWave controlling) Vera is still running.

But it doesn’t really reset to the factory nothing state, I still have my original IP address so it isn’t truly “blank” How can I get it to the Zero State?

clippermiami · March 31, 2015, 8:19pm

In going back through the logs I noticed this which appears to be the root of all the activity:

01	03/31/15 16:13:31.461	FileUtils::ReadURL 7/resp:0 size 0 https://127.0.0.1/alert?PK_AccessPoint=30010119&HW_Key=l764eZaXaGF3SRF8RkXeUdClxodkgy2o&DeviceID=414&LocalDate=2015-03-28%2017:17:51&LocalTimestamp=1427577471&AlertType=3&SourceType=3&Argument=58&Format=&Code=ConditionSatisfied&Value=Vera2HeartbeatRCVD&Description=Vera%202%20Heartbeat%20Received&Users= <0x2b455680>

Which appears to be trying to send a message to null users “Vera 2 Heartbeat Received” which message no longer exists int he system and hasn’t for several days! This was used for debugging my Vera-Vera Heartbeat gizmo and was removed over the weekend. Vera has been restarted a number of times since then so why would this message be hanging around and causing hundreds of retries?

[Update]
During the periods when this is not happening CPU usage is in the mid-single digits! But i do not understand why this deleted message is “hanging” on and being repeated a thousand times every half hour

clippermiami · April 1, 2015, 3:50am

well its now been about 6 hours and the strange message transmission has simply stopped of its own accord! Nominal CPU utilization is now in low single digits with single jumps to 12-21% and then immediately back to single digits.

I have no idea why but it now appears to be operating at a rational level. Response to sensors is almost instantaneous so things are looking good. As I said I have no earthly idea why but its now operating well with Memory utilization hovering around 67% and CPU in the 2-8% range.

Thanks to everyone for their ideas, suggestions and putting up with this.

Now if Tech Support can get my Alarm/Camera Vera back running it looks like things will be good.

clippermiami · April 1, 2015, 11:30am

I guess I spoke too soon. I checked the Vera this morning and the phantom message is back, thousands of them, tens of thousands. Vera apparently never forgets anything no matter how trivial.

I’ve added back the Aeon Energy Monitor, AutoVera and 3 instances of ImperHome and aside from the times when Vera is generating the Phantom Message the CPU Utilization remains in the mid-single digits and Memory Utilization is 74%.

The Phantom Message repeated continuously thousand and thousands of times:

01	04/01/15 9:56:09.471	RAServerSync::SendAlert retries 6 failed https://127.0.0.1/alert?PK_AccessPoint=30010119&HW_Key=l764eZaXaGF3SRF8RkXeUdClxodkgy2o&DeviceID=414&LocalDate=2015-03-26%2018:47:59&LocalTimestamp=1427410079&AlertType=3&SourceType=3&Argument=60&Format=&Code=ConditionSatisfied&Value=Vera2HeartbeatRCVD&Description=Vera%202%20Heartbeat%20Received&Users= age: 486490 file: /etc/cmh/persist/a_1427407920_1427410079_1324418 <0x2b9ff680>
01	04/01/15 9:56:09.512	FileUtils::ReadURL 7/resp:0 size 0 https://127.0.0.1/alert?PK_AccessPoint=30010119&HW_Key=l764eZaXaGF3SRF8RkXeUdClxodkgy2o&DeviceID=414&LocalDate=2015-03-28%2016:41:24&LocalTimestamp=1427575284&AlertType=3&SourceType=3&Argument=58&Format=&Code=ConditionSatisfied&Value=Vera2HeartbeatRCVD&Description=Vera%202%20Heartbeat%20Received&Users= <0x2b9ff680>

Some interesting things in this message:

The Device ID is the PLEG that used to generate the notiification
The Date of the message “2015-03-28” is the last date the notification existed in the PLEG, it was deleted after that
The message is repeated about every 10 minutes and runs for about 2 minutes then stops and repeats again 10 minutes later

Now, if I can get rid of the Phantom Message, and Vera doesn’t find another one in its closet somewhere to replace it, my Vera should be at top form.

clippermiami · April 1, 2015, 3:37pm

Now that my other Vera (Alarm/Camera) is back online i’m seeing exactly the same behavior; periodic generation of thousands of messages, albeit different content that what’s happening on the ZWave Vera. As with the first Vera, these messages are generated every 10 minutes for about 2 minute bursts and are all “old” in the sense that the content date in the messages is several days ago.

This leads me to think that somewhere along the way I have managed to misconfigure both systems and created my own problem. The messages are all being sent to the localhost (127.0.0.1), the address for which the “AlternateEventServer” is currently configured. So I’m beginning to think it has something to do with that, which I may have “toyed” with while installing the original EventWatcher.

Any advice from the internals gurus on how to set this right and stop this nonsense?

ServiceXp · April 1, 2015, 3:50pm

I really think you need to call Tech, and have them go over your setup, something is out of wack!

clippermiami · April 1, 2015, 3:55pm

Yes, I have a request into Tech Support. now that my other Vera is back online and exhibiting the same problem i have included it in the request as well. I freely admit that it now certainly looks like something I have done along the way and I’m hoping they can resolve whatever it is.

ServiceXp · April 1, 2015, 4:17pm

From what I’ve read, it doesn’t seem like tech. will have any problem sorting it out…

It’s really the only thing that Vera LTD seems to do quite well. (good techs)…

clippermiami · April 3, 2015, 12:15pm

[size=14pt]It APPEARS that the problem is resolved[/size]

Tech Support came through in the end and found all this “stuff” sitting in the /persist folder waiting for delivery … which of course would never happen because there was no target to accept the message. The cleared out the folder and Vera has been running like it was brand new

Thanks also to Richard Schaefer who jumped in and was assisting, without hiw I doubt I would have know to look for the root problem.

And of course a tip of the hat to everyone here who chimed in with their thoughts, all invaluable.

Both Veras had this problem, the ZWave Vera was far worse however. But now that it is resolved on both Veras I can report that the nominal CPU usage on both Veras, Vera-1 the ZWave system and Vera-2 the Alarm/Blue Iris Interface is now in the low-to-mid-single digits, responsiveness is practically instantaneous.

Again thanks to everyone. Now if I can resist screwing it up again

RichardTSchaefer · April 3, 2015, 12:41pm

A root cause to this was the removal of “Event Watcher”
The real root cause was probably lack of memory, which required the removal of “Event Watcher”.

MCV does not provide a hook to the app (plugin) developers that runs before a plugin is deleted.
Event Watcher uses the Alternate Event server API for Vera. When you remove Event Watcher you must disable it.

In this case Every Event that was generated after “Event Watcher” was removed was queued up.
And all of these events were trying to get delivered … and failed … so they kept accumulating and retrying.

I guess “Event Watcher” needs a “Click ME Before Uninstalling Me” button some where.

ServiceXp · April 3, 2015, 12:55pm

Thanks for the follow up guys…

@clippermiami – So… are you ready to “upgrade” to UI1.7xx now… ?

clippermiami · April 3, 2015, 12:59pm

[quote=“ServiceXp, post:51, topic:186459”]Thanks for the follow up guys…

@clippermiami – So… are you ready to “upgrade” to UI1.7xx now… ? :P[/quote]

Yeah, right … real soon new. I’ll get back to you on that, I need to cast the chicken bones

akbooer · April 7, 2015, 10:40am

[quote=“RichardTSchaefer, post:50, topic:186459”]A root cause to this was the removal of “Event Watcher”
The real root cause was probably lack of memory, which required the removal of “Event Watcher”.

MCV does not provide a hook to the app (plugin) developers that runs before a plugin is deleted.
Event Watcher uses the Alternate Event server API for Vera. When you remove Event Watcher you must disable it.

In this case Every Event that was generated after “Event Watcher” was removed was queued up.
And all of these events were trying to get delivered … and failed … so they kept accumulating and retrying.

I guess “Event Watcher” needs a “Click ME Before Uninstalling Me” button some where.[/quote]

Actually, at the risk of double-posting (See here [url=http://forum.micasaverde.com/index.php/topic,31596.msg228711.html#msg228711]http://forum.micasaverde.com/index.php/topic,31596.msg228711.html#msg228711[/url]) but aiming for clarity, let me re-iterate:

[tt] [/tt]“This is a problem with Vera’s Alternate Event Server, (rather than EventWatcher, per se) which you must have enabled some time. Unfortunately, their recipe for turning it off doesn’t seem to work.”

I refer to the information posted here: [url=http://wiki.micasaverde.com/index.php/AlternateEventServer]http://wiki.micasaverde.com/index.php/AlternateEventServer[/url]. In particular, the suggestion:

[tt] [/tt]To stop logging to your own server, call the variableset again but leave the Value empty.

…does not seem to work reliably. I assume that you could hack the UPnP User Data to remove the AlternateEventServer reference, but I haven’t tried that myself.

clippermiami · April 7, 2015, 11:15am

[quote=“akbooer, post:53, topic:186459”][quote=“RichardTSchaefer, post:50, topic:186459”]A root cause to this was the removal of “Event Watcher”
The real root cause was probably lack of memory, which required the removal of “Event Watcher”.

MCV does not provide a hook to the app (plugin) developers that runs before a plugin is deleted.
Event Watcher uses the Alternate Event server API for Vera. When you remove Event Watcher you must disable it.

In this case Every Event that was generated after “Event Watcher” was removed was queued up.
And all of these events were trying to get delivered … and failed … so they kept accumulating and retrying.

I guess “Event Watcher” needs a “Click ME Before Uninstalling Me” button some where.[/quote]

Actually, at the risk of double-posting (See here [url=http://forum.micasaverde.com/index.php/topic,31596.msg228711.html#msg228711]http://forum.micasaverde.com/index.php/topic,31596.msg228711.html#msg228711[/url]) but aiming for clarity, let me re-iterate:

[tt] [/tt]“This is a problem with Vera’s Alternate Event Server, (rather than EventWatcher, per se) which you must have enabled some time. Unfortunately, their recipe for turning it off doesn’t seem to work.”

I refer to the information posted here: [url=http://wiki.micasaverde.com/index.php/AlternateEventServer]http://wiki.micasaverde.com/index.php/AlternateEventServer[/url]. In particular, the suggestion:

[tt] [/tt]To stop logging to your own server, call the variableset again but leave the Value empty.

…does not seem to work reliably. I assume that you could hack the UPnP User Data to remove the AlternateEventServer reference, but I haven’t tried that myself.[/quote]

I tried setting the value to and to 127.0.0.1 and neither made any difference. In the end the repeating flood was killed by tech support deleting them from the /persist/ folder. That however does not appear to be the case with the camera message I posted on EventWatcher thread, those its generating fresh

akbooer · April 7, 2015, 12:56pm

Yes, as I said, that doesn’t work (but it should?)

That however does not appear to be the case with the camera message I posted on EventWatcher thread, those its generating fresh

I seem to have missed that one... which post was that?

clippermiami · April 7, 2015, 1:25pm

Yes, as I said, that doesn’t work (but it should?)

That however does not appear to be the case with the camera message I posted on EventWatcher thread, those its generating fresh

I seem to have missed that one... which post was that?[/quote]

Every minute or so I get a few dozen of these:

02	04/07/15 9:20:57.121	Generic_IP_Camera_Manager::REQ_Image return:23 httpresp:503 unhandled <0x30b0a680>
02	04/07/15 9:20:57.340	write_data_header aborting with 0/503 0x48 0x54 0x54 0x50 0x2f 0x31 0x2e 0x31 0x20 0x35 0x30 0x33 0x20 0x53 0x65 0x72 0x76 0x69 0x63 0x65 0x20 0x55 0x6e 0x61 0x76 0x61 0x69 0x6c 0x61 0x62 0x6c 0x65 0xd 0xa (HTTP/1.1 503 Service Unavailablern) <0x321d2680>
02	04/07/15 9:20:57.341	Generic_IP_Camera_Manager::REQ_Image return:23 httpresp:503 unhandled <0x321d2680>
02	04/07/15 9:20:57.353	write_data_header aborting with 0/503 0x48 0x54 0x54 0x50 0x2f 0x31 0x2e 0x31 0x20 0x35 0x30 0x33 0x20 0x53 0x65 0x72 0x76 0x69 0x63 0x65 0x20 0x55 0x6e 0x61 0x76 0x61 0x69 0x6c 0x61 0x62 0x6c 0x65 0xd 0xa (HTTP/1.1 503 Service Unavailablern) <0x3070a680>
02	04/07/15 9:20:57.354	Generic_IP_Camera_Manager::REQ_Image return:23 httpresp:503 unhandled <0x3070a680>
01	04/07/15 9:20:59.491	JobHandler_LuaUPnP::REQ_SlaveDataChanged unknown uuid:4d494342-5342-5645-0000-000001c9eb07 <0x321d2680>
02	04/07/15 9:21:00.105	NotifyForeignMasters no response from http://192.168.15.115:3480/data_request?id=slave_data_changed&PK_AccessPoint=30008987&UDN=uuid:4d494342-5342-5645-0000-000001c9e69b buffer ERROR <0x2b6c9680>
01	04/07/15 9:21:04.491	JobHandler_LuaUPnP::REQ_SlaveDataChanged unknown uuid:4d494342-5342-5645-0000-000001c9eb07 <0x321d2680>

I have the Blue Iris Plug In installed and several of the cameras are not active in BI unless the alarm system is armed so I suspected at first that these messages might be caused by that. But there are way more of them than there are inactive cameras

The “NotifyForeignMasters” message may be related to my earlier tests with Bridged Veras as these messages also occur in the other Vera.

RichardTSchaefer · April 7, 2015, 1:29pm

These are caused by your display apps (i.e. Vera Dashboard) requesting images using the Vera API.
This has nothing to do with EventWatcher.

clippermiami · April 7, 2015, 2:41pm

[quote=“RichardTSchaefer, post:57, topic:186459”]These are caused by your display apps (i.e. Vera Dashboard) requesting images using the Vera API.
This has nothing to do with EventWatcher.[/quote]

I originally posted it to Blue Iris Plug in thinking that it might have something to do with the plug in requesting images from inactive BI cameras. I didn’t think EvenWatcher was involved in this one.

jquincy · April 7, 2015, 7:09pm

[quote=“RichardTSchaefer, post:50, topic:186459”]A root cause to this was the removal of “Event Watcher”
The real root cause was probably lack of memory, which required the removal of “Event Watcher”.

MCV does not provide a hook to the app (plugin) developers that runs before a plugin is deleted.
Event Watcher uses the Alternate Event server API for Vera. When you remove Event Watcher you must disable it.

In this case Every Event that was generated after “Event Watcher” was removed was queued up.
And all of these events were trying to get delivered … and failed … so they kept accumulating and retrying.

I guess “Event Watcher” needs a “Click ME Before Uninstalling Me” button some where.[/quote]

How does one disable it after it is uninstalled?

integlikewhoa · April 7, 2015, 7:57pm

[quote=“clippermiami, post:58, topic:186459”][quote=“RichardTSchaefer, post:57, topic:186459”]These are caused by your display apps (i.e. Vera Dashboard) requesting images using the Vera API.
This has nothing to do with EventWatcher.[/quote]

I originally posted it to Blue Iris Plug in thinking that it might have something to do with the plug in requesting images from inactive BI cameras. I didn’t think EvenWatcher was involved in this one.[/quote]

I was having alot of issues with my edge, and have recently removed blueiris plugin and all cameras for that matter from VERA to re leave the stress. I was seeing alot of calls for big images in the logs and I like to see the logs cleaner now.