New Beta of Windows Performance Toolkit

With the release of the first Windows Anniversary SDK Beta also a new version of Windows Performance Toolkit was shipped. If you want to search for the changes here are the most significant ones. Not sure if the version number of the beta will change but it seems to target 10.0.14366.1000.

image

Stack Tags for Context Switch Events

Now you can assign tags for wait call stacks which is a big help if you want to have tags why your application is waiting for something.  Here is sample snippet of common sources of waits.

<Tag Name="Waits">
    <Tag Name="Thread Sleep">
         <Entrypoint Module="ntdll.dll" Method="NtDelayExecution*"/>
    </Tag>
    <Tag Name="IO Completion Port Wait">
         <Entrypoint Module="ntoskrnl.exe" Method="IoRemoveIoCompletion*"/>
    </Tag>
    <Tag Name="CLR Wait" Priority="-1">
         <Entrypoint Module="clr.dll" Method="Thread::DoAppropriateWait*"/>
    </Tag>
    <Tag Name=".NET Thread Join">
         <Entrypoint Module="clr.dll" Method="Thread::JoinEx*"/>
    </Tag>
    <Tag Name="Socket">
         <Tag Name="Socket Receive Wait">
               <Entrypoint Module="mswsock.dll" Method="WSPRecv*"/>
         </Tag>
         <Tag Name="Socket Send Wait">
               <Entrypoint Module="mswsock.dll" Method="WSPSend*"/>
         </Tag>
         <Tag Name="Socket Select Wait">
               <Entrypoint Module="ws2_32.dll" Method="select*"/>
         </Tag>
    </Tag>
    <Tag Name="Garbage Collector Wait">
         <Entrypoint Module="clr.dll" Method="WKS::GCHeap::WaitUntilGCComplete*"/>
    </Tag>
</Tag>

That feature is actually already part of the Windows 10 Update 1 WPA (10.0.10586.15, th2_release.151119-1817) but I have come just over that feature now. That makes hang analysis a whole lot easier. But a really new feature are Flame Graphs which Bruce Dawson wanted since a long time built into WPA. I have written some small tool to generate them also some time ago Visualize Your Callstacks Via Flame Graphs but it never got much traction.

image

If you want to see e.g. why your threads are blocking you get in the context switch view now a nice view what are the blocking reasons and which thread did unblock your threads most often. You can stack two Wait views over each other so you can drill down to the relevant time where something is hanging and you can get to conclusions much faster now.

image

Another nice feature is that if you select a region in the graph and hold down the Ctrl key you can select multiple regions at one time and highlight them which is useful if you frequently need to zoom in into different regions and you move between them. The current flame graphs cannot really flame call stacks because the resulting flames become so small you have no chance to select them. Zooming with Ctrl and the mouse wheel only zooms into the time region which is for a flame graph perhaps not what I want. I would like to have a zoom where I can make parts of the graph readable again.

Symbol loading has got significantly faster and it seems also to crash less often which is quite surprising for a beta.

My Presets Window for managing presets

Another new feature is the My Presets Window which is useful if you work with custom WPA profiles. From there you can select from different loaded profiles the graph in your current view and simply add it.

image

 

image

 

Reference Set Tracing

WPR now also supports Reference Set analysis along with a new graph in WPA. This basically traces every page access and release in the system which allows you to track exactly how your working set evolved over time and why.

image

Since page in/out operations happen very frequently this is a high volume provider. With xperf you can enable it with the keyword REFSET. The xperf documentation about it only tells you

REFSET         : Support footprint analysis

but until now no tool was publicly available to decode the events in a meaningful manner. I still do not understand how everything works together there but it looks powerful to deeply understand when something is paged in or out.

image

TCP/IP Graph

WPA has for a long time known nothing about the network. That is changing now a bit.

image

ACK Delays are nice but as far as I understand TCP the application is free to send the ACK until the server has got the data ready. If you see high ACK delay times you cannot point directly to the network but you still need to investigate the server if something was happening there as well. For network issues I still like Wireshark much more because it understands not only raw TCP  but also the higher protocols. For a network delay analysis TCP retransmit events are the most important ones. The next thing to look at are the packet round trip times (RTT) where Wireshark does an incredible good job at it. I have seen some ETW events in the kernel which have a SRTT (Sample RTT) field but I do not know how significant that actually is.

 

