Simple Solutions To Strange Problems!!

Basic Auth may take precedence over Win Auth on IE 6 for a website hosted on IIS 7

AshishSingh — Sat, 10 Apr 2010 14:03:00 GMT

Issue:
=====
For a website hosted on IIS 7, and having Basic and Windows Authentication both enabled we got the prompt for Basic Auth while browsing the site from IE 6. In other words IE 6 was not giving any precedence to Windows Auth over Basic Auth.

Resolution:
========
We took some fiddler traces and noticed that the Basic auth was returned as the first in the list of authentication headers sent by the IIS 7 server like below.

WWW-Authenticate: Basic realm="servername"

WWW-Authenticate: Negotiate

WWW-Authenticate: NTLM

Now it is important to note here that the issue happened just on IE 6. The behavior has been documented here http://blogs.msdn.com/ie/archive/2006/03/15/552246.aspx, where it says

"Lastly, we've made a change to IE7 to ensure that if the server offers multiple authentication methods, Basic is chosen only if no other authentication methods are provided. In previous releases of IE, IE chose the first authentication method offered by the server"

So as expected we did not get the prompt on IE 7 and IE 8, since they silently used Windows Auth. It was application's requirement to have both authentication modes selected due to the requirement of the website.

While troubleshooting the issue, we found that the ApplicationHost.config file had the two modules for Windows Auth and Basic Auth listed in incorrect order.

The order they were in was

                <add name="WindowsAuthenticationModule" lockItem="true" />
                <add name="BasicAuthenticationModule" lockItem="true" />

We reversed the order as follows (Yes, Basic first) to fix the issue.

                <add name="BasicAuthenticationModule" lockItem="true" />
                <add name="WindowsAuthenticationModule" lockItem="true" />

So it is processed as last in first out and sent to browser.

NTLM authentication may not work for websites based due to Network Security Policies

AshishSingh — Sun, 04 Apr 2010 08:19:00 GMT

Issue:

===============

We used to get three prompts resulting in 401.1 while our website hosted on IIS 6 was configured to use NTLM. The event logs showed following entries during the issue.

Event Type: Failure Audit

Event Source: Security

Event Category: Logon/Logoff

Event ID: 529

Date: 10/08/2009

Time: 16:30:27

User: NT AUTHORITY\SYSTEM

Computer: ********

Description:

Logon Failure:

Reason: Unknown user name or bad password

User Name: Administrator

Domain: ****

Logon Type: 3

Logon Process: NtLmSsp

Authentication Package: NTLM

Workstation Name: ******

Caller User Name: -

Caller Domain: -

Caller Logon ID: -

Caller Process ID: -

Transited Services: -

Source Network Address: ***********

Source Port: 1856

Resolution:

===============

We found that even the file shares were not working, so this was not just a website specific problem.

We took the network traces and found from the network traces that we were using NTLM v1 on the client as opposed to NTLM v2.

The v2 is more secure and is preferred. Probably they had set LMCompatibility to 0 as discussed in

http://support.microsoft.com/kb/239869

So we focussed our investigation towards the NTLM versions being used and the group policy settings for them.

We found that our security group policies had prohibited NTLNv1 due to which we had the issue.

On the client and the web server the local security policy was set to "Send NTLM response only".

On the domain controller the domain controller security policy was set to "Send NTLMv2 response only\refuse LM & NTLM". So there appeared to be few mismatches according to our observation and the GP settings.

We changed the domain controller security policy and the lcoal security policies on the web server and client machines, to ‘Send LM & NTLM – use NTLMv2 session security if negotiated’ and this fixed the issue.

Windows Authentication for accounts with large kerberos tickets may not work despite having MaxtokenSize in place

AshishSingh — Sat, 03 Apr 2010 12:41:00 GMT

Issue:

=========================

For users with large groups (100,120+), any webpage with integrated authentication enabled and hosted on IIS 6 did not come up and returns 401.1.

Resolution:

=========================

This issue happens because of the size of Kerberos tokens and the issues webserver has while dealing with those.

The following article http://support.microsoft.com/kb/327825 discusses a reg key MaxTokenSize to be increased with a maximum value of 65535.

Key: HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Lsa\Kerberos\Parameters
Entry: MaxTokenSize
Data type: REG_DWORD
Value: 65535

The default value for the above key is 12,000 on Win 2k3 systems but in this case we had found that the token size was never more than 7000 (figured with network traces), so it did not make sense to increase this on all the Windows Based systems in the forest.

So increasing the reg MaxTokenSize may not always help and something on the webserver needs to be tweaked to support this too.

We have this article http://support.microsoft.com/kb/820129 which discusses two reg keys MaxFieldLength and MaxRequestBytes. We increased the values of MaxFieldLength and MaxRequestBytes on the IIS server from the default of 16384 to 32768 (may vary according to ticket size) and this fixed the issue.

The full path of the registry keys is HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\HTTP\Parameters. The keys have to be added as DWORD's. Their description says

MaxFieldLength - Sets an upper limit for each header. See MaxRequestBytes. This limit translates to approximately 32k characters for a URL. Default Value – 16384, Range 64 - 65534 (64k - 2) bytes

MaxRequestBytes -Determines the upper limit for the total size of the Request line and the headers. Its default setting is 16KB. If this value is lower than MaxFieldLength, the MaxFieldLength value is adjusted.

Default Value – 16384, Range 256 - 16777216 (16MB) bytes

So, to summarize, we may need to tweak above settings for webserver as well if Kerberos authentication does not work for an account which is a part of large number of groups along with focussing at the MaxTokenSize key, since we need IIS too, to support large sized headers.

Too Frequent Application Pool recycling in IIS can lead to unexpected issues

AshishSingh — Fri, 02 Apr 2010 15:42:00 GMT

Issue:

=============================

We were getting following errors while browsing our asp.net web application in different websites.

1. "Sys.WebForms.PageRequestManagerServerErrorException: An unknown error occurred while processing the request on the server. The status code returned from the server was: 500"

2. An error has occurred in the application. Please contact administrator.

Object reference not set to an instance of an object.

3. Error: The request data is invalid. Please try creating/editing the request again.

4. An unexpected condition has occurred in a application. The information contained here should be made available to your site administrative staff.

Request details Url=http://URL/Page.aspx (method=POST)

5. Event ID; 2262, ISAPI 'c;\windows\microsoft.net\framework\v2.0.50727\aspnet_isapi.dll' reported itself as unhealthy for the following reason: 'Deadlock detected'.

Resolution:

=================================

We found that all the errors were because of one factor. Once again event logs helped and we found that the worker process was recycling very quickly. They looked similar to

"A worker process with process ID IDNumber serving application pool AppPoolName has requested a recycle because it reached its scheduled recycle time."

"A worker process with process ID IDNumber serving application pool AppPoolName has requested a recycle because it reached its private bytes memory limit."

The 500 errors that we got would typically request when the worker process is exiting and a request reaches it. We looked at the Application pool properties in IIS and found that the property “Recycle worker process in minutes” was set to 1 hr. We also found that the value of Maximum used memory (in MB) was set to 100 MB. Due to these two factors, the worker process was recycling very quickly and resulted in all the above errors intermittently.

We suggested to uncheck the settings and as expected, this action fixed the issue.

If we choose to recycle the application, one may choose a specific time by using the option “recycle worker processes at following times”. For the second setting (Maximum used Memory), it is generally good to have the option unchecked unless we have a serious memory leak problem.

IISADMIN service failed to verify anonymous/wam account

AshishSingh — Fri, 02 Apr 2010 15:27:00 GMT

Issue:

=============

The websites were not working on IIS 6 and we got the following errors in event logs everytime we restarted IIS

Event Type: Warning

Event Source: IISADMIN

Event Category: None

Event ID: 105

Date: 11/09/2009

Time: 09:17:55

User: N/A

Computer: ServerName

Description:

IISADMIN service failed to verify anonymous/wam account DomainName\IUSRNAME. Some IIS functions can fail for this reason.

Issue started after they reinstalled IIS. The webserver was also a Domain Controller.

Resolution:

==============

We found that the WAMUSERNAME was not specified with domain name like DomainName\IWAMUserName rather just IWAM_OZ.
We edited the wamuser account with domain account\username format and that too started throwing same error in event logs for IWAM account. To resolve the issue we edited the IUSR name and removed the domain name and kept it like a local user name.

This error has normally been seen when IIS has been hosted on Domain controllers. It is better to keep DC on separate server than the webserver. If we have a real domain account as IUSR identity, we do need to use the syntax Domain\AccountName.

A situation when performance of a website go down after enabling WebGarden

AshishSingh — Sat, 07 Mar 2009 14:58:00 GMT

Issue

====

An Asp website hangs intermittently and we saw the following errors in event logs

Event Type: Warning Event Source: W3SVC-WP Event Category: None Event ID: 2262 Date: 24/03/2010 Time: 14:37:58 User: N/A Computer: compurtername Description: ISAPI 'C:\WINDOWS\system32\inetsrv\asp.dll' reported itself as unhealthy for the following reason: 'ASP unhealthy because 98% of executing requests are hung and 100% of the request queue is full.'.

Issue started after we enabled web gardening on the website.

Resolution:

===============

We took some hang dumps of IIS and analyzed them using Windbg. Most of the threads were busy doing activities like below

0:136> kb 100
ChildEBP RetAddr Args to Child
2de2e984 7c826e09 77e649ff 2de2ea2c 40110080 ntdll!KiFastSystemCallRet
2de2e988 77e649ff 2de2ea2c 40110080 2de2e9c8 ntdll!ZwCreateFile+0xc
2de2ea24 77e41a8e 00000000 40000000 00000000 kernel32!CreateFileW+0x377
2de2ea48 0b6ee42b 2de2ea6c 40000000 00000000 kernel32!CreateFileA+0x30
WARNING: Stack unwind information not available. Following frames may be wrong.
2de2eaf4 77d05186 1332c040 066a9a6c 2de2eb58 AspUpload!DllUnregisterServer+0xcdfd
2de2eb14 77d14acf 1332c040 00000068 00000004 oleaut32!tPushValJmpTab+0x102
2de2eba4 0b6e1982 05ebd60c 1332c040 00000000 oleaut32!CTypeInfo2::Invoke+0x234
2de2ebcc 7347d36b 1332c040 00000017 734614f4 AspUpload!DllUnregisterServer+0x354
2de2ec20 73468ad1 01c0f918 1332c040 00000017 vbscript!CatchIDispatchInvoke+0x46
2de2ec60 73468a40 0a0c1ee0 1332c040 00000017 vbscript!IDispatchInvoke2+0xaf
2de2ec9c 734689f2 0a0c1ee0 1332c040 00000017 vbscript!IDispatchInvoke+0x59
2de2edb0 7346613b 0a0c1ee0 1332c040 00000017 vbscript!InvokeDispatch+0x13a
2de2edd4 73468b57 0a0c1ee0 1332c040 00000017 vbscript!InvokeByName+0x42
2de2f0b0 734633e0 2de2f434 00000001 0a0c1ee0 vbscript!CScriptRuntime::Run+0x2587
2de2f1a8 73463eb7 2de2f434 00000001 098f87e0 vbscript!CScriptEntryPoint::Call+0x5c
2de2f47c 734633e0 2de2f800 00000000 0a0c1ee0 vbscript!CScriptRuntime::Run+0x20d4
2de2f574 734665d7 2de2f800 00000000 098f8810 vbscript!CScriptEntryPoint::Call+0x5c
2de2f848 734633e0 00000000 00000000 0a0c1ee0 vbscript!CScriptRuntime::Run+0x1f08
2de2f940 734637d1 00000000 00000000 00000000 vbscript!CScriptEntryPoint::Call+0x5c
2de2f998 73463b9c 0edc47d0 00000000 00000000 vbscript!CSession::Execute+0xb4
2de2f9e8 73461849 00000000 00000000 709e19c0 vbscript!COleScript::ExecutePendingScripts+0x13e
2de2fa04 709e2bfa 02c02220 02c02220 02716e38 vbscript!COleScript::SetScriptState+0x150
2de2fa30 709e2bbc 00000000 709e19c0 0953f4e8 asp!CActiveScriptEngine::TryCall+0x19
2de2fa6c 709e2af2 00000000 6472474e 02a048b8 asp!CActiveScriptEngine::Call+0x31
2de2fa88 709e29f6 2de2fb0c 00000000 00000000 asp!CallScriptFunctionOfEngine+0x5b
2de2fadc 709e2921 02f02d58 00000000 2de2fb68 asp!ExecuteRequest+0x17e
2de2fb44 709e24e0 02f02d58 02a048b8 2de2fb68 asp!Execute+0x24c
2de2fb98 709e244a 00000000 00000000 07426770 asp!CHitObj::ViperAsyncCallback+0x3f0
2de2fbb4 4a77b5ea 02a94310 046be518 2de2fd74 asp!CViperAsyncRequest::OnCall+0x92
2de2fbd0 77720d30 07426770 000e2628 00000000 comsvcs!CSTAActivityWork::STAActivityWorkHelper+0x32
2de2fc1c 777217dc 00000000 000e2628 4a77b5b8 ole32!EnterForCallback+0xc4
2de2fd7c 776f03b4 2de2fc54 4a77b5b8 07426770 ole32!SwitchForCallback+0x1a3
2de2fda8 7769c194 000e2628 4a77b5b8 07426770 ole32!PerformCallback+0x54
2de2fe40 7772433a 046be518 4a77b5b8 07426770 ole32!CObjectContext::InternalContextCallback+0x159
2de2fe60 4a77b78c 046be518 4a77b5b8 07426770 ole32!CObjectContext::DoCallback+0x1c
2de2fecc 4a77bcf2 06e49950 06e49930 00132e64 comsvcs!CSTAActivityWork::DoWork+0x12d
2de2fee4 4a77c7de 07426770 00000001 06e49930 comsvcs!CSTAThread::DoWork+0x18
2de2ff04 4a77cabf 00000000 0f451ec0 097eba48 comsvcs!CSTAThread::ProcessQueueWork+0x37
2de2ff84 77bcb530 06e49930 00000000 00000000 comsvcs!CSTAThread::WorkerLoop+0x190
2de2ffb8 77e6482f 097eba48 00000000 00000000 msvcrt!_threadstartex+0x74
2de2ffec 00000000 77bcb4bc 097eba48 00000000 kernel32!BaseThreadStart+0x34

So the thread appears to be busy doing a CreateFile operation. Note that this may not necessarily be a normal create file operation we expect.

kernel32!CreateFileA is a generic function used for many activities.

However when we dump the argument to CreateFileA function

0:136> dc 2de2ea6c
2de2ea6c 35385c5c 2e32312e 372e3631 61645c35 \\11.12.13.14\da
2de2ea7c 415c6174 79532057 6d657473 6d495c73 ta\XYZ Share\Ma
2de2ea8c 73656761 7564415c 6f57746c 745c6b72 inFolder\Subfolder\
2de2ea9c 3031375c 5f343537 706a2e31 7c820067 imagename.jpg..|
2de2eaac 2de2eadc 77e622ec 77e622f6 00000000 ...-.".w.".w....
2de2eabc 113f7ebc 00000000 2de2eab8 00000001 .~?........-....
2de2eacc 2de2ec10 77e61a60 77e62300 ffffffff ...-`..w.#.w....
2de2eadc 77e622f6 77e622f6 0b6ee400 00000000 .".w.".w..n.....

Note : The path has been modified for the sake of data privacy.

From above we see that the major part of the contention is when copying image files to a network path

\\11.12.13.14\data\XYZ Share\MainFolder\Subfolder\imagename.jpg

All those requests are in ThirdPartyDll.dll creating image files on the share above. Some of them have been doing this for quite some time, so the reason for the contention that eventually leads to the health recycling is that it simply takes a long time to copy files over there, especially when many threads are copying files at the same time. Since this is a system wide resource (the network), the fact that web garden is turned on, only adds fuel to the fire by allowing even more concurrent requests that are all writing to the same share. In the other web garden instance there are once again lots of threads writing files to this same share so in total too many threads concurrently trying to write images to this share.

Then when we focussed on the the file share, we found it had followign kind of entries in event logs near the time the web server became unresponsive.

Event Type:　Warning
Event Source:　Srv
Event Category:　None
Event ID:　2025
Date:　　25/03/2010
Time:　　13:14:45
User:　　N/A
Computer:　FileServer-
Description:
The server has detected an attempted Denial-Of-Service attack from client \\ClientIpAddress, and has disconnected the connection.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.
Data:
0000: 00 00 00 00 02 00 48 00　　 ......H.
0008: 00 00 00 00 e9 07 00 80　　 ....é..€
0010: 00 00 00 00 22 00 00 c0　　 ...."..À
0018: 00 00 00 00 00 00 00 00　　 ........
0020: 00 00 00 00 00 00 00 00　　 ........

This appeared in perfect sync with the dump analysis. The issue seems to be happening due to large number of simultaneous connections to the content server. Now this issue has been discussed in http://support.microsoft.com/kb/898468. The workaround 1 mentions how we can increase the connections (if it is a genuine load) and can help with this issue. The key is MaxMpxCt at HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\lanmanserver\parameters which is set to a default value of 50.

We increased the value to 200 in this case and this fixed the issue.

So to summarize, by increasing the number of worker processes in an application pool, we increased teh number of such connections leading to a poor performance. The factors were therefore external but they got exposed after enabling web gardening. Enable WebGardening if we have ample of processor and hardware support. If you can go for multiple Application pools, prefer it over web gardening. But off course, in a situation like what we discussed, it may still cause issues.