VC crashing over night

[PegLegTV]

My VC setup on my main PC is crashing on me over night, it started about a week before 2.2.3.8 was released, so it's not a bug specific to 2.2.3.8. I've tried to trouble shoot the problem to no avail I have the "voxLog.txt" from the last two days but I can't seem to find the cause of the problem.

it's not happening every night it seems random, I've gone through all my scheduled events (eventghost and Google calendar) and none of them are triggered consistently with the crashes,


Windows 10 (with all updates)
VC 2.2.3.8
Kodi 17.3

I'll send the logs to you in a personal message

let me know if you need more information

thank you

[jitterjames]

I'm afraid you're on your own on this one, at least for now.  I won't have time to look at this for the next couple of weeks.

I recommend checking for sleep related issues.  I suspect your computer is always on so that would rule sleep out.

After that you'll probably just have to rip some stuff out and put it back in to see what works.

[PegLegTV]

thanks for the reply, I'll keep plucking away

[PegLegTV]

so I have done some more digging and observations, it seems that my VC is having issues connecting to my VeraEdge, my VC PC is connected to my Ethernet Switch along with my Vera Edge

every time VC has crashed with in the last 4 lines of the VC log has been a grouping of data request to my VeraEdge so I started to do some testing with VC triggering devices on my VeraEdge, most of the time it was almost instant and other times it would take up to 6 Seconds, and if a couple events where triggered during the freeze it would then cause VC to Crash,

at one point while testing VC took a couple seconds to connect and when it finally turned the light on I had 3 of the same events (Vera1.Switch.7.On) showed up in my history window

so I restarted my VeraEdge, my VC PC, and my Router, but eventually VC Crashed again,

so I copied a data request from my log to my web browser and it connected instantly, I found a post about VC not connecting to Vera Edge so I tried to change the port number to 49451 in VC as talked about here http://voxcommando.com/forum/index.php?topic=2464.msg21231#msg21231, but that resulted with a long delay with every test, and would give me double or triple events

8/22/2017 12:12:38 AM   279   [plugin] actionString from post: vc.triggerevent&&Scenes.Bright
8/22/2017 12:12:38 AM   357   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821293&Timeout=600&MinimumDelay=1000
8/22/2017 12:12:39 AM   285   addHistoryItem [vcevent] Vera1.Dim.7.100

8/22/2017 12:12:39 AM   388   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821297&Timeout=600&MinimumDelay=1000
8/22/2017 12:12:40 AM   297   addHistoryItem [vcevent] Vera1.Dim.7.100

8/22/2017 12:12:40 AM   399   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821313&Timeout=600&MinimumDelay=1000
8/22/2017 12:12:41 AM   402   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821313&Timeout=600&MinimumDelay=1000
8/22/2017 12:12:42 AM   841   received udp command:VC.TriggerEvent&&Beam 2.0.LightLvl&&13.39
8/22/2017 12:12:42 AM   841   Action is NOT threadsafe: VC.TriggerEvent
8/22/2017 12:12:42 AM   841   action repeat set to: 1
8/22/2017 12:12:42 AM   841   Action:  VC.TriggerEvent
8/22/2017 12:12:42 AM   841   Param1:Beam 2.0.LightLvl
8/22/2017 12:12:42 AM   841   Param2:13.39
8/22/2017 12:12:42 AM   841   addHistoryItem [action] VC.TriggerEvent:Beam 2.0.LightLvl&&13.39

I'm not sure if this could be a problem

Action is NOT threadsafe: VC.TriggerEvent

so Last night I looked to see what problems people where having with the newest Vera Firmware and I went ahead and updated my VeraEdge, to 1.7.3014 (Thankfully no new problems) but VC ended up crashing again today


I'm not sure how frequent VC is supposed to request data from the VeraEdge but it seams sporadic, at least looking my log it does

not sure where to go from here, any help would be greatly appreciated

[jitterjames]

I'm using 1.7.3014 firmware on my edge and not having any problems with VC and the Edge.

The Edge is an under powered resource hungry device.  Sometimes it may get slow and poking it a lot only makes things worse.  If you have many devices and/or plugins running on the Edge then it is possible you can slim things down, or use less aggressive polling methods on the Edge to make it more responsive.

I'm not sure why you think that VC is having trouble connecting to the Edge.  You can test this in the plugin settings using the "test" button.

There is no reason why the port should matter as far as I know.  I would stick with the default port.

