Reporting services unexpectedly loads .NET Framework 4.0 by default and fails with HTTP 500 while browsing Report Server and Report manager URL
This week i was working on a challenging case where we've reporting service 2008 R2 installed and when we start the service from Reporting services configuration manager, it starts itself successfully.
When you tried to browse either the report manager url or the report server url, it fails with HTTP 500 error being displayed on the browser.
So, i started with the normal troubleshooting of looking at the Reporting services logfiles, which showed us the following,
library!DefaultDomain!ca0!07/05/2012-02:22:21:: i INFO: Catalog SQL Server Edition = Enterprise
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:43:: i INFO: Appdomain:8 ReportServer_MSSQLSERVER_0-1-129859465624456482 started.
rshost!rshost!f38!07/05/2012-02:22:43:: i INFO: Application domain type ReportServer statistics: created: 1, unloaded: 1, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:43:: i INFO: Appdomain:9 ReportServer_2-2-129859465635532482 started.
rshost!rshost!f38!07/05/2012-02:22:43:: i INFO: Application domain type ReportServer statistics: created: 2, unloaded: 2, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:43:: i INFO: Appdomain:10 ReportServer_3-3-129859465636468482 started.
rshost!rshost!f38!07/05/2012-02:22:43:: i INFO: Application domain type ReportServer statistics: created: 3, unloaded: 3, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:43:: i INFO: Appdomain:11 ReportServer_4-4-129859465637560482 started.
rshost!rshost!f38!07/05/2012-02:22:43:: i INFO: Application domain type ReportServer statistics: created: 4, unloaded: 4, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:43:: i INFO: Appdomain:12 ReportServer_5-5-129859465638496482 started.
rshost!rshost!f38!07/05/2012-02:22:44:: i INFO: Application domain type ReportServer statistics: created: 5, unloaded: 5, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:44:: i INFO: Appdomain:13 ReportServer_6-6-129859465639432482 started.
rshost!rshost!f38!07/05/2012-02:22:44:: i INFO: Application domain type ReportServer statistics: created: 6, unloaded: 6, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:44:: i INFO: Appdomain:14 ReportServer_7-7-129859465640524482 started.
rshost!rshost!f38!07/05/2012-02:22:44:: i INFO: Application domain type ReportServer statistics: created: 7, unloaded: 7, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:44:: i INFO: Appdomain:15 ReportServer_8-8-129859465641460482 started.
rshost!rshost!f38!07/05/2012-02:22:44:: i INFO: Application domain type ReportServer statistics: created: 8, unloaded: 8, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:44:: i INFO: Appdomain:16 ReportServer_9-9-129859465642396482 started.
rshost!rshost!f38!07/05/2012-02:22:44:: i INFO: Application domain type ReportServer statistics: created: 9, unloaded: 9, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:44:: i INFO: Appdomain:17 ReportServer_10-10-129859465643488482 started.
rshost!rshost!f38!07/05/2012-02:22:44:: i INFO: Application domain type ReportServer statistics: created: 10, unloaded: 10, failed: 0, timed out: 0.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:44:: i INFO: Appdomain:18 ReportServer_11-11-129859465644424482 started.
appdomainmanager!DefaultDomain!f38!07/05/2012-02:22:44:: e ERROR: AppDomain ReportServer_11 failed to start. Error: The configuration system has already been initialized.
library!DefaultDomain!f38!07/05/2012-02:22:44:: e ERROR: Throwing Microsoft.ReportingServices.Diagnostics.Utilities.ReportServerHttpRuntimeInternalException: Failed to create HTTP Runtime, Microsoft.ReportingServices.Diagnostics.Utilities.ReportServerHttpRuntimeInternalException: An internal or system error occurred in the HTTP Runtime object for application domain ReportServer_11. ---> System.InvalidOperationException: The configuration system has already been initialized.
at System.Configuration.ConfigurationManager.SetConfigurationSystem(IInternalConfigSystem configSystem, Boolean initComplete)
at System.Web.Configuration.HttpConfigurationSystem.EnsureInit(IConfigMapPath configMapPath, Boolean listenToFileChanges, Boolean initComplete)
at System.Web.Hosting.HostingEnvironment.Initialize(ApplicationManager appManager, IApplicationHost appHost, IConfigMapPathFactory configMapPathFactory, HostingEnvironmentParameters hostingParameters, PolicyLevel policyLevel, Exception appDomainCreationException)
at System.Web.Hosting.HostingEnvironment.Initialize(ApplicationManager appManager, IApplicationHost appHost, IConfigMapPathFactory configMapPathFactory, HostingEnvironmentParameters hostingParameters, PolicyLevel policyLevel, Exception appDomainCreationException)
at System.Web.Hosting.ApplicationManager.CreateAppDomainWithHostingEnvironment(String appId, IApplicationHost appHost, HostingEnvironmentParameters hostingParameters)
Well, after starring at the above message for some time as it didn't reveal much, i decided to take a look at the event viewer logs.
Log Name: Application
Source: ASP.NET 4.0.30319.0
Date: 7/5/2012 9:03:00 AM
Event ID: 1325
Task Category: None
Level: Error
Keywords: Classic
User: N/A
Computer: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Description:
Failed to initialize the AppDomain:ReportServer_11
Exception: System.InvalidOperationException
Message: The configuration system has already been initialized.
StackTrace: at System.Configuration.ConfigurationManager.SetConfigurationSystem(IInternalConfigSystem configSystem, Boolean initComplete)
at System.Web.Configuration.HttpConfigurationSystem.EnsureInit(IConfigMapPath configMapPath, Boolean listenToFileChanges, Boolean initComplete)
at System.Web.Hosting.HostingEnvironment.Initialize(ApplicationManager appManager, IApplicationHost appHost, IConfigMapPathFactory configMapPathFactory, HostingEnvironmentParameters hostingParameters, PolicyLevel policyLevel, Exception appDomainCreationException)
at System.Web.Hosting.HostingEnvironment.Initialize(ApplicationManager appManager, IApplicationHost appHost, IConfigMapPathFactory configMapPathFactory, HostingEnvironmentParameters hostingParameters, PolicyLevel policyLevel, Exception appDomainCreationException)
at System.Web.Hosting.ApplicationManager.CreateAppDomainWithHostingEnvironment(String appId, IApplicationHost appHost, HostingEnvironmentParameters hostingParameters)
at System.Web.Hosting.ApplicationManager.CreateAppDomainWithHostingEnvironmentAndReportErrors(String appId, IApplicationHost appHost, HostingEnvironmentParameters hostingParameters)
Again, neither the event viewer logs didn't reveal much other than giving me a hint that the error is being thrown by ASP.NET 4.0.
Now, this is quite surprising as Reporting Service 2008 R2 was never compiled against .NET 4.0 and it was compiled against .NET 3.5 (Which will still use the .NET Framework 2.0 runtime).
The next immediate question was, under what circumstances an application will be forced to load a different .NET framework (In our case, it is .NET framework 4.0 is being loaded).
To cross verify this i quickly took a Process Explorer trace and found all the .NET 4.0 dll's getting loaded in to the process space.
As a quick check i uninstalled .NET Framework 4.0 and Reporting service started to work without any errors. But unfortunately, there were other applications that are dependent on .NET Framework 4.0 which started to fail.
So in got the .NET Framework 4.0 reinstalled back on the machine and the problem reoccured.
After thinking for sometime, i finally decided to force the application to use a specific .NET Framework by adding the following tag in the Reportinservicesservice.exe.config and Report Server's web.config files.
Ref: https://msdn.microsoft.com/en-us/library/w4atty68.aspx
<configuration>
<startup>
<supportedRuntime version="v2.0.50727"/>
</startup>
</configuration>
After restarting the service, nothing changed and we ran in to the same error.
So we enabled the Fusion logging in the registry to see if there are any assembly binding errors.
Ref: https://blogs.msdn.com/b/suzcook/archive/2003/05/29/57120.aspx
While checking the fusion log for System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089.HTM, i found the following,
The operation was successful.
Bind result: hr = 0x0. The operation completed successfully.
Assembly manager loaded from: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable C:\Program Files\Microsoft SQL Server\MSRS10_50.MSSQLSERVER\Reporting Services\ReportServer\bin\ReportingServicesService.exe
--- A detailed error log follows.
=== Pre-bind state information ===
LOG: User = xxxxxxxxxxxxxxx
LOG: DisplayName = System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089
(Fully-specified)
LOG: Appbase = file:///C:/Program Files/Microsoft SQL Server/MSRS10_50.MSSQLSERVER/Reporting Services/ReportServer/bin/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = ReportingServicesService.exe
Calling assembly : ReportingServicesAppDomainManager, Version=10.0.0.0, Culture=neutral, PublicKeyToken=89845dcd8080cc91.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\Program Files\Microsoft SQL Server\MSRS10_50.MSSQLSERVER\Reporting Services\ReportServer\bin\ReportingServicesService.exe.Config
LOG: Using host configuration file:
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Version redirect found in framework config: 2.0.0.0 redirected to 4.0.0.0.
LOG: Post-policy reference: System, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089
LOG: Reusing an assembly instance that was previously loaded (C:\Windows\Microsoft.Net\assembly\GAC_MSIL\System\v4.0_4.0.0.0__b77a5c561934e089\System.dll).
This gave me a hint that there seems to be some kind of redirection that has happened. But even after looking after all the files from fusion logs over hours together and searching in the internet, i didn't get any direction to proceed further.
I compared all the config files from the faulty machine including the machine.config's, web.config's etc. But everything was normal and as expected.
That was the time i turned towards the Mr. dependent tool, "PROCESS MONITOR" from https://technet.microsoft.com/en-US/sysinternals which was written by our esteemed Technical Fellow, Mark Russinovich.
I stopped the Reporting server service from the configuration manager, started the capture in process monitor tool and started the Reporting server service. Then i stopped the trace and saved the file.
I opened the file and started to go through the file to see while initializing the process, what are the registry keys and files that were accessed by the Reporting server service.
Unfortunately everything seems to be fine there as well with all access to the paths succeeding. But again there i saw all the .NET Framewotk 4.0 assemblies being loaded.
So i decided the trace to be compared with a proper working trace from my machine. I used the same Process Monitor tool and captured a working scenario trace.
While going through the working and non working traces simultaneously, line by line something very interesting captured my attention. That is none other than the access to the following registry key,
HKLM\SOFTWARE\Microsoft\.NETFramework\OnlyUseLatestCLR
The result on the working machine for this key was NAME NOT FOUND where as the result from non-working machine was SUCCESS.
I immediately looked at the calls below and found that in my machine the call for policy files was going to 2.0,
HKLM\SOFTWARE\Microsoft\.NETFramework\Policy\v2.0
Where as for non-working scenario it was,
HKLM\SOFTWARE\Microsoft\.NETFramework\Policy\v4.0
So i did a quick check on the internet to see what this key, "OnlyUseLatestCLR" is all about and found the following details.
It is not recommended that you ever set the OnlyUseLatestCLR key. On a normal box, this key does not exist (which is equivalent to setting it to 0).
Setting this key forces all applications to use the latest CLR on the box. Even specifying a non-existent or invalid framework will result in the latest framework.
This completley breaks multi-targeting builds on a box. Also, it will break many applications which cannot be run when this is set.
Then i immediately checked the working machine and the Key was not there where as on the non-working machine the key was there, though with the value set to 0.
All i did was, deleted the key and rebooted the machine.
Well, all the struggle i went through just paid off. It made everything on the machine back ot normal and Reporting Service started to work like a champ!!
Though this took me so much of time and effort to nail this down, but certainly i enjoyed the challenge that was thrown at me.
Please note that this setting is not specific to Reporting Services 2008 R2. It will impact any .NET managed application. So it is worth to keep an eye on this key and ensure you don't set this on your machine, not even to ZERO.
HTH!
Selva.
[All the posts are AS-IS with no warranty]