Load files from Zip/CAB

image

You no longer need to extract the etl files but WPA can open them directly which is great if you deal with compressed files a lot.

The Bad

  • The new WPT no longer works on Windows 7 so beware.
  • For WPR/UI I have mixed feelings because it is not really configurable and records too much. The recorded amount of data exceeds easily one GB on a not busy machine if I enable CPU Disk, File and Reference Set tracing. The beta version also records for the Disk profile Storeport traces which are only useful if you suspect bugs in your hard disk firmware or special hard disk drivers. If I enable context switch tracing with call stacks I usually do not need for every file/disk operation the call stacks since I will find it anyway in the context switch traces at that time. If VirtualAlloc tracing is enabled the stack traces for the free calls are recorded which are seldom necessary because double frees are most often not the issue. Memory leaks are much more common. For these the allocation call stacks are the only relevant ones.
  • The improvements to the ETW infrastructure with Windows 8.1 which support filtering of specific events or to record stack traces only for some specific events have not made it into WPR nor xperf. I really would like to see more feature parity between what the kernel supports and what xperf allows me to configure to reduce the sometimes very high ETW event rates down to something manageable.
  • Currently xperf can start only two kernel trace sessions (NT Kernel Logger and Circular Kernel Context Logger) but not a generic kernel tracing session where one can have up to 8 since Windows 8. Besides this I am not sure if setting the profiling frequency is even possible to set for a specific kernel session.

Conclusions

The new version has many improvements which can help a lot to get new insights in your system in ways that were not possible before. Flame Graphs look nice and I hope that the final version makes it possible to zoom in somehow.

The WPA viewer is really a great tool and has gotten a lot of added features which shows that more and more people are using it.

Advertisements

Show GDI Handles by Type in Windbg

What are GDI Handles? Every GDI (Graphics Device Interface) object has a handle which is associated to one specific process. If you create UI resources (not windows) like

  • Fonts
  • Bitmaps
  • Device Contexts (DC)
  • Pens
  • Regions

then you are using GDI resources. There is a hard cap on 10K GDI objects per process. If you have a memory leak in window related code then the chances are high that your process will not crash due to an out of memory condition but because a generic GDI or GDI+ error did occur. If this happens after a many hour stress test you will have a hard time to figure out what went wrong, if all you have got is a memory dump with an exception like this:

System.Runtime.InteropServices.ExternalException was unhandled by user code
Message="A generic error occurred in GDI+."
Source="System.Drawing"
ErrorCode=-2147467259
StackTrace:
   at System.Drawing.Image.Save(Stream stream, ImageCodecInfo encoder, EncoderParameters    encoderParams)
   at System.Drawing.Image.Save(Stream stream, ImageFormat format)

To make things more complex .NET tries hard to reuse existing objects and most often it avoids GDI and GDI+ entirely. You can create more than 10K Bitmaps in a Windows Forms or WPF application without problems. Not every object on your managed heap is backed by GDI handle based object! But some of them are. This can be confusing sometimes.

GDI handle leaks are not easy to diagnose since there are not many tools out there that are able to display more than the total count like Task Manager with the GDI-Object count column.

image

Process Explorer can display pretty much anything but if you search for GDI objects it will let you down. Process Hacker (an open source Process Explorer clone with more features) on the other hand can display them via the context menu

image

The best tool I have found so far is GDIView from NirSoft. But it seems at least on Windows 8.1 to display sometimes much less handles than Task Manager shows. Do not entirely trust the reported numbers. It displays in the All GDI column the same value as Task Manager which should be pretty reliable. If the other columns add up the to the total reported value then you should be fine. Interestingly there exists no Performance counter for GDI objects which is quite odd since it is still an essential resource although MS seems to try hard to put GDI out of service. 

 

image

 

The problem with all of the above tools is that they do not work with memory dumps. Windbg had an extension which is since about 10 years no longer part of the Windbg package which did only work until Windows 2000 and not even on Windows XP.

So what can you do? First we need a GDI Handle leak. Bitmap.GetHbitmap will create a GDI backed bitmap and return you the handle to it. The following code creates therefore a leak of 1000 bitmap GDI objects:

        private void Button_Click(object sender, RoutedEventArgs e)
        {
            Bitmap bmp = new Bitmap(100, 100);
            for (int i = 0; i < 1000; i++)
            {
                bmp.GetHbitmap();
            }
        }

