[PATCH v2 0/3] MR2274: ntdll: Add source file and line to debug traces.
-- v2: 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..dca943447f9 100644 --- a/include/wine/debug.h +++ b/include/wine/debug.h @@ -93,12 +93,19 @@ struct __wine_debug_context int version; /* for forward compatibility */ const char *function; const char *file; + const void *retaddr; int line; }; -#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
Reopening as several people expressed interest after all, with a new version of the changes that only pass the additional information around, without changing the debug traces. This should also be more or less ABI compatible, using a new struct in place of the current function name string pointer, and checking the first char -assuming function names were never empty- to decide whether the passed pointer is a string or a new context info struct. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25777
On Tue Feb 28 18:58:13 2023 +0000, Rémi Bernon wrote:
Reopening as several people expressed interest after all, with a new version of the changes that only pass the additional information around, without changing the debug traces. This should also be more or less ABI compatible, using a new struct in place of the current function name string pointer, and checking the first char -assuming function names were never empty- to decide whether the passed pointer is a string or a new context info struct. I've also included a change to pass the return address while we're at it, I think it's generally useful.
-- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25779
I'm going to approve this on the basis that I do not expect it to break anything, but I will not give an opinion on whether it's desirable. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25909
This merge request was approved by Esme Povirk. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274
participants (2)
-
Esme Povirk (＠madewokherd) -
Rémi Bernon