Some Thoughts on Debugging AutoBoost Bugchecks

x BlueRobot

Administrator
Staff member
Joined
May 7, 2013
Posts
10,400
There are three different bugchecks related to Autoboost: Stop 0x153, Stop 0x162 and Stop 0x192. All of which are caused by slightly different error conditions.

Before we begin diving into these bugchecks, it's imperative that you understand what AutoBoost is and how it aims to resolve common thread scheduling problems. AutoBoost was designed to overcome the priority inversion problem, which occurs when a higher priority level thread is blocked from running because a lower priority thread is holding a resource which the higher priority thread requires. This is a classic deadlock situation whereby two threads are preventing each other from processing. This is sometimes also known as CPU starvation.

The following excerpt from Windows Internals 7th Edition describes this problem:

Windows Internals 7th Edition Part 1 said:
Imagine the following situation: A priority 7 thread is running, preventing a priority 4 thread from ever receiving CPU time. However, a priority 11 thread is waiting for some resource that the priority 4 thread has locked. But because the priority 7 thread in the middle is eating up all the CPU time, the priority 4 thread will never run long enough to finish whatever it’s doing and release the resource
blocking the priority 11 thread. This scenario is known as priority inversion.​

AutoBoost partly decides which threads to boost the priority for based on the locks which they hold and any locks which they may be waiting on too. This information is maintained in an array (currently maximum of 6) of _KLOCK_ENTRY objects. Each object describes the locks which the thread currently holds and any locks which the thread may be waiting upon itself.

Rich (BB code):
9: kd> dt _KTHREAD -y LockEntries
nt!_KTHREAD
   +0x320 LockEntries : [6] _KLOCK_ENTRY

The locks which are currently held by the thread are described by a red-black tree structure, this can be found in the lock entry object:

Rich (BB code):
9: kd> dt _KLOCK_ENTRY -y OwnerTree
nt!_KLOCK_ENTRY
   +0x030 OwnerTree : _RTL_RB_TREE

Likewise, the locks which the thread is waiting upon are held in another red-black tree:

Rich (BB code):
9: kd> dt _KLOCK_ENTRY -y WaiterTree
nt!_KLOCK_ENTRY
   +0x040 WaiterTree : _RTL_RB_TREE

The tree is then transversed to determine which priority level the thread should be boosted to. The owner thread's priority is then boosted to the same priority as the thread which is waiting on the lock to be released. This commonly known as priority inheritance. Please note that the thread's priority will never be boosted beyond priority level 15. Additionally, the AutoBoost framework is currently only implemented for push locks and guarded mutexes.

You can dump push locks using the following:

Rich (BB code):
9: kd> dt _EX_PUSH_LOCK
nt!_EX_PUSH_LOCK
   +0x000 Locked           : Pos 0, 1 Bit
   +0x000 Waiting          : Pos 1, 1 Bit
   +0x000 Waking           : Pos 2, 1 Bit
   +0x000 MultipleShared   : Pos 3, 1 Bit
   +0x000 Shared           : Pos 4, 60 Bits
   +0x000 Value            : Uint8B
   +0x000 Ptr              : Ptr64 Void

Guarded mutexes use the KGUARDED_MUTEX structure which isn't available with public symbols.

Since a majority of these bugchecks appear to be caused by push locks, and this form of synchronisation mechanism is sparely documented, I thought it would be wise to add some information regarding their acquisition and release.

When you attempt to acquire a push lock, ExAcquirePushLockExclusiveEx will set-up a _KLOCK_ENTRY structure for the calling thread, it will then check if the push lock has been acquired by checking that the acquired bit has been set, and if so, then the lock entry will be added to the waiting tree of the corresponding lock entry. Otherwise, it will be added to the owner tree of the lock entry.

The LockState property of the _KLOCK_STATE_ENTRY structure is then set to the push lock which we're acquiring.