Ok when I put that into my WPF application I get a nice GDI leak when I press the magic button.

image

Now we need to search the internet for helpful resource how to dump GDI objects. After some searching I pretty much always land on some security related kernel hacking sites which are an interesting read on its own. These guys really know their stuff and I guess they have also some older copy of the Windows source code somewhere around. I have found https://blog.coresecurity.com/2015/09/28/abusing-gdi-for-ring0-exploit-primitives/ which talks about a fascinating way to abuse Bitmaps for kernel exploits which still seem to work today. But what is more important he also talks about that the kernel manages GDI handles for each process in a specific kernel region which is read only mapped back to the process address space.

That is important to know since we have a chance to look at GDI kernel structures in user mode process dumps. There is hope to retrieve information about GDI handles also in 2016. The next good thing is that the definition of GDICell structure seems to be still valid on Windows 8 (and on my Windows 10 home installation).

typedef struct {
  PVOID64 pKernelAddress; // 0x00
  USHORT wProcessId;      // 0x08
  USHORT wCount;          // 0x0a
  USHORT wUpper;          // 0x0c
  USHORT wType;           // 0x0e
  PVOID64 pUserAddress;   // 0x10
} GDICell;                // sizeof = 0x18

The post also tells us where we need to search for the GDI Handle table. It is part of the Process Environment Block (PEB) which Windbg can dump since a long time. But !peb will not display the GDI handle table. Instead we need to dump the structure with the ntdll symbols directly.

.process will print the PEB pointer value which we can then feed into dt

0:014> .process
Implicit process is now 00000000`00923000
0:014> dt ntdll!_PEB GdiSharedHandleTable 00923000
   +0x0f8 GdiSharedHandleTable : 0x00000000`013e0000 Void

Now we know the start of the GDI handle table. How big is it? The !address command can tell us that:

0:014> !address 13e0000

Usage:                  Other
Base Address:           00000000`013e0000
End Address:            00000000`01561000
Region Size:            00000000`00181000 (   1.504 MB)
State:                  00001000          MEM_COMMIT
Protect:                00000002          PAGE_READONLY
Type:                   00040000          MEM_MAPPED
Allocation Base:        00000000`013e0000
Allocation Protect:     00000002          PAGE_READONLY
Additional info:        GDI Shared Handle Table


Content source: 1 (target), length: 1000

It seems we are not the first ones to do that since under Additional info the name of the memory region has a really descriptive name. That looks promising. With the | command we get the current process id in hex and we are ready for a first try to search the GDI table for GDICell structures which should contain our current PID as part of the GDI handle table.

0:014> |
.  0    id: 35b8    attach    name: D:\GdiLeaker\bin\Debug\GdiLeaker.exe
0:014> s -w 13e0000 1561000 35b8
00000000`013f02f8  35b8 0000 1c05 4005 0000 0000 0000 0000  .5.....@........
00000000`013f3580  35b8 0000 de05 4005 0000 0000 0000 0000  .5.....@........
00000000`013f7948  35b8 0000 8005 4005 0000 0000 0000 0000  .5.....@........
00000000`013f7fd8  35b8 0000 c80a 400a 3370 00d4 0000 0000  .5.....@p3......
00000000`013facf0  35b8 0000 5e05 4005 0000 0000 0000 0000  .5...^.@........
00000000`013fb9c8  35b8 0000 0a01 4401 0000 00c8 0000 0000  .5.....D........
00000000`013fdac8  35b8 0000 9305 4005 0000 0000 0000 0000  .5.....@........
00000000`013fe428  35b8 0000 4905 4005 0000 0000 0000 0000  .5...I.@........
....

The number of printed lines look good. Since the kernel structures have also a wType member which should describe the GDI handle type we dig deeper until we find http://stackoverflow.com/questions/13905661/how-to-get-list-of-gdi-handles which tells us that 05 is the Bitmap GDI handle type. Since 6 bytes after the pid the type should follow we can check on our printed memory and sure there is mostly a 5 at this memory location. The rest of the word seems to be used for other information.

Lets create a Windbg script out of that and automate the complete process. Now attach to our GDI leaker and dump the GDI handle table before and after we have leaked 1000 bitmaps.

Important: If you are running on a 64 bit OS you need to attach the 64 bit Windbg even if you debug a 32 bit application!

