Announcement

**spud** · November 30, 2015, 09:46 AM

Originally posted by Furious View Post

Hi Spud,
any chance of integrating some more error trapping and overall more robustness with the local and remote instances in the future?
So far, I'm running about 4 different error messages which will restart the local or remote instances, and I've now seen a problem a couple of times where the speech is recognised, but then it won't actually fire the event until the plugin is restarted (if phrase x on local or phrase x on remote is recognised, do y). Problem is I can't trigger on that, as there's nothing logged, and it's not as if the plugins get restarted multiple times a day already.
I've put monitoring in place to constantly poll to see if there's a network issue for the remote instance, even though this is wired, nothing is apparent.

Do you need specific errors, as there are some which are easily to repro:

Of course I'm willing to make the plugin as robust as possible. The hard part for me is to reproduce the problems you are seeing. So yes please give me specific errors and as much details as you can about how to reproduce them.

Originally posted by Furious View Post

Unresponsive plugin instance after checking/unchecking snapshot box with this error:
DEBUG System.Net.HttpListenerException (0x80004005): The I/O operation has been aborted because of either a thread exit or an application request at System.Net.HttpListener.GetContext() at HSPI_KINECT.SnapshotServer.b__0()

I assume you mean checking/unchecking the "Use Kinect camera as NetCam" checkbox on the Camera tab?
The exception in this log line is expected when the snapshot server is stopped, that's why it is only logged at the Debug level. So, this one I can reproduce but it doesn't make the plugin unresponsive for me, the voice recognition still works correctly when I check/uncheck the box. Does the problem occur for you everytime, and what do you mean exactly by unresponsive?

Originally posted by Furious View Post

Enabling or disabling other plugins in the interfaces page causes the kinect plugin to stop (just logs Shutting down Plug-In: Kinect)

Looks like this problem is a HS3 bug, I think I saw it a couple of times in the past but right now I can't reproduce it. If we can find a deterministic method to reproduce it I can work with Rich to fix it.

**Furious** · December 1, 2015, 11:47 AM

Seems I cannot currently repro reliably the check/uncheck snapshot to cause the problem, so I'll keep hacking at that. The HS logs are fairly busy so wrap in like 5 days.

Here's one - pretty good chance that stopping the local instance using the interface, then starting it again will not initialise, and you get the interfaces page reporting an error. Might be to do with the file not being given up in time from the previous instance, even though I don't have log to file enabled:

Code:

Dec-01 16:30:34	 	Info	Plugin Kinect with instance: has disconnected
Dec-01 16:30:34	 	Error	Initializing plug-in(1): Kinect Instance::System.IO.IOException: The process cannot access the file 'C:\Program Files (x86)\HomeSeer HS3\Logs\Kinect.txt' because it is being used by another process. at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath) at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost) at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost) at System.IO.StreamWriter..ctor(String path, Boolean append) at System.IO.File.AppendText(String path) at HSPI_KINECT.Logger.Init() at HSPI_KINECT.KinectApp.Init()

No idea on how work out the events not firing - does the trace logging actually show enough detail to see if it actually changed a status in HS? There's nothing i can find in the log, the plugin was restarted at 6am this morning, and decided to stop doing events sometime during the day.. Note that there is nothing logged between the two successful phrases, it just didn't fire an event. Restarting the plugin fixes this.

Code:

Dec-01 15:08:02	 	Kinect	DEBUG House telly off
Dec-01 15:08:02	 	Kinect	DEBUG Phrase recognized with confidence=0.8923106
Dec-01 15:07:53	 	Kinect	DEBUG House telly off
Dec-01 15:07:53	 	Kinect	DEBUG Phrase recognized with confidence=0.7655651

While trawling, I found this little error which also triggered a restart of the plugin:

Code:

Dec-01 00:05:21	 	Kinect	DEBUG Stopping Speech Recognition
Dec-01 00:05:21	 	Kinect	ERROR Error 2012, cannot continue

Maybe something can be put into an array of the last 50 or so trace events before the "stopping speech recognition" is reported, and then that dumped to a file or the HS log? Also, maybe trace logging for 1 minute after a speech recognition event?
Just throwing some ideas as it's fairly impossible to have trace logging on, as movement in front of the two sensors will flat out fill a text log and the HS log.

**spud** · December 2, 2015, 09:00 PM

please test version 3.0.0.38 attached.
- fixed some problems with the log file not being closed properly
- added some more logs at debug level, and removed some unused log at trace level.
- fixed copy/paste of events (parameters of the copy were missing)
- worked the autoreconnect command line parameter

regarding the problem of the event not firing, when it happens does it happen for all the Kinect events or just some specific ones? If it is some specific ones please provide some screenshot of those events.
in .38 there should be more logs at debug level to see what's going on here

thanks

Attached Files

**Furious** · December 3, 2015, 02:38 AM

Awesome, thanks spud, I'll get to installing them tonight.

I went ahead and put trace logging on the last couple of days, and increased the HS log size by an order of magnitude.

So, this morning, fired off a few VR commands, nothing happened. The logs are firing any other PI event fine (zwave, BLLAN, etc)
Checking the logs, trace using the older version doesn't trap anything - as you can see, it's actually recognising the phrase with a very high confidence:

Code:

Dec-03 07:04:21	 	Kinect	DEBUG House how cold is it
Dec-03 07:04:21	 	Kinect	DEBUG Phrase recognized with confidence=0.9868922
Dec-03 07:04:21	 	Kinect	DEBUG House how cold is it
Dec-03 07:04:21	 	Kinect	DEBUG Phrase recognized with confidence=0.9380326
Dec-03 07:04:20	 	Kinect	TRACE Phrase hypothesized = House how cold is it, Confidence=0.800694

So, decided to disable the logging. First thing I notice is that there is a kinect PI entry in the drop down, but only the remote instance (config - living room). No config, no forums, no help.
Clicking the config for the remote instance, I get a blank page, and the following error in the log:

Code:

Dec-03 07:25:51	 	Error	Getting web page from plugin page kinectconfig:LivingRoom:Object reference not set to an instance of an object.

I have to turn the local PI off and back on a few times to get it to properly initialise.

From what I can see in the logs, enabling the weatherxml PI using another event at around 6:15am triggers the local instance of the kinect PI to stop. Once this happens, things decide to stop working.

Code:

Dec-03 06:13:00	 	Kinect	DEBUG Speech Recognition Stopped
Dec-03 06:13:00	 	Kinect	DEBUG Stopping Speech Recognition
Dec-03 06:13:00	 	Plug-In	Shutting down Plug-In: Kinect
Dec-03 06:13:00	 	Event	Running script in background: C:/Program Files (x86)/HomeSeer HS3/scripts/Jon00PluginSet.vben("Main","weatherXML;1")
Dec-03 06:13:00	 	Event	Event Trigger "Time, periodic and polling events Start weather plugin"

**spud** · December 3, 2015, 08:55 AM

Originally posted by Furious View Post

Awesome, thanks spud, I'll get to installing them tonight.

I went ahead and put trace logging on the last couple of days, and increased the HS log size by an order of magnitude.

So, this morning, fired off a few VR commands, nothing happened. The logs are firing any other PI event fine (zwave, BLLAN, etc)
Checking the logs, trace using the older version doesn't trap anything - as you can see, it's actually recognising the phrase with a very high confidence:

Code:

Dec-03 07:04:21         Kinect    DEBUG House how cold is it
Dec-03 07:04:21         Kinect    DEBUG Phrase recognized with confidence=0.9868922
Dec-03 07:04:21         Kinect    DEBUG House how cold is it
Dec-03 07:04:21         Kinect    DEBUG Phrase recognized with confidence=0.9380326
Dec-03 07:04:20         Kinect    TRACE Phrase hypothesized = House how cold is it, Confidence=0.800694

So, decided to disable the logging. First thing I notice is that there is a kinect PI entry in the drop down, but only the remote instance (config - living room). No config, no forums, no help.
Clicking the config for the remote instance, I get a blank page, and the following error in the log:

Code:

Dec-03 07:25:51         Error    Getting web page from plugin page kinectconfig:LivingRoom:Object reference not set to an instance of an object.

I have to turn the local PI off and back on a few times to get it to properly initialise.

when the event firing problem happens does it happen for all the Kinect events or just some specific ones? If it is some specific ones please provide some screenshot of those events.
with version .38 there will be more things logged when a Kinect event is triggered, so please post your new logs as soon as you get this problem again.

regarding links missing and blank page, there are some obvious problem in HS3 when dealing with multiple instance plugins. I need Rich to have a look at it, but as you know this can take time.

Originally posted by Furious View Post

From what I can see in the logs, enabling the weatherxml PI using another event at around 6:15am triggers the local instance of the kinect PI to stop. Once this happens, things decide to stop working.

Code:

Dec-03 06:13:00         Kinect    DEBUG Speech Recognition Stopped
Dec-03 06:13:00         Kinect    DEBUG Stopping Speech Recognition
Dec-03 06:13:00         Plug-In    Shutting down Plug-In: Kinect
Dec-03 06:13:00         Event    Running script in background: C:/Program Files (x86)/HomeSeer HS3/scripts/Jon00PluginSet.vben("Main","weatherXML;1")
Dec-03 06:13:00         Event    Event Trigger "Time, periodic and polling events Start weather plugin"

Jon00's script to start/stop plugins does not work well for plugins with multiple instances. See latest posts of this thread: http://board.homeseer.com/showthread...=150325&page=3
so I would avoid using it.

**Furious** · December 3, 2015, 11:40 AM

Oh, looks like theres a new version of Jon's PI I need to install

In this case, I'm not using that to stop and start the Kinect PI, I'm just using it to ensure the weatherxml PI is started - so I'm thinking it won't affect it.
Also, if I actually stop the weatherxml PI from the interfaces screen just using the on/off button on the web page, it also stops the (remote) kinect PI

Code:

Dec-03 16:40:50	 	Kinect	TRACE - AudioPosition = 08:28:18.5400000; InputStreamEnded = True
Dec-03 16:40:50	 	Kinect	DEBUG Speech Recognition Stopped
Dec-03 16:40:50	 	Kinect	DEBUG Stopping Speech Recognition

As you can see, this is using the new version. The next log entries are interesting, as it shows that my event to restart the remote PI fires, but reinitialisation fails due to not being able to access the file. Then the local instance dies too:

Code:

Dec-03 16:41:06	 	Warning	I/O interface Kinect is down, executable is not running, restarting ...
Dec-03 16:41:05	 	Info	Plugin Kinect with instance: has disconnected
Dec-03 16:41:03	 	Info	Plugin Kinect with instance: LivingRoom has disconnected
Dec-03 16:41:03	 	Kinect	TRACE - AudioPosition = 00:00:00; InputStreamEnded = True
Dec-03 16:41:03	 	Kinect	DEBUG Speech Recognition Stopped
Dec-03 16:41:03	 	Kinect	DEBUG Stopping Speech Recognition
Dec-03 16:41:03	 	Kinect	ERROR Error 2012, cannot continue
Dec-03 16:41:03	 	Kinect	DEBUG Frame skipped
Dec-03 16:41:02	 	Info	Plugin Kinect with instance: LivingRoom has disconnected
Dec-03 16:41:02	 	Error	Initializing plug-in(1): Kinect Instance:LivingRoom:System.IO.IOException: The process cannot access the file 'C:\Users\admin\Documents\Logs\Kinect_LivingRoom.txt' because it is being used by another process. at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath) at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost) at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost) at System.IO.StreamWriter..ctor(String path, Boolean append) at System.IO.File.AppendText(String path) at HSPI_KINECT.Logger.LogFileInit() at HSPI_KINECT.Logger.Init() at HSPI_KINECT.KinectApp.Init()

Dec-03 16:41:02	 	Kinect	ERROR System.IO.IOException: The process cannot access the file 'C:\Users\admin\Documents\Logs\Kinect_LivingRoom.txt' because it is being used by another process. at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath) at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost) at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost) at System.IO.StreamWriter..ctor(String path, Boolean append) at System.IO.File.AppendText(String path) at HSPI_KINECT.Logger.LogFileInit() at HSPI_KINECT.Logger.Init() at HSPI_KINECT.KinectApp.Init()