I am noticing that you are getting Vera events that are arriving via UDP messages which is not how the vera plugin normally works so you must have another instance of VC or something which is echoing the events.  It seems more likely that there is something in your configuration that is causing problems.  I would probably need to get your entire VC folder to spot any obvious issues but if you have multiple instances of VC running on your PC or on other systems and they are echoing events then this would further complicate things.

The "not threadsafe" line in the log is just information and does not indicate any problems.

I'm not sure what you mean by sporadic but VC requests updates from Vera and then sits and waits until Vera sends a response.  If there is no activity on the the Vera then it will not respond until something changes, or a certain amount of time (30 seconds) passes.  Then the process repeats.  If there is no activity then it will result in a new request every 30 seconds, but if a light turns on (and Vera knows about it) then it should tell VC right away.

Note that just because the last thing in your log is an event from the Vera does not mean that this is the cause of the crash.  It could be totally unrelated.  The vera polling events tends to clutter the log because they run at a short interval so there is simply a high chance that they will be the last thing you see in the log.  If the Vera is involved then I suspect it's more likely to be related to what that event is triggering.  Especially if you are getting multiple events.  It's hard to tell from such a short snippet of the log but it seems that maybe you have an infinite self triggering event loop.

[PegLegTV]

sorry for the small snippet of code, I new you where busy so I was trying to show how VC had polled the VeraEdge two seconds apart two times, and I just noticed that I removed another part of the log I was going to post showing the different timing of the data request and forgot to put it back in

this was the section I forgot to put back in my post lastnight

8/22/2017 12:12:42 AM   844   Action INFO:
8/22/2017 12:13:06 AM   859   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821314&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:07 AM   869   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821314&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:09 AM   709   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821320&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:10 AM   719   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821320&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:36 AM   869   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821321&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:37 AM   875   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821321&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:43 AM   718   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821322&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:44 AM   725   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821322&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:45 AM   741   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821325&Timeout=600&MinimumDelay=1000
8/22/2017 12:13:46 AM   748   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821325&Timeout=600&MinimumDelay=1000
8/22/2017 12:14:06 AM   838   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821326&Timeout=600&MinimumDelay=1000
8/22/2017 12:14:07 AM   846   [plugin] http://192.168.1.24:49451/data_request?id=lu_status2&LoadTime=1503288815&DataVersion=288821326&Timeout=600&MinimumDelay=1000

the time stamp on these request are sporadic as they don't seem to be following the 30 seconds

                                                                                                                                                                                                             

VC crashed again this morning, but I wasn't able to get the log file because I connected remotely to fix it (outside the network), but I had a new little popup that I haven't seen before

Message from webpage:

out of memory at line 1

nothing happend when I clicked okay, when I clicked "Close Program" on the Voxcommando has stopped working popup the little windows where closed as well

I can send you another link to two logs that I have saved from the 13th and 15th, other wise I can send you a log the next time VC Crashes that will be more current

I am noticing that you are getting Vera events that are arriving via UDP messages which is not how the vera plugin normally works so you must have another instance of VC or something which is echoing the events.  It seems more likely that there is something in your configuration that is causing problems.  I would probably need to get your entire VC folder to spot any obvious issues but if you have multiple instances of VC running on your PC or on other systems and they are echoing events then this would further complicate things.

as of now I don't use Vera Events to do anything, I just double checked my tree and I have a blank command (No Actions) with a couple Vera events but I have them commented out (Vera1.Switch.7.Off1 added a 1 to the end of all of them), and I have two instanses of VC Running one on my main VC PC and one on my laptop for editing and building commands they use the same voicecommands.xml ( I copy the laptop voicecommands.xml to the Main VC PC when I make changes to Voxcommando)

let me know if you want to look at my configuration and I can send you a link to it as well

[jitterjames]

I don't think the "message from webpage" error is from VC.  Maybe it's from EventGhost?

Yes please send me your configuration because the UDP messages are not normal and I'm also seeing actions in your log that are triggering events which I do not understand.

Also, are you running VC with any additional command line parameters?  If you are using the secret "always threading everything" stress-test feature then please stop using that.

[jitterjames]

Also, please check that you are not using both tabs of the Vera plugin settings to connect to the same Vera Edge.

[PegLegTV]

I'm not using any additional command line parameters, and my vera is only using vera1 tab, vera2 tab is empty