0:013> $$>a<"D:\GdiDump\DumpGdi.txt"
GDI Handle Table 00000000013e0000 0000000001561000
GDI Handle Count      14
    DeviceContexts: 4
    Regions:        2
    Bitmaps:        2
    Palettes:       0
    Fonts:          3
    Brushes:        3
    Pens:           0
    Uncategorized:  0
0:013> g
0:014> $$>a<"D:\GdiDump\DumpGdi.txt"
GDI Handle Table 00000000013e0000 0000000001561000
GDI Handle Count      1021
    DeviceContexts: 8
    Regions:        3
    Bitmaps:        1003
    Palettes:       0
    Fonts:          3
    Brushes:        4
    Pens:           0
    Uncategorized:  0

Bingo! That looks pretty good. I have tried my script on various processes and the results are promising. This works also with full memory dumps which is a long missing piece of important information. Often enough no screenshot with Task Manager and the GDI handle count was taken so this information is lost if the failed process was terminated in the meantime. In some processes ca. 10-20% of the handle information seems to be missing. Since GDIView shows pretty much the same numbers I hope that this script will not be too far off for your crashed processes. Give it a try or post some additions if you know more about the internals of GDI.

 

Here is the code of DumpGDI.txt

$$ Run as: $$>a<DumpGdi.txt
$$ Written by Alois Kraus 2016
$$ uses pseudo registers r0-5 and r8-r14

r @$t1=0
r @$t8=0
r @$t9=0
r @$t10=0
r @$t11=0
r @$t12=0
r @$t13=0
r @$t14=0
$$ Increment count is 1 byte until we find a matching field with the current pid
r @$t4=1

r @$t0=$peb
$$ Get address of GDI handle table into t5
.foreach /pS 3 /ps 1 ( @$GdiSharedHandleTable { dt ntdll!_PEB GdiSharedHandleTable @$t0 } ) { r @$t5 = @$GdiSharedHandleTable }

$$ On first call !address produces more output. Do a warmup
.foreach /pS 50 ( @$myStartAddress {!address  @$t5} ) {  }


$$ Get start address of file mapping into t2
.foreach /pS 4 /ps 40 ( @$myStartAddress {!address  @$t5} ) { r @$t2 = @$myStartAddress }
$$ Get end address of file mapping into t3
.foreach /pS 7 /ps 40 ( @$myEndAddress {!address  @$t5} ) { r @$t3 = @$myEndAddress }
.printf "GDI Handle Table %p %p", @$t2, @$t3

.for(; @$t2 < @$t3; r @$t2 = @$t2 + @$t4) 
{
  $$ since we walk bytewise through potentially invalid memory we need first to check if it points to valid memory
  .if($vvalid(@$t2,4) == 1 ) 
  {
     $$ Check if pid matches
     .if (wo(@$t2) == @$tpid ) 
     { 
        $$ increase handle count stored in $t1 and increase step size by 0x18 because we know the cell structure GDICell has a size of 0x18 bytes.
        r @$t1 = @$t1+1
        r @$t4 = 0x18
        $$ Access wType of GDICELL and increment per GDI handle type
        .if (by(@$t2+6) == 0x1 )  { r @$t8 =  @$t8+1  }
        .if (by(@$t2+6) == 0x4 )  { r @$t9 =  @$t9+1  }
        .if (by(@$t2+6) == 0x5 )  { r @$t10 = @$t10+1 }
        .if (by(@$t2+6) == 0x8 )  { r @$t11 = @$t11+1 }
        .if (by(@$t2+6) == 0xa )  { r @$t12 = @$t12+1 }
        .if (by(@$t2+6) == 0x10 ) { r @$t13 = @$t13+1 }
        .if (by(@$t2+6) == 0x30 ) { r @$t14 = @$t14+1 }
     } 
  } 
}

.printf "\nGDI Handle Count      %d", @$t1
.printf "\n\tDeviceContexts: %d", @$t8
.printf "\n\tRegions:        %d", @$t9
.printf "\n\tBitmaps:        %d", @$t10
.printf "\n\tPalettes:       %d", @$t11
.printf "\n\tFonts:          %d", @$t12
.printf "\n\tBrushes:        %d", @$t13
.printf "\n\tPens:           %d", @$t14
.printf "\n\tUncategorized:  %d\n", @$t1-(@$t14+@$t13+@$t12+@$t11+@$t10+@$t9+@$t8)