There is an entry to say it's restarted, the process is there and seems active, but it's not properly registered in HS (I see it reconnect, but the menu option in interfaces isn't present), so perhaps it's not passing on events to trigger to HS?

Code:

Dec-03 16:41:06	 	Info	Plugin Kinect has connected. IP:127.0.0.1:49890

**spud** · December 3, 2015, 02:19 PM

Originally posted by Furious View Post

Oh, looks like theres a new version of Jon's PI I need to install

In this case, I'm not using that to stop and start the Kinect PI, I'm just using it to ensure the weatherxml PI is started - so I'm thinking it won't affect it.

Yes it will, I tried this script and I saw it starting/stoping a different plugin that the one I wanted to start/stop because I had a lot of plugins using mutltiple instances in my interface page.
There is no HS API to start/stop a plugin, I don't know exactly how this script works but I guess it parses the interfaces page and try to trigger the same postback than when you click the button. It's kind of a hack and not very robust so please do not use this script while trying to figure out problem with Kinect, it is already difficult enough to troubleshoot, let's not add some complexity.

Originally posted by Furious View Post

As you can see, this is using the new version. The next log entries are interesting, as it shows that my event to restart the remote PI fires, but reinitialisation fails due to not being able to access the file. Then the local instance dies too:

How do you restart the remote PI? It looks like whatever method you use, it doesn't kill the already running instance (or wait for it to close properly), so you end up with two HSPI_Kinect.exe processes running with the same instance name which is a good recipe for bad things happening.
Once again I would prefer that you do not use some external tools to restart the Kinect plugin while we are trying to troubleshoot. Let's try to make it work correctly without workarounds.

version 3.0.0.39 attached will let the plugin to init properly even if the log file is locked by another process. You will still see an error though, and if you do it means there are 2 processes running which can lead to unexpected behavior.

Attached Files

**Furious** · December 3, 2015, 03:38 PM

Ok, fair enough, no restart PI script for the time being

Just to explain what my events do:
1. Remote restart. This does a remote powershell session to the PC, runs a stop-process -force on the PI exe, waits 3 seconds, then relaunches the exe with the required parameters
2. Local restart. Run pskill locally to kill the exe. Then, use the plugin starter to start the kinect PI

I did have a flash of inspiration. I noticed that the weatherxml PI was off again. So, checked the logs, and this is what I saw:

Code:

Dec-03 16:40:59	 	Info	Plugin Kinect with instance LivingRoom has connected. IP:192.168.5.10:50952
Dec-03 16:40:57	 	Info	Plugin weatherXML with instance: has disconnected
Dec-03 16:40:57	 	Plug-In	Shutting down Plug-In: weatherXML
Dec-03 16:40:54	 	Info	Plugin Kinect with instance: LivingRoom has disconnected
Dec-03 16:40:54	 	Event	Event Trigger "Monitoring and triggered events restart kinect plugin"

Now I remembered there is some integration with weatherxml, so I am wondering if one could influence the other. I've turned on logging in that PI to see if there is anything on that side - and it would explain why when I turn that PI off or on, it causes the kinect PI to shut down...

Here's me turning the weatherxml PI back on, it kills the remote PI with no trace entry:

Code:

Dec-03 20:30:31	 	weatherXML	The Operating System version is Windows
Dec-03 20:30:31	 	weatherXML	InitIO called, plug-in is being initialized... 3.0.0.39
Dec-03 20:30:31	 	Info	Plugin weatherXML has connected. IP:127.0.0.1:56694
Dec-03 20:30:25	 	Kinect	DEBUG Speech Recognition Stopped
Dec-03 20:30:25	 	Kinect	DEBUG Stopping Speech Recognition
Dec-03 20:30:25	 	Plug-In	Shutting down Plug-In: Kinect

The console window on the remote PI has two entries saying stopping speech and then stopped recognition, and never tries to reload or re-initialise. Looking at the kinect process, there's no memory or cpu movement, so I'm guessing it's not got something to trap for that and reinitialise.

**Furious** · December 3, 2015, 03:51 PM

Definitely a 100% repro on the enabling or disabling of the weatherxml PI - and it doesn't kick a trace on stopping recognition, even with .39:

Code:

Dec-03 20:46:05	 	Info	Plugin weatherXML with instance: has disconnected
Dec-03 20:46:05	 	Plug-In	Shutting down Plug-In: weatherXML
Dec-03 20:46:00	 	weatherXML	Triggers to check: 0
Dec-03 20:46:00	 	weatherXML	Check for last ran triggers
Dec-03 20:46:00	 	weatherXML	Check timer items
Dec-03 20:45:58	 	Kinect	DEBUG Speech Recognition Stopped
Dec-03 20:45:58	 	Kinect	DEBUG Stopping Speech Recognition
Dec-03 20:45:58	 	Plug-In	Shutting down Plug-In: Kinect

Can't see anything to disable the integration in weatherxml

**spud** · December 3, 2015, 04:33 PM

I can reproduce the problem with WeatherXML it looks like it does strange things at startup which result in a call to ShutdownIO in the Kinect plugin

I sent a PM to CFGuy.

While waiting for his help, could you test with WeatherXML disabled?

**Furious** · December 3, 2015, 04:43 PM

Great stuff, I'll carry on with that disabled for the time being, see if I can shake some other errors loose

**CFGuy** · December 3, 2015, 06:52 PM

Originally posted by spud

Hi,

In some specific conditions it looks like starting the weatherXML plugin stops one instance of the Kinect plugin.
I can reproduce the problem as well as another user, (ShutdownIO is actually called in my plugin)

Could you help us debugging this problem, here is the thread:
http://board.homeseer.com/showthread.php?p=1212287#post1212287

I see in the logs that at startup weatherXML "check for integration plugins" what does it do exactly?

thanks

Originally posted by CFGuy

I have a Boolean variable called bPlugKinect.
I do a check to see if the Kinect plugin is active. If it is I set the variable to True. If not, I set the variable to False.

If the variable is true then I display the Kinect message on the weatherXML plugin integration page. I also display the VR strings and how to setup the VR events on the Settings page. Both of these are just displays of text.

On the HS events page, if the bPlugKinect variable is true then I add an extra weatherXML action. It displays as "Kinect VR Control"
If that action is selected I grab the global variable.
hs.GetVar("kinectlastvoicecommand")
After that I just use the text to set what is being asked for.

On startup, I setup a delayed separate thread to check for which plugins are installed. I have it delayed to allow for the other plugins to be finished starting before I check. I check for the Random Plugin, PhLocation, PushOver 3P, Kinect and HSTouch.

The way I check for them is the following:
I loop over the list of active plugins using hs.GetPluginsList
Then I check the names.

This is the code:
**********
Dim paPlug AS PluginAccess = Nothing
if pluginName.ToLower = "kinect" Then
paPlug = NewPluginAccess(hs, "Kinect", "")
If paPlug.Connected Then
bPlugKinect = True
Else
bPlugKinect = False
End if
End if
**********

The only difference between the Kinect plugin and the others I check is that the Kinect plugin can have remote instances. So I do have a function that as I loop over hs.GetPluginsList I check for a : in the Kinect name. If none exists then I just use the name provided by GetPluginsList. If there is a : then I grab the text before the : and check for that.

One user reported that the check was not working because they were not running a local instance. They only had remote instances. So I added some code on the weatherXML plugin integration page that allows the user to select a checkbox and tell weatherXML to go ahead and set the bPlugKinect variable to true. If they do that then the code above does not run. I just set the variable to true and skip to the other plugins that I am checking.

I never call ShutDownIO. The only place that it exists is in the HS expected sub.

I'd be glad to make some changes but not sure what to change. The code is exactly the same as what I use to check for the other plugins.

Originally posted by spud

why do you use PluginAccess and check the Connected value at all? As far as I know GetPluginsList only returns plugin instances that are actually running, moreover it returns remote instances as well. (I use it in one of my plugins)
I suspect there is something fishy in PluginAccess, could you build a version of your plugin where you do not use it at all?

Can we continue this discussion in the public thread, so that it is not lost, and in case we need Rich to see it.

thanks

I can remove PluginAccess for the Kinect check. But I still need to use it for the some of the others as I need the connection to be able to call functions in the other plugins. I have a new version of weatherXML I was going to post this weekend. I will get this change made as part of the new version.

**spud** · December 3, 2015, 07:35 PM

Originally posted by CFGuy View Post

I can remove PluginAccess for the Kinect check. But I still need to use it for the some of the others as I need the connection to be able to call functions in the other plugins. I have a new version of weatherXML I was going to post this weekend. I will get this change made as part of the new version.

forget it, it's not specific to your plugin it happens with every plugin. Sorry for the false accusation.

so now I have a good deterministic way to reproduce the problem:
- start a local instance of plugin1
- start a remote instance of plugin1 with instance=test
- start any other local plugin

ShutdownIO is called in plugin1 instance=test

I will try to have Rich look at this problem

**Furious** · December 4, 2015, 04:47 PM

So glad it's been repro'ed, I've been going slowly nuts keep poking at this to see why my setup is so fragile compared to others over the last few months - was seriously considering just dropping the whole thing. It was a welcome change to be able to do VR commands today.

I saw I'd accidentally left one of the timed events to restart an itunes PI, and that also triggered the kinect remote instance to die. So, still had a nightly restart remote instance restart, but the remote instance actually recovered nicely. That's now disabled, I want to see how long it'll stay up now.

I've not had a remote instance disconnect any other time, so I'm wondering if there is at least one other trigger for the shutdownIO bug, as the logs show that the weatherxml PI would die sometime during the day and knock out the kinect remote instance. I'll turn the PI back on in a few days and then report back.

Announcement

Error trapping

Error trapping

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment