[PATCH 0/1] MR2274: ntdll: Add source file and line to debug traces.
From: Rémi Bernon <rbernon(a)codeweavers.com> --- dlls/msxml3/main.c | 8 +++---- dlls/ntdll/ntdll.spec | 2 +- dlls/ntdll/thread.c | 6 +++--- dlls/ntdll/unix/debug.c | 6 +++--- dlls/windowscodecs/libtiff.c | 4 ++-- dlls/winecrt0/debug.c | 14 ++++++------ include/wine/debug.h | 41 ++++++++++++++++++++++-------------- 7 files changed, 44 insertions(+), 37 deletions(-) diff --git a/dlls/msxml3/main.c b/dlls/msxml3/main.c index 66e23114bfa..9b90407e428 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, __WINE_DBG_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, __WINE_DBG_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, __WINE_DBG_FILE, __LINE__, caller, ": %s", err->message); else - wine_dbg_log(dbcl, &__wine_dbch_msxml, caller, "\n"); + wine_dbg_log(dbcl, &__wine_dbch_msxml, __WINE_DBG_FILE, __LINE__, caller, "\n"); } /* Support for loading xml files from a Wine Windows drive */ diff --git a/dlls/ntdll/ntdll.spec b/dlls/ntdll/ntdll.spec index 3117e4c9b72..ee16fc38d7a 100644 --- a/dlls/ntdll/ntdll.spec +++ b/dlls/ntdll/ntdll.spec @@ -1704,7 +1704,7 @@ # Debugging @ stdcall -norelay __wine_dbg_write(ptr long) @ cdecl -norelay __wine_dbg_get_channel_flags(ptr) -@ cdecl -norelay __wine_dbg_header(long long str) +@ cdecl -norelay __wine_dbg_header(long long str long str) @ cdecl -norelay __wine_dbg_output(str) @ cdecl -norelay __wine_dbg_strdup(str) diff --git a/dlls/ntdll/thread.c b/dlls/ntdll/thread.c index b0b61419e37..fc3e8da485c 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 char *file, int line, const char *function ) { static const char * const classes[] = { "fixme", "err", "warn", "trace" }; struct debug_info *info = get_info(); @@ -151,8 +151,8 @@ 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 )) - pos += snprintf( pos, sizeof(info->output) - (pos - info->output), "%s:%s:%s ", - classes[cls], channel->name, function ); + pos += snprintf( pos, sizeof(info->output) - (pos - info->output), "%s:%s:%s:%d:%s ", + classes[cls], channel->name, file, line, 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..bab8211add9 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 char *file, int line, const char *function ) { static const char * const classes[] = { "fixme", "err", "warn", "trace" }; struct debug_info *info = get_info(); @@ -324,8 +324,8 @@ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_ pos += sprintf( pos, "%04x:", (UINT)GetCurrentThreadId() ); } if (function && cls < ARRAY_SIZE( classes )) - pos += snprintf( pos, sizeof(info->output) - (pos - info->output), "%s:%s:%s ", - classes[cls], channel->name, function ); + pos += snprintf( pos, sizeof(info->output) - (pos - info->output), "%s:%s:%s:%d:%s ", + classes[cls], channel->name, file, line, function ); info->out_pos = pos - info->output; return info->out_pos; } diff --git a/dlls/windowscodecs/libtiff.c b/dlls/windowscodecs/libtiff.c index 1bfc555f116..176eb393ec5 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, __WINE_DBG_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, __WINE_DBG_FILE, __LINE__, module, format, args ) != -1) __wine_dbg_output( "\n" ); } diff --git a/dlls/winecrt0/debug.c b/dlls/winecrt0/debug.c index 2ac4505fb85..c0bb0b4861d 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 char *file, int line, const char *function ); 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 char *file, int line, const char *function ) { char buffer[200], *pos = buffer; @@ -243,10 +241,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 char *file, int line, const char *function ) { LOAD_FUNC( __wine_dbg_header ); - return p__wine_dbg_header( cls, channel, function ); + return p__wine_dbg_header( cls, channel, file, line, function ); } #endif /* __WINE_PE_BUILD */ diff --git a/include/wine/debug.h b/include/wine/debug.h index c20924818dd..2022cc60efd 100644 --- a/include/wine/debug.h +++ b/include/wine/debug.h @@ -27,6 +27,7 @@ #include <stdarg.h> #include <stdio.h> +#include <string.h> #include <windef.h> #include <winbase.h> #ifndef GUID_DEFINED @@ -87,8 +88,16 @@ struct __wine_debug_channel const enum __wine_debug_class __dbcl = __WINE_DBCL##dbcl; \ __WINE_DBG_LOG +#ifdef __FILE_NAME__ +#define __WINE_DBG_FILE __FILE_NAME__ +#elif defined(__GNUC__) || defined(__clang__) +#define __WINE_DBG_FILE (__builtin_strrchr( __FILE__, '/' ) ? __builtin_strrchr( __FILE__, '/' ) + 1 : __FILE__) +#else +#define __WINE_DBG_FILE (strrchr( __FILE__, '/' ) ? strrchr( __FILE__, '/' ) + 1 : __FILE__) +#endif + #define __WINE_DBG_LOG(...) \ - wine_dbg_log( __dbcl, __dbch, __func__, __VA_ARGS__); } } while(0) + wine_dbg_log( __dbcl, __dbch, __WINE_DBG_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))) @@ -113,7 +122,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 char *file, int line, const char *function ); /* * Exported definitions and macros @@ -171,12 +180,12 @@ 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 ) { int ret; @@ -185,22 +194,22 @@ static inline int __wine_dbg_cdecl wine_dbg_vlog( enum __wine_debug_class cls, format++; function = NULL; } - if ((ret = __wine_dbg_header( cls, channel, function )) != -1) ret += wine_dbg_vprintf( format, args ); + if ((ret = __wine_dbg_header( cls, channel, file, line, function )) != -1) ret += wine_dbg_vprintf( format, args ); 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
I think this is useful to distinguish between multiple functions sharing the same name, or between similar messages within the same function. Arguably this could be done by renaming the functions, or making the message more unique, but it'd be easier to just add more context. With WinRT this is especially true as the same interfaces are implemented for many classes, and functions names are already overly verbose. The output could be made optional but I'm not sure why it should be. In any case, passing the data to `__wine_dbg_header` will also help anyone with similar local change avoid the huge cost of a `wine/debug.h` diff. The same thing would be true with return address information, but I think it's more debatable whether it is useful outside of debugging. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25404
Yes, isn’t it better to just name the functions differently or put some info in the message itself? If it is a problem for winrt maybe we’d better introduce a new trace macro with extra context? Note that if the log is from slightly different version the line numbers won’t match. I think at very least this should be enabled by special debug channel, making it always there will increase the log size with a noise which is not needed most of the time.
On 24 Feb 2023, at 8:06, Rémi Bernon <wine(a)gitlab.winehq.org> wrote:
I think this is useful to distinguish between multiple functions sharing the same name, or between similar messages within the same function. Arguably this could be done by renaming the functions, or making the message more unique, but it'd be easier to just add more context.
With WinRT this is especially true as the same interfaces are implemented for many classes, and functions names are already overly verbose.
The output could be made optional but I'm not sure why it should be. In any case, passing the data to `__wine_dbg_header` will also help anyone with similar local change avoid the huge cost of a `wine/debug.h` diff. The same thing would be true with return address information, but I think it's more debatable whether it is useful outside of debugging.
-- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25404
On Fri Feb 24 14:28:34 2023 +0000, **** wrote:
Paul Gofman replied on the mailing list: ``` Yes, isn’t it better to just name the functions differently or put some info in the message itself? If it is a problem for winrt maybe we’d better introduce a new trace macro with extra context? Note that if the log is from slightly different version the line numbers won’t match. I think at very least this should be enabled by special debug channel, making it always there will increase the log size with a noise which is not needed most of the time. ``` I think even if the line numbers don't match exactly it is still helpful.
And I don't think renaming the functions is a solution, it can only be done after you've discovered the ambiguity. In the end having `class_name_interface_name_method_name` function vs `file_name:interface_name_method_name` in the log is exactly the same. It makes the code little less verbose, which, when interface names or function names alone get close to 200 char, is desirable, while making the one class per file (imho is a good practice) more useful. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25408
On 2/24/23 08:46, Rémi Bernon (@rbernon) wrote:
And I don't think renaming the functions is a solution, it can only be done after you've discovered the ambiguity.
In the end having `class_name_interface_name_method_name` function vs `file_name:interface_name_method_name` in the log is exactly the same. It makes the code little less verbose, which, when interface names or function names alone get close to 200 char, is desirable, while making the one class per file (imho is a good practice) more useful.
Yes, sure. But maybe another macro then? Or, maybe, same macro TRACE can check another define macro enabling extended context and add this info to the message itself instead of header?
On Fri Feb 24 15:55:57 2023 +0000, **** wrote:
Paul Gofman replied on the mailing list: ``` On 2/24/23 08:46, Rémi Bernon (@rbernon) wrote:
And I don't think renaming the functions is a solution, it can only be
done after you've discovered the ambiguity.
In the end having `class_name_interface_name_method_name` function vs
`file_name:interface_name_method_name` in the log is exactly the same. It makes the code little less verbose, which, when interface names or function names alone get close to 200 char, is desirable,
while making the one class per file (imho is a good practice) more useful.
Yes, sure. But maybe another macro then? Or, maybe, same macro TRACE can check another define macro enabling extended context and add this info to the message itself instead of header? ``` It seems overly complicated when we can just add the context. Many other projects just do this, I think it's quite straightforward.
I would be okay with a specific channel to have it only optionally enabled, but I'm not sure to see why it'd bad to print it all the time and it defeat a bit the purpose of getting more context in logs upfront. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25417
Esme Povirk (@madewokherd) commented about dlls/ntdll/ntdll.spec:
# Debugging @ stdcall -norelay __wine_dbg_write(ptr long) @ cdecl -norelay __wine_dbg_get_channel_flags(ptr) -@ cdecl -norelay __wine_dbg_header(long long str) +@ cdecl -norelay __wine_dbg_header(long long str long str) I think Wine Mono's wpfgfx_cor3.dll uses this function and would be broken by the change.
-- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25430
Esme Povirk (@madewokherd) commented about dlls/winecrt0/debug.c:
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 char *file, int line, const char *function )
Shouldn't the output of this function be changed as well? -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25431
Esme Povirk (@madewokherd) commented about include/wine/debug.h:
const enum __wine_debug_class __dbcl = __WINE_DBCL##dbcl; \ __WINE_DBG_LOG
+#ifdef __FILE_NAME__ +#define __WINE_DBG_FILE __FILE_NAME__ +#elif defined(__GNUC__) || defined(__clang__) +#define __WINE_DBG_FILE (__builtin_strrchr( __FILE__, '/' ) ? __builtin_strrchr( __FILE__, '/' ) + 1 : __FILE__) +#else +#define __WINE_DBG_FILE (strrchr( __FILE__, '/' ) ? strrchr( __FILE__, '/' ) + 1 : __FILE__)
I'm not sure the strrchr approach is reliable because the path may have a \ when compiling on Windows. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25432
I don't like the approach of solving a local issue by moving it at global scope. And increasing verbosity of logs for DLLs that are already very verbose will make things worse for these. Furthermore: - if context is important, why don't you include the DLL name in the trace? - change to ntdll will break binary compatibility (eg some .so exec will no longer work) IMO we'd be better off by: - increasing verbosity on a DLL and/or file approach - this can be done without changing ntdll interface, by just replacing function parameter by a locally generated string including function + the context needed - this could even go a step further as the printed context could be what the DLL/file is interested in (and could be different from filename+lineno...) something like; ``` #define __WINE_DBG_LOG(...) \ - wine_dbg_log( __dbcl, __dbch, __func__, __VA_ARGS__); } } while(0) + wine_dbg_log( __dbcl, __dbch, __WINE_DBG_CONTEXT, __VA_ARGS__); } } while(0) + + #ifndef __WINE_DBG_CONTEXT + #define __WINE_DBG_CONTEXT __func__ + #endif ``` and then in .c file that requires it, #define __WINE_DBG_CONTEXT wine_dbg_sprintf("%s:%u:%u", __FILE__, __LINE__, __func__) before including wine/debug.h (could be also defined at DLL level from Makefile) -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25476
This merge request was closed by Rémi Bernon. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274
On Sat Feb 25 09:07:52 2023 +0000, eric pouech wrote:
I don't like the approach of solving a local issue by moving it at global scope. And increasing verbosity of logs for DLLs that are already very verbose will make things worse for these. Furthermore: - if context is important, why don't you include the DLL name in the trace? - change to ntdll will break binary compatibility (eg some .so exec will no longer work) IMO we'd be better off by: - increasing verbosity on a DLL and/or file approach - this can be done without changing ntdll interface, by just replacing function parameter by a locally generated string including function + the context needed - this could even go a step further as the printed context could be what the DLL/file is interested in (and could be different from filename+lineno...) something like; ``` #define __WINE_DBG_LOG(...) \ - wine_dbg_log( __dbcl, __dbch, __func__, __VA_ARGS__); } } while(0) + wine_dbg_log( __dbcl, __dbch, __WINE_DBG_CONTEXT, __VA_ARGS__); } } while(0) + + #ifndef __WINE_DBG_CONTEXT + #define __WINE_DBG_CONTEXT __func__ + #endif ``` and then in .c file that requires it, ``` #define __WINE_DBG_CONTEXT wine_dbg_sprintf("%s:%u:%u", __FILE__, __LINE__, __func__) ``` before including wine/debug.h (could be also defined at DLL level from Makefile) I think this is also too complex, though pre-formatting some context in place of the function name is an interesting idea.
-- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25477
I'm late here, but personally I would have liked that idea. And indeed I have local patches for including filename, line, return address and other information in each log line. In particular, I find it helpful to have filename and line to quickly locate where the logging site is, even when I am dealing with parts of Wine I'm not too familiar with. Sometimes I've used the return address to distinguish between calls made directly by the application or resulting from other Wine code. I find that helpful to quickly understand what the application intention is, independently of what then happens because of Wine. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25555
On Mon Feb 27 11:49:42 2023 +0000, Giovanni Mascellani wrote:
I'm late here, but personally I would have liked that idea. And indeed I have local patches for including filename, line, return address and other information in each log line. In particular, I find it helpful to have filename and line to quickly locate where the logging site is, even when I am dealing with parts of Wine I'm not too familiar with. Sometimes I've used the return address to distinguish between calls made directly by the application or resulting from other Wine code. I find that helpful to quickly understand what the application intention is, independently of what then happens because of Wine. I only closed it because it seems that people have strong preferences here and because I didn't think it was worth spending any time discussing the details. I still believe it is useful and would love to see anything similar upstream (including return address information being passed to debug functions).
-- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25556
I haven't taken more than one look at the log output produced by this, so I can't say much for sure, but I'm inclined to agree that this is desirable, for pretty much the reasons Rémi gave. There are less parts of Wine that need this kind of disambiguation than that don't, but it doesn't seem too in-the-way either. Even where the function name is unambiguous, I think there's a benefit in terms of reducing the need to ask questions like "is CreateFileMapping() in file.c or memory.c?" [Answer: neither, it's in sync.c.] Thoughts: * Should we include the DLL name in the trace as well? I can see situations where that'd help (quartz, mfplat), but also it takes up space, and will usually be redundant with the channel... * Is there much of a point in including the line number? I doubt it, the file and function name is probably enough and from there you can easily browse to a trace. On the other hand, this *would* allow you to have multiple identical messages in the same function, which can be especially handy if you want to copy/paste a bunch of traces while debugging... In response to Eric's comment:
I don't like the approach of solving a local issue by moving it at global scope. And increasing verbosity of logs for DLLs that are already very verbose will make things worse for these.
But this isn't a "local issue" exactly. It's a problem that occurs in multiple places. I've run into this in quartz. In some sense the only reason it's *not* more widespread is that we put namespace prefixes on things defensively.
Furthermore:
if context is important, why don't you include the DLL name in the trace?
Like Rémi already said, that makes names unnecessarily long.
change to ntdll will break binary compatibility (eg some .so exec will no longer work)
__wine_* APIs are internal and shouldn't be depended on anyway. This isn't the first time we've changed them.
IMO we'd be better off by:
increasing verbosity on a DLL and/or file approach this can be done without changing ntdll interface, by just replacing function parameter by a locally generated string including function + the context needed this could even go a step further as the printed context could be what the DLL/file is interested in (and could be different from filename+lineno...)
This would make wine dlls inconsistent wrt how they print trace messages, and would also add more work for anyone who wants to take advantage of this. I don't think that's an improvement. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25613
But why this should go unconditionally, without a dedicated debug channel (like, e. g., pid)? Or do you think those should be removed as well and all the possible context fields should just be there? On 2/27/23 13:17, Zebediah Figura (@zfigura) wrote:
I haven't taken more than one look at the log output produced by this, so I can't say much for sure, but I'm inclined to agree that this is desirable, for pretty much the reasons Rémi gave. There are less parts of Wine that need this kind of disambiguation than that don't, but it doesn't seem too in-the-way either.
Even where the function name is unambiguous, I think there's a benefit in terms of reducing the need to ask questions like "is CreateFileMapping() in file.c or memory.c?" [Answer: neither, it's in sync.c.]
Thoughts:
* Should we include the DLL name in the trace as well? I can see situations where that'd help (quartz, mfplat), but also it takes up space, and will usually be redundant with the channel...
* Is there much of a point in including the line number? I doubt it, the file and function name is probably enough and from there you can easily browse to a trace. On the other hand, this *would* allow you to have multiple identical messages in the same function, which can be especially handy if you want to copy/paste a bunch of traces while debugging...
In response to Eric's comment:
I don't like the approach of solving a local issue by moving it at global scope. And increasing verbosity of logs for DLLs that are already very verbose will make things worse for these. But this isn't a "local issue" exactly. It's a problem that occurs in multiple places. I've run into this in quartz. In some sense the only reason it's *not* more widespread is that we put namespace prefixes on things defensively.
Furthermore:
if context is important, why don't you include the DLL name in the trace? Like Rémi already said, that makes names unnecessarily long.
change to ntdll will break binary compatibility (eg some .so exec will no longer work)
__wine_* APIs are internal and shouldn't be depended on anyway. This isn't the first time we've changed them.
IMO we'd be better off by:
increasing verbosity on a DLL and/or file approach this can be done without changing ntdll interface, by just replacing function parameter by a locally generated string including function + the context needed this could even go a step further as the printed context could be what the DLL/file is interested in (and could be different from filename+lineno...) This would make wine dlls inconsistent wrt how they print trace messages, and would also add more work for anyone who wants to take advantage of this. I don't think that's an improvement.
On 2/27/23 13:41, Paul Gofman wrote:
But why this should go unconditionally, without a dedicated debug channel (like, e. g., pid)? Or do you think those should be removed as well and all the possible context fields should just be there?
Oh, I think I missed that suggestion actually. I like that idea.
Is there much of a point in including the line number? I doubt it, the file and function name is probably enough and from there you can easily browse to a trace. On the other hand, this *would* allow you to have multiple identical messages in the same function, which can be especially handy if you want to copy/paste a bunch of traces while debugging...
I find it useful to just open the file and go to the right line without having to type the function name and then follow the function until you find the right message. It helps me keeping the thought flow I had while reading the logs. But I realize that's quite a personal thing, so my own solution for that is having my local development patches. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25725
On Tue Feb 28 11:27:33 2023 +0000, Giovanni Mascellani wrote:
Is there much of a point in including the line number? I doubt it, the file and function name is probably enough and from there you can easily browse to a trace. On the other hand, this *would* allow you to have multiple identical messages in the same function, which can be especially handy if you want to copy/paste a bunch of traces while debugging... I find it useful to just open the file and go to the right line without having to type the function name and then follow the function until you find the right message. It helps me keeping the thought flow I had while reading the logs. But I realize that's quite a personal thing, so my own solution for that is having my local development patches. I think the question whether we should pass as much context as we can, ie: function and line information, doesn't depend on preferences. Not doing it forces everyone who is interested in having more context to keep very expensive local changes.
Whether they are printed out or not, or in a way or another might depend on preferences, but at least that's just a couple of very light changes in `__wine_dbg_header`. Note that that's arguably true for the `strrchr` thing here, and maybe we should just pass `__FILE__` without thinking about it, and letting people print the full path if they like. That's also true with return address information, which I think could be useful to have. -- https://gitlab.winehq.org/wine/wine/-/merge_requests/2274#note_25739
participants (7)
-
eric pouech (＠epo) -
Esme Povirk (＠madewokherd)
-
Giovanni Mascellani (＠giomasce)
-
Paul Gofman -
Rémi Bernon
-
Zebediah Figura -
Zebediah Figura (＠zfigura)