Way to troubleshoot memory leak using performance monitor and UMDH

  • Article

Please refer to support.microsoft.com/kb/268343 to know every detail about using UMDH and analyzing UMDH logs.

The article below is a basic example to show how to analyze memory leak using performance monitor and UMDH.

Steps to use UMDH are:

  1. Install the UMDH utility. (UMDH utility is included with the Debugging Tools for Windows.)
  2. Set the system PATH environment variable to include the folder where you installed UMDH.
  3. Set _NT_SYMBOL_PATH environment variable. For Example: Set _NT_SYMBOL_PATH = symsrv*symsrv.dll*C:\localsymbols*msdl.microsoft.com/download/symbols
  4. Enable gflags. Example: gflags -i YourApplication.exe +ust
  5. Run UMDH command.  Example: UMDH –p:<PID> -f: YourLog.log

 

Ideally performance monitor logs should be gathered and should include the private bytes. Ideally it is good to collect the following counters:

  1. Private bytes
  2. Virtual Bytes
  3. Working Set – Private

 

Here is a typical example of analyzing performance monitor and UMDH logs.

Analyzing performance monitor logs

Figure 1: The time range which is 5 hours and 5 minutes for which the performance monitor and UMDH logs were collected.

 

Figure 2: Black line highlighted above shows the working set private bytes for the process. It is not a step function of time. At 11:16:28 AM it gets to a stable state after which we cannot see any steep rise either in the private bytes or in the working set private bytes.

 

Figure 3: Area view of the working set private bytes and private bytes for the process – Not a step function.

 

Take another set of performance logs. The analysis is shown below:

Figure 4: Private bytes and working set private for the process – showing a horizontal line without any change.

 

Figure 5: Area view for working set private bytes and private bytes for the process. 

 

UMDH Analysis

Consider two logs Log1.log and Log2.log captured at different intervals of time. A way to compute the difference is shown below: 

UMDH –d Log1.log Log2.log > CMP12.txt

The -d command line option tells UMDH to display in decimal instead of hexadecimal. The output of the command compares the differences of the allocations between the two logs and provides information that is similar to the following:

+ 5320 ( f110 - 9df0) 3a allocs BackTrace00053 Total increase == 5320

The "5320" is the difference in the number of bytes allocated. In this case, there were 0x5320 more bytes allocated between the times that the two logs were captured. The bytes came from the call-stack that is identified by "BackTrace00053".

Let us now see the comparison logs for the process on which UMDH logs have been collected.

There were 5 UMDH logs collected at a certain interval of time. They are:

  1. Test-n0.log
  2. Test-n1.log
  3. Test-n2.log
  4. Test-n3.log
  5. Test-n4.log

We made a cumulative comparison of the logs. See below:

Command run: Umdh.exe -d Test-n0.log Test-n1.log > CMP01.txt

Total increase == 493610 requested + 125590 overhead = 619200

Overheads: 125590 bytes = 0.12 MB.

Command run: Umdh.exe -d Test-n1.log Test-n2.log > CMP12.txt

Total decrease ==      0 requested +      0 overhead =      0

No overheads.

Command run: Umdh.exe -d Test-n2.log Test-n5.log > CMP25.txt

Total decrease ==      0 requested +      0 overhead =      0

No overheads.

This matches the results shown by the performance monitor logs (Figure 4 and Figure 5). There is a sudden steep rise in the working set private (as the process allocates memory) and with the passage of time the overheads gets reduced to 0, which means “no leak”.

There were 5 more UMDH logs for the same process collected at a different time and at different intervals of time. They are:

  1. 2ndTest-r0.log
  2. 2ndTest-r1.log
  3. 2ndTest-r2.log
  4. 2ndTest-r3.log
  5. 2ndTest-r4.log

Command run: Umdh.exe -d 2ndTest-r0.log 2ndTest-r1.log > 2ndCMP01.txt

Total increase == 551954 requested + 128126 overhead = 680080

Overheads: 128126 bytes = 0.12 MB.

Command run: Umdh.exe -d 2ndTest-r1.log 2ndTest-r2.log > 2ndCMP12.txt

Total increase ==     24 requested +    168 overhead =    192

Overhead: 168 bytes = 0.00016 MB.

Command run: Umdh.exe -d 2ndTest-r2.log 2ndTest-r3.log > 2ndCMP23.txt

Total increase ==     68 requested +    476 overhead =    544

Overhead: 476 bytes = 0.00052 MB.

This +/- 0.0005 MB allocations can be interpreted from the performance monitor logs shown below:

There has never been a steep rise in the private bytes from 11:15:28 AM till the end which can be interpreted as “no-leak”.

This is just an example to show how to use UMDH and performance monitor logs for analyzing memory leak.

Reference: support.microsoft.com/kb/268343

 

By Shamik Misra, Escalation Services, DSI Distributed Services