Every now and then we got a call for an application which, randomly and without a specific pattern or apparent reason, shuts down all user’s sessions. Since ASP.NET 2.0 we can use Web Events to have more information on what is happening at the runtime level and this time the message we had in the event log was pretty clear: Event code: 1002 Event message: Application is shutting down. Reason: Configuration changed. Event time: Event time (UTC): Event ID: Event sequence: Event occurrence: 1 Event detail code: Application information: Application domain: /LM/W3SVC/1045621189/Root-2-1742334186915428 Trust level: Full Application Virtual Path: / Application Path: C:\Inetpub\wwwroot\ Machine name: <machinename> Process information: Process ID: 1234 Process name: w3wp.exe Account name: NT AUTHORITY\NETWORK SERVICE We used Process Monitor to track access to the relevant .config files which are usually the cause for this kind of problem, but with no luck. To make a long story short, we had a look at the events around the time when the session was lost and we noticed it usually followed some exception tracking logic the customer had used, so we had a look at the source code and found something interesting: the customer had some code to write and…
-
-
StackOverflow continued: DataSource or DataSourceID?
I have already wrote here about a StackOverflowException I recently came across; after a while I got another quite similar problem, still a StackOverflowException with a very long recursion. Thread 36 is the one where the exception was thrown: 0:000> !threadsThreadCount: 21UnstartedThread: 0BackgroundThread: 21PendingThread: 0DeadThread: 0Hosted Runtime: no PreEmptive GC Alloc Lock ID OSID ThreadOBJ State GC Context Domain Count APT Exception 17 1 950 000f2580 1808220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker) 27 2 1bfc 00100018 b220 Enabled 00000000:00000000 000eed48 0 MTA (Finalizer) 28 3 300 00117068 80a220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Completion Port) 29 4 1cf4 0011a458 1220 Enabled 00000000:00000000 000eed48 0 Ukn 9 5 ec0 001702e0 220 Enabled 00000000:00000000 000eed48 0 Ukn 31 6 2414 00171f68 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker) 32 7 1f24 00172338 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker) 33 8 97c 001729e0 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker) 34 9 13bc 00173088 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker) 35 a 22f8 00173a50 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker) 36 b 1e60 00174540 180b220 Disabled 12445a64:124475b8 0011ab48 1 MTA (Threadpool Worker) System.StackOverflowException (1a0a00a4) 37 c 1c8c 00174cf8 180b220 Enabled 00000000:00000000 000eed48…
-
SharePoint and Office Live? Access forbidden!
I recently came across an odd problem the customer got on his SharePoint server: when the clients had the Office Live add-on installed they were constantly refused with a 403 error. The problem is well described here. If you have this problem, there is a fix for you: 970946. If you do not want to install the fix, you might consider to filter the UserAgent string you receive on the server (well, you should filter it before the web request is processed on the server) as one of my customers is testing: if the UserAgent string contains the word “Mozilla” and “Office”* or “non-browser” or “FrontPage”*, just remove the unwanted token. Carlo Quote of the day: All things are difficult before they are easy. – Thomas Fuller
-
Three errors, one cause: me!
A few days ago I was working on a repro I got from a customer as I very often do, and for some reason after a while my IIS started to behave oddly, pages where not served, the application pool was stuck doing “something” and whenever I tried to open the IIS Manager I got the error “There was an error when trying to connect. Do you want to retype your credentials and try again? Cannot create a file when that file already exists”: Needless to say that being IIS on my local machine and I have not made any changes to the security/ACLs/DCOM etc… there should be no need to retype my credentials; and by the way, even retyping them did not help. By the way, if I tried to remotely connect to another machine of mine, I got the message “The type initializer for ‘Microsoft.Web.Management.Remoting.HttpChannel’ threw an exception”: My next step has been to try to restart the World Wide Web Publishing Service: it was (oddly?) stopped, but again I got an error “Windows could not start the World Wide Web Publishing Service service on Local Computer. Error 1068: The dependency service or group failed to start”: The…
-
Logparser automated within Windbg
The .shell command in Windbg allows to pipe the output of a debugger command to an external process and automatically print its output back inside the debugger window; a useful example is the command FIND, for example if we want to parse the stack for every thread and find every call where the word “isapi” is involved: 0:036> .shell -ci "~*kpL1000" find /i "isapi"013cff78 1004f94e ISAPI_Rewrite!TerminateFilter+0x3cef013cffb0 1004f9f3 ISAPI_Rewrite!TerminateFilter+0x4462e013cffec 00000000 ISAPI_Rewrite!TerminateFilter+0x446d30144ff78 1004f94e ISAPI_Rewrite+0x77630144ffb0 1004f9f3 ISAPI_Rewrite!TerminateFilter+0x4462e0144ffec 00000000 ISAPI_Rewrite!TerminateFilter+0x446d3.shell: Process exited Incidentally also LogParser (one of my favorite debugging tools) can accept data to be parsed from the input stream using the STDIN keyword, so for example refactoring a script I posted some time ago we can find out if there are any duplicated assemblies in our application pool that should be moved to the GAC: 0:000> .shell -ci "!peb" logparser "select extract_filename(text) as Duplicated_Assemblies, count(Duplicated_Assemblies) as Hits from STDIN where index_of(text, 'temporary asp.net files') > 0 group by Duplicated_Assemblies having count(Duplicated_Assemblies) > 1" -i:textline -o:nat -rtp:-1Duplicated_Assemblies Hits ---------------------------- ----errormanager.dll 2winformsui.dll 2externallibraryinterface.dll 2ptshopengine.dll 2schemas.dll 2dbengine.dll 2flowservice.dll 2Statistics:-----------Elements processed: 182Elements output: 7Execution time: 0.02 seconds.shell: Process exited Following the same principle, we can find out if there are strong named assemblies in our…
-
StackOverflowException and DataBind()
The application pool for this site was getting disabled quite frequently and we found quite a few entries like the following in the event log: Event Type: Error Event Source: W3SVC Event Category: None Event ID: 1002 Date: 19/11/2008 Time: 15:20:23 User: N/A Computer: <computername> Description: Application pool ‘DefaultAppPool’ is being automatically disabled due to a series of failures in the process(es) serving that application pool In this case the customer already had some debugging skills so when he called CSS he already had a few dumps available to analyze; they were some process shutdown dumps (taken on Kernel32!TerminateProcess), strangely we had no second chance dumps (maybe because of one of these reasons?) but they’ve been a good point to start from anyway. First, let’s have a look at the exceptions: 0:000> !dumpheap -type Exception -stat [...]Statistics: MT Count TotalSize Class Name79333ed4 1 12 System.Text.DecoderExceptionFallback79333e90 1 12 System.Text.EncoderExceptionFallback79330d44 1 72 System.ExecutionEngineException79330cb4 1 72 System.StackOverflowException79330c24 1 72 System.OutOfMemoryException7931ffd4 1 72 System.NullReferenceException6610c7fc 1 84 System.Web.HttpUnhandledException79330dd4 2 144 System.Threading.ThreadAbortException79318afc 2 144 System.InvalidOperationException7931740c 5 160 System.UnhandledExceptionEventHandlerTotal 16 objects Remember, a few special exceptions are loaded when the AppDomain is first created (see here) so let’s try to see if there is still something significant…
-
Where’s my dump gone?!?
Have you ever found yourself patiently waiting for a problem to reproduce with your debugger ready, and when it happens you just find there are no signs of your dump anywhere? If you are using adplus you likely had the text logs, but nothing more… In such situations it is possible that the OS is terminating the process before the dump is fully written. If you are tying to dump an IIS process and you want to save some time and headaches, try this small cunning: temporarily disable the “Enable pinging” and “Enable rapid-fail protection” flags in the Health tab for your application pool: Sometimes can be useful to tell IIS to not kill a failing worker process but rather leave it orphaned: Features of Worker Process Isolation Mode Orphaning Worker Processes You can configure worker process isolation mode to orphan a worker process that the WWW service deems to be failing. The WWW service usually terminates a failing worker process and replaces it. If you enable orphaning, the WWW service allows a failing worker process to continue running, but separates it from the application pool (making it an orphan) and starts a new worker process in its place. You…
-
WPF, 3D and services: supported (again)?
I wrote about why GDI+ is not supported in a service a couple of years ago but this is still a debated topic (or I should better say a misunderstood topic), then WPF (Windows Presentation Foundation) came into the game and it brought some more uncertainties with it. Recently I worked on a custom application which basically was meant to made of a Windows Form client and a WCF Web Service used to get some data from a database, create a 3D image (a sort of chart) and send it to the client as a jpg image; the graphic part was done using classes such as Viewport3D, PerspectiveCamera, ModelVisual3D, RenderTargetBitmap and others taken from the System.Windows.Media.* and System.Drawing namespaces. Everything was working fine as long as the project was being developed and debugged against the ASP.NET Development Server (Cassini), but when the project was deployed to IIS7 the image returned was missing the 3D part and the fancy transparency and shadow effects added through WPF classes, it merely had a blue background, nothing more. The first thing I thought to, are the differences between Cassini and IIS: the former is a process (not a service), it runs under the credentials…
-
Fatal Execution Engine Error on x64 Framework
I got two FEEE cases in a row last week, both of them for the same cause so I thought to blog about it hoping to save some stress and headshakes to someone else. The affected platform is 64 bit Framework (32 bit works fine), either Web or Windows application: randomly the application crashes and if you check your event log you’ll find messages like the following: Event Type: Error Event Source: .NET Runtime Date: 12-02-2009 10:58:36 User: N/A Computer: <computername> Description: .NET Runtime version 2.0.50727.3082 – Fatal Execution Engine Error (000006427F8A5DC8) (80131506) The stack of the faulting thread looks like this: 0:025> kpL1000 Child-SP RetAddr Call Site 00000000`0643e350 00000642`78acb013 mscorwks!COMCryptography::_DecryptData+0x329 00000000`0643e590 00000642`801f4b87 mscorlib_ni!System.Security.Cryptography.CryptoAPITransform.TransformFinalBlock(<HRESULT 0x80004001>)+0x123 00000000`0643e620 00000642`801f25c7 CryptoSample!MyCryptoClass.Decrypt(<HRESULT 0x80004001>)+0xf7 00000000`0643e960 00000642`bc8e449b System_Web_ni!System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute(<HRESULT 0x80004001>)+0x257 00000000`0643ea10 00000642`bc8f2215 System_Web_ni!System.Web.HttpApplication.ExecuteStep(<HRESULT 0x80004001>)+0xab 00000000`0643eab0 00000642`bc8e3553 System_Web_ni!System.Web.HttpApplication+ApplicationStepManager.ResumeSteps(<HRESULT 0x80004001>)+0x1a5 00000000`0643eb60 00000642`bc8e7874 System_Web_ni!System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(<HRESULT 0x80004001>)+0xd3 00000000`0643ebc0 00000642`bc8e745c System_Web_ni!System.Web.HttpRuntime.ProcessRequestInternal(<HRESULT 0x80004001>)+0x1c4 00000000`0643ec50 00000642`bc8e608c System_Web_ni!System.Web.HttpRuntime.ProcessRequestNoDemand(<HRESULT 0x80004001>)+0x7c 00000000`0643ec90 00000642`7f602322 System_Web_ni!System.Web.Hosting.ISAPIRuntime.ProcessRequest(<HRESULT 0x80004001>)+0x18c 00000000`0643edc0 00000642`7f503bb3 mscorwks!CallDescrWorker+0x82 00000000`0643ee20 00000642`7f5251f8 mscorwks!CallDescrWorkerWithHandler+0xd3 00000000`0643eec0 00000642`7f525563 mscorwks!ForwardCallToManagedMethod+0x160 00000000`0643ef60 00000642`7f544738 mscorwks!COMToCLRWorkerBody+0x35b 00000000`0643f1c0 00000642`7f50c8ae mscorwks!COMToCLRWorkerDebuggerWrapper+0x50 00000000`0643f230 00000642`7f60249e mscorwks!COMToCLRWorker+0x366 00000000`0643f520 00000642`fff58293 mscorwks!GenericComCallStub+0x5e 00000000`0643f5d0 00000642`fff58633 webengine!HttpCompletion::ProcessRequestInManagedCode+0x2a3 00000000`0643fa80 00000642`fff9abf4 webengine!HttpCompletion::ProcessCompletion+0x63 00000000`0643fac0 00000642`7f48dc77 webengine!CorThreadPoolWorkitemCallback+0x24 00000000`0643faf0 00000642`7f4a289a mscorwks!UnManagedPerAppDomainTPCount::DispatchWorkItem+0x157 00000000`0643fb90 00000642`7f41f0ac mscorwks!ThreadpoolMgr::WorkerThreadStart+0x1ba 00000000`0643fc30 00000000`77d6b6da mscorwks!Thread::intermediateThreadProc+0x78 00000000`0643ff80 00000000`00000000 kernel32!BaseThreadStart+0x3a 0:025> !clrstac OS Thread Id: 0x1258 (25) Child-SP RetAddr Call Site…
-
IIS logs around midnight
Recently I had an interesting discussion with a friend of mine about IIS logging: basically he configured his web server to create a new log every day and then wanted to use a third party tool to extract some statistics and graphics from the logs. Unfortunately the tool often has troubles and gets weird results because sometime at the end of the old log file (the one about the ending day) they have some records whose date and time is into the new day. Something like the following: #Software: Microsoft Internet Information Services 7.0 #Version: 1.0 #Date: 2009-03-06 23:59:53 #Fields: date time s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) sc-status sc-substatus sc-win32-status time-taken 2009-03-06 23:59:59 ::1 GET /MidnightTest/Never+doubt+thy+debugger.htm - 80 - ::1 Mozilla/4.0+(compatible;+MSIE+7.0;+Windows+NT+6.0;+WOW64;+Trident/4.0;+SLCC1;+.NET+CLR+2.0.50727;+InfoPath.2;+FDM;+.NET+CLR+3.5.21022;+.NET+CLR+1.1.4322;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30618;+OfficeLiveConnector.1.3;+OfficeLivePatch.0.0;+MS-RTC+EA+2;+MS-RTC+LM+8) 200 0 0 15 2009-03-06 23:59:59 ::1 GET /MidnightTest/Never+doubt+thy+debugger_files/global.js - 80 - ::1 Mozilla/4.0+(compatible;+MSIE+7.0;+Windows+NT+6.0;+WOW64;+Trident/4.0;+SLCC1;+.NET+CLR+2.0.50727;+InfoPath.2;+FDM;+.NET+CLR+3.5.21022;+.NET+CLR+1.1.4322;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30618;+OfficeLiveConnector.1.3;+OfficeLivePatch.0.0;+MS-RTC+EA+2;+MS-RTC+LM+8) 200 0 0 15 2009-03-06 23:59:59 ::1 GET /MidnightTest/Never+doubt+thy+debugger_files/light_sidebar_left_wide.css - 80 - ::1 Mozilla/4.0+(compatible;+MSIE+7.0;+Windows+NT+6.0;+WOW64;+Trident/4.0;+SLCC1;+.NET+CLR+2.0.50727;+InfoPath.2;+FDM;+.NET+CLR+3.5.21022;+.NET+CLR+1.1.4322;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30618;+OfficeLiveConnector.1.3;+OfficeLivePatch.0.0;+MS-RTC+EA+2;+MS-RTC+LM+8) 200 0 0 15 2009-03-06 23:59:59 ::1 GET /MidnightTest/Never+doubt+thy+debugger_files/customcss.css - 80 - ::1 Mozilla/4.0+(compatible;+MSIE+7.0;+Windows+NT+6.0;+WOW64;+Trident/4.0;+SLCC1;+.NET+CLR+2.0.50727;+InfoPath.2;+FDM;+.NET+CLR+3.5.21022;+.NET+CLR+1.1.4322;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30618;+OfficeLiveConnector.1.3;+OfficeLivePatch.0.0;+MS-RTC+EA+2;+MS-RTC+LM+8) 200 0 0 15 2009-03-06 23:59:59 ::1 GET /MidnightTest/Never+doubt+thy+debugger_files/vjr6phmypy.cache - 80 - ::1 Mozilla/4.0+(compatible;+MSIE+7.0;+Windows+NT+6.0;+WOW64;+Trident/4.0;+SLCC1;+.NET+CLR+2.0.50727;+InfoPath.2;+FDM;+.NET+CLR+3.5.21022;+.NET+CLR+1.1.4322;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30618;+OfficeLiveConnector.1.3;+OfficeLivePatch.0.0;+MS-RTC+EA+2;+MS-RTC+LM+8) 404 3 50 0 2009-03-06 23:59:59 ::1 GET /MidnightTest/Never+doubt+thy+debugger_files/msAnalytics.cache - 80 - ::1 Mozilla/4.0+(compatible;+MSIE+7.0;+Windows+NT+6.0;+WOW64;+Trident/4.0;+SLCC1;+.NET+CLR+2.0.50727;+InfoPath.2;+FDM;+.NET+CLR+3.5.21022;+.NET+CLR+1.1.4322;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30618;+OfficeLiveConnector.1.3;+OfficeLivePatch.0.0;+MS-RTC+EA+2;+MS-RTC+LM+8) 404 3 50 0 2009-03-06 23:59:59…