Rick,

We've been having a problem with our SQL connections (as my question from about a week ago mentioned) and so yesterday I set the app pool for west wind to recycle at 12:00 AM every day in a hopes to keep us up until I can get to the actual cause of the SQL error. When the app pool recycled this morning, we got the following error (in wcErrors.txt):

2019-01-26 00:00:03.031 - 7_d38f1d70 - Unhandled Exception (Mainline): Creating an instance of the COM component with CLSID {E9BAB4D7-AE90-4A2D-BC08-D33E72DC285C} from the IClassFactory failed due to the following error: 80004005 Unspecified error (Exception from HRESULT: 0x80004005 (E_FAIL)). at Westwind.WebConnection.ComServerManager.LoadServers() at Westwind.WebConnection.ComProcessor.LoadServers(Boolean initializeOnly) at Westwind.WebConnection.ComProcessor.ProcessRequest() at Westwind.WebConnection.WebConnectionHandler.ProcessRequest(HttpContext context) - /cpwc.wc?hours=120&lat=41.6749100&lon=-83.7476500&platform=PO&prg=cpweather&proc=getHrlyFc&startDt=01%2f26%2f2019&startTm=0000&timeZone=GMT-0500

After that error, we got this error until I was told we were 'down' and I manually restarted IIS:

2019-01-26 00:00:06.500 - 8_bfd38c11 - Unable to retrieve COM Instance: Creating an instance of the COM component with CLSID {E9BAB4D7-AE90-4A2D-BC08-D33E72DC285C} from the IClassFactory failed due to the following error: 80004005 Unspecified error (Exception from HRESULT: 0x80004005 (E_FAIL)). - /cpwc.wc?hours=120&lat=42.0229000&lon=-87.9484500&platform=PO&prg=cpweather&proc=getHrlyFc&startDt=01%2f26%2f2019&startTm=0000&timeZone=GMT-0600

We had this error (different url params/methods but same error) for 5 hours this morning. We get calls against our web service every second and so there are a lot of them logged. What causes this and how do I stop it from happening? As I'm looking at the wcErrors.txt log I'm seeing a lot of these that I can tie back to other times I know the app pool recycled.

Thanks,

Scott

Looks like the Com server can't instantiate. My guess is there's something in the server startup that's preventing the server from loading - most likely code in OnInit() or OnLoad() of the server. Maybe a connection to SQL that can't be made? A file that's not found? Make sure you have non-interactive COM mode enabled.

What version of Web Connection are you running?

Recent versions of Web Connection 6.2x plus have moved application startup code out of the the server's Init() which allows servers to instantiate without running tons of user code. The problem with running user code as part of the Init() sequence is that you can't trap errors there and report them back, hence the Unspecified error most likely. Application level server initialization is delayed until OnLoad() and the first hit.

+++ Rick ---

Rick,

We are running Web Connect 6.21.

The onInit() and onLoad() methods are the defaults. We haven't changed anything:

PROTECTED FUNCTION OnInit

*** If you need to override your application's startup path
*** to something other than the current directory do it here:
*** THIS.cAppStartPath = <your custom path>
*** THIS.cAppIniFile = addbs(THIS.cAppStartPath) + "Cpmobile.ini"

THIS.cAppName = "Cpmobile"
THIS.cAppIniFile = addbs(THIS.cAppStartPath) + "Cpmobile.ini"

ENDFUNC

PROTECTED FUNCTION OnLoad

*** This URL is executed when clicking on the Automation Server
*** Form's Exit button. It forces operation through a browser!
THIS.cCOMReleaseUrl=THIS.oConfig.cComReleaseUrl



*** Add persistent SQL Server Connection
#IF WWC_USE_SQL_SYSTEMFILES
    THIS.AddProperty("oSQL", CREATE("wwSQL"))
    IF !THIS.oSQL.Connect(THIS.oConfig.cSQLConnectString)
	   MESSAGEBOX("Couldn't connect to SQL Service. Check your SQL Connect string in the INI file.",48,"Web Connection")
	   CANCEL
    ENDIF
#ENDIF

