drltrace.PID.log may not have CALLID and TID in synthesizer.py

[gonbbb]

Hi

I tried to run one-trace against toy_example.exe .
(In the following script, absolute paths were used in practice.)

ref. https://github.com/sslab-gatech/winnie/tree/master/harnessgen#one-trace

$ pin.exe -t \path\to\tools\Tracer\x64\Debug\Tracer.dll -logfile "\path\to\cor1_1" -trace_mode "all" -only_to_target "\path\to\toy_example.exe " -only_to_lib "\path\to\example_library.dll " -- path\to\toy_example.exe "test.txt"

example_library loaded at 00007FFE21880000
msg:Hello, World!

Error 1
Result: 0

The contents of the test.txt are as follows

Hello, World!

In this case, this script don't emit memdump. So I make empty memdump file.

$ touch memdump

The contents of the drltrace.PID.log are as follows

CHECKING MODULE...
TARGET MODULE START ADDR:0x140000000
TARGET MODULE END ADDR: 0x14000f000 ? ??:0


==
Module Table: version 4, count 14
0  , 0  , 0x40000000, 0x4000f000, 0x80001145, 0000000000000000, 0x00000000, 0x00000000,  C:\path\to\winnie\harnessgen\lib\pin\toy_example.exe
1  , 1  , 0x2d5f0000, 0x2d8b8000, 0x5abf0710, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\KERNELBASE.dll
2  , 2  , 0x2f980000, 0x2fa3e000, 0x5f3170d0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\KERNEL32.DLL
3  , 3  , 0x2fc30000, 0x2fe25000, 0x2fc30000, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SYSTEM32\ntdll.dll
4  , 4  , 0x2d8c0000, 0x2d9c0000, 0x5b196110, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\ucrtbase.dll
5  , 5  , 0x204b0000, 0x204cb000, 0x4096fe30, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SYSTEM32\VCRUNTIME140.dll
6  , 6  , 0x00000000, 0x00085000, 0x0003f6bc, 0000000000000000, 0x00000000, 0x00000000,  C:\vendor\conemu-maximus5\ConEmu\ConEmuHk64.dll
7  , 7  , 0x2e7b0000, 0x2e950000, 0x5cf77f30, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\USER32.dll
8  , 8  , 0x2d9c0000, 0x2d9e2000, 0x2d9c0000, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\win32u.dll
9  , 9  , 0x2f950000, 0x2f97b000, 0x5f2a48d0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\GDI32.dll
10 , 10 , 0x2da90000, 0x2db9d000, 0x5b550af0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\gdi32full.dll
11 , 11 , 0x2d9f0000, 0x2da8d000, 0x5b3f5390, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\msvcp_win.dll
12 , 12 , 0x2f1e0000, 0x2f210000, 0x5e3c14d0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\IMM32.DLL
13 , 13 , 0x21880000, 0x21888000, 0x43101540, 0000000000000000, 0x00000000, 0x00000000,  C:\path\to\winnie\harnessgen\lib\pin\example_library.dll

The following is the result of running the synthesizer.py against "C:\Windows\System32\KERNELBASE.dll" .

$ python3 synthesizer.py harness -t drltrace.PID.log -d memdump -s "C:\Windows\System32\KERNELBASE.dll"
Traceback (most recent call last):
  File "C:\path\to\winnie\harnessgen\synthesizer.py", line 147, in <module>
    main()
  File "C:\path\to\winnie\harnessgen\synthesizer.py", line 135, in main
    syn = SingleSynthesizer(args.trace_file, args.dump_dir,
  File "C:\path\to\winnie\harnessgen\common.py", line 472, in __init__
    self.start_cid, self.trace_tid = ret_start_point(self.trace_pn, self.start_func.encode())
  File "C:\path\to\winnie\harnessgen\common.py", line 33, in ret_start_point
    cid = int(line.split(b"CALLID[")[1].split(b"]")[0])
IndexError: list index out of range
exit status 1

winnie/harnessgen/common.py

Lines 23 to 37 in b046bce

	def ret_start_point(pn: str, keyword: bytes):
	"""
	1) return cid and tid from this example line
	CALLID[3] TID[3756] IJ T2M 0x63621040->0x65cf6450(avformat-gp-57.dll!avformat_open_input+0x0)
	2) for now, this function is case sensitive
	"""
	with open(pn, 'rb') as f:
	lines = f.readlines()
	for line in lines:
	if keyword in line and b"0x0" in line:
	cid = int(line.split(b"CALLID[")[1].split(b"]")[0])
	tid = int(line.split(b"TID[")[1].split(b"]")[0])
	return cid, tid
	raise Exception("Cannot find the starting function from the trace file")

The ret_start_point method should return cid and tid, but where are the cid and tid in this drltrace.PID.log?

1  , 1  , 0x2d5f0000, 0x2d8b8000, 0x5abf0710, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\KERNELBASE.dll

If there is any incorrect use of the above, please let us know.

Thanks.

[gonbbb]

I apologize for sending this while editing.

[Jinmo]

Hello, that line is shown at the end of the execution, not for each call. It seems like no calls are detected from your setting, likely because the library is not detected using \path\to\example_library.dll; try replacing it to example_library.dll in the parameters.

[gonbbb]

@Jinmo
I run the one-trace command without the /path/to part(example_library.dll), memdump(.pre, .post), CALLID, and TID appear.

Thank you.

[gonbbb]

@Jinmo

The following is the result of running the synthesizer.py against "GetCurrentProcess" .
It is because return None at find_module().
(The same result was obtained when calling -s memcpy, e.g.)

Is this a mistake in the way the command is executed?

I apologize for asking so many questions.

$ python3 synthesizer.py harness -t drltrace.PID.log -d memdump -s "GetCurrentProcess"
Traceback (most recent call last):
  File "\path\to\winnie\harnessgen\synthesizer.py", line 147, in <module>
    main()
  File "\path\to\winnie\harnessgen\synthesizer.py", line 135, in main
    syn = SingleSynthesizer(args.trace_file, args.dump_dir,
  File "\path\to\winnie\harnessgen\common.py", line 485, in __init__
    self.defined_types, self.defined_funcs = self.typedef()
  File "\path\to\winnie\harnessgen\common.py", line 518, in typedef
    assert mod
AssertionError
exit status 1

winnie/harnessgen/common.py

Lines 297 to 302 in b046bce

	def find_module(self, address: int) -> typing.Tuple[typing.Union[bytes, None], int, int]:
	for path, (base, end) in self.modules.items():
	if base <= address <= end:
	return path, base, end
	return None, 0, 0

The contents of drltrace.PID.log is the following.

CHECKING MODULE...
TARGET MODULE START ADDR:0x140000000
TARGET MODULE END ADDR: 0x14000f000 ? ??:0
LIBRARY MODULE START ADDR:0x7ffe229c0000
LIBRARY MODULE END ADDR: 0x7ffe229c8000 ? ??:0
==
CALLID[0] TID[0] IC T2M @0x1400014c5(\path\to\winnie\harnessgen\lib\pin\toy_example.exe!unnamedImageEntryPoint+0x380)->0x7ffe229c1070(\path\to\winnie\harnessgen\lib\pin\example_library.dll!test+0x0)
 -A0: 0x50fb40[DP] > 0x51bfa0[DP] > 0x6c6c6548 (str:Hell)
 -A1: 0x7ffe229c1070[CP] > 0x83485340
 -A2: 0x0
 -A3: 0x0
 -A4: 0x57202c6f6c6c6548
 -A5: 0xa0d21646c726f
 -A6: 0x0
 -A7: 0x0
 -A8: 0x0
 -A9: 0x0
==
RETID[0] TID[0] RET2T 0x7ffe229c11df(\path\to\winnie\harnessgen\lib\pin\example_library.dll!test+0x16f)->0x1400014c7(\path\to\winnie\harnessgen\lib\pin\toy_example.exe!unnamedImageEntryPoint+0x382)
RETVAL: 0x0


==
Module Table: version 4, count 14
0  , 0  , 0x40000000, 0x4000f000, 0x80001145, 0000000000000000, 0x00000000, 0x00000000,  \path\to\winnie\harnessgen\lib\pin\toy_example.exe
1  , 1  , 0x2d5f0000, 0x2d8b8000, 0x5abf0710, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\KERNELBASE.dll
2  , 2  , 0x2f980000, 0x2fa3e000, 0x5f3170d0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\KERNEL32.DLL
3  , 3  , 0x2fc30000, 0x2fe25000, 0x2fc30000, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SYSTEM32\ntdll.dll
4  , 4  , 0x2d8c0000, 0x2d9c0000, 0x5b196110, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\ucrtbase.dll
5  , 5  , 0x204b0000, 0x204cb000, 0x4096fe30, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SYSTEM32\VCRUNTIME140.dll
6  , 6  , 0x00000000, 0x00085000, 0x0003f6bc, 0000000000000000, 0x00000000, 0x00000000,  C:\vendor\conemu-maximus5\ConEmu\ConEmuHk64.dll
7  , 7  , 0x2e7b0000, 0x2e950000, 0x5cf77f30, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\USER32.dll
8  , 8  , 0x2d9c0000, 0x2d9e2000, 0x2d9c0000, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\win32u.dll
9  , 9  , 0x2f950000, 0x2f97b000, 0x5f2a48d0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\GDI32.dll
10 , 10 , 0x2da90000, 0x2db9d000, 0x5b550af0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\gdi32full.dll
11 , 11 , 0x2d9f0000, 0x2da8d000, 0x5b3f5390, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\msvcp_win.dll
12 , 12 , 0x2f1e0000, 0x2f210000, 0x5e3c14d0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\IMM32.DLL
13 , 13 , 0x229c0000, 0x229c8000, 0x45381540, 0000000000000000, 0x00000000, 0x00000000,  \path\to\winnie\harnessgen\lib\pin\example_library.dll

---

p.s.

I run dumpbin command and extract function in DLL. (Visual Studio 2022)
The " -s test" case was also run, with the same results as above.
(full: $ python3 synthesizer.py harness -t drltrace.PID.log -d memdump -s "test")

>dumpbin /exports example_library.dll
Microsoft (R) COFF/PE Dumper Version 14.31.31104.0
Copyright (C) Microsoft Corporation.  All rights reserved.


Dump of file example_library.dll

File Type: DLL

  Section contains the following exports for example_library.dll

    00000000 characteristics
    FFFFFFFF time date stamp
        0.00 version
           1 ordinal base
           1 number of functions
           1 number of names

    ordinal hint RVA      name

          1    0 00001070 test

  Summary

        1000 .data
        1000 .pdata
        1000 .rdata
        1000 .reloc
        1000 .rsrc
        2000 .text

[Jinmo]

It seems like a bug in library_trace.cpp; can you try replacing the following lines

winnie/harnessgen/lib/Tracer/library_trace.cpp

Lines 1475 to 1476 in b046bce

	fprintf(out, "%-3d, %-3d, 0x%08x, 0x%08x, 0x%08x, %016x, 0x%08x, 0x%08x, %s\n",
	index, index, item.start, item.end, item.entry, item.r1, item.r2, item.r3, item.path.c_str());

to

		fprintf(out, "%-3d, %-3d, 0x%08lx, 0x%08lx, 0x%08lx, %016lx, 0x%08lx, 0x%08lx,  %s\n",
			index, index, item.start, item.end, item.entry, item.r1, item.r2, item.r3, item.path.c_str());

?

[gonbbb]

It is worked by your replacing, thank you.
However, the target address of function(e.g. @0x1400014c5, from. #20 (comment)) is obviously larger than the address in the DLL.

CALLID[0] TID[0] IC T2M @0x1400014c5(\path\to\winnie\harnessgen\lib\pin\toy_example.exe!unnamedImageEntryPoint+0x380)->0x7ffe229c1070(\path\to\winnie\harnessgen\lib\pin\example_library.dll!test+0x0)

This is because I built on x64.

So I built both Tracer and toy_example on x86, and the assertion(at typedef) was not trapped.
Is the address space for 32bit in the current scripts? Or is it target-dependent?

---

p.s.

The contents of drltrace.PID.log, built on x86 toy_example

CHECKING MODULE...
TARGET MODULE START ADDR:0x400000
TARGET MODULE END ADDR: 0x405000 ? ??:0
LIBRARY MODULE START ADDR:0x58ee0000
LIBRARY MODULE END ADDR: 0x58ee6000 ? ??:0
==
CALLID[0] TID[0] IC T2M @0x401068(\path\to\winnie\harnessgen\lib\pin\toy_example.exe!fuzz_me+0x68)->0x58ee1040(\path\to\winnie\harnessgen\lib\pin\example_library.dll!test+0x0)
 -A0: 0x19fe4c[DP] > 0x746574[DP] > 0x0
 -A1: 0x5af378[DP] > 0x5af384[DP] > 0x555c3a43 (str:C:\U)
 -A2: 0x746574[DP] > 0x0
 -A3: 0x0
 -A4: 0x0
 -A5: 0x0
 -A6: 0x0
 -A7: 0x0
 -A8: 0x0
 -A9: 0x0
==
RETID[0] TID[0] RET2T 0x58ee10cc(\path\to\winnie\harnessgen\lib\pin\example_library.dll!test+0x8c)->0x40106a(\path\to\winnie\harnessgen\lib\pin\toy_example.exe!fuzz_me+0x6a)
RETVAL: 0x0


==
Module Table: version 4, count 14
0  , 0  , 0x00400000, 0x00405000, 0x00801425, 0000000000000000, 0x00000000, 0x00000000,  \path\to\winnie\harnessgen\lib\pin\toy_example.exe
1  , 1  , 0x76380000, 0x76594000, 0xec816050, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\KernelBase.dll
2  , 2  , 0x765b0000, 0x766a0000, 0xecb7f640, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\kernel32.dll
3  , 3  , 0x77130000, 0x772d3000, 0x77130000, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\ntdll.dll
4  , 4  , 0x75700000, 0x75820000, 0xeae2ba30, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\ucrtbase.dll
5  , 5  , 0x74fe0000, 0x74ff5000, 0xe9fcee10, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\vcruntime140.dll
6  , 6  , 0x7e110000, 0x7e17e000, 0xfc254566, 0000000000000000, 0x00000000, 0x00000000,  C:\vendor\conemu-maximus5\ConEmu\ConEmuHk.dll
7  , 7  , 0x76120000, 0x762bc000, 0xec27ce50, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\user32.dll
8  , 8  , 0x75a60000, 0x75a78000, 0x75a60000, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\win32u.dll
9  , 9  , 0x756a0000, 0x756c4000, 0xead474a0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\gdi32.dll
10 , 10 , 0x768d0000, 0x769ac000, 0xed1ffe90, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\gdi32full.dll
11 , 11 , 0x75820000, 0x7589b000, 0xeb057800, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\msvcp_win.dll
12 , 12 , 0x756d0000, 0x756f5000, 0xeada4410, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SysWOW64\imm32.dll
13 , 13 , 0x58ee0000, 0x58ee6000, 0xb1dc14e6, 0000000000000000, 0x00000000, 0x00000000,  \path\to\winnie\harnessgen\lib\pin\example_library.dll

[ElaineYao]

Hello @gonbbb and @Jinmo, I am writing to ask for your help with a similar issue that I'm facing. I followed the code replacement suggestion provided in #20 (comment), but I'm still experiencing the Assertion Error. Specifically, after running the command $ python3 synthesizer.py harness -t drltrace.PID.log -d memdump -s "test", I received the following outputs:

Traceback (most recent call last):
  File "\path\to\winnie\harnessgen\synthesizer.py", line 147, in <module>
    main()
  File "\path\to\winnie\harnessgen\synthesizer.py", line 135, in main
    syn = SingleSynthesizer(args.trace_file, args.dump_dir,
  File "\path\to\winnie\harnessgen\common.py", line 485, in __init__
    self.defined_types, self.defined_funcs = self.typedef()
  File "\path\to\winnie\harnessgen\common.py", line 518, in typedef
    assert mod
AssertionError
exit status 1

I was wondering if you have some idea of why this is happening and the possible solutions. Any advice would be helpful. Thanks in advance!

The drltracePID.log file is also attached:

CHECKING MODULE...
TARGET MODULE START ADDR:0x140000000
TARGET MODULE END ADDR: 0x14000e000 ? ??:0
TARGET MODULE START ADDR:0x140000000
TARGET MODULE END ADDR: 0x14000e000 ? ??:0
LIBRARY MODULE START ADDR:0x7ff8c81f0000
LIBRARY MODULE END ADDR: 0x7ff8c81f8000 ? ??:0
==
CALLID[0] TID[0] IC T2M @0x140001495(\path\to\winnie\harnessgen\lib\pin\toy_example.exe!fuzz_me+0x75)->0x7ff8c81f1070(\path\to\winnie\harnessgen\lib\pin\example_library.dll!test+0x0)
 -A0: 0x481a70[DP] > 0x484060[DP] > 0x746574[DP] > 0x0
 -A1: 0x7ff8c81f1070[CP] > 0x83485340
 -A2: 0x0
 -A3: 0x0
 -A4: 0x746574[DP] > 0x0
 -A5: 0x0
 -A6: 0x0
 -A7: 0x0
 -A8: 0x0
 -A9: 0x0
==
RETID[0] TID[0] RET2T 0x7ff8c81f11ff(\path\to\winnie\harnessgen\lib\pin\example_library.dll!test+0x18f)->0x140001497(\path\to\winnie\harnessgen\lib\pin\toy_example.exe!fuzz_me+0x77)
RETVAL: 0x0


==
Module Table: version 4, count 9
0  , 0  , 0x40000000, 0x4000e000, 0x8000100f, 0000000000000000, 0x00000000, 0x00000000,  \path\to\winnie\harnessgen\lib\pin\toy_example.exe
1  , 1  , 0xcace0000, 0xcafb2000, 0x959d6750, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\KERNELBASE.dll
2  , 2  , 0xcba20000, 0xcbadf000, 0x974576b0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\KERNEL32.DLL
3  , 3  , 0xcd370000, 0xcd568000, 0xcd370000, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SYSTEM32\ntdll.dll
4  , 4  , 0xcb200000, 0xcb300000, 0x96416110, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\ucrtbase.dll
5  , 5  , 0xbf2e0000, 0xbf2fb000, 0x7e5cff90, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\SYSTEM32\VCRUNTIME140.dll
6  , 6  , 0xcbe30000, 0xcbecc000, 0x97c7ce10, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\sechost.dll
7  , 7  , 0xcb3b0000, 0xcb4d5000, 0x967bf0a0, 0000000000000000, 0x00000000, 0x00000000,  C:\Windows\System32\RPCRT4.dll
8  , 8  , 0xc81f0000, 0xc81f8000, 0x903e1574, 0000000000000000, 0x00000000, 0x00000000,  \path\to\winnie\harnessgen\lib\pin\example_library.dll