When you edit the script with Notepad++ try Perl as scripting language. The syntax highlighter will do pretty good job on it. Windbg scripts do not look nice but they work and make dump analysis a lot easier. If you want to use Windbg efficiently I highly recommend you read more about .foreach, .printf, and pseudo registers.

If you e.g. search for a memory leak in a managed process you usually do !DumpHeap -stat -live to see all still reachable objects. If you omit -live then you see also all temporary objects which are not yet GCed which can also be interesting if there is a large difference between these two. Now you have identified a type and you click on the blue link in Windbg which will then print all object instances of that type.

Lets try that with FactoryRecord instances where we get the list of object addresses if we click in Windbg on the blue link of the !DumpHeap -stat command.

Statistics:
      MT    Count    TotalSize Class Name
6db871a0      114         6384 System.Configuration.FactoryRecord

If we dump one object instance we see that there is an interesting name inside it which could help to diagnose the context in which it was allocated

0:014> !DumpObj /d 02c98ca8
Name:        System.Configuration.FactoryRecord
MethodTable: 6db871a0
EEClass:     6db532f8
Size:        56(0x38) bytes
File:        C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Configuration\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Configuration.dll
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
7257e918  4000249        4        System.String  0 instance 02c98c50 _configKey
7257e918  400024a        8        System.String  0 instance 02c984b0 _group
7257e918  400024b        c        System.String  0 instance 02c98ad4 _name
6db86f9c  400024c       2c ...SimpleBitVector32  1 instance 02c98cd4 _flags
7257e918  400024d       10        System.String  0 instance 02c98b08 _factoryTypeName
6dc0c698  400024e       20         System.Int32  1 instance      200 _allowDefinition
6dc0c6d0  400024f       24         System.Int32  1 instance      100 _allowExeDefinition
6db87168  4000250       30 ...errideModeSetting  1 instance 02c98cd8 _overrideModeDefault
7257e918  4000251       14        System.String  0 instance 02c86bd8 _filename
725807a0  4000252       28         System.Int32  1 instance      123 _lineNumber
7257ecb8  4000253       18        System.Object  0 instance 00000000 _factory
00000000  4000254       1c                       0 instance 00000000 _errors

Lets say we are after the group name. If we dump this object

0:014> !DumpObj /d 02c984b0
Name:        System.String
MethodTable: 7257e918
EEClass:     721bf344
Size:        50(0x32) bytes
File:        C:\WINDOWS\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      system.web/caching
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
725807a0  4000243        4         System.Int32  1 instance       18 m_stringLength
7257f35c  4000244        8          System.Char  1 instance       73 m_firstChar
7257e918  4000248       40        System.String  0   shared   static Empty

then we see that this FactoryRecord has something to do with system.web/caching. Now we want to dump the group names of all FactoryRecord instances to get an overview.

.foreach( @$my { !DumpHeap -short -mt 6db871a0  } ) { r @$t0 = @$my; .printf "\n%mu", poi(@$t0+8)+8 }
...
system.transactions
system.transactions

system.web
system.web
system.web
system.web
system.web
system.web
system.web
system.web
system.web
system.web

...

The basic  idea is to dump the object addresses of all FactoryRecord instances. Since in .NET the Method Table (MT) pointer is the synonym for a type we use the MT pointer as argument to !DumpHeap -mt 6db871a0  to print only FactoryRecord instances. The additional -short limits the output to only object addresses which makes it a perfect fit for .foreach. 

For some reason you need to assign the local variable from the foreach loop @$my to a pseudo register @$t0 to make calculations possible. Oh and do not forget the spaces between @$t0 = @$my. The @ before the variable $xx is not strictly necessary but it speeds up the debugger evaluation engine a bit.

To get the pointer to the _group string which is 8 bytes after the FactoryRecord pointer we read it via poi(@$t0+8). Now we have the pointer to the string object. I know that .NET strings are null terminated UTF-16 strings. We can use therefore .printf “\n%mu” to print the string contents. On x64 the offset to the char array of a .NET string is 0xc and for x86 it is 8 which I have used above. These little shortcuts can make a dump analysis dramatically faster.

Although I like Visual Studio a lot, for more advanced things you need to use the power of Windbg. Give it a try when you analyze your next dump.