Function call graph from Temu trace

[Hossein Hadian Jazi]

I want to generate function call graph from the TEMU trace. I found trace_reader in utils which generate a .out file. It seems the out file is a function call graph.

The command that I am using is as follows:

$./vine - 1.0/trace_utils/trace_reader - trace font.trace - fmap font.trace.functions - flog font.trace.functions.out - funlist font.trace.list.functions - modlist font.trace.modlist.function > font.trace.disasm

I have some questions related to this:

1- Is the out file is function call graph of the trace? 

2- If yes I did not get it's structure! the structure is similar to this:(I attached two sample file)

000004 584 CALL ntdll.dll::LdrInitializeThunk (102)

000014 584 CALL ntdll.dll::sub_7C9226FC (103)

000028 584 CALL ntdll.dll::sub_7C9222E9 (104)

000035 584 CALL ntdll.dll::sub_7C9199D7 (105)

000038 584 CALL ntdll.dll::sub_7C90E8AB (106)

000057 584 RET ntdll.dll::sub_7C90E8AB (106)

000077 584 CALL ntdll.dll::sub_7C90E8E6 (106)

000086 584 RET ntdll.dll::sub_7C90E8E6 (106)

000087 584 RET ntdll.dll::sub_7C9199D7 (105)

000092 584 RET ntdll.dll::sub_7C9222E9 (104)

000095 584 RET ntdll.dll::sub_7C9226FC (103)

000101 584 CALL ntdll.dll::sub_7C90E8AB (103)

000120 584 RET ntdll.dll::sub_7C90E8AB (103)

000147 584 CALL ntdll.dll::sub_7C92280E (103)

000165 584 CALL ntdll.dll::sub_7C91CABA (104)

000183 584 CALL ntdll.dll::RtlAppendUnicodeToString (105)

000195 584 CALL ntdll.dll::RtlInitUnicodeString (106)

000307 584 RET ntdll.dll::RtlInitUnicodeString (106)

000324 584 CALL ntdll.dll::memmove (106)

000394 584 RET ntdll.dll::memmove (106)

What I did not understand are the first two columns! Specially the second column which is the same number in all rows for my output. Does it mean 584 calls all of functions?? (also there is no function with the label of 584)

If 584 is not caller of functions how can I extract caller-callee relationship?

Thanks in advance.

Hossein

[Stephen McCamant]

>>>>> "HHJ" == Hossein Hadian Jazi <hadianjaz...@gmail.com> writes:

HHJ> I want to generate function call graph from the TEMU trace. I
HHJ> found trace_reader in utils which generate a .out file. It seems
HHJ> the out file is a function call graph.

HHJ> The command that I am using is as follows:
HHJ> $./vine - 1.0/trace_utils/trace_reader - trace font.trace - fmap
HHJ> font.trace.functions - flog font.trace.functions.out - funlist
HHJ> font.trace.list.functions - modlist font.trace.modlist.function >
HHJ> font.trace.disasm

HHJ> I have some questions related to this:

HHJ> 1- Is the out file is function call graph of the trace?

It is a log of calls and returns, so it's related to a call graph, but
not quite the same. It's just linearly structured, not graph
structured: if a function is called multiple times, there will be
multiple entries in the log. Order is significant: the entries are in
chronological order. And the log doesn't explicitly name the caller,
only the function being called or the function being returned from. It
only shows calls and returns that actually occurred during the trace,
not other ones that could happen. And it only knows the names for
functions that appear in the file you pass as the argument to -fmap,
so you only see names for exported symbols.

HHJ> 2- If yes I did not get it's structure! the structure is similar
HHJ> to this:(I attached two sample file)

HHJ> 000004 584 CALL ntdll.dll::LdrInitializeThunk (102)
HHJ> 000014 584 CALL ntdll.dll::sub_7C9226FC (103)
HHJ> 000028 584 CALL ntdll.dll::sub_7C9222E9 (104)
HHJ> 000035 584 CALL ntdll.dll::sub_7C9199D7 (105)
HHJ> 000038 584 CALL ntdll.dll::sub_7C90E8AB (106)
HHJ> 000057 584 RET ntdll.dll::sub_7C90E8AB (106)

HHJ> What I did not understand are the first two columns! Specially
HHJ> the second column which is the same number in all rows for my
HHJ> output. Does it mean 584 calls all of functions?? (also there is
HHJ> no function with the label of 584) If 584 is not caller of
HHJ> functions how can I extract caller-callee relationship?

The code that generates this log is in the function print_fun_info in
trace_reader.ml.

The first column is the position of each call or return instruction in
the sequence of all trace entries. The second column is a thread
identifier: if it's always the same, that indicates your program was
single-threaded. For Windows programs TEMU figures out the thread ID
based on information accessible from the %fs segment; you can see the
implementation as get_current_tid() in shared/procmod.cpp. The final
number in parentheses is the height of the call/return stack, where
the initial height is set arbitrarily, either the argument to
-funstacksize or a default of 100.

To figure out the caller-callee relationships you need to do a
sequential pass over the log maintaining a shadow call stack. If you
push a function name on the stack on a CALL and pop off the top of the
stack on a RET, then at each CALL, the entry on the top of the stack
before the instruction is the caller.

Hope this helps,

-- Stephen

[Hossein Hadian Jazi]

Thanks a lot for your answer. It was very helpful.

[Hossein Hadian Jazi]

Hi Stephen,

I have another question. As I see TEMU trace distinguish between local function calls and imported function calls like these two lines:

local call:

7c911470: call   0x000000007c90e8ab J@0x00000000[0xffffd43b][4](R) T0 M@0x0022fac4[0x0022fd0c][4](W) T0 ntdll.dll::sub_7C90E8AB (108)

external call:

7c921c29: call   0x000000007c914f8f J@0x00000000[0xffff3366][4](R) T0 M@0x0022fb18[0x0022fc94][4](W) T0 ntdll.dll::RtlAppendUnicodeStringToString (104)

Could you please tell me how TEMU distinguish between them? I have some traces and want to do these kind of differentiation but I do not know how can I do that?

Thanks in advance.

On Wednesday, 17 June 2015 13:54:33 UTC-3, Stephen McCamant wrote: