From 23e1777054f2a801ce14991793cf68b577717deb Mon Sep 17 00:00:00 2001 From: Bernhard Loos <bernhardloos@googlemail.com> Date: Thu, 1 Sep 2011 09:21:06 +0200 Subject: [PATCH] ntdll: Provide a timestamp debug channel, which prints a millisecond resolution timestamp in front of debug output. --- dlls/ntdll/debugtools.c | 8 +++++++- dlls/ntdll/relay.c | 16 ++++++++++++++++ 2 files changed, 23 insertions(+), 1 deletion(-) diff --git a/dlls/ntdll/debugtools.c b/dlls/ntdll/debugtools.c index cb0828502bd..dfb44af3913 100644 --- a/dlls/ntdll/debugtools.c +++ b/dlls/ntdll/debugtools.c @@ -39,6 +39,7 @@ #include "ntdll_misc.h" WINE_DECLARE_DEBUG_CHANNEL(tid); +WINE_DECLARE_DEBUG_CHANNEL(timestamp); static struct __wine_debug_functions default_funcs; @@ -164,8 +165,13 @@ static int NTDLL_dbg_vlog( enum __wine_debug_class cls, struct __wine_debug_chan /* only print header if we are at the beginning of the line */ if (info->out_pos == info->output || info->out_pos[-1] == '\n') { + if (TRACE_ON(timestamp)) + { + ULONG ticks = NtGetTickCount(); + ret = wine_dbg_printf( "%3u.%03u:", ticks / 1000, ticks % 1000 ); + } if (TRACE_ON(tid)) - ret = wine_dbg_printf( "%04x:", GetCurrentThreadId() ); + ret += wine_dbg_printf( "%04x:", GetCurrentThreadId() ); if (cls < sizeof(classes)/sizeof(classes[0])) ret += wine_dbg_printf( "%s:%s:%s ", classes[cls], channel->name, function ); } diff --git a/dlls/ntdll/relay.c b/dlls/ntdll/relay.c index 4855a0003d1..3bf7791820d 100644 --- a/dlls/ntdll/relay.c +++ b/dlls/ntdll/relay.c @@ -37,6 +37,7 @@ #include "wine/debug.h" WINE_DEFAULT_DEBUG_CHANNEL(relay); +WINE_DECLARE_DEBUG_CHANNEL(timestamp); #if defined(__i386__) || defined(__x86_64__) @@ -396,6 +397,13 @@ __ASM_GLOBAL_FUNC( call_entry_point, #endif +static void print_timestamp(void) +{ + ULONG ticks = NtGetTickCount(); + DPRINTF( "%3u.%03u:", ticks / 1000, ticks % 1000 ); +} + + /*********************************************************************** * relay_call * @@ -414,6 +422,8 @@ static LONGLONG WINAPI relay_call( struct relay_descr *descr, unsigned int idx, ret = call_entry_point( entry_point->orig_func, nb_args, stack + 1, flags ); else { + if (TRACE_ON(timestamp)) + print_timestamp(); if (entry_point->name) DPRINTF( "%04x:Call %s.%s(", GetCurrentThreadId(), data->dllname, entry_point->name ); else @@ -423,6 +433,8 @@ static LONGLONG WINAPI relay_call( struct relay_descr *descr, unsigned int idx, ret = call_entry_point( entry_point->orig_func, nb_args, stack + 1, flags ); + if (TRACE_ON(timestamp)) + print_timestamp(); if (entry_point->name) DPRINTF( "%04x:Ret %s.%s()", GetCurrentThreadId(), data->dllname, entry_point->name ); else @@ -933,6 +945,8 @@ void WINAPI __regs_SNOOP_Entry( CONTEXT *context ) context->Eip = (DWORD)fun->origfun; + if (TRACE_ON(timestamp)) + print_timestamp(); if (fun->name) DPRINTF("%04x:CALL %s.%s(",GetCurrentThreadId(),dll->name,fun->name); else DPRINTF("%04x:CALL %s.%d(",GetCurrentThreadId(),dll->name,dll->ordbase+ordinal); if (fun->nrofargs>0) { @@ -967,6 +981,8 @@ void WINAPI __regs_SNOOP_Return( CONTEXT *context ) if (ret->dll->funs[ret->ordinal].nrofargs<0) ret->dll->funs[ret->ordinal].nrofargs=(context->Esp - ret->origESP-4)/4; context->Eip = (DWORD)ret->origreturn; + if (TRACE_ON(timestamp)) + print_timestamp(); if (ret->args) { int i,max; -- GitLab