Rich (BB code):
9: kd> dt _KLOCK_ENTRY_LOCK_STATE -y LockState
nt!_KLOCK_ENTRY_LOCK_STATE
   +0x000 LockState : Ptr64 Void

The ExfAcquirePushLockExclusiveEx function will be called if the push lock is already held by another thread; a _EX_PUSH_LOCK_WAIT_BLOCK structure is then constructed, which is the wait block for the push lock which we attempted to acquire. This wait block contains a doubly linked list of all the waiting threads which are waiting to acquire exclusive access to the push lock. It should be noted that push locks can not be acquired at DISPATCH_LEVEL (IRQL level 2) or above, attempting to do so, will likely end up in a Stop 0x192. However, please note, that for the thread to call ExAcquirePushLockExclusiveEx and attempt to grant exclusive access to the push lock, then the thread must enter a critical region which will raise the IRQL Level to 1 or APC_LEVEL, this then disables user-mode and normal kernel APCs.

To release exclusive access to a push lock, the ExReleasePushLockExclusive macro will be called, this will release the push lock and enable it to be acquired by another thread. If the 2nd bit of the push lock is set, then the ExfTryToWakePushLock is called which will set the gate object associated to the wait block to the signaled state, which will then cause any waiting thread to be released from it's wait state, the push lock value will then be updated by using a lock cmpxchg instruction.

The lock entries will be checked for the thread which was holding the push lock by checking that the acquired bit has been set to true, and the lock state contains the same pointer as the push lock. Remember that push locks are merely pointers. If the push lock is unable to be found in any of the thread's lock entries and the AutoBoostEntriesExhausted flag for the thread is false, then the system will bugcheck with a Stop 0x162.

The following video also provides some background on the acquisition and release of push locks:


The accompanying slides can be found in the references at the end of this post.




Now, we've gained some understanding of how Autoboost is implemented and the problem it aims to help to resolve. Let's investigate the bugchecks which are associated to the AutoBoost framework. Firstly, we'll examine the Stop 0x153, which indicates that a thread holding a lock was prematurely terminated.

Rich (BB code):
KERNEL_LOCK_ENTRY_LEAKED_ON_THREAD_TERMINATION (153)
A thread was terminated before it had freed all its AutoBoost lock entries.
This is typically caused when a thread never released a lock it previously
acquired (e.g. by relying on another thread to release it), or if the thread
did not supply a consistent set of flags to lock package APIs.
Arguments:
Arg1: ffffd902d2aa7080, The address of the thread
Arg2: ffffd902d2aa73a0, The address of the entry that was not freed
Arg3: 0000000000000001, Lock pointer was not NULL
Arg4: ffffae08901abc50, The address of the lock associated with the entry

If we dump the thread object from the first parameter, we can indeed see, that the thread was terminated prematurely.

Rich (BB code):
8: kd> !thread ffffd902d2aa7080
THREAD ffffd902d2aa7080  Cid 0f0c.1e64  Teb: 0000000000000000 Win32Thread: 0000000000000000 TERMINATED
Not impersonating
GetUlongFromAddress: unable to read from fffff8053162ba04
Owning Process            ffffd902d2d6d080       Image:         msiexec.exe
Attached Process          N/A            Image:         N/A
fffff78000000000: Unable to get shared data
Wait Start TickCount      444115
Context Switch Count      148757         IdealProcessor: 11  
ReadMemory error: Cannot get nt!KeMaximumIncrement value.
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x00000000778063b0
Stack Init 0000000000000000 Current ffffec8b4552c490
Base ffffec8b4552d000 Limit ffffec8b45527000 Call 0000000000000000
Priority 8 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5

It should be mentioned, that there is a number of AutoBoost fields on the _KTHREAD structure. I'll mention the ones which are of most interest.

Rich (BB code):
8: kd> dt _KTHREAD -y AutoBoostActive ffffd902d2aa7080
nt!_KTHREAD
   +0x074 AutoBoostActive : 0y1

The AutoBoostActive field either indicates if AutoBoost was enabled for the thread or it was AutoBoost tracking was enabled for the lock which the thread is holding; in either case, we can clearly see that it was enabled.

