ISA Server Stop Answering Requests and Firewall Service Hangs

The problem that this post is going to discuss was related to a random issue where certain times of the day the ISA Server was stopping answering requests and when the firewall administrator tried to restart the firewall service the service didn’t start. The only event that we have prior to the issue happens was the one below:

Event Type: Error

Event Source: Microsoft ISA Server Web Proxy

Event Category: None

Event ID: 14172

Date: 13/3/2009

Time: 18:37:43

User: N/A

Computer: ISASRV

Description:

The cache was not properly initialized. caching will be disabled (internal code 503.287.4.0.2167.887). Identify the specific reason for the failure from previous relevant event logs. Fix the problem, and then restart the Firewall service to enable caching.

Doing a quick assessment I could see that the Antivirus was scanning all folders, including ISA Folders (not good at all). As a troubleshooting step I disabled the AV but the issue persisted. Using ProcMon I could see that when ISA Storage process (ISAStg.exe) was trying to read a value in register the AV filter drive was still present in kernel mode and intercepting the request. Here it is the sequence:

ISASTG process:

34408 2:23:05.8643957 PM isastg.exe 3904 RegEnumValue HKLM\SOFTWARE\Microsoft\Fpc\Storage\Array-Root\Arrays\{0A8D8F99-6862-47B9-9388-12890728AF1A}\Servers\{B622A644-418A-40E1-988F-C1182B246652}\Proxy-Cache-Directories\Proxy-Cache-Directory1 SUCCESS Index: 3, Name: msFPCDirectoryName, Type: REG_SZ, Length: 34, Data: D:\urlcache\Dir1

The stack for this process shows the AV filter drive (klif.sys):

0 ntoskrnl.exe ntoskrnl.exe + 0x17859f 0x8097859f C:\WINDOWS\system32\ntoskrnl.exe

1 ntoskrnl.exe ntoskrnl.exe + 0x146c3c 0x80946c3c C:\WINDOWS\system32\ntoskrnl.exe

2 klif.sys klif.sys + 0xfa1c 0xf685fa1c    C:\WINDOWS\system32\drivers\klif.sys

3 ADVAPI32.dll ADVAPI32.dll + 0x12530 0x77f62530 C:\WINDOWS\system32\ADVAPI32.dll

4 isastg.exe isastg.exe + 0x8352 0x408352 D:\Program Files\Microsoft ISA Server\isastg.exe

5 isastg.exe isastg.exe + 0x9054 0x409054 D:\Program Files\Microsoft ISA Server\isastg.exe

6 RPCRT4.dll RPCRT4.dll + 0x30193 0x77c80193 C:\WINDOWS\system32\RPCRT4.dll

7 RPCRT4.dll RPCRT4.dll + 0x933e1 0x77ce33e1 C:\WINDOWS\system32\RPCRT4.dll

8 RPCRT4.dll RPCRT4.dll + 0x935c4 0x77ce35c4 C:\WINDOWS\system32\RPCRT4.dll

9 RPCRT4.dll RPCRT4.dll + 0x2ff7a 0x77c7ff7a C:\WINDOWS\system32\RPCRT4.dll

10 RPCRT4.dll RPCRT4.dll + 0x3042d 0x77c8042d C:\WINDOWS\system32\RPCRT4.dll

11 RPCRT4.dll RPCRT4.dll + 0x30353 0x77c80353 C:\WINDOWS\system32\RPCRT4.dll

12 RPCRT4.dll RPCRT4.dll + 0x311dc 0x77c811dc C:\WINDOWS\system32\RPCRT4.dll

13 RPCRT4.dll RPCRT4.dll + 0x312f0 0x77c812f0 C:\WINDOWS\system32\RPCRT4.dll

14 RPCRT4.dll RPCRT4.dll + 0x38678 0x77c88678 C:\WINDOWS\system32\RPCRT4.dll

15 RPCRT4.dll RPCRT4.dll + 0x38792 0x77c88792 C:\WINDOWS\system32\RPCRT4.dll

16 RPCRT4.dll RPCRT4.dll + 0x3872d 0x77c8872d C:\WINDOWS\system32\RPCRT4.dll

17 RPCRT4.dll RPCRT4.dll + 0x2b110 0x77c7b110 C:\WINDOWS\system32\RPCRT4.dll

18 kernel32.dll kernel32.dll + 0x24829 0x77e64829 C:\WINDOWS\system32\kernel32.dll

Later on we fail to create the file:

34838 2:23:05.9429702 PM mspadmin.exe 612 CreateFile D:\urlcache SUCCESS Desired Access: Read Attributes, Read Control, Write DAC, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, Impersonating: S-1-5-21-2611182321-852623426-2620623114-500, OpenResult: Opened

34839 2:23:05.9430612 PM mspadmin.exe 612 QueryBasicInformationFile D:\urlcache SUCCESS CreationTime: 2/13/2009 1:51:15 PM, LastAccessTime: 2/13/2009 2:23:04 PM, LastWriteTime: 2/13/2009 1:51:15 PM, ChangeTime: 2/13/2009 1:51:15 PM, FileAttributes: D

34840 2:23:05.9431081 PM mspadmin.exe 612 QuerySecurityFile D:\urlcache BUFFER OVERFLOW Information: Owner, Group, DACL, 0x80000000

We uninstalled the AV and the issue didn’t happen anymore. Since his environment had a requirement to have AV installed on ever single Windows machine we implemented the correct folder exclusion following the article “Considerations when using antivirus software on ISA Server” and the environment got stabilized.

Interesting side of this story is that this article was published exactly one year ago, one year later we still have firewall administrators not following such recommendation and therefore having unexpected downtimes.