High memory usage by registry (CM) on Windows 2008 R2 (serving ADFS2, + website)
-
Friday, June 29, 2012 9:10 PM
I have a windows 2008 r2 sp1 server that is experiencing memory issues. The server is currently runing an instance of ADFS 2 and a website (asp.net).
The first thing I noticed was that under TaskMgr, Kernel Memory (MB) paged was at 5604
Using poolmon, I was able to determine that the bulk of that memory was being used by CM - Configuration Manager (the registry)
Tag Type Allocs Frees Diff Bytes Per Alloc
CM Paged 98890205 ( 2) 90170894 ( 2) 8719311 4743296576 ( 0) 5434,743,296,576 bytes!
I'm not really sure how to further debug this issue however - how can I tell why the registry has all this memory, and how to get it to release it?
EDIT 1:
The physical registry files themselves seem of normal size.
Using the powershell script @ http://jdhitsolutions.com/blog/2011/05/get-registry-size-and-age/confirms what I saw looking at the physical registry files, that the registry itself is not overly huge?
Computername : (removed) Status : OK CurrentSize : 67 MaximumSize : 2048 FreeSize : 1981 PercentFree : 96.728515625 Created : 4/1/2011 11:38:02 AM Age : 454.23:41:28.2540682- Edited by Becke Friday, June 29, 2012 9:13 PM
All Replies
-
Saturday, June 30, 2012 10:55 AM
Would you dig deeper with Process Explorer and let us see your findings? Here is reference to Process Explorer
http://technet.microsoft.com/en-us/sysinternals/bb896653.aspx
Regards
- Proposed As Answer by Arthur_LiMicrosoft Contingent Staff, Moderator Monday, July 02, 2012 9:30 AM
- Unproposed As Answer by Becke Monday, July 02, 2012 5:46 PM
-
Monday, July 02, 2012 9:30 AMModerator
Hi,
I would like to confirm what is the current situation? If there is anything that I can do for you, please do not hesitate to let me know, and I will be happy to help.
Arthur Li
If you are TechNet Subscription user and have any feedback on our support quality, please send your feedback here.
Arthur Li
TechNet Community Support
-
Monday, July 02, 2012 6:37 PM
I'm somewhat familiar with process explorer, but nothing that I'm seeing is really jumping out at me.
We additionally have a test server that is not experiencing this memory issue, and flipping back and forth between the 2 while looking at process explorer and handles is not making anything jump out for me. I will continue to dig. I thought it might be runaway registry handles or something like that, but I've not really noticed any large differences between the 2 servers other than the fact that one of them has a chunk of memory being held onto by the registry somehow.
- Edited by Becke Monday, July 02, 2012 6:38 PM
-
Monday, July 02, 2012 6:39 PM
1. There have been issues with .NET update solved by removing and reinstalling it.
2. If you want to solve possible memory leaks, then you could hardly do it without diagnostic tools.
Regards
Milos
-
Monday, July 02, 2012 7:32 PM
I'm not aware of any .NET issues on the server.
Are you saying that there has been .NET updates that have lead to high paged pool memory usage by Configuration Manager?
-
Monday, July 02, 2012 8:51 PM
Would it be possible for you to run an perhaps post the output from the following command using LiveKD?
!reg openhandles
A Link to LiveKD and instructions:
http://technet.microsoft.com/en-us/sysinternals/bb897415.aspx
Doug Kentner
-
Monday, July 02, 2012 10:40 PM
The output is quite large and I'm going through and comparing it to our functional test system to see which sections have any great differences in handle counts etc, but there is one set of values on the server that is showing symptoms that looks very odd:
===========================================================================================
Hive: \Registry\User\S-(removed sid)_Classes
===========================================================================================
Couldn't get HashEntryAddr from fffff8a00b6e2ff0
Couldn't get HashEntryAddr from fffff8a00b6e3008
Couldn't get HashEntryAddr from fffff8a00b6e3020
Couldn't get HashEntryAddr from fffff8a00b6e3038
Couldn't get HashEntryAddr from fffff8a00b6e3050
Couldn't get HashEntryAddr from fffff8a00b6e3068
Couldn't get HashEntryAddr from fffff8a00b6e3080....This goes on for a total of 341 entries of Couldn't get HashEntryAddr, which based on some quick googling, is not a message seen that often...
- Edited by Becke Monday, July 02, 2012 10:40 PM
-
Monday, July 02, 2012 10:49 PM
Is this server being used for Remote Desktop Services by any chance?
Also, a few additional questions
1. Does the Paged pool grow to that size right after startup?
2. How many SIDs appear in Regedit under HKEY_Users
3. Are there any ntuser.dat files in the users folder that are excessively large?
Doug Kentner
- Edited by dkentner Monday, July 02, 2012 10:57 PM
-
Tuesday, July 03, 2012 12:06 AM
No - it is not used for Remote Desktop Services
1. Don't know yet. This server is allowed very little downtime, I'm trying to schedule a restart in the next outage window but that will be a few days. I plan on tracking a number of stats when I do.
2. 11 users
The sid associated with the "Couldn't get HashEntryAddr" lines above belongs to a local service account running a ssh service.
On the test server the same service also running under a local service account, but does not have high memory usage nor error messages in kd. I'm not sure how to tell if these weird entries (Couldn't get HashEntryAddr) are associated with the high memory usage or just something else that's flaking out.
3 size of the entire c:\users folder is 350mb, so nope. looks like they're all about 512kb~- Edited by Becke Tuesday, July 03, 2012 12:09 AM
-
Tuesday, July 03, 2012 2:50 PM
Thanks for the answers. can we try the following liveKD command to see if we can determine the size of the hives in the pool?
!reg dumppool
we'll look for abnormally large values in the stable and volatile length properties for each hive to hopefully get a view of which Hive is consuming so much of the pool
Let's also run
!reg hivelist
and post the output here if we can
Doug Kentner
- Edited by dkentner Tuesday, July 03, 2012 2:55 PM
-
Wednesday, July 04, 2012 12:03 AM
Confirm high paged pool memory by registry using kd instead of poolmon
0: kd> !poolused 0 CM Pool Used: NonPaged Paged Tag Allocs Used Allocs Used CM 11 1408 8719495 4743396672 Configuration Manager (registry) , Binary: nt!cm TOTAL 11 1408 8719495 4743396672Look at open handles
0: kd> !reg openhandles
reviewed counts.
entry with highest handle count:146 handles to KCB = fffff8a00bc7e008 : \REGISTRY\USER\(removed sid)
hive with highest total handle count:Hive: \REGISTRY\MACHINE\SOFTWARE (0x458 handles found)
seems pretty low/normal compared to other servers... ?
hivelist
dumppool0: kd> !hivelist
-------------------------------------------------------------------------------------------------------------
| HiveAddr |Stable Length|Stable Map|Volatile Length|Volatile Map|MappedViews|PinnedViews|U(Cnt)| BaseBlock | FileName
-------------------------------------------------------------------------------------------------------------
| fffff8a00000d010 | 1000 | fffff8a00000d0c8 | 1000 | fffff8a00000d340 | 0 | 0 | 0| fffff8a00000f000 | <NONAME>
| fffff8a000025010 | bed000 | fffff8a00002b000 | 3d000 | fffff8a000025340 | 0 | 0 | 0| fffff8a000026000 | SYSTEM
| fffff8a000053010 | 24000 | fffff8a0000530c8 | c000 | fffff8a000053340 | 0 | 0 | 0| fffff8a000063000 | <UNKNOWN>
| fffff8a0026d4410 | 1a5000 | fffff8a0026d44c8 | 1000 | fffff8a0026d4740 | 0 | 0 | 0| fffff8a002687000 | \Microsoft\Windows\UsrClass.dat
| fffff8a0027b0410 | 78000 | fffff8a0027b04c8 | 4000 | fffff8a0027b0740 | 0 | 0 | 0| fffff8a15c985000 | C:\Users\(removed)\ntuser.dat
| fffff8a002e06410 | 1f000 | fffff8a002e064c8 | 1000 | fffff8a002e06740 | 0 | 0 | 0| fffff8a00467c000 | ?\C:\Users\(removed)\ntuser.dat
| fffff8a003487410 | 1000 | fffff8a0034874c8 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a004af9000 | \Microsoft\Windows\UsrClass.dat
| fffff8a004df4410 | 2dca000 | fffff8a0054da000 | 7000 | fffff8a004df4740 | 0 | 0 | 0| fffff8a004cab000 | emRoot\System32\Config\SOFTWARE
| fffff8a00526d410 | a000 | fffff8a00526d4c8 | 1000 | fffff8a00526d740 | 0 | 0 | 0| fffff8a004d86000 | emRoot\System32\Config\SECURITY
| fffff8a0052a6010 | 7000 | fffff8a0052a60c8 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a005295000 | \SystemRoot\System32\Config\SAM
| fffff8a005302410 | 28000 | fffff8a0053024c8 | 1000 | fffff8a005302740 | 0 | 0 | 0| fffff8a0086f9000 | temRoot\System32\Config\DEFAULT
| fffff8a005611010 | 6000 | fffff8a0056110c8 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a00560f000 | <UNKNOWN>
| fffff8a005bdf410 | 20000 | fffff8a005bdf4c8 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a005b82000 | files\NetworkService\NTUSER.DAT
| fffff8a005c7d010 | 1f000 | fffff8a005c7d0c8 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a005c94000 | <UNKNOWN>
| fffff8a00bb2d410 | 501000 | fffff8a00bad4000 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a00baba000 | Volume Information\Syscache.hve
| fffff8a00c7ab010 | 1000 | fffff8a00c7ab0c8 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a00c79d000 | <UNKNOWN>
| fffff8a00c7d3010 | 1f000 | fffff8a00c7d30c8 | 1000 | fffff8a00c7d3340 | 0 | 0 | 0| fffff8a00c79b000 | \??\C:\Users\TEMP\ntuser.dat
| fffff8a00cdf3010 | 1000 | fffff8a00cdf30c8 | 0 | 0000000000000000 | 0 | 0 | 0| fffff8a00bcea000 | <UNKNOWN>
| fffff8a00cdf4010 | 20000 | fffff8a00cdf40c8 | 1000 | fffff8a00cdf4340 | 0 | 0 | 0| fffff8a00cdf8000 | \??\C:\Users\(removed)\ntuser.dat-------------------------------------------------------------------------------------------------------------0: kd> !reg dumppool
*** ERROR: Module load completed but symbols could not be loaded for LiveKdD.SYS
dumping hive at fffff8a00000d010 (NONAME)
Stable Length = 1000
1/1 pages present
Volatile Length = 1000
1/1 pages present
dumping hive at fffff8a000025010 (SYSTEM)
Stable Length = bed000
3053/3053 pages present
Volatile Length = 3e000
62/62 pages present
dumping hive at fffff8a000053010 (UNKNOWN)
Stable Length = 24000
32/36 pages present
Volatile Length = c000
12/12 pages present
dumping hive at fffff8a0026d4410 (\Microsoft\Windows\UsrClass.dat)
Stable Length = 1a5000
421/421 pages present
Volatile Length = 1000
1/1 pages present
dumping hive at fffff8a0027b0410 (C:\Users\(removed)\ntuser.dat)
Stable Length = 78000
120/120 pages present
Volatile Length = 4000
4/4 pages present
dumping hive at fffff8a002e06410 (?\C:\Users\(removed)\ntuser.dat)
Stable Length = 1f000
31/31 pages present
Volatile Length = 1000
1/1 pages present
dumping hive at fffff8a003487410 (\Microsoft\Windows\UsrClass.dat)
Stable Length = 1000
1/1 pages present
Volatile Length = 0
dumping hive at fffff8a004df4410 (emRoot\System32\Config\SOFTWARE)
Stable Length = 2dca000
11722/11722 pages present
Volatile Length = 7000
7/7 pages present
dumping hive at fffff8a00526d410 (emRoot\System32\Config\SECURITY)
Stable Length = a000
10/10 pages present
Volatile Length = 1000
1/1 pages present
dumping hive at fffff8a0052a6010 (\SystemRoot\System32\Config\SAM)
Stable Length = 7000
7/7 pages present
Volatile Length = 0
dumping hive at fffff8a005302410 (temRoot\System32\Config\DEFAULT)
Stable Length = 28000
40/40 pages present
Volatile Length = 1000
1/1 pages present
dumping hive at fffff8a005611010 (UNKNOWN)
Stable Length = 6000
6/6 pages present
Volatile Length = 0
dumping hive at fffff8a005bdf410 (files\NetworkService\NTUSER.DAT)
Stable Length = 20000
32/32 pages present
Volatile Length = 0
dumping hive at fffff8a005c7d010 (UNKNOWN)
Stable Length = 1f000
31/31 pages present
Volatile Length = 0
dumping hive at fffff8a00bb2d410 (Volume Information\Syscache.hve)
Stable Length = 501000
1109/1281 pages present
Volatile Length = 0
dumping hive at fffff8a00c7ab010 (UNKNOWN)
Stable Length = 1000
1/1 pages present
Volatile Length = 0
dumping hive at fffff8a00c7d3010 (\??\C:\Users\TEMP\ntuser.dat)
Stable Length = 1f000
31/31 pages present
Volatile Length = 1000
1/1 pages present
dumping hive at fffff8a00cdf3010 (UNKNOWN)
Stable Length = 1000
1/1 pages present
Volatile Length = 0
dumping hive at fffff8a00cdf4010 (\??\C:\Users\(removed)\ntuser.dat)
Stable Length = 20000
32/32 pages present
Volatile Length = 1000
1/1 pages present
Total pages present = 16773 / 16949
0: kd>
EDIT - I should also note that today the "Couldn't get HashEntryAddr from" were no present in the openhandles results - not sure if that was just some temporary issue or what.- Edited by Becke Wednesday, July 04, 2012 12:17 AM
-
Wednesday, July 04, 2012 5:27 AM
Well that's really odd. I was hoping we'd see a hive with a large volatile size or something that would account for the extra allocations, but as far as the registry hives go it looks normal, but those 8.7M allocations to the paged pool is insane... I suppose we could peek at some of the allocations it's made and see if there's anything in there that happens to include anything unusual but there's an awful lot of memory there and at least some of it is valid registry data.
I'm trying to find what else would allocate with the CM tag other than the Hives but haven't found anything yet. In the mean time if you wanted to look at some of the allocations here's a sample of what I was looking at on my 2008R2 VM in kd:
as a side note, how does memory utilization for the remote registry service look. and are we doing anything special with this box when it comes to performance counters or collection?
1: kd> !poolfind CM 1
GetPointerFromAddress: unable to read from 0000000000000000Scanning large pool allocation table for Tag: CM (fffffa800595c000 : fffffa8005a1c000)
*fffff8a000bc8000 :free large page allocation, Tag was CM , size was 0x1f000 bytes
*fffff8a000afc3b0 size: 220 previous size: 10 (Allocated) CM
*fffff8a0010c97e0 size: 220 previous size: 4d0 (Allocated) CM
*fffff8a001127000 :free large page allocation, Tag was CM , size was 0xbc80 bytesSearching Paged pool (fffff8a000000000 : fffff8bfffffffff) for Tag: CM
*fffff8a00000b150 size: 10 previous size: a0 (Free) CM
*fffff8a00000cbe0 size: 50 previous size: 180 (Allocated) CM
*fffff8a00000cee0 size: 40 previous size: 10 (Allocated) CM
*fffff8a000023db0 size: 10 previous size: 180 (Free) CM
*fffff8a000040d40 size: 220 previous size: 180 (Allocated) CM
*fffff8a000067190 size: 50 previous size: 10 (Allocated) CM
*fffff8a0000671e0 size: 220 previous size: 50 (Allocated) CM
*fffff8a0000aeb50 size: 50 previous size: 50 (Allocated) CM
*fffff8a0000aeba0 size: 220 previous size: 50 (Allocated) CM
*fffff8a0003fdfa0 size: 60 previous size: 20 (Allocated) CM
*fffff8a000464000 size: 220 previous size: 0 (Allocated) CM
*fffff8a000465f60 size: 10 previous size: 110 (Free) CM
*fffff8a000466000 size: 70 previous size: 0 (Allocated) CM
*fffff8a00073f950 size: 50 previous size: 30 (Allocated) CM
*fffff8a000a34630 size: 10 previous size: 40 (Free) CM
*fffff8a000ab4e40 size: 50 previous size: 30 (Allocated) CM
*fffff8a000ab6090 size: 40 previous size: 90 (Allocated) CM
*fffff8a000aca000 size: 220 previous size: 0 (Allocated) CM
*fffff8a000ad4f90 size: 10 previous size: 220 (Free) CM
*fffff8a000af96c0 size: 10 previous size: 70 (Free) CM
*fffff8a000b53210 size: 60 previous size: 70 (Allocated) CM
*fffff8a000b6a000 size: 220 previous size: 0 (Allocated) CM
*fffff8a000bb83e0 size: 60 previous size: 60 (Allocated) CM
*fffff8a000bc8000 size: 220 previous size: 0 (Allocated) CM...terminating - searched pool to fffff8a000d33be0
1: kd> !verifier 0x80 fffff8a00000b150
Verifier pool tracing information is not available.
Either Driver Verifier is not enabled, or Verifier failed to allocate memory for the pool log.
1: kd> db fffff8a00000b150
fffff8a0`0000b150 0a 01 01 00 43 4d 20 20-42 e1 e1 8d 25 74 44 04 ....CM B...%tD.
fffff8a0`0000b160 01 01 05 03 43 4d 50 65-d0 62 05 05 80 fa ff ff ....CMPe.b......
fffff8a0`0000b170 00 00 00 00 00 00 00 00-c8 bc 00 00 a0 f8 ff ff ................
fffff8a0`0000b180 10 46 02 00 a0 f8 ff ff-2e 00 30 00 00 00 00 00 .F........0.....
fffff8a0`0000b190 f2 cb 00 00 a0 f8 ff ff-17 46 8f ef ff ff ff ff .........F......
fffff8a0`0000b1a0 a8 24 02 00 a0 f8 ff ff-0c 00 00 00 6e 00 00 00 .$..........n...
fffff8a0`0000b1b0 05 01 0a 03 50 45 41 55-a1 94 ef d3 41 e6 c6 24 ....PEAU....A..$
fffff8a0`0000b1c0 c0 b0 00 00 a0 f8 ff ff-c0 b2 00 00 a0 f8 ff ff ................
1: kd> db fffff8a00000cbe0
fffff8a0`0000cbe0 18 01 05 03 43 4d 20 20-02 00 00 00 00 00 14 00 ....CM ........
fffff8a0`0000cbf0 5c 00 52 00 45 00 47 00-49 00 53 00 54 00 52 00 \.R.E.G.I.S.T.R.
fffff8a0`0000cc00 59 00 5c 00 4d 00 41 00-43 00 48 00 49 00 4e 00 Y.\.M.A.C.H.I.N.
fffff8a0`0000cc10 45 00 5c 00 53 00 59 00-53 00 54 00 45 00 4d 00 E.\.S.Y.S.T.E.M.
fffff8a0`0000cc20 00 00 3c 00 02 00 00 00-00 00 14 00 ff ff 1f 00 ..<.............
fffff8a0`0000cc30 05 01 04 03 43 4d 4e e2-12 00 00 00 00 00 18 00 ....CMN.........
fffff8a0`0000cc40 01 00 02 00 00 00 00 00-e7 97 fe 6e 00 00 00 00 ...........n....
fffff8a0`0000cc50 00 00 00 00 00 00 00 00-07 00 43 55 52 52 45 4e ..........CURREN
1: kd> db fffff8a00000cee0
Doug Kentner
- Edited by dkentner Wednesday, July 04, 2012 5:40 AM
-
Thursday, July 05, 2012 4:26 PM
Becke,
I am troubleshooting this same issue in one of our two Windows 2008 R2 / ADFS 2 environments. Both of my environments are virtual on VMware ESXi 4.1. One environment displays this behavior while I remain unable to recreate the same behavior in a seemingly identical testing environment. As both of my environments are virtual, I was looking for a correlation as to whether you environment is Physical or Virtual.
Thanks
-
Thursday, July 05, 2012 5:35 PMIt is also vmware 4.1 hosts. we are trying setting reserved memory = allocated memory to see if that helps (apparently this is sometimes an issue, although it looks like that normally shows up as driver locks)
-
Thursday, July 05, 2012 7:39 PM
In my environment that has the issue, we have tried setting the reserve memory = allocated memory and did not see a change in behavior. As this was a ESX 3.5 environment originally, I am upgrading to HW v7 tonight. The environment that is working correctly is already HW v7. Yours would not be HW v4 by chance would it?
-
Thursday, July 05, 2012 8:04 PMI verified all of our servers are on v7
-
Friday, July 06, 2012 4:44 PM
Sam,
In your environment that does experience the issue does the consumption happen all at once at startup? or does it grow gradually?
Doug Kentner
-
Friday, July 06, 2012 5:46 PMMy changes went last night and right now my problem servers are looking good or at least better than they have in a while. I will update again on Monday after they have had time to run for a few days.
Current settings:
- ESXi 4.1
- Windows 2008 R2 SP1
- VM Hardware v7
- Memory Reservation = Memory Allocation
-
Tuesday, July 10, 2012 1:49 PMIt happens over time. At startup we climb to ~ 30% memory (6 GB allocated / reserved). Then over the next few days it slowly climbs till we reboots (about 4 days) at ~ 80%. Adding memory reservaction = allocated and upgrading to HW v7 had no impact.
-
Tuesday, July 10, 2012 1:55 PM
Memory Reservation = Allocated and HW v7 upgrade did not impact this issue. Though I see that ADFS seems to be creating user profiles for each authenticated user. The environment exhibiting this issues has about 10x the number of profiles (16K) as in my "working" environment. I cannot help but wonder if it is related?
-
Tuesday, July 10, 2012 2:33 PMThat's a good observation. I Assume the profiles aren't staying loaded or visible in regedit, but to your point there could be some type of leak occurring when it creates (presumably loads and unloads) the profile. There may be some ADFS documentation we could find to go through the details of that process a little closer.
Doug Kentner
-
Wednesday, July 11, 2012 7:12 PM
here is a good MS KB that describes the Attribute Store and how the process "should" work. But leaves me looking at the custom code our developers wrote. However, it provides some insight on to the authentication process
AD FS 2.0 Attribute Store Overview
.png)