I think I would remove that secret  command line parameter from the forum, I can only imagine the type of headaches that could create for you guys lol

do you still have the dropbox link I sent you for the logs? if so I think you should be able to view my copy of VC for my main PC, if not let me know and I'll send you a new link in a PM

I'm almost positive that the "message from webpage" error is from VC, as it wouldn't let me click the okay button, and when I clicked close program for vc those windows where also closed, if I see one again I'll let you know

[jitterjames]

I looked at your logs and configuration.  I don't see anything that is obviously wrong.  There are times in the log where it looks like VC is having to do a lot of work but that's not necessarily related.

If you think it might be related to Vera then I guess you need to disable that plugin and run for a few days to see if it makes any difference.

You mentioned that you have two PCs running the same configuration. Are they both crashing the same amount?  At the same time?

[PegLegTV]

only the Main PC VC is crashing, the one on my laptop is always on and has the same plugins but only for testing and building,

I'll Try disabling the Vera Plugin and see how that goes.

[PegLegTV]

you where right, It's not the Vera Plugin.

I disabled the Vera plugin on Tuesday, and when I woke up Wednesday morning VC had Crashed and I when I checked the log all that was entered in the log was:

8/23/2017 01:26:23 AM   VoxLog created / UAC test passed.

I went through all my Scheduled events (Eventghost Scheduler, Google Calendar, Tasker) but none of them went off at that time.

It did not Crash this morning so I'll keep digging and let you know what I find

[jitterjames]

I disabled the Vera plugin on Tuesday, and when I woke up Wednesday morning VC had Crashed and I when I checked the log all that was entered in the log was:

8/23/2017 01:26:23 AM   VoxLog created / UAC test passed.

Sounds like maybe your logging was turned off!  There should be a lot more in the log just from starting up.

If you PC and Laptop both have the same configuration and the laptop is not crashing then I would start by trying to figure out what is different between the two systems / setups.

[PegLegTV]

That's what I'm looking into now, I've already changed the way a couple of commands are triggered to see if that will helps,

what gets me is that I don't have any thing scheduled to do a full Restart of VC only quick restarts so the log shouldn't be showing startup at 1:26 AM as I was in bed by that time, I'm looking into outside causes (Wall tablet, tablet remote, Tasker, phones, Laptops.....) being that one big difference is that my laptop doesn't have anything controlling it from outside the pc

hope that makes scenes 
 

[PegLegTV]

well it looks like it was command related, I believe it to be this command:

Code: [Select]