Additionally, there is another field called AutoBoostEntriesExhausted, while this was mentioned earlier, I'm not exactly sure of it's purpose, but I presume it suggests if the thread has the maximum amount of lock entries?

Rich (BB code):
8: kd> dt _KTHREAD -y AutoBoostEntriesExhausted ffffd902d2aa7080
nt!_KTHREAD
   +0x078 AutoBoostEntriesExhausted : 0y0

Lastly, there is the AbOwnedEntryCount which indicates the number of lock entries the thread currently owns. In this case there is only one and is this the one mentioned by the bugcheck description.

Rich (BB code):
8: kd> dt _KTHREAD -y AbOwnedEntryCount ffffd902d2aa7080
nt!_KTHREAD
   +0x58f AbOwnedEntryCount : 0x1 ''

We know that the thread was still holding a lock when it was terminated. To investigate this further, let's dump the associated lock entry object.

Rich (BB code):
8: kd> dt _KLOCK_ENTRY ffffd902d2aa73a0
nt!_KLOCK_ENTRY
   +0x000 TreeNode         : _RTL_BALANCED_NODE
   +0x000 FreeListEntry    : _SINGLE_LIST_ENTRY
   +0x018 EntryFlags       : 0x1010032
   +0x018 EntryOffset      : 0x32 '2'
   +0x019 ThreadLocalFlags : 0 ''
   +0x019 WaitingBit       : 0y0
   +0x019 Spare0           : 0y0000000 (0)
   +0x01a AcquiredByte     : 0x1 ''
   +0x01a AcquiredBit      : 0y1
   +0x01b CrossThreadFlags : 0x1 ''
   +0x01b HeadNodeBit      : 0y1
   +0x01b IoPriorityBit    : 0y0
   +0x01b IoQoSWaiter      : 0y0
   +0x01b Spare1           : 0y00000 (0)
   +0x018 StaticState      : 0y00110010 (0x32)
   +0x018 AllFlags         : 0y000000010000000100000000 (0x10100)
   +0x01c SpareFlags       : 0
   +0x020 LockState        : _KLOCK_ENTRY_LOCK_STATE
   +0x020 LockUnsafe       : 0xffffae08`901abc50 Void
   +0x020 CrossThreadReleasableAndBusyByte : 0x50 'P'
   +0x021 Reserved         : [6]  "???"
   +0x027 InTreeByte       : 0xff ''
   +0x028 SessionState     : 0x00000000`ffffffff Void
   +0x028 SessionId        : 0xffffffff
   +0x02c SessionPad       : 0
   +0x030 OwnerTree        : _RTL_RB_TREE
   +0x040 WaiterTree       : _RTL_RB_TREE
   +0x030 CpuPriorityKey   : 0 ''
   +0x050 EntryLock        : 0
   +0x058 BoostBitmap      : _KLOCK_ENTRY_BOOST_BITMAP
   +0x05c SparePad         : 0

The AcquiredBit field is set, so we're holding a lock and the LockUnsafe field points to the address of the push lock which we were holding at the time of the thread termination. Notice that it matches the address shown in the fourth parameter of the bugcheck?

Rich (BB code):
8: kd> dt _EX_PUSH_LOCK ffffae08901abc50
win32k!_EX_PUSH_LOCK
   +0x000 Locked           : 0y1
   +0x000 Waiting          : 0y0
   +0x000 Waking           : 0y0
   +0x000 MultipleShared   : 0y0
   +0x000 Shared           : 0y000000000000000000000000000000000000000000000000000000000000 (0)
   +0x000 Value            : 1
   +0x000 Ptr              : 0x00000000`00000001 Void

The Locked field is set, therefore we hold that a thread is currently holding this lock. As we know from examining the lock entry structure, this lock was held by our terminated thread. There isn't much you can do to debug this bugcheck unfortunately, although, if we dump the call stack, we can see that the process which the thread was associated to had been terminated.

Rich (BB code):
8: kd> knL
 # Child-SP          RetAddr           Call Site
00 ffffec8b`46c99588 fffff805`31431813 nt!KeBugCheckEx
01 ffffec8b`46c99590 fffff805`3185ec0e nt!KeCleanupThreadState+0x165887
02 ffffec8b`46c995d0 fffff805`317f8410 nt!PspThreadDelete+0x1e
03 ffffec8b`46c99640 fffff805`3123a969 nt!ObpRemoveObjectRoutine+0x80
04 ffffec8b`46c996a0 fffff805`317eb1b7 nt!ObfDereferenceObjectWithTag+0xc9
05 ffffec8b`46c996e0 fffff805`318366d5 nt!ObCloseHandleTableEntry+0x2c7
06 ffffec8b`46c99820 fffff805`31836371 nt!ExSweepHandleTable+0xd5
07 ffffec8b`46c998d0 fffff805`31836899 nt!ObKillProcess+0x35
08 ffffec8b`46c99900 fffff805`3185ceb3 nt!PspRundownSingleProcess+0x131
09 ffffec8b`46c99980 fffff805`31837f1b nt!PspExitThread+0x60b
0a ffffec8b`46c99a90 fffff805`313d2918 nt!NtTerminateProcess+0xeb
0b ffffec8b`46c99b00 00000000`777a1cbc nt!KiSystemServiceCopyEnd+0x28
0c 00000000`00f8ec48 00000000`00000000 0x777a1cbc

My suggestion would be to find out who is calling NtTerminateProcess. In our case, the process was msiexec.exe, which is a Windows installer used for installing .msi packages. The next bugcheck we'll investigate is Stop 0x162, which when a thread has attempted to release a lock which it does not own.




Rich (BB code):
KERNEL_AUTO_BOOST_INVALID_LOCK_RELEASE (162)
A lock tracked by AutoBoost was released by a thread that did not own the lock.
This is typically caused when some thread releases a lock on behalf of another
thread (which is not legal with AutoBoost tracking enabled) or when some thread
tries to release a lock it no longer owns.
Arguments:
Arg1: ffffdb8d223cb080, The address of the thread
Arg2: ffffcb81844bab50, The lock address
Arg3: 00000000ffffffff, The session ID of the thread
Arg4: 0000000000000000, Reserved

The first parameter contains the address of the thread which attempted to release the lock. The second parameter is the lock object in question. This appears to have been freed at the time of the crash. Let's examine the call stack to see what may have happened. As we can see, it does certainly seem that a lock was released inappropriately. I'm not sure what exactly KeAbPostRelease does, however, judging from the function name, I would presume it's some form of callback function which is called after a lock tracked by AutoBoost is released. I also noticed that the AbPostRelease function takes a parameter with the address of ffffcb81`844bab30, which is very close to the address of our push lock.

Rich (BB code):
9: kd> knL
 # Child-SP          RetAddr           Call Site
00 ffff880e`4fb4f898 fffff804`281de4b5 nt!KeBugCheckEx
01 ffff880e`4fb4f8a0 fffff804`2867fb30 nt!KeAbPostRelease+0xcb5b5 << Crash here!
02 ffff880e`4fb4f8f0 fffff804`2867f355 nt!AlpcpReceiveMessage+0x620
03 ffff880e`4fb4f9d0 fffff804`281d3c15 nt!NtAlpcSendWaitReceivePort+0x105 << Listens to incoming ALPC messages
04 ffff880e`4fb4fa90 00007fff`fb35d1a4 nt!KiSystemServiceCopyEnd+0x25
05 00000070`e20ff148 00000000`00000000 0x00007fff`fb35d1a4

We can find more information about what the lock is associated to by using the !pool command. It appears to be related to an ALPC message. This makes perfect sense since we were receiving an ALPC message at the time of the crash.

Rich (BB code):
9: kd> !pool ffffcb81844bab50
Pool page ffffcb81844bab50 region is Paged pool
 ffffcb81844ba000 size:  580 previous size:    0  (Allocated)  Ntff
 ffffcb81844ba590 size:  580 previous size:    0  (Allocated)  Ntff
*ffffcb81844bab20 size:  360 previous size:    0  (Allocated) *AlMs
        Pooltag AlMs : ALPC message, Binary : nt!alpc
 ffffcb81844bae80 size:  160 previous size:    0  (Free)       ...}

The ALPC message object is stored at 0x40 bytes from the pool allocation start address. Let's use the !alpc command with the message switch to dump the associated message.

Rich (BB code):
9: kd> !alpc /m ffffcb81`844bab60

Message ffffcb81844bab60
  MessageID             : 0x19AC (6572)
  CallbackID            : 0x40A40A (4236298)
  SequenceNumber        : 0x0000016D (365)
  Type                  : LPC_REQUEST
  DataLength            : 0x0054 (84)
  TotalLength           : 0x007C (124)
  Canceled              : No
  Release               : No
  ReplyWaitReply        : No
  Continuation          : Yes
  OwnerPort             : ffffdb8d14b8d880 [ALPC_CLIENT_COMMUNICATION_PORT]
  WaitingThread         : 0000000000000000
  QueueType             : ALPC_MSGQUEUE_PENDING
  QueuePort             : ffffdb8d14bb2c90 [ALPC_CONNECTION_PORT]
  QueuePortOwnerProcess : ffffdb8d14b6e440 (svchost.exe)
  ServerThread          : ffffdb8d223cb080 << Same thread shown in the first parameter
  QuotaCharged          : No
  CancelQueuePort       : 0000000000000000
  CancelSequencePort    : 0000000000000000
  CancelSequenceNumber  : 0x00000000 (0)
  ClientContext         : 0000017d1764ede0
  ServerContext         : 0000000000000000
  PortContext           : 00000265e5274040
  CancelPortContext     : 0000000000000000
  SecurityData          : ffffcb81803d9d70
  View                  : 0000000000000000
  HandleData            : 0000000000000000

The actual lock object is stored as part of a larger structure called a blob. Blobs are special objects used by the ALPC library for managing objects related to ALPC such as messages. Blobs have similar attributes to objects exposed by the Object Manager: they can be garbage collected, have their references tracked and locked through synchronisation mechanisms such as push locks. Blobs are allocated using paged pool. We can dump a blob object by using the _BLOB structure.

Rich (BB code):
9: kd> dt _BLOB ffffcb81844bab30
nt!_BLOB
   +0x000 ResourceList     : _LIST_ENTRY [ 0xffffcb81`844bab30 - 0xffffcb81`844bab30 ]
   +0x000 FreeListEntry    : _SLIST_ENTRY
   +0x010 u1               : <anonymous-tag>
   +0x011 ResourceId       : 0x2 ''
   +0x012 CachedReferences : 0n0
   +0x018 ReferenceCount   : 0n1
   +0x020 Lock             : _EX_PUSH_LOCK << Second parameter

I believe the ResourceId is used to index into the _BLOB_ID enumeration; 0x2 points to a message type, which makes perfect sense since we're dealing with a ALPC message.

Rich (BB code):
9: kd> dt _BLOB_ID
nt!_BLOB_ID
   BLOB_TYPE_UNKNOWN = 0n0
   BLOB_TYPE_CONNECTION_INFO = 0n1
   BLOB_TYPE_MESSAGE = 0n2
   BLOB_TYPE_SECURITY_CONTEXT = 0n3
   BLOB_TYPE_SECTION = 0n4
   BLOB_TYPE_REGION = 0n5
   BLOB_TYPE_VIEW = 0n6
   BLOB_TYPE_RESERVE = 0n7
   BLOB_TYPE_DIRECT_TRANSFER = 0n8
   BLOB_TYPE_HANDLE_DATA = 0n9
   BLOB_TYPE_MAX_ID = 0n10

Unfortunately, I haven't been able to find much information at all about KeAbPostRelease. However, from reading some threads regarding this crash, it appears that this is commonly caused by drivers not implementing synchronization mechanisms correctly. I would strongly suggest running Driver Verifier with the deadlock verification checks enabled.




Lastly, there is the Stop 0x192, which indicates that a thread acquired a AutoBoost lock at an IRQL at DISPATCH_LEVEL or above.

Rich (BB code):
KERNEL_AUTO_BOOST_LOCK_ACQUISITION_WITH_RAISED_IRQL (192)
A lock tracked by AutoBoost was acquired while executing at DISPATCH_LEVEL or
above.
Arguments:
Arg1: ffff990ec984a080, The address of the thread.
Arg2: ffffa92601302f90, The lock address.
Arg3: 0000000000000000, The IRQL at which the lock was acquired.
Arg4: 0000000000000000, Reserved.

Rich (BB code):
0: kd> dt nt!_KPRCB -y DebuggerSavedIrql fffff8074b809180
   +0x5b98 DebuggerSavedIRQL : 0 ''

You may have noticed that the IRQL in the third parameter is at PASSIVE_LEVEL. I believe that this bugcheck has a generic umbrella description for all crashes which are related to threads attempting to acquire push locks. And the reason why the system crashes, is because the thread has already exhausted the number of locks which it can wait upon, the AutoBoostEntriesExhausted field is set to true in this instance, which is unlike the other Autoboost bugchecks which I've examined. I could be wrong, although, that is what makes the most sense to me in this circumstance.

Rich (BB code):
0: kd> dt _KTHREAD -y AutoBoostEntriesExhausted ffff990ec984a080
nt!_KTHREAD
   +0x078 AutoBoostEntriesExhausted : 0y1

The win32kbase!GdiHandleEntryDirectory::AcquireEntryLock function does appear to enter and leave a critical region whilst attempting to obtain the push lock, this would only raise the IRQL Level to 1.

Rich (BB code):
0: kd> !stack -p
Call Stack : 12 frames
## Stack-Pointer    Return-Address   Call-Site
00 ffffd70155e14238 fffff8074ec39c35 nt!KeBugCheckEx+0
    Parameter[0] = 0000000000000192
    Parameter[1] = ffff990ec984a080
    Parameter[2] = ffffa92601302f90
    Parameter[3] = 0000000000000000
01 ffffd70155e14240 ffffa9528a5ea377 nt!ExAcquirePushLockExclusiveEx+145 (perf)
    Parameter[0] = ffffa92601302f90 << Our push lock
    Parameter[1] = 0000000000000000
    Parameter[2] = (unknown)
    Parameter[3] = (unknown)
02 ffffd70155e14280 ffffa9528a5e82c4 win32kbase!GdiHandleEntryDirectory::AcquireEntryLock+c7 (perf)
    Parameter[0] = (unknown)
    Parameter[1] = ffff990ec984a080 << Thread attempting to acquire push lock
    Parameter[2] = 0000000000000000
    Parameter[3] = (unknown)
[...]

Again unfortunately, I haven't been able to gather much information from the dump file, and I would advise that Driver Verifier be run, it would be particularly interesting to see if the IRQL verification checks are able to catch anything.

References:

https://census-labs.com/media/windows_10_rs2_rs3_exploitation_primitives.pdf
Windows 10 Anniversary Update: GDI handle management and vulnerabilities exploitation
ALPC monitoring
Pwning Windows Kernel - Unkillable User-Mode Process - Part 2
https://recon.cx/2008/a/thomas_garnier/LPC-ALPC-slides.pdf
avalon1610/ALPC
https://recon.cx/2008/a/thomas_garnier/LPC-ALPC-paper.pdf
ReactOS: ntoskrnl/ex/pushlock.c File Reference
Windows Internals 6th Edition Part 1
 

Has Sysnative Forums helped you? Please consider donating to help us support the site!

Back
Top