After reviewing the collected T4 data from node L, it was
determined that each time an MWAIT spike (Blue)
occurred, there was also a similar Kernel Mode spike
(Red) just before and throughout the MWAIT spike.
Note: A process in a Mutex wait state is considered an MWAIT process. See Figure 2 below:
![](pagedyn_1.jpg)
Figure 2:
KERNEL MODE
and
PROCESSES in MUTEX WAIT
A process in a Mutex wait state is considered an MWAIT
process. See Figure 2 below.
A process running in Kernel
Mode owns a MUTEX causing the number of other processes waiting for the same
MUTEX to spike. Normally, the time spent in Kernel Mode holding a MUTEX is very
short, but there is evidence to show that some Kernel Mode operations are taking
longer than expected, and thus causing the other processes, waiting for the same
MUTEX, to spike at times.
In the following example
(Figure 3), process 288E3D5A ran continually from 10:11:54.174601 to
10:11:58.000763 with most PC samples in EXE$DEALLOCATE_C+0001C or
EXE$DEALLOCATE_C+00020, and an occasional LOGICAL_NAMES+00288. During this time,
other processes waiting for the same MUTEX are placed in a MUTEX wait state.
$
ANALYZE/SYSTEM
SDA> PCS LOAD
SDA> PCS START TRACE
wait 10 minutes
SDA> PCS STOP TRACE
SDA> SET OUTPUT PC.DAT
SDA> PCS SHOW TRACE
SDA> PCS UNLOAD
SDA> EXIT
$ EDIT PC.DAT
:
Timestamp CPU PC IPL Pid Routine Module
---------------------- --- -------- --- --------
-------------------------------- ------
31-OCT 10:11:54.000216 03 80124F74 3 00000000 SCH$CALC_CPU_LOAD_C+00464
PROCESS_MANAGEMENT+00000F74
:
31-OCT 10:11:54.174601 03 8003FCFC 2 288E3D5A EXE$DEALLOCATE_C+0001C
SYSTEM_PRIMITIVES_MIN+00013CFC
: 1866 total PC samples in this collection from the same PID
that contained:
EXE$DEALLOCATE_C 1808 samples
LOGICAL_NAMES 58 samples
31-OCT 10:11:58.000763 03 8003FD10 2 288E3D5A EXE$DEALLOCATE_C+00030
SYSTEM_PRIMITIVES_MIN+00013D10
:
Figure 3:
SYSTEM PC SAMPLES SUMMARIZED
The System Dump Analyzer (SDA)
MTX tool is used to determine which MUTEX has the highest usage. In Figure 4,
the MUTEX with the highest usage is the LNM MUTEX (logical name MUTEX).
Figure 4:
MUTEX USAGE
After observing the system
following a reboot, it was evident that the Paged Dynamic Memory (PAGEDYN) free
list fragmentation increased the longer the system was up. As the fragmentation
increased, the Kernel Mode time and the number of processes in MUTEX wait state
increased. Once the PAGEDYN freelist exceeded 10,000 free blocks, the pauses
started becoming noticeable to the users.
The high LNM MUTEX utilization was presented to the
customer and they were able to identify that their applications used the Job
Logical Name Tables quite extensively. Working with the customer, we determined
that their production applications frequently execute thousands of Logical Name
creations and deletions in the Job Logical Name Table. The data structures that
support the Job Logical Name Tables (LNMx) are allocated from PAGEDYN.
PAGEDYN has always been organized as a singly linked list.
Each time new LNMx structures are to be allocated from
PAGEDYN, the LOGICAL_ NAMES code acquires the LNM MUTEX and also requests the
memory allocation code to traverse the PAGEDYN linked list, one data structure
at a time until the proper sized LNMx structure can be allocated from PAGEDYN.
The LOGICAL_ NAMES code then adds the LNMx to an existing Job Logical Name Table
or creates a new Job Logical Name Table.
When a LNMx is to be returned, the LOGICAL_NAMES code must
also acquire the LNM MUTEX and remove the LNMx structure from the Job Logical
Name Table and call the memory deallocation code to traverse the PAGEDYN linked
list one data structure at a time until the proper place is determined to insert
the returned LNMx structure.
If PAGEDYN has become fragmented into several pieces, this
can cause users to experience performance problems while the singly linked list
is being traversed. During the time that it takes to allocate or return a LNMx,
other processes that want to allocate or delete logical names or logical name
tables go into a MUTEX wait state.
After reviewing the customer's system, it was determined
that PAGEDYN was very fragmented. In the example shown in Figure 5, there are
34,826 fragments. Most of the fragments are less than 64 decimal bytes in
length:
$ SHOW
MEMORY/POOL/FULL
:
Paged Dynamic Memory
Current Size (MB) 143.04 Current Size (Pagelets) 292960
Free Space (MB) 84.24 Space in Use (MB) 58.79
Largest Var Block (MB) 81.30 Smallest Var Block (bytes) 16.00
Number of Free Blocks 34826 Free Blocks LEQU 64 bytes 33533
|