<?xml version="1.0" encoding="utf-16"?>
<!--VoxCommando 2.2.3.8-->
<command id="707" name="OLD ++TvShow Updater" enabled="true" alwaysOn="False" confirm="False" requiredConfidence="0" loop="False" loopDelay="0" loopMax="0" description="">
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Speak</param>
      <param>{Var.Sender}</param>
      <param>TTS</param>
      <param>Updating Remote TV Show List</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>File.Read</cmdType>
    <params>
      <param>{Path.VC}\XbmcPayloads\xbmcTvShowTitles.xml</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.RegEx</cmdType>
    <params>
      <param>&lt;phrase&gt;(.*?)&lt;/phrase&gt;</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.MatchConcat</cmdType>
    <params>
      <param>,</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Tools.Decode.HTML</cmdType>
    <params>
      <param>{LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.Replace</cmdType>
    <params>
      <param>&amp;</param>
      <param>and</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.RegExReplace</cmdType>
    <params>
      <param>\((\d+)\)</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.SetVar</cmdType>
    <params>
      <param>TVAlphSort</param>
      <param>{LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Select</cmdType>
    <params>
      <param>SortingTV</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Navigate</cmdType>
    <params>
      <param>http://alphabetizer.flap.tv/</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Wait</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.ElementByTag</cmdType>
    <params>
      <param>INPUT</param>
      <param>2</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Click</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.ElementByTag</cmdType>
    <params>
      <param>INPUT</param>
      <param>15</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Click</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.ElementByTag</cmdType>
    <params>
      <param>TEXTAREA</param>
      <param>0</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Focus</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.SetText</cmdType>
    <params>
      <param>{Var.TVAlphSort}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.ElementByTag</cmdType>
    <params>
      <param>BUTTON</param>
      <param>1</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Click</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Wait</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.ElementByTag</cmdType>
    <params>
      <param>TEXTAREA</param>
      <param>0</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.Focus</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>RoboB.GetText</cmdType>
    <params />
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Push</param>
      <param>Living Room Remote</param>
      <param>TVShow=:={LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Push</param>
      <param>Living Room Wall Tablet</param>
      <param>TVShow=:={LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Speak</param>
      <param>{Var.Sender}</param>
      <param>TTS</param>
      <param>Finished Updating Remote TV Show List</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
</command>
^^^^this command would get a list of my Basic TV Shows, then use Robob plugin to navigate to http://alphabetizer.flap.tv/ , in order to put the shows in alphabetical order, and then send the list to my remote Tablet, the command was triggered when the kodi library was done updating,

my new command for this uses kodi to get the tv shows in alphabetical order, and then removes my DIY Shows from the list, and I only have it run when needed by voice, (a new show added, or old show removed from kodi)

Code: [Select]

<?xml version="1.0" encoding="utf-16"?>
<!--VoxCommando 2.2.3.8-->
<command id="672" name="New TV Show Updater" enabled="true" alwaysOn="False" confirm="False" requiredConfidence="0" loop="False" loopDelay="0" loopMax="0" description="">
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Speak</param>
      <param>{Var.Sender}</param>
      <param>TTS</param>
      <param>Updating Remote TV Show List</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>XJson.Raw</cmdType>
    <params>
      <param>VideoLibrary.GetTVShows</param>
      <param>"filter": {"field": "playcount", "operator": "lessthan", "value": "2"}, "limits": { "start" : 0 }, "properties": ["playcount"], "sort": { "order": "ascending", "method": "label" } }, "id": "libMovies"}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.RegEx</cmdType>
    <params>
      <param>"label":\s"(.*?)"</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.MatchConcat</cmdType>
    <params>
      <param>,</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.SetVar</cmdType>
    <params>
      <param>TVList</param>
      <param>{LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <loop>
    <loopParams>
      <from>1</from>
      <to>{M:DiyShows.DiyShowCount}</to>
    </loopParams>
    <loopActions>
      <action>
        <cmdType>Results.Replace</cmdType>
        <params>
          <param>-</param>
          <param><![CDATA[ ]]></param>
          <param>{M:DiyShows.TVL{j}}</param>
        </params>
        <cmdRepeat>1</cmdRepeat>
      </action>
      <action>
        <cmdType>Results.Replace</cmdType>
        <params>
          <param>{LastResult}</param>
          <param />
          <param>{Var.TVList}</param>
        </params>
        <cmdRepeat>1</cmdRepeat>
      </action>
      <action>
        <cmdType>Results.SetVar</cmdType>
        <params>
          <param>TVList</param>
          <param>{LastResult}</param>
        </params>
        <cmdRepeat>1</cmdRepeat>
      </action>
    </loopActions>
  </loop>
  <action>
    <cmdType>Results.Replace</cmdType>
    <params>
      <param>,,</param>
      <param>,</param>
      <param>{Var.TVList}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.SetVar</cmdType>
    <params>
      <param>TVList</param>
      <param>{LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.RegExReplace</cmdType>
    <params>
      <param>,$</param>
      <param />
      <param>{Var.TVList}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.SetVar</cmdType>
    <params>
      <param>TVList</param>
      <param>{LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.Replace</cmdType>
    <params>
      <param>&amp;</param>
      <param>and</param>
      <param>{Var.TVList}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.SetVar</cmdType>
    <params>
      <param>TVList</param>
      <param>{LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.Replace</cmdType>
    <params>
      <param>,,</param>
      <param>,</param>
      <param>{Var.TVList}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>Results.SetVar</cmdType>
    <params>
      <param>TVList</param>
      <param>{LastResult}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>System.SetClipboardText</cmdType>
    <params>
      <param>{Var.TVList}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Push</param>
      <param>Living Room Remote</param>
      <param>TVShow=:={Var.TVList}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Push</param>
      <param>Living Room Wall Tablet</param>
      <param>TVShow=:={Var.TVList}</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <action>
    <cmdType>VC.TriggerEvent</cmdType>
    <params>
      <param>Speak</param>
      <param>{Var.Sender}</param>
      <param>TTS</param>
      <param>Finished Updating Remote TV Show List</param>
    </params>
    <cmdRepeat>1</cmdRepeat>
  </action>
  <event>Browse.DIY</event>
  <phrase>Update TV Show List</phrase>
</command>

Thank you for all the help, and tips