[PATCH v3 0/3] MR2274: ntdll: Add source file and line to debug traces.
-- v3: ntdll: Add return address information in __wine_debug_context. ntdll: Add file and line information in __wine_debug_context. ntdll: Introduce struct __wine_debug_context for extensible debug info. https://gitlab.winehq.org/wine/wine/-/merge_requests/2274
From: Rémi Bernon <rbernon(a)codeweavers.com> --- dlls/ntdll/thread.c | 12 ++++++++++-- dlls/ntdll/unix/debug.c | 12 ++++++++++-- dlls/winecrt0/debug.c | 24 +++++++++++++++--------- include/wine/debug.h | 20 +++++++++++++++++--- 4 files changed, 52 insertions(+), 16 deletions(-) diff --git a/dlls/ntdll/thread.c b/dlls/ntdll/thread.c index b0b61419e37..ed26c69908b 100644 --- a/dlls/ntdll/thread.c +++ b/dlls/ntdll/thread.c @@ -132,7 +132,7 @@ const char * __cdecl __wine_dbg_strdup( const char *str ) * __wine_dbg_header (NTDLL.@) */ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *function ) + const struct __wine_debug_context *context ) { static const char * const classes[] = { "fixme", "err", "warn", "trace" }; struct debug_info *info = get_info(); @@ -150,9 +150,17 @@ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_ } if (TRACE_ON(pid)) pos += sprintf( pos, "%04lx:", GetCurrentProcessId() ); pos += sprintf( pos, "%04lx:", GetCurrentThreadId() ); - if (function && cls < ARRAY_SIZE( classes )) + if (context && cls < ARRAY_SIZE( classes )) + { + const char *function; + + if (context->compat) function = (const char *)context; + else if (context->version != WINE_DEBUG_CONTEXT_VERSION) function = ""; + else function = context->function; + pos += snprintf( pos, sizeof(info->output) - (pos - info->output), "%s:%s:%s ", classes[cls], channel->name, function ); + } info->out_pos = pos - info->output; return info->out_pos; } diff --git a/dlls/ntdll/unix/debug.c b/dlls/ntdll/unix/debug.c index bc0e3c1c694..7ee57544af2 100644 --- a/dlls/ntdll/unix/debug.c +++ b/dlls/ntdll/unix/debug.c @@ -302,7 +302,7 @@ int __cdecl __wine_dbg_output( const char *str ) * __wine_dbg_header (NTDLL.@) */ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *function ) + const struct __wine_debug_context *context ) { static const char * const classes[] = { "fixme", "err", "warn", "trace" }; struct debug_info *info = get_info(); @@ -323,9 +323,17 @@ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_ if (TRACE_ON(pid)) pos += sprintf( pos, "%04x:", (UINT)GetCurrentProcessId() ); pos += sprintf( pos, "%04x:", (UINT)GetCurrentThreadId() ); } - if (function && cls < ARRAY_SIZE( classes )) + if (context && cls < ARRAY_SIZE( classes )) + { + const char *function; + + if (context->compat) function = (const char *)context; + else if (context->version != WINE_DEBUG_CONTEXT_VERSION) function = ""; + else function = context->function; + pos += snprintf( pos, sizeof(info->output) - (pos - info->output), "%s:%s:%s ", classes[cls], channel->name, function ); + } info->out_pos = pos - info->output; return info->out_pos; } diff --git a/dlls/winecrt0/debug.c b/dlls/winecrt0/debug.c index 2ac4505fb85..82b7db657a7 100644 --- a/dlls/winecrt0/debug.c +++ b/dlls/winecrt0/debug.c @@ -34,9 +34,8 @@ WINE_DECLARE_DEBUG_CHANNEL(timestamp); static const char * (__cdecl *p__wine_dbg_strdup)( const char *str ); static int (__cdecl *p__wine_dbg_output)( const char *str ); static unsigned char (__cdecl *p__wine_dbg_get_channel_flags)( struct __wine_debug_channel *channel ); -static int (__cdecl *p__wine_dbg_header)( enum __wine_debug_class cls, - struct __wine_debug_channel *channel, - const char *function ); +static int (__cdecl *p__wine_dbg_header)( enum __wine_debug_class cls, struct __wine_debug_channel *channel, + const struct __wine_debug_context *context ); static const char * const debug_classes[] = { "fixme", "err", "warn", "trace" }; @@ -178,9 +177,8 @@ static int __cdecl fallback__wine_dbg_output( const char *str ) return fwrite( str, 1, len, stderr ); } -static int __cdecl fallback__wine_dbg_header( enum __wine_debug_class cls, - struct __wine_debug_channel *channel, - const char *function ) +static int __cdecl fallback__wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_channel *channel, + const struct __wine_debug_context *context ) { char buffer[200], *pos = buffer; @@ -196,9 +194,17 @@ static int __cdecl fallback__wine_dbg_header( enum __wine_debug_class cls, } if (TRACE_ON(pid)) pos += sprintf( pos, "%04x:", (UINT)GetCurrentProcessId() ); pos += sprintf( pos, "%04x:", (UINT)GetCurrentThreadId() ); - if (function && cls < ARRAY_SIZE( debug_classes )) + if (context && cls < ARRAY_SIZE( debug_classes )) + { + const char *function; + + if (context->compat) function = (const char *)context; + else if (context->version != WINE_DEBUG_CONTEXT_VERSION) function = ""; + else function = context->function; + snprintf( pos, sizeof(buffer) - (pos - buffer), "%s:%s:%s ", debug_classes[cls], channel->name, function ); + } return fwrite( buffer, 1, strlen(buffer), stderr ); } @@ -243,10 +249,10 @@ unsigned char __cdecl __wine_dbg_get_channel_flags( struct __wine_debug_channel } int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *function ) + const struct __wine_debug_context *context ) { LOAD_FUNC( __wine_dbg_header ); - return p__wine_dbg_header( cls, channel, function ); + return p__wine_dbg_header( cls, channel, context ); } #endif /* __WINE_PE_BUILD */ diff --git a/include/wine/debug.h b/include/wine/debug.h index c20924818dd..985c72866ff 100644 --- a/include/wine/debug.h +++ b/include/wine/debug.h @@ -87,6 +87,14 @@ struct __wine_debug_channel const enum __wine_debug_class __dbcl = __WINE_DBCL##dbcl; \ __WINE_DBG_LOG +struct __wine_debug_context +{ + char compat; /* for backward compatibility */ + int version; /* for forward compatibility */ + const char *function; +}; +#define WINE_DEBUG_CONTEXT_VERSION 1 + #define __WINE_DBG_LOG(...) \ wine_dbg_log( __dbcl, __dbch, __func__, __VA_ARGS__); } } while(0) @@ -113,7 +121,7 @@ extern unsigned char __cdecl __wine_dbg_get_channel_flags( struct __wine_debug_c extern const char * __cdecl __wine_dbg_strdup( const char *str ); extern int __cdecl __wine_dbg_output( const char *str ); extern int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *function ); + const struct __wine_debug_context *context ); /* * Exported definitions and macros @@ -178,14 +186,20 @@ static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, struct __wine_debug_channel *channel, const char *function, const char *format, va_list args ) { + struct __wine_debug_context info = + { + .version = WINE_DEBUG_CONTEXT_VERSION, + .function = function, + }; + struct __wine_debug_context *context = &info; int ret; if (*format == '\1') /* special magic to avoid standard prefix */ { format++; - function = NULL; + context = NULL; } - if ((ret = __wine_dbg_header( cls, channel, function )) != -1) ret += wine_dbg_vprintf( format, args ); + if ((ret = __wine_dbg_header( cls, channel, context )) != -1) ret += wine_dbg_vprintf( format, args ); return ret; } -- GitLab https://gitlab.winehq.org/wine/wine/-/merge_requests/2274
From: Rémi Bernon <rbernon(a)codeweavers.com> --- dlls/msxml3/main.c | 8 ++++---- dlls/windowscodecs/libtiff.c | 4 ++-- include/wine/debug.h | 34 +++++++++++++++++++--------------- 3 files changed, 25 insertions(+), 21 deletions(-) diff --git a/dlls/msxml3/main.c b/dlls/msxml3/main.c index 66e23114bfa..c4234711fa2 100644 --- a/dlls/msxml3/main.c +++ b/dlls/msxml3/main.c @@ -74,7 +74,7 @@ void wineXmlCallbackLog(char const* caller, xmlErrorLevel lvl, char const* msg, len = vsnprintf(buff, max_size, msg, ap); if (len == -1 || len >= max_size) buff[max_size-1] = 0; - wine_dbg_log(dbcl, &__wine_dbch_msxml, caller, "%s", buff); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, "%s", buff); } void wineXmlCallbackError(char const* caller, xmlErrorPtr err) @@ -88,11 +88,11 @@ void wineXmlCallbackError(char const* caller, xmlErrorPtr err) default: dbcl = __WINE_DBCL_ERR; break; } - wine_dbg_log(dbcl, &__wine_dbch_msxml, caller, "error code %d", err->code); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, "error code %d", err->code); if (err->message) - wine_dbg_log(dbcl, &__wine_dbch_msxml, caller, ": %s", err->message); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, ": %s", err->message); else - wine_dbg_log(dbcl, &__wine_dbch_msxml, caller, "\n"); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, "\n"); } /* Support for loading xml files from a Wine Windows drive */ diff --git a/dlls/windowscodecs/libtiff.c b/dlls/windowscodecs/libtiff.c index 1bfc555f116..3173da0ea0b 100644 --- a/dlls/windowscodecs/libtiff.c +++ b/dlls/windowscodecs/libtiff.c @@ -39,14 +39,14 @@ WINE_DECLARE_DEBUG_CHANNEL(tiff); static void tiff_error_handler( const char *module, const char *format, va_list args ) { if (!ERR_ON(tiff)) return; - if (wine_dbg_vlog( __WINE_DBCL_ERR, &__wine_dbch_tiff, module, format, args ) != -1) + if (wine_dbg_vlog( __WINE_DBCL_ERR, &__wine_dbch_tiff, __FILE__, __LINE__, module, format, args ) != -1) __wine_dbg_output( "\n" ); } static void tiff_warning_handler( const char *module, const char *format, va_list args ) { if (!WARN_ON(tiff)) return; - if (wine_dbg_vlog( __WINE_DBCL_WARN, &__wine_dbch_tiff, module, format, args ) != -1) + if (wine_dbg_vlog( __WINE_DBCL_WARN, &__wine_dbch_tiff, __FILE__, __LINE__, module, format, args ) != -1) __wine_dbg_output( "\n" ); } diff --git a/include/wine/debug.h b/include/wine/debug.h index 985c72866ff..c53d8fbd32d 100644 --- a/include/wine/debug.h +++ b/include/wine/debug.h @@ -92,11 +92,13 @@ struct __wine_debug_context char compat; /* for backward compatibility */ int version; /* for forward compatibility */ const char *function; + const char *file; + int line; }; -#define WINE_DEBUG_CONTEXT_VERSION 1 +#define WINE_DEBUG_CONTEXT_VERSION 2 #define __WINE_DBG_LOG(...) \ - wine_dbg_log( __dbcl, __dbch, __func__, __VA_ARGS__); } } while(0) + wine_dbg_log( __dbcl, __dbch, __FILE__, __LINE__, __func__, __VA_ARGS__); } } while(0) #if defined(__MINGW32__) || (!defined(__WINE_USE_MSVCRT) && (defined(__GNUC__) || defined(__clang__))) #define __WINE_PRINTF_ATTR(fmt,args) __attribute__((format (printf,fmt,args))) @@ -179,17 +181,19 @@ static inline int __wine_dbg_cdecl wine_dbg_printf( const char *format, ... ) return ret; } -static int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, - struct __wine_debug_channel *channel, const char *func, - const char *format, va_list args ) __WINE_PRINTF_ATTR(4,0); -static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, - struct __wine_debug_channel *channel, - const char *function, const char *format, va_list args ) +static int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, struct __wine_debug_channel *channel, + const char *file, int line, const char *function, + const char *format, va_list args ) __WINE_PRINTF_ATTR(6,0); +static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, struct __wine_debug_channel *channel, + const char *file, int line, const char *function, + const char *format, va_list args ) { struct __wine_debug_context info = { .version = WINE_DEBUG_CONTEXT_VERSION, .function = function, + .file = file, + .line = line, }; struct __wine_debug_context *context = &info; int ret; @@ -203,18 +207,18 @@ static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, return ret; } -static int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, - struct __wine_debug_channel *channel, const char *func, - const char *format, ... ) __WINE_PRINTF_ATTR(4,5); -static inline int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, - struct __wine_debug_channel *channel, - const char *function, const char *format, ... ) +static int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, struct __wine_debug_channel *channel, + const char *file, int line, const char *function, + const char *format, ... ) __WINE_PRINTF_ATTR(6,7); +static inline int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, struct __wine_debug_channel *channel, + const char *file, int line, const char *function, + const char *format, ... ) { va_list args; int ret; va_start( args, format ); - ret = wine_dbg_vlog( cls, channel, function, format, args ); + ret = wine_dbg_vlog( cls, channel, file, line, function, format, args ); va_end( args ); return ret; } -- GitLab https://gitlab.winehq.org/wine/wine/-/merge_requests/2274
From: Rémi Bernon <rbernon(a)codeweavers.com> --- dlls/msxml3/main.c | 8 ++++---- dlls/windowscodecs/libtiff.c | 4 ++-- include/wine/debug.h | 26 +++++++++++++++++--------- 3 files changed, 23 insertions(+), 15 deletions(-) diff --git a/dlls/msxml3/main.c b/dlls/msxml3/main.c index c4234711fa2..c6b6b51f68a 100644 --- a/dlls/msxml3/main.c +++ b/dlls/msxml3/main.c @@ -74,7 +74,7 @@ void wineXmlCallbackLog(char const* caller, xmlErrorLevel lvl, char const* msg, len = vsnprintf(buff, max_size, msg, ap); if (len == -1 || len >= max_size) buff[max_size-1] = 0; - wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, "%s", buff); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, __WINE_DBG_RETADDR, "%s", buff); } void wineXmlCallbackError(char const* caller, xmlErrorPtr err) @@ -88,11 +88,11 @@ void wineXmlCallbackError(char const* caller, xmlErrorPtr err) default: dbcl = __WINE_DBCL_ERR; break; } - wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, "error code %d", err->code); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, __WINE_DBG_RETADDR, "error code %d", err->code); if (err->message) - wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, ": %s", err->message); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, __WINE_DBG_RETADDR, ": %s", err->message); else - wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, "\n"); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __FILE__, __LINE__, caller, __WINE_DBG_RETADDR, "\n"); } /* Support for loading xml files from a Wine Windows drive */ diff --git a/dlls/windowscodecs/libtiff.c b/dlls/windowscodecs/libtiff.c index 3173da0ea0b..dcaeaaad4fb 100644 --- a/dlls/windowscodecs/libtiff.c +++ b/dlls/windowscodecs/libtiff.c @@ -39,14 +39,14 @@ WINE_DECLARE_DEBUG_CHANNEL(tiff); static void tiff_error_handler( const char *module, const char *format, va_list args ) { if (!ERR_ON(tiff)) return; - if (wine_dbg_vlog( __WINE_DBCL_ERR, &__wine_dbch_tiff, __FILE__, __LINE__, module, format, args ) != -1) + if (wine_dbg_vlog( __WINE_DBCL_ERR, &__wine_dbch_tiff, __FILE__, __LINE__, module, __WINE_DBG_RETADDR, format, args ) != -1) __wine_dbg_output( "\n" ); } static void tiff_warning_handler( const char *module, const char *format, va_list args ) { if (!WARN_ON(tiff)) return; - if (wine_dbg_vlog( __WINE_DBCL_WARN, &__wine_dbch_tiff, __FILE__, __LINE__, module, format, args ) != -1) + if (wine_dbg_vlog( __WINE_DBCL_WARN, &__wine_dbch_tiff, __FILE__, __LINE__, module, __WINE_DBG_RETADDR, format, args ) != -1) __wine_dbg_output( "\n" ); } diff --git a/include/wine/debug.h b/include/wine/debug.h index c53d8fbd32d..77deeb5f00c 100644 --- a/include/wine/debug.h +++ b/include/wine/debug.h @@ -94,11 +94,18 @@ struct __wine_debug_context const char *function; const char *file; int line; + const void *retaddr; }; -#define WINE_DEBUG_CONTEXT_VERSION 2 +#define WINE_DEBUG_CONTEXT_VERSION 3 + +#if defined(__GNUC__) || defined(__clang__) +#define __WINE_DBG_RETADDR __builtin_extract_return_addr(__builtin_return_address(0)) +#else +#define __WINE_DBG_RETADDR ((void *)0) +#endif #define __WINE_DBG_LOG(...) \ - wine_dbg_log( __dbcl, __dbch, __FILE__, __LINE__, __func__, __VA_ARGS__); } } while(0) + wine_dbg_log( __dbcl, __dbch, __FILE__, __LINE__, __func__, __WINE_DBG_RETADDR, __VA_ARGS__); } } while(0) #if defined(__MINGW32__) || (!defined(__WINE_USE_MSVCRT) && (defined(__GNUC__) || defined(__clang__))) #define __WINE_PRINTF_ATTR(fmt,args) __attribute__((format (printf,fmt,args))) @@ -182,10 +189,10 @@ static inline int __wine_dbg_cdecl wine_dbg_printf( const char *format, ... ) } static int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *file, int line, const char *function, - const char *format, va_list args ) __WINE_PRINTF_ATTR(6,0); + const char *file, int line, const char *function, const void *retaddr, + const char *format, va_list args ) __WINE_PRINTF_ATTR(7,0); static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *file, int line, const char *function, + const char *file, int line, const char *function, const void *retaddr, const char *format, va_list args ) { struct __wine_debug_context info = @@ -194,6 +201,7 @@ static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, s .function = function, .file = file, .line = line, + .retaddr = retaddr, }; struct __wine_debug_context *context = &info; int ret; @@ -208,17 +216,17 @@ static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, s } static int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *file, int line, const char *function, - const char *format, ... ) __WINE_PRINTF_ATTR(6,7); + const char *file, int line, const char *function, const void *retaddr, + const char *format, ... ) __WINE_PRINTF_ATTR(7,8); static inline int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, struct __wine_debug_channel *channel, - const char *file, int line, const char *function, + const char *file, int line, const char *function, const void *retaddr, const char *format, ... ) { va_list args; int ret; va_start( args, format ); - ret = wine_dbg_vlog( cls, channel, file, line, function, format, args ); + ret = wine_dbg_vlog( cls, channel, file, line, function, retaddr, format, args ); va_end( args ); return ret; } -- GitLab https://gitlab.winehq.org/wine/wine/-/merge_requests/2274
v3: Rebased and updated to avoid some possible `__wine_debug_context` initialization order warning. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_28826
Is there a chance for this to be accepted? I think many people have a similar local change, and several people expressed interest here. There's diverging opinion on how and when to then print the information but at least keeping local changes for that wouldn't cause such a large recompilation overhead. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_33911
I would also prefer having this because it can sometimes be really hard to tell where you're at in traces. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_34430
participants (2)
-
Bernhard Kölbl -
Rémi Bernon