Can't use user mode trace when installed Spectre&Meltdown patch.

[howknows]

Hi guys,

My Windows10 installed the newest patch this week ,it's used for patch Intel CPU--Spectre&Meltdown vulnerabilities. But today when I test WindowsIntelPt project on this machine, I find it is something wrong in user mode trace. And everything is Okay before I installed the newest windows patch...
Log like this:

`Talos Intel PT Test Application
Version 0.5

Intel Processor Tracing support for this CPU: YES
Would you like to do the Kernel Tests? [Y/N] n
Insert here the target process to trace: 872
872
On how many processors would you like to run the process? [1/4] 1
Creating trace files (binary and readable)... Success!
Creating target process... OK

Using IP filtering mode!
New Process main module base address: 0x7FF7F1640000, size 0x00041000.

Starting the Tracing and resuming the process...
Error!

*** PT Trace results ***
Number of traced CPUs: 1 - Affinity mask: 0x00000001.
CPU 0
Error!

Global number of PT packets acquired: 0.
All the dumps have been saved in "D:\mirror\transfer\Compiled_IntelPt\1746-01082018_Dumps".
Press any key to exit...`

I guess the problem is the newest windows used different CR3 between user mode and kernel mode.

[howknows]

nt!_KPROCESS
+0x000 Header : _DISPATCHER_HEADER
+0x018 ProfileListHead : _LIST_ENTRY
+0x028 DirectoryTableBase : Uint8B
+0x030 ThreadListHead : _LIST_ENTRY
+0x040 ProcessLock : Uint4B
+0x044 ProcessTimerDelay : Uint4B
+0x048 DeepFreezeStartTime : Uint8B
+0x050 Affinity : _KAFFINITY_EX
+0x0f8 ReadyListHead : _LIST_ENTRY
+0x108 SwapListEntry : _SINGLE_LIST_ENTRY
+0x110 ActiveProcessors : _KAFFINITY_EX
+0x1b8 AutoAlignment : Pos 0, 1 Bit
+0x1b8 DisableBoost : Pos 1, 1 Bit
+0x1b8 DisableQuantum : Pos 2, 1 Bit
+0x1b8 DeepFreeze : Pos 3, 1 Bit
+0x1b8 TimerVirtualization : Pos 4, 1 Bit
+0x1b8 CheckStackExtents : Pos 5, 1 Bit
+0x1b8 PpmPolicy : Pos 6, 3 Bits
+0x1b8 ActiveGroupsMask : Pos 9, 20 Bits
+0x1b8 ReservedFlags : Pos 29, 3 Bits
+0x1b8 ProcessFlags : Int4B
+0x1bc BasePriority : Char
+0x1bd QuantumReset : Char
+0x1be Visited : UChar
+0x1bf Flags : _KEXECUTE_OPTIONS
+0x1c0 ThreadSeed : [20] Uint4B
+0x210 IdealNode : [20] Uint2B
+0x238 IdealGlobalNode : Uint2B
+0x23a Spare1 : Uint2B
+0x23c StackCount : _KSTACK_COUNT
+0x240 ProcessListEntry : _LIST_ENTRY
+0x250 CycleTime : Uint8B
+0x258 ContextSwitches : Uint8B
+0x260 SchedulingGroup : Ptr64 _KSCHEDULING_GROUP
+0x268 FreezeCount : Uint4B
+0x26c KernelTime : Uint4B
+0x270 UserTime : Uint4B
+0x274 ReadyTime : Uint4B
+0x278 UserDirectoryTableBase : Uint8B
+0x280 AddressPolicy : UChar
+0x281 Spare2 : [71] UChar
+0x2c8 InstrumentationCallback : Ptr64 Void
+0x2d0 SecureState :

I find UserDirectoryTableBase filed have user mode CR3 value.

[cheat-engine]

Just wondering, is there an 'official' way to get UserDirectoryTableBase ? (Sure you can hardcode KPROCESS but with patches that's just waiting for crashes)

[illera88]

Hi,

I'm facing the same problem. I've debugged PtControlApp code and the problem is in this call to DeviceIoControl.

The Error code returned by the GetLastError in the next line is 0x3b (59).

Any idea here?

Thanks!

[richinseattle]

Thanks for bringing this issue to my attention. The current code has not been tested by Andrea or myself on systems that have had the meltdown patches applied. Meltdown did cause some architectural changes with the way page tables are accessed from usermode, however in the IOCTL handler, I'm not positive changing the directory base lookup is the correct fix since the kernel page tables should be able to access both kernel and process pages.

I just moved from Austin to Seattle this weekend and all of my gear is in boxes for the next couple weeks until I can find time to unpack.

If anyone would like to test a quick fix and report back here, you can change line 102 of IntelPt.cpp in the driver to access the offset of the new UserDirectoryTableBase at offset 0x278. The index of [5] should be updated to [79] on that line to reference the new offset to test this possible solution. If this does not fix it, I will need to get a kernel debugging setup again in a few weeks.

WindowsIntelPT/WindowsPtDriver/IntelPt.cpp

Line 102 in 66667b0

targetCr3 = ((ULONG_PTR *)desc.peProc)[5];

Andrea has since moved on to the Windows Kernel development team at MSFT and has restrictions on his opensource contributions.

-rich

[illera88]

Hi Rich,
I just tried to change that and unfortunately that didn't work :(

Let me know if there is something else I can try.

Thanks!!

[cheat-engine]

You may want to strip the first 12 bits of targetcr3
With process-context identifiers (PCIDs) enabled bit 0 to 12 specify the contextid.

Also, I noticed that targets running as administrator do not have the UserDirectoryTableBase filled in (it's not 0, it's 1) so they have the same CR3 in usermode as they do in kernelmode (In that case, use the old index 5)

(Or leave the cr3 as it is and just remove the check. It's possible that intel-pt checks the exact CR3 value, so those bits may need to be set, but I am unsure)

[howknows]

@illera88 You can try this:
targetCr3 = ((ULONG_PTR *)desc.peProc)[79];
targetCr3 &= (ULONG_PTR)((ULONG_PTR)(-1) - 0xFFF);
CR3 lower 12bits indicate the cr3 is user cr3 or kernel cr3.
If the CR3 lower 12bits is 1 ,the cr3 indicate user cr3.
If the CR3 lower 12bits is 2,the cr3 indicate kernel cr3.

[illera88]

We are getting closer:
with:

targetCr3 = ((ULONG_PTR *)desc.peProc)[79];
targetCr3 &= (ULONG_PTR)((ULONG_PTR)(-1) - 0xFFF);

Talos Intel PT Test Application
Version 0.5

Intel Processor Tracing support for this CPU: YES
Would you like to do the Kernel Tests? [Y/N] N
Insert here the target process to trace: C:\Windows\System32\notepad.exe
On how many processors would you like to run the process? [1/8] 1
Creating trace files (binary and readable)... Success!
Creating target process... OK

       Using IP filtering mode!
New Process main module base address: 0x7FF74F950000, size 0x00041000.

Starting the Tracing and resuming the process... OK

Waiting for the traced process to exit...

failed to determine errata (error -27)[10: unknown packet: unknown opcode]
[10: error printing the packet: unknown opcode]
[d18: unknown packet: unknown opcode]
[d18: error printing the packet: unknown opcode]
[2ad8: unknown packet: unknown opcode]
[2ad8: error printing the packet: unknown opcode]
[3568: unknown packet: unknown opcode]
[3568: error printing the packet: unknown opcode]
[54c8: unknown packet: unknown opcode]
[54c8: error printing the packet: unknown opcode]
[9218: unknown packet: unknown opcode]
[9218: error printing the packet: unknown opcode]
[d0e8: unknown packet: unknown opcode]
[d0e8: error printing the packet: unknown opcode]
[fd28: unknown packet: unknown opcode]
[fd28: error printing the packet: unknown opcode]
[13b38: unknown packet: unknown opcode]
[13b38: error printing the packet: unknown opcode]
[19968: unknown packet: unknown opcode]
[19968: error printing the packet: unknown opcode]
[1b728: unknown packet: unknown opcode]
[1b728: error printing the packet: unknown opcode]
[1c6b8: unknown packet: unknown opcode]
[1c6b8: error printing the packet: unknown opcode]
[1d4b0: unknown packet: unknown opcode]
[1d4b0: error printing the packet: unknown opcode]
[0: sync error: reached end of trace stream]


*** PT Trace results ***
Number of traced CPUs: 1   -   Affinity mask: 0x00000001.
CPU 0
   Number of traced IP ranges: 1
   Number of acquired packets: 71592

Global number of PT packets acquired: 71592.
All the dumps have been saved in "C:\Users\default.LAPTOP-BGOSJ7N3\Documents\code\WindowsIntelPT\x64\Release\1138-03082018_Dumps".
Press any key to exit...

As you can see there is a problem either capturing the packets or parsing them with intelPt since ptdump fails at parsing time.

It complains about errata.
I attach here the dump files (changed .bin extension to .log):
cpu00_bin.bin.log
cpu00_text.log

Any idea?

[cheat-engine]

Not sure as I don't have a parser, but this log looks like it's the log when it's not doing any instruction tracing and only system tracing events are in there. (clock changes etc...)

So likely it's not seeing the CR3 it's looking for.
Instead of zeroing out the bits, leave them be, but remove that if ((targetCr3 & 0xFFF) != 0) return STATUS_INVALID_ADDRESS; condition

[illera88]

Yes, I think you are right since I don't see TNT or IP packets.

I tried what you said and... Upssss.
That didn't work xD

I'm open to other ideas.

[cheat-engine]

it goes further so that's 'good'. could be it's that assert in the dpc handler that still checks index 5 (it'll fail)
if not you'll need to attach a kernel debugger to find it(or load windbg with the memory dump)

[illera88]

If you meant changing:

// Verify that the Target CR3 still matches
targetCr3 = ((ULONGLONG*)curCpuData.lpTargetProc)[79]; // it was 5
ASSERT(targetCr3 == curCpuData.lpTargetProcCr3);

I already tried and crashed.

[illera88]

Gonna analyze the crash dump with windbg. I'll let you know what I find

[illera88]

Here are my results. I've commented out the lines 1187 and 1188 from IntelPt.cpp.

When used:

if (desc.peProc) {
		targetCr3 = ((ULONG_PTR *)desc.peProc)[5]; // 79 same
		// Check the found target CR3 (it should have the last 12 bits set to 0, due to the PFN standard)
		//if ((targetCr3 & 0xFFF) != 0) return STATUS_INVALID_ADDRESS;
		DrvDbgPrint("[" DRV_NAME "] Starting Intel Processor Trace for processor %i. Target CR3: 0x%llX\r\n", curProcId, targetCr3);
	}

FAULTING_SOURCE_FILE:  c:\windowsintelpt\windowsptdriver\intelpt.cpp

FAULTING_SOURCE_LINE_NUMBER:  191

FAULTING_SOURCE_CODE:  
   187: 	rtitCtlDesc.Fields.BranchEn = options.Fields.bTraceBranchPcks;
   188: 
   189: 	if (lpProcPtData->lpTargetProcCr3) {
   190: 		// Set the page table filter for the target process 
>  191: 		__writemsr(MSR_IA32_RTIT_CR3_MATCH, (ULONGLONG)targetCr3);
   192: 		rtitCtlDesc.Fields.CR3Filter = 1;
   193: 	}
   194: 	else {
   195: 		// Set the register to 0
   196: 		__writemsr(MSR_IA32_RTIT_CR3_MATCH, 0);

---

If used:

if (desc.peProc) {
		targetCr3 = ((ULONG_PTR *)desc.peProc)[79];
		// Check the found target CR3 (it should have the last 12 bits set to 0, due to the PFN standard)
		//if ((targetCr3 & 0xFFF) != 0) return STATUS_INVALID_ADDRESS;
		DrvDbgPrint("[" DRV_NAME "] Starting Intel Processor Trace for processor %i. Target CR3: 0x%llX\r\n", curProcId, targetCr3);
	}

or

if (desc.peProc) {
		targetCr3 = ((ULONG_PTR *)desc.peProc)[79];
        targetCr3 &= (ULONG_PTR)((ULONG_PTR)(-1) - 0xFFF);
		// Check the found target CR3 (it should have the last 12 bits set to 0, due to the PFN standard)
		if ((targetCr3 & 0xFFF) != 0) return STATUS_INVALID_ADDRESS;
		DrvDbgPrint("[" DRV_NAME "] Starting Intel Processor Trace for processor %i. Target CR3: 0x%llX\r\n", curProcId, targetCr3);
	}

or

if (desc.peProc) {
		targetCr3 = ((ULONG_PTR *)desc.peProc)[5];
        targetCr3 &= (ULONG_PTR)((ULONG_PTR)(-1) - 0xFFF);
		// Check the found target CR3 (it should have the last 12 bits set to 0, due to the PFN standard)
		if ((targetCr3 & 0xFFF) != 0) return STATUS_INVALID_ADDRESS;
		DrvDbgPrint("[" DRV_NAME "] Starting Intel Processor Trace for processor %i. Target CR3: 0x%llX\r\n", curProcId, targetCr3);
	}

or

if (desc.peProc) {
		targetCr3 = ((ULONG_PTR *)desc.peProc)[79];
        targetCr3 &= (ULONG_PTR)((ULONG_PTR)(-1) - 0xFFF);
		// Check the found target CR3 (it should have the last 12 bits set to 0, due to the PFN standard)
		if ((targetCr3 & 0xFFF) != 0) return STATUS_INVALID_ADDRESS;
		DrvDbgPrint("[" DRV_NAME "] Starting Intel Processor Trace for processor %i. Target CR3: 0x%llX\r\n", curProcId, targetCr3);
	}

I get a crash PROFILER_CONFIGURATION_ILLEGAL

DEFAULT_BUCKET_ID:  WIN8_DRIVER_FAULT

BUGCHECK_STR:  0x17B

PROCESS_NAME:  System

CURRENT_IRQL:  f

ANALYSIS_SESSION_HOST:  DEFAULT

ANALYSIS_SESSION_TIME:  03-08-2018 15:47:10.0739

ANALYSIS_VERSION: 10.0.16299.15 amd64fre

LAST_CONTROL_TRANSFER:  from fffff80092e44ca1 to fffff8009300c430

STACK_TEXT:  
fffff800`9526af28 fffff800`92e44ca1 : 00000000`0000017b 00000000`00000000 00000000`00000570 00000001`00002109 : nt!KeBugCheckEx
fffff800`9526af30 fffff800`92f2b8c5 : fffff800`9526af50 ffffa9cd`f7fe0293 00000000`00000001 00000000`00000dfb : hal!HalpPerfInterrupt+0x91
fffff800`9526af70 fffff800`9300dd1a : fffff800`9525ba50 fffff800`92e6e350 00000000`00000985 ffffe700`236b8440 : nt!KiCallInterruptServiceRoutine+0xa5
fffff800`9526afb0 fffff800`9300e227 : 00000000`00000002 00000000`00000000 fffff800`9525bb00 00000000`00000001 : nt!KiInterruptSubDispatchNoLockNoEtw+0xea
fffff800`9525b9d0 fffff800`9300fcf2 : 00000000`00000000 fffff800`91410180 fffff800`932b0380 ffffe700`2bb53080 : nt!KiInterruptDispatchNoLockNoEtw+0x37
fffff800`9525bb60 00000000`00000000 : fffff800`9525c000 fffff800`95255000 00000000`00000000 00000000`00000000 : nt!KiIdleLoop+0x32


THREAD_SHA1_HASH_MOD_FUNC:  d441e04df42d9d63d400168683d62f86853bfb57

THREAD_SHA1_HASH_MOD_FUNC_OFFSET:  edd3423ca3accf7c0a815c1970a52c73fa11facb

THREAD_SHA1_HASH_MOD:  8f10dde4625c9c2162066c77da81d77dc598d02b

FOLLOWUP_IP: 
nt!KiCallInterruptServiceRoutine+a5
fffff800`92f2b8c5 0fb6f8          movzx   edi,al

FAULT_INSTR_CODE:  45f8b60f

SYMBOL_STACK_INDEX:  2

SYMBOL_NAME:  nt!KiCallInterruptServiceRoutine+a5

FOLLOWUP_NAME:  MachineOwner

MODULE_NAME: nt

IMAGE_NAME:  ntkrnlmp.exe

---

[cheat-engine]

Disassembled hal!HalpPerfInterrupt:

hal!HalpPerfInterrupt:
fffff803`77638c10 4053            push    rbx
fffff803`77638c12 4883ec30        sub     rsp,30h
fffff803`77638c16 488b9988000000  mov     rbx,qword ptr [rcx+88h]
fffff803`77638c1d 488d05dc770100  lea     rax,[hal!EmonProfileInterface (fffff803`77650400)]
fffff803`77638c24 483905e5430200  cmp     qword ptr [hal!HalpProfileInterface (fffff803`7765d010)],rax
fffff803`77638c2b 0f8586000000    jne     hal!HalpPerfInterrupt+0xa7 (fffff803`77638cb7)
fffff803`77638c31 8b0591850200    mov     eax,dword ptr [hal!HalpProfileFeatures (fffff803`776611c8)] 
fffff803`77638c37 a801            test    al,1 
fffff803`77638c39 747c            je      hal!HalpPerfInterrupt+0xa7 (fffff803`77638cb7) ;go to +a7 if HalpProfileFeatures 0
;HalpProfileFeatures is 1
fffff803`77638c3b b98e030000      mov     ecx,38Eh     ; IA32_PERF_GLOBAL_STATUS
fffff803`77638c40 0f32            rdmsr
fffff803`77638c42 48c1e220        shl     rdx,20h
fffff803`77638c46 48b90000000000008000 mov rcx,80000000000000h ;bit 55 (IA32_PERF_GLOBAL_STATUS.Trace_ToPA_PMI)
fffff803`77638c50 480bc2          or      rax,rdx  ;rax contains the full MSR value
fffff803`77638c53 4885c1          test    rcx,rax  ;test if bit 55 is set
fffff803`77638c56 745f            je      hal!HalpPerfInterrupt+0xa7 (fffff803`77638cb7) ;if it's not a trace PMI, go to +a7
;executed when it is a PMI
fffff803`77638c58 48833da816030000 cmp     qword ptr [hal!KdDebuggerNotPresent (fffff803`7766a308)],0 ;under normal usage this value is 1 , so the cmp will be false
fffff803`77638c60 7440            je      hal!HalpPerfInterrupt+0x92 (fffff803`77638ca2) ;if kernel debug is used, go to +92
;no KD
fffff803`77638c62 41b870050000    mov     r8d,570h
fffff803`77638c68 418bc8          mov     ecx,r8d
fffff803`77638c6b 0f32            rdmsr ;read msr 0x570 (IA32_RTIT_CTL)
fffff803`77638c6d 48c1e220        shl     rdx,20h 
fffff803`77638c71 49ba0000000011110000 mov r10,111100000000h
fffff803`77638c7b 480bc2          or      rax,rdx ;RAX=IA32_RTIT_CTL value
fffff803`77638c7e 4985c2          test    r10,rax ;test if any of the ADDR*_CFG.FilterConfig bit 0 is set
                                    ;r10=111100000000h
                                    ;Bits: 32 : ADDR0_CFG bit 0
                                           36 : ADDR1_CFG bit 0
                                           40 : ADDR2_CFG bit 0
                                           44 : ADDR3_CFG bit 0                                    

fffff803`77638c81 741f            je      hal!HalpPerfInterrupt+0x92 (fffff803`77638ca2) ;if none of the Addr*_CFG are configured as traceEnabler, go to +a7
;else BSOD
fffff803`77638c83 0f32            rdmsr
fffff803`77638c85 48c1e220        shl     rdx,20h
fffff803`77638c89 b97b010000      mov     ecx,17Bh
fffff803`77638c8e 480bc2          or      rax,rdx
fffff803`77638c91 4c89542420      mov     qword ptr [rsp+20h],r10
fffff803`77638c96 4c8bc8          mov     r9,rax
fffff803`77638c99 33d2            xor     edx,edx
fffff803`77638c9b ff15a71a0300    call    qword ptr [hal!_imp_KeBugCheckEx (fffff803`7766a748)]  <---- BSOD
fffff803`77638ca1 cc              int     3
;kernelmode debug is enabled, or the addr ranges are ok
fffff803`77638ca2 488b056fb00200  mov     rax,qword ptr [hal!HalpProcessorTraceInterruptHandler (fffff803`77663d18)]  ;What is this and how do I activate this in windows ?
fffff803`77638ca9 4885c0          test    rax,rax
fffff803`77638cac 7409            je      hal!HalpPerfInterrupt+0xa7 (fffff803`77638cb7) if HalpProcessorTraceInterruptHandler==0 goto +a7
fffff803`77638cae 488bcb          mov     rcx,rbx
fffff803`77638cb1 ff15991b0300    call    qword ptr [hal!_guard_dispatch_icall_fptr (fffff803`7766a850)]


;passed the tests, no processtracveinterrupthandler set, or profilefeatures is 1
fffff803`77638cb7 488b05528b0200  mov     rax,qword ptr [hal!HalpPerfInterruptHandler (fffff803`77661810)]
fffff803`77638cbe 488bcb          mov     rcx,rbx
fffff803`77638cc1 4885c0          test    rax,rax
fffff803`77638cc4 7408            je      hal!HalpPerfInterrupt+0xbe (fffff803`77638cce)
fffff803`77638cc6 ff15841b0300    call    qword ptr [hal!_guard_dispatch_icall_fptr (fffff803`7766a850)]
fffff803`77638ccc eb27            jmp     hal!HalpPerfInterrupt+0xe5 (fffff803`77638cf5)
fffff803`77638cce 488b053b430200  mov     rax,qword ptr [hal!HalpProfileInterface (fffff803`7765d010)]
fffff803`77638cd5 488b4028        mov     rax,qword ptr [rax+28h]
fffff803`77638cd9 ff15711b0300    call    qword ptr [hal!_guard_dispatch_icall_fptr (fffff803`7766a850)]
fffff803`77638cdf 488b052a160300  mov     rax,qword ptr [hal!HalPrivateDispatchTable (fffff803`7766a310)]
fffff803`77638ce6 33c9            xor     ecx,ecx
fffff803`77638ce8 488b8018040000  mov     rax,qword ptr [rax+418h]
fffff803`77638cef ff155b1b0300    call    qword ptr [hal!_guard_dispatch_icall_fptr (fffff803`7766a850)]
fffff803`77638cf5 b001            mov     al,1
fffff803`77638cf7 4883c430        add     rsp,30h
fffff803`77638cfb 5b              pop     rbx
fffff803`77638cfc c3              ret

So, it looks like windows will BSOD if the first bit of any ADDR*_CFG is set to 1
ADDR*_CFG have the following setup
0 - unused
1 - filterEn (start filtering when this range is entered)
2 - tracestop (stop filtering when this range is entered)

this means that if you use the filterEn option to specify a start block only windows will BSOD

So

WindowsIntelPT/WindowsPtDriver/IntelPt.cpp

Line 207 in 66667b0

if (lpProcPtData->dwNumOfActiveRanges > 0) {

needs to be adjusted so it never sets it to 1, and only allows you to do full traces instead of specifying the regions you wish to observe, or run with a kernel debugger attached

For me this isn't such a problem, but it is a shame for people who wish to trace certain routines only (More efficient)