*** Add any of YOUR data paths and code 
*** SET DEFAULT is at EXE/Start path by default
SET PATH TO "..\Data" ADDITIVE   && optional

*** Force .NET version to 4.0
*DO wwDotnetBridge
*InitializeDotnetVersion("V4")  && Use Version 4

*** Add any SET CLASSLIB or SET PROCEDURE code here

ENDFUNC

These are the settings in our .ini file: Debugmode=Off Unattendedcommode=On

I also am not understanding why it starts flawlessly when I restart all of IIS but simply recycling the app pool causes so many issues.

Any other thoughts?

Ok those methods are likely not the problem.

Make sure the COM server is compiled as Single Use Exe COM Server, not multi-threaded!

App Pool recycling should work the same way as any other load. Can you reload form the Module Administration page (click Load Servers which unloads and reloads).

Only thing I can think of that something in the app pool is perhaps not configured right: Permissions? 32 bit/vs 64bit? Multiple virtuals mapped to the same folder? Web Identity being forwarded into the server (I hope not 😃).

The ProcessRequest() error is a request failing. So this could be related to failing requests. If these failures become frequent they will eventually kill the COM servers without cleaning up the COM server pool, which eventually corrupts the server pool to the point that servers can't load.

First thing you should do is make sure your COM server runs in unattended mode so that any UI or other errors always return an error and don't just fail hard with unspecified errors. That might give you more information plus if it's a file open dialog or SQL connection error it won't hang the server instance.

In 7.0 unattended mode is now on by default, in older versions you have to specify it in the configuration (or your own code):

Unattendedcommode=On

+++ Rick ---

Rick,

I just checked and 'Enable 32-Bit Applications' is set to false. I could have sworn when I first set it up I set it to true but maybe that was just on my local box. I switch that to true and give it a shot.

Unattendedcommode=On is already set (just checked). Hopefully it's as easy as enabling 32-bit applications.

My question though is if it works to switch it to enable 32-bit = true, why has it worked so far? I CAN load the COM servers through the browser admin interface. If it's the 32 bit thing I'll take it but want to understand why it's working at all with that set to false?

Thanks.

In theory you should be able to run in 64 bit mode, but 32 bit mode for COM generally is more reliable. Since it's an out of process server, it works, but the COM system itself and especially STA components are pretty much optimized for Win32 in Windows, so that is the better choice.

Let us know how it turns out.

+++ Rick ---

Rick,

