Function parameters are reported, but not the name

[hasherezade]

In case if a function has parameter tracking enabled, but it is called from a shellcode that is not traced, its parameters are reported, but not the name.

Example:

5ed0d;called: ?? [ca83000+fa8]
6a78;ntdll.NtdllDefWindowProc_A
1ee5b;user32.[CallNextHookEx+b1]*
	Arg[0] = ptr 0x0ca837c4 -> "lVali"
	Arg[1] = 0x00000004 = 4
	Arg[2] = 0

	Arg[0] = ptr 0x00cc0004 -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[1] = ptr 0x0dcc2a3c -> "https://[removed]"
	Arg[2] = 0
	Arg[3] = 0

	Arg[0] = ptr 0x00cc000c -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[1] = 0x00000013 = 19
	Arg[2] = ptr 0x0ca86a14 -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[3] = ptr 0x0ca86c1c -> {\x01\x02\x00\x00\x00\x00\x00\x00}

	Arg[0] = ptr 0x0ca83b4c -> "aswe"
	Arg[1] = 0
	Arg[2] = 0

Used settings:
TinyTracer.ini

ENABLE_SHORT_LOGGING=True
FOLLOW_SHELLCODES=1
;FOLLOW_SHELLCODES:
; 0 : trace only the main target module
; 1 : follow only the first shellcode called from the main module
; 2 : follow also the shellcodes called recursively from the the original shellcode
; 3 : follow any shellcodes
TRACE_RDTSC=False
LOG_SECTIONS_TRANSITIONS=True
LOG_SHELLCODES_TRANSITIONS=False
HEXDUMP_SIZE=8
HOOK_SLEEP=False
SLEEP_TIME=10
LOG_INDIRECT_CALLS=False

params.txt

wininet;InternetOpenA;3
wininet;InternetOpenUrlA;4

Sample:

• d0b854dcea72fd8db68478961d30c52ce1f3aa56ecb5589e3cacb496edb147ab

[hasherezade]

The reason of this behavior is, the tags (including the called function name) are produced by the function _SaveTransitions:

tiny_tracer/TinyTracer.cpp

Line 98 in ae72aa3

VOID _SaveTransitions(const ADDRINT addrFrom, const ADDRINT addrTo)

which takes as an argument EIP from where the function was called. This EIP is then checked against the list of the traced shellcodes. If the EIP is within the traced area, the call is logged.

On the other hand, the arguments trace is produced by the function LogFunctionArgs called by:

tiny_tracer/TinyTracer.cpp

Lines 398 to 427 in ae72aa3

	VOID MonitorFunctionArgs(IMG Image, const WFuncInfo &funcInfo)
	{
	const CHAR* fName = funcInfo.funcName.c_str();
	size_t argNum = funcInfo.paramCount;
	RTN funcRtn = RTN_FindByName(Image, fName);
	if (!RTN_Valid(funcRtn) || !funcInfo.isValid()) return; // failed
	std::cout << "Watch " << IMG_Name(Image) << ": " << fName << " [" << argNum << "]\n";
	RTN_Open(funcRtn);
	RTN_InsertCall(funcRtn, IPOINT_BEFORE, AFUNPTR(LogFunctionArgs),
	IARG_RETURN_IP,
	IARG_ADDRINT, fName,
	IARG_UINT32, argNum,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 0,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 1,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 2,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 3,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 4,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 5,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 6,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 7,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 8,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 9,
	IARG_FUNCARG_ENTRYPOINT_VALUE, 10,
	IARG_END
	);
	RTN_Close(funcRtn);
	}

where not the call EIP is passed, but the return EIP:

    RTN_InsertCall(funcRtn, IPOINT_BEFORE, AFUNPTR(LogFunctionArgs),
        IARG_RETURN_IP,
        IARG_ADDRINT, fName,

The inserted function will be used as a callback when the execution entered into the monitored function. Pin provides no way to pass the EIP of the line that executed the call, only the EIP where it will return.

So, in the situation where the call was made not from the EIP that is within the trace shellcode, but yet it returns to the traced shellcode, the parameters will be logged, but not the origin.

Example:

> cbe3000+704;called: ?? [cbdc000+9b0] 
> cbdc000+9b0;wininet.InternetOpenA
RET: cbe3000 + 709

It happens because the call is implemented by CALL-JMP:

0CBE3704 | E8 A792FFFF | call <JMP.&InternetOpenA> |  

and the jump table is in another allocated region:

0CBDC9B0 | FF25 CC72BE0C | jmp dword ptr ds:[<&InternetOpenA>] | JMP.&InternetOpenA

[hasherezade]

After the changes, if the call is done from an untraced shellcode, but it returns to the traced area, the return will be logged.
Example:

6a78;ntdll.NtdllDefWindowProc_A
1ee5b;user32.[CallNextHookEx+b1]*
> cbf3000+ff1;RET from: [cbe6000+610] -> user32.GetMessageA
> cbf3000+709;RET from: [cbec000+9b0] -> wininet.InternetOpenA
	Arg[0] = ptr 0x0cbf37c4 -> "lVali"
	Arg[1] = 0x00000004 = 4
	Arg[2] = 0

> cbf3000+72c;RET from: [cbec000+9b8] -> wininet.InternetOpenUrlA
	Arg[0] = ptr 0x00cc0004 -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[1] = ptr 0x0dee2a3c -> "https://[removed]"
	Arg[2] = 0
	Arg[3] = 0

> cbf3000+76b;RET from: [cbec000+9a0] -> wininet.HttpQueryInfoA
	Arg[0] = ptr 0x00cc000c -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[1] = 0x00000013 = 19
	Arg[2] = ptr 0x0cbf6a14 -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[3] = ptr 0x0cbf6c1c -> {\x01\x02\x00\x00\x00\x00\x00\x00}

> cbf3000+7b3;RET from: [cbec000+9a8] -> wininet.InternetCloseHandle
> cbf3000+7be;RET from: [cbec000+9a8] -> wininet.InternetCloseHandle
> cbf3000+a63;RET from: [cbec000+9b0] -> wininet.InternetOpenA
	Arg[0] = ptr 0x0cbf3b4c -> "aswe"
	Arg[1] = 0
	Arg[2] = 0

If we enable tracing all the shellcodes (i.e. FOLLOW_SHELLCODES=3), and now the calling element will be among the traced shellcodes, the call will be logged as before:

> cbe1000+304;kernel32.VirtualFree
> cbec000+9b0;wininet.InternetOpenA
	Arg[0] = ptr 0x0cbf37c4 -> "lVali"
	Arg[1] = 0x00000004 = 4
	Arg[2] = 0

> cbec000+9b8;wininet.InternetOpenUrlA
	Arg[0] = ptr 0x00cc0004 -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[1] = ptr 0x0d982a3c -> "https://[removed]"
	Arg[2] = 0
	Arg[3] = 0

> cbec000+9a0;wininet.HttpQueryInfoA
	Arg[0] = ptr 0x00cc000c -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[1] = 0x00000013 = 19
	Arg[2] = ptr 0x0cbf6a14 -> {\x00\x00\x00\x00\x00\x00\x00\x00}
	Arg[3] = ptr 0x0cbf6c1c -> {\x01\x02\x00\x00\x00\x00\x00\x00}

> cbec000+9a8;wininet.InternetCloseHandle
> cbec000+9a8;wininet.InternetCloseHandle
> cbec000+9b0;wininet.InternetOpenA
	Arg[0] = ptr 0x0cbf3b4c -> "aswe"
	Arg[1] = 0
	Arg[2] = 0