HS startup: Error in Hub.GetBuffer: The operation has timed out

[claude]

For some time now (since end of July 2014), every time I start HS3, I get the following message: "Error in Hub.GetBuffer: The operation has timed out". All is fine after that.

Insteon hub: 1st gen
Insteon plugin: 3.0.5.11
HS3: 3.0.0.149
Power fail recovey: Off

Anyone else seeing this?

[claude]

Really, no one else?

Mark: any hints as to what I should look at to resolve this? Attached error report; had to chop off older instances because of upload size limit..

[mnsandler]

claude,
i'll take a look, but its kind of difficult to fix a problem i can't replicate.

[claude]

I understand and agree. Given I seem to be the only one with this issue, it may very well be tied to my particular environment.

I was hoping, just looking at the top of the log, you could point me in some direction that I could chase down myself.

Error: Error in Hub.GetBuffer: The operation has timed out -- Details System.Net.WebException: The operation has timed out
at System.Net.HttpWebRequest.GetResponse()
at System.Xml.XmlDownloadManager.GetNonFileStream(Uri uri, ICredentials credentials, IWebProxy proxy, RequestCachePolicy cachePolicy)
at System.Xml.XmlDownloadManager.GetStream(Uri uri, ICredentials credentials, IWebProxy proxy, RequestCachePolicy cachePolicy)
at System.Xml.XmlUrlResolver.GetEntity(Uri absoluteUri, String role, Type ofObjectToReturn)
at System.Xml.XmlTextReaderImpl.FinishInitUriString()
at System.Xml.XmlTextReaderImpl..ctor(String uriStr, XmlReaderSettings settings, XmlParserContext context, XmlResolver uriResolver)
at System.Xml.XmlReaderSettings.CreateReader(String inputUri, XmlParserContext inputContext)
at System.Xml.XmlReader.Create(String inputUri, XmlReaderSettings settings, XmlParserContext inputContext)
at System.Xml.XmlReader.Create(String inputUri)
at Insteon.Support.Hub.SocketPortClass.GetBuffer() -- 2015-01-03 14:31:11

While HS3 is already running, if I disable and re-enable the Insteon plugin, no time-outs are logged. The time-out issue only comes into play at HS3 startup.

I'm assuming the plugin processes its own XML requests and socket management without any help from HS3, right? If that's the case, what are your thoughts on what could delay the Hub's response, specifically at HS3 startup, knowing that at any other time it responds in a timely manner?

[mnsandler]

are you running hs3 as a service or anything other than a foreground application?

[claude]

There you go! You questioning whether I was running as a service rang a bell.

I do run as a service, but that's not the root cause. Looking back at my log files, I now know that the issue only occurs after a reboot. So, simply restarting HS3 (as a service) does not produce an error.

I had the"HS wrapper" service set to 'automatic start'. I changed it to 'delayed automatic start' and so far no errors.

Here's what I think was happening. For some reason, my TCP stack takes some time to settle down at boot up, plus the fact that I can't set dependencies with my wrapper service. I suspect both the Insteon and Envisalink plugins were trying to open sockets the TCP stack was not ready to service at that point, at least not respond back immediately.

So I'll monitor my system over time to validate my assumption.

Thanks for the trigger Mark.

[mnsandler]

Glad we resolved it. I really don't think HS3 runs well as a service based on what i've read: apparently updates caused problems as one time; not sure if this is resolved.