Unfortunately, that didn't seem to fix it. The app pool reset at 12:00 AM a few minutes ago and we got a slew of errors until I manually restarted IIS. I was connected to the admin page via a browser to watch to see how the app pool recycle would go so not sure how that factors into it. We were getting a few requests in as it hit the time to recycle. Here's the error log until I manually connected in to the server and restarted IIS (I've deleted the query string params as they are all different and irrelevant):

2019-01-27 00:00:05.928 - 10_63a8dfcd - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:05.928 - 10_63a8dfcd - Server Execution Error
Input string was not in a correct format.
---
   at System.Text.StringBuilder.AppendFormatHelper(IFormatProvider provider, String format, ParamsArray args)
   at System.String.FormatHelper(IFormatProvider provider, String format, ParamsArray args)
   at Westwind.WebConnection.WebConnectionHandler.StandardPageBase(String Header, String Message, String ExternalFile)
   at Westwind.WebConnection.WebConnectionHandler.ErrorResponse(String Header, String Message, String ExternalFile, Int32 statusCode)
   at Westwind.WebConnection.ComProcessor.ProcessRequest() - /cpwc.wc?
2019-01-27 00:00:07.146 - 15_6156837d - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:08.662 - 21_a16f4377 - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:09.865 - 32_8b25482d - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:10.865 - 37_2e3ed267 - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:11.396 - 10_7ca9dea0 - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:11.412 - 9_de2ce18d - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:12.349 - 38_b4b77279 - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:12.631 - 15_a74f0143 - Unable to retrieve COM Instance:  - /cpwc.wc?
2019-01-27 00:00:13.068 - 8_3d55029c - Unhandled Exception (Mainline): Server cpmobile.cpmobileServer[16] failed to start in time.
   at Westwind.WebConnection.ComServerManager.LoadServers()
   at Westwind.WebConnection.ComProcessor.LoadServers(Boolean initializeOnly)
   at Westwind.WebConnection.ComProcessor.ProcessRequest()
   at Westwind.WebConnection.WebConnectionHandler.ProcessRequest(HttpContext context) - /cpwc.wc?
2019-01-27 00:00:13.115 - 28_3b4acb42 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:13.881 - 39_ddaac7f4 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:14.146 - 21_871af727 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:14.865 - 40_79b7167a - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:15.349 - 32_fa997b3f - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:15.865 - 41_60a054c8 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:18.537 - 7_e62980de - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:20.459 - 15_1ea7eb99 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:20.834 - 10_6f2fd6dc - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:26.631 - 9_115fbb3e - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:32.490 - 10_767fe590 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:47.865 - 40_121c0d87 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:53.537 - 21_c8132534 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:00:59.178 - 38_1efea37c - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:01:04.975 - 28_624dc299 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:01:31.803 - 7_bf33e559 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time. - /cpwc.wc?
2019-01-27 00:02:04.287 - 5_5d229706 - Unhandled Exception (Mainline): Collection was modified; enumeration operation may not execute.
   at System.ThrowHelper.ThrowInvalidOperationException(ExceptionResource resource)
   at System.Collections.Generic.Dictionary`2.Enumerator.MoveNext()
   at Westwind.WebConnection.WebConnectionHandler.ShowServerList(StringBuilder output, Boolean noPerf)
   at Westwind.WebConnection.WebConnectionHandler.HandleAdminTasks()
   at Westwind.WebConnection.WebConnectionHandler.ProcessRequest(HttpContext context) - /admin/ShowServerList.wc?1548572522792
2019-01-27 00:02:05.037 - 8_33cbe0c7 - Unhandled Exception (Mainline): Collection was modified; enumeration operation may not execute.
   at System.ThrowHelper.ThrowInvalidOperationException(ExceptionResource resource)
   at System.Collections.Generic.Dictionary`2.Enumerator.MoveNext()
   at Westwind.WebConnection.WebConnectionHandler.ShowServerList(StringBuilder output, Boolean noPerf)
   at Westwind.WebConnection.WebConnectionHandler.HandleAdminTasks()
   at Westwind.WebConnection.WebConnectionHandler.ProcessRequest(HttpContext context) - /admin/ShowServerList.wc?1548572524797

Any other thoughts on what could be causing Web Connect to fail to reload after an app pool recycle? I'm wondering if it has to do with a hit(s) coming in right as it's time for the app pool recycle? I tested it earlier in the evening and there were no requests coming in as the app pool recycled but there were several coming in when it recycled and we started getting these errors.

Thanks,

Scott

Scott,

That trace is not very helpful - what's needed is to see what comes before these COM Server couldn't be loaded errors. They might not show up here because it might be a problem in the server's startup code (although I'm not sure what that could be).

