Order of events in .texttrace file (and maybe also in .trace file)

[gitttt]

Hi!

I am a bit confused by the order of events in a trace. Is it that the [B] event comes first, then all [I] events for all instructions in this basic block, and then all [M] for memory accesses of the instructions in the basic block? This is how it is here (taken from the ls example):

[B] EXEC_ID: 27 THREAD_ID: 0000000000000001 START_ADDRESS: 0000000004004e18 END_ADDRESS: 0000000004004e39
[I] 0000000004004e18: mov rax, r13
[I] 0000000004004e1b: add rax, qword ptr [rdx]
[I] 0000000004004e1e: cmp dword ptr [rdx + 8], 8
[I] 0000000004004e22: jne 0x4005048
[I] 0000000004004e28: mov rcx, r13
[I] 0000000004004e2b: add rcx, qword ptr [rdx + 0x10]
[I] 0000000004004e2f: add rdx, 0x18
[I] 0000000004004e33: cmp rdx, r12
[I] 0000000004004e36: mov qword ptr [rax], rcx
[I] 0000000004004e39: jb 0x4004e18
[M] EXEC_ID: 28 INS_ADDRESS: 0000000004004e1b START_ADDRESS: 00000000040008f0 LENGTH: 8 MODE: R DATA: a82d220000000000
[M] EXEC_ID: 28 INS_ADDRESS: 0000000004004e1e START_ADDRESS: 00000000040008f8 LENGTH: 4 MODE: R DATA: 08000000
[M] EXEC_ID: 28 INS_ADDRESS: 0000000004004e2b START_ADDRESS: 0000000004000900 LENGTH: 8 MODE: R DATA: 2023010000000000
[M] EXEC_ID: 28 INS_ADDRESS: 0000000004004e36 START_ADDRESS: 0000000004222da8 LENGTH: 8 MODE: W DATA: 2023010400000000

Yet, here is a counter example:

[B] EXEC_ID: 40 THREAD_ID: 0000000000000001 START_ADDRESS: 0000000004004e60 END_ADDRESS: 0000000004004ec1
[I] 0000000004004e60: mov r15, qword ptr [r12 + 8]
[I] 0000000004004e65: mov rcx, r13
[I] 0000000004004e68: add rcx, qword ptr [r12]
[I] 0000000004004e6c: mov rax, r15
[I] 0000000004004e6f: mov r15d, r15d
[I] 0000000004004e72: shr rax, 0x20
[I] 0000000004004e76: test r15, r15
[I] 0000000004004e79: lea rax, qword ptr [rax + rax*2]
[I] 0000000004004e7d: lea r14, qword ptr [rdi + rax*8]
[I] 0000000004004e81: je 0x4004feb
[I] 0000000004004e87: test r14, r14
[I] 0000000004004e8a: je 0x4005030
[I] 0000000004004e90: movzx edx, byte ptr [r14 + 4]
[I] 0000000004004e95: mov rax, qword ptr [r14 + 8]
[I] 0000000004004e99: add rax, qword ptr [rip + 0x21eb58]
[I] 0000000004004ea0: and edx, 0xf
[I] 0000000004004ea3: cmp dl, 0xa
[I] 0000000004004ea6: je 0x4005067
[I] 0000000004004eac: sub r15, 6
[I] 0000000004004eb0: cmp r15, 0x1e
[I] 0000000004004eb4: ja 0x4004feb
[I] 0000000004004eba: movsxd rdx, dword ptr [r8 + r15*4]
[I] 0000000004004ebe: add rdx, r8
[I] 0000000004004ec1: jmp rdx
[M] EXEC_ID: 41 INS_ADDRESS: 0000000004004fe3 START_ADDRESS: 00000000040009f0 LENGTH: 8 MODE: R DATA: 0000000000000000
[M] EXEC_ID: 41 INS_ADDRESS: 0000000004004fe8 START_ADDRESS: 0000000004223018 LENGTH: 8 MODE: W DATA: e07a010400000000

Note that the INS_ADDRESS: 0000000004004fe3 for example, is not in the basic block with START_ADDRESS: 0000000004004e60.

Maybe I misunderstood the order of events. Did I? I am asking because what I would like it the following:

The order of events should be in the order of the actual execution. In particular, the [M] should be right after the corresponding [I]. Can tracergrind do this for me or do I have to process the .texttrace myself?

[doegox]

TracerGrind is more like flushing its queues from time to time and it's hard to predict their order. Once its content is in a DB it doesn't really matter. But for "human readable" traces I would advise you to use TracerPIN instead for your specific case, there everything is perfectly ordered: [T]/[C]/[B]/[R]/[I]/[W]

[gitttt]

by DB you mean the sqlite database? Would you say it is easier to get the events in order using the database? Or are they maybe already ordered in the database?

EDIT: I get what you mean. By querying and joining etc. one can the right pairs of instruction- and memory-events

[doegox]

yes sqlite. events will then be on separate tables and you can query the memory events related to one instruction so if you go through the ins table and look for the corresponding ins_id in the mem table you'll get what you want.

[haxelion]

The event in texttrace are in the same order than in the trace and it's always the same, it's just the other way around : M, B, I

That's the one you saw in the second example. In your first example you're in a loop (see the [I] 0000000004004e39: jb 0x4004e18?) and the memory R/W in your example are from the next loop iteration.