I wonder if the issue might be that your server is running under Interactive identity and servers start to fail when the Interactive account gets auto-logged off. If running under Interactive without an active login (or a login that doesn't have DCOM execution rights) the server will fail to load. Did you set explicit DCOM Impersonation for the server? If you did, I highly recommend you leave the DCOM settings at the default Launching User and let the IIS Application pool handle passing down the security.

Just for clarification - application pool shutdowns (other than machine startup) should be no different from a normal restart of servers so i'm not sure why the reccling is a problem other than that there might be a problem that fails to let the server load.

When it fails on hte server see if you can go into the machine and that you can launch the COM server from FoxPro or the command line.

These topics might be of help:

• Testing your COM Server - COM Server Configuration

• Dealing with COM Server Load Errors

+++ Rick ---

Rick,

I've looked at the links, double checked the 'identity' is set to 'LocalSystem', I have never done anything with DCOM settings (other than running your com server setup script), and all of the other settings look correct.

I was checking in the windows event log and every time the app pool recycle fails the windows event log has:

The server {E9BAB4D7-AE90-4A2D-BC08-D33E72DC285C} did not register with DCOM within the required timeout.

which seems to coincide with WC errors I'm seeing of

2019-01-27 00:00:13.115 - 28_3b4acb42 - Unable to retrieve COM Instance: Server cpmobile.cpmobileServer[16] failed to start in time

Is there any way to increase the com server loading time and I could see if that fixes my issue? We do run 16 Com servers (we broker a lot of SQL connections) and so if the server is busy I could believe that it failed to start all 16 within whatever the default timeout is?

Thanks,

Scott

Hello, just my 2 cents I had same problem putting this code in Oninit() was very helpful to locate the timeout problem ( on the foxpro side )

SET COVERAGE TO c:\mylog.log

Yes that's what I was suspecting - there is a problem loading your COM server, although I can't tell you what the load error might be or why it might not work at one time, and work on another.

It sounds to me like your COM server is timing out when it loads. Maybe the request that's getting hit is having a problem (like connecting to SQL).

I would recommend adding tracing to the server's startup code to see when and if requests end up actually hitting the server. It might be useful to have trace messages output at the beginning and end of both OnInit() and OnLoad and compare that to times of failure in the event log and wcErrors.txt.

Startup Error Tracing

You can't change the DCOM load timeout, but changing the timeout wouldn't solve anything because the timeout is at least 20 seconds - if it takes that long to load a server you have other issues 😃 Based on the startup code you posted, server load should not take more than a second since you have no startup code. That's where tracing hopefully can help - if the server is even getting that far.

Given the intermittent nature the only thing I can think of that it has something to do with permissions or domain account that change - maybe when the machine logs off/on.

+++ Rick ---

I'm posting a follow up to this discussion as this may be of interest to others.

I took a look at Scott's server last night and we narrowed the problem down to running a large pool of COM objects. Scott's app is running 16 COM instances and the Web Connection server would randomly hang up with when the Application Pool was recycled or restarted.

After some experimentation and checking and double checking settings, I tried limiting the number of pool instances to smaller numbers and the problem disappeared. In fact, we were able to run up to 15 instances without problems but at 16 instances - as luck would have it - recycling problems would start showing up. The larger the pool above 16 the more likely hanging failures would show when the Application Pool was recycles or IIS restarted.

Magic Number?

At this point I was still skeptical so I tried to duplicate the problem on my local machine in my local test environment. I'm running on Windows 10 here, and I set up Web Connection demo servers and I was unable to reproduce the problem, even running 30 pool instances. I could run and recycle without any issues for long runs at a time.

I then moved testing to my live Web Server which is a Server 2016 installation - and I ended up getting the same results we saw on Scott's server:

• Running 15 server instances - no problems
• Running 16 server instances - recycling would short hang up servers

I also managed to get an error message out of the logs:

COM object that has been separated from its underlying RCW cannot be used.

which happens only during the initial failure after which errors show up that the COM server cannot be loaded.

This is very frustrating as the problem does not appear to be directly related to the Web Connection implementation but rather seems to be specific to some Windows internals that are running out of resources somehow. It's made worse by the fact that I can't reproduce and debug it locally.

I also posted a message on StackOverflow in case somebody has run into a related issue before:

• Stack Overflow Question

What to do?

The first and obvious solution is - stick with 15 or less servers in the COM pool. 15 servers is a lot of instances, so for most applications that should be a viable option.

If you really need more instances it's also possible to run in file mode which allows you to run more instances, but you do lose some management features in the process. The Web Connection module does allow remote start/stop and auto-start, but there's no auto-recovery if a server fails or is hung up.

I've also made a few small changes in the WebConnection Module that might help:

• Added option to create STA Threads instead of MTA threads for the COM Pool
• Added additional locks for blocking COM server collection access to avoid dead-locks

The STA thread option sits behind a new flag in web.config called UseStaComServers (name may change in the future) which switched between MTA (false is the default) and STA threads (true).

You can grab the latest version from:

• Web Connection Experimental Preview

This doesn't fix the problem but it does seem to improve the frequency at which failures occur. The safe bet continues to be 15 or less instances.

+++ Rick ---