From: "Rémi Bernon" Subject: Re: [PATCH] include: Use __cdecl calling convention for wine_dbg_log(). Message-Id: <8832f565-e0ee-763d-f712-7dccd83f6c4b@codeweavers.com> Date: Fri, 18 Sep 2020 18:52:22 +0200 In-Reply-To: <0af3be11-847d-0548-02d3-bf4eaa363480@codeweavers.com> References: <20200910193811.420427-1-mbruni@codeweavers.com> <0af3be11-847d-0548-02d3-bf4eaa363480@codeweavers.com> On 2020-09-10 22:30, Rémi Bernon wrote: > On 2020-09-10 21:38, Matteo Bruni wrote: >> The practical consequence is that registers are saved / restored >> inside wine_dbg_log() instead of in the caller, which means not >> incurring in the overhead when debug channels are disabled. >> >> Signed-off-by: Matteo Bruni >> --- >> This came up from hacking around yesterday with Paul and Rémi. I >> haven't tested the patch extensively but it seems to do the >> trick. wine_dbg_log() in practice is never inlined for me and that's >> the reason why this is enough. It's not possible to remove the inline >> keyword from the definition because that makes it trigger the "unused >> static function" warning all over Wine. >> >> Worth mentioning that this patch makes sure that wine_dbg_log() has >> the same calling convention as __wine_dbg_header() and the other >> debug functions in ntdll. >> --- >>   include/wine/debug.h | 12 ++++++------ >>   1 file changed, 6 insertions(+), 6 deletions(-) >> >> diff --git a/include/wine/debug.h b/include/wine/debug.h >> index 912d61a90af0..462a43e22e20 100644 >> --- a/include/wine/debug.h >> +++ b/include/wine/debug.h >> @@ -193,12 +193,12 @@ static inline int __wine_dbg_cdecl >> wine_dbg_printf( const char *format, ... ) >>       return __wine_dbg_output( buffer ); >>   } >> -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 __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 __cdecl wine_dbg_log( enum __wine_debug_class cls, >> +                                        struct __wine_debug_channel >> *channel, >> +                                        const char *function, const >> char *format, ... ) >>   { >>       char buffer[1024]; >>       __wine_dbg_va_list args; >> > > Well, if we intend to make these functions __cdecl, probably they all > should be, in this header, including the inline helpers, as we've seen > that any missing attribute can make the spilling leak to its callers. > > Then, I didn't look very precisely either, but I believe there's > actually a big issue that makes it not so simple after all (correct me > if I'm wrong though, maybe it's all good): > > If we set "ms_abi" attribute to these vararg functions, then their > calling convention will be as such. Thus, we cannot use anymore the sysv > va_list in there, and we have instead to use the __ms_va_list (defined > to __builtin_ms_va_list in this case). > > Now, doing so will break the vsnprintf call, when it goes to libc, as it > expects a sysv va_list argument instead. > > One possible way that I see would be instead to have a > __wine_dbg_vsnprintf export in ntdll, that either forward the call to > msvcrt vsnprintf (which already expects a __ms_va_list argument), or to > an ntdll.so implementation. > > The ntdll.so implementation will have to be here anyway, to support its > own traces, as it cannot go back to msvcrt for that. It will have to > handle the __ms_va_arg somehow, possibly translating it for libc (which > actually may not be so hard, with snprintf and one argument at a time), > or handle the formatting on its own. > > The latter could actually make the whole thing worth the effort, if we > consider that TRACE messages could benefit from a specific printf > implementation with some extensions. For instances, it could print > strings and wstrings at the same time, in a safe way, without needing > the debugstr_a/w anymore. Same for guids for instance. Hi! I actually pushed the idea a little bit further and implemented it, in the attached patches, to illustrate a bit and because I think it could possibly still be interesting. The SSE register spilling savings are actually a little bit underwhelming. As we have seen, any ms_abi function that calls a sysv_abi function (or a non specified, in an ELF builtin) will spill the XMM registers to the stack and restore them after the call. Marking the debug functions ms_abi mostly helps with the leaf functions that do not call anything else, but for instance in wined3d, there's a lot of unspecified helpers that will cause the same spilling to happen. We will have to specify ms_abi on all of them to solve the issue. Then, making all functions ms_abi pushes the spilling down the call chain, and if there's a system function to call in the end, it will have to spill the registers anyway. If that function is called much more often than the Wine entry point, then it may also not be ideal to force the register spilling there, and having it on the entry point would be preferable. Anyway, making debug functions ms_abi should not hurt in any case, they are not supposed to be called often, they never go back from sysv_abi to ms_abi, and keeping their own induced spilling internally is better regardless of what the surrounding code does. Now, what I find the most useful, is what this implementation allows us to do with debug TRACE messages. As it makes every debug formatting go through ntdll.so, I think it has at least two interesting properties: 1) We can control the formatting, and as I did in the patch, extend the format specifiers as we like, and get rid of most of the static inline debug helpers (I don't know if that's a good thing or not, but I personally like to be able to do so). 2) The actual value formatting is done consistently by glibc. There's no value formatting difference between PE code and ELF code TRACE messages. And thanks to 1) we can still support MSVC-specific format specifiers, we just need to convert them to the glibc equivalents. Cheers, -- Rémi Bernon From f1577a828239773a0a2e435400209e11f7a7acea Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?R=C3=A9mi=20Bernon?= Date: Thu, 10 Sep 2020 10:04:55 +0200 Subject: [PATCH 1/4] include: Reduce SSE register spilling induced by __wine_dbg* calls. This makes all wine/debug.h helpers and functions __cdecl, and uses __ms_va_list for varargs. As it's not going to work with libc vsnprintf, we also need to introduce a new ntdll __wine_dbg_vsnprintf export. The calls could be redirected to msvcrt vsnprintf but as we also need it for ntdll.so, this implements the format string parsing (including MS extensions), and forwards each argument to glibc snprintf. Having the format string parsing in NTDLL will also let us introduce some other extensions for TRACE messages, to replace common dbgstr_* helpers for instance and reduce the amount of common code. This also replaces __wine_dbg_output with __wine_dbg_vprintf, that combines both the formatting and the output to save a few calls. --- dlls/ntdll/ntdll.spec | 3 +- dlls/ntdll/thread.c | 13 ++- dlls/ntdll/unix/debug.c | 196 ++++++++++++++++++++++++++++++++++++++- dlls/ntdll/unix/loader.c | 3 +- dlls/ntdll/unixlib.h | 3 +- dlls/winecrt0/debug.c | 28 ++++-- include/wine/debug.h | 92 ++++++++---------- 7 files changed, 268 insertions(+), 70 deletions(-) diff --git a/dlls/ntdll/ntdll.spec b/dlls/ntdll/ntdll.spec index 453c4827572..7d6581437eb 100644 --- a/dlls/ntdll/ntdll.spec +++ b/dlls/ntdll/ntdll.spec @@ -1604,8 +1604,9 @@ # Debugging @ cdecl -norelay __wine_dbg_get_channel_flags(ptr) @ cdecl -norelay __wine_dbg_header(long long str) -@ cdecl -norelay __wine_dbg_output(str) @ cdecl -norelay __wine_dbg_strdup(str) +@ cdecl -norelay __wine_dbg_vprintf(str ptr) +@ cdecl -norelay __wine_dbg_vsnprintf(ptr long str ptr) # Virtual memory @ cdecl -syscall __wine_locked_recvmsg(long ptr long) diff --git a/dlls/ntdll/thread.c b/dlls/ntdll/thread.c index 0f31fe18a7d..ae0371052f0 100644 --- a/dlls/ntdll/thread.c +++ b/dlls/ntdll/thread.c @@ -66,13 +66,20 @@ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_ } /*********************************************************************** - * __wine_dbg_output (NTDLL.@) + * __wine_dbg_vprintf (NTDLL.@) */ -int __cdecl __wine_dbg_output( const char *str ) +int __cdecl __wine_dbg_vprintf( const char *format, __ms_va_list args ) { - return unix_funcs->dbg_output( str ); + return unix_funcs->dbg_vprintf( format, args ); } +/*********************************************************************** + * __wine_dbg_vsnprintf (NTDLL.@) + */ +int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ) +{ + return unix_funcs->dbg_vsnprintf( buffer, length, format, args ); +} /******************************************************************* * KiUserApcDispatcher (NTDLL.@) diff --git a/dlls/ntdll/unix/debug.c b/dlls/ntdll/unix/debug.c index 368baac46f4..117dc9153bb 100644 --- a/dlls/ntdll/unix/debug.c +++ b/dlls/ntdll/unix/debug.c @@ -30,6 +30,8 @@ #include #include #include +#include +#include #ifdef HAVE_UNISTD_H # include #endif @@ -236,15 +238,18 @@ const char * __cdecl __wine_dbg_strdup( const char *str ) } /*********************************************************************** - * __wine_dbg_output (NTDLL.@) + * __wine_dbg_vprintf (NTDLL.@) */ -int __cdecl __wine_dbg_output( const char *str ) +int __cdecl __wine_dbg_vprintf( const char *format, __ms_va_list args ) { struct debug_info *info = get_info(); - const char *end = strrchr( str, '\n' ); + char buffer[1024], *str, *end; int ret = 0; - if (end) + __wine_dbg_vsnprintf( buffer, sizeof(buffer), format, args ); + + str = buffer; + if ((end = strrchr( str, '\n' ))) { ret += append_output( info, str, end + 1 - str ); write( 2, info->output, info->out_pos ); @@ -287,6 +292,189 @@ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_ return append_output( info, buffer, strlen( buffer )); } +int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ) +{ + char fmtbuf[1024]; + char *buf = buffer, *end = buffer + length; + char *fmt = fmtbuf, *tmp = fmt; + char *spec, *width, *prec, old; + int ret, w, p; + + assert(strlen(format) < sizeof(fmtbuf)); + memcpy(fmtbuf, format, strlen(format) + 1); + + while (buf < end && *fmt) + { + if (!(tmp = strchr(tmp + 1, '%'))) tmp = fmt + strlen(fmt); + else if (fmt[0] == '%' && tmp == fmt + 1) continue; + old = *tmp; + *tmp = 0; + + if (fmt[0] != '%') spec = tmp; + else spec = fmt + 1 + strcspn(fmt + 1, "AacCdeEfFgGinopsSuxXZ%"); + + if (fmt[1] == '-' || fmt[1] == '+' || fmt[1] == ' ' || fmt[1] == '#' || fmt[1] == '0') width = fmt + 2; + else width = fmt + 1; + + if (*width == '*') w = va_arg(args, int); + else if (!(w = atoi(width))) w = -1; + + if (!(prec = strchr(fmt, '.')) || ++prec >= spec) p = INT_MAX; + else if (*prec == '*') p = va_arg(args, int); + else if (!(p = atoi(prec))) p = INT_MAX; + +#define append_checked(b, l, x) \ + do { if ((ret = (x)) >= 0 && ret < (l)) b += ret; \ + else if (ret < 0) return ret; \ + else return b - buffer + ret; } while (0) +#define snprintf_checked(b, l, ...) append_checked(b, l, snprintf(b, l, __VA_ARGS__)) +#define snprintf_dispatch(b, l, f, a) \ + append_checked(b, l, (width && *width == '*' ? (prec && *prec == '*' ? snprintf(b, l, f, w, p, a) \ + : snprintf(b, l, f, w, a)) \ + : (prec && *prec == '*' ? snprintf(b, l, f, p, a) \ + : snprintf(b, l, f, a)))) + + switch (*spec) + { + case 'c': + case 'C': + if (spec[-1] == 'l' || spec[-1] == 'w' || (spec[0] == 'C' && spec[-1] != 'h')) + { + unsigned int wc = va_arg(args, unsigned int); + if (wc >= ' ' && wc <= '~') snprintf_checked(buf, end - buf, "%c", wc); + else snprintf_checked(buf, end - buf, "\\U%04x", wc); + snprintf_checked(buf, end - buf, spec + 1); + } + else + { + snprintf_checked(buf, end - buf, "%c", va_arg(args, int)); + snprintf_checked(buf, end - buf, spec + 1); + } + break; + case 'd': + case 'i': + case 'o': + case 'u': + case 'x': + case 'X': + if (spec[-1] == '4' && spec[-2] == '6' && spec[-3] == 'I') + { + spec[-3] = 'j'; + spec[-2] = spec[0]; + spec[-1] = 0; + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, uintmax_t)); + snprintf_checked(buf, end - buf, spec + 1); + break; + } + if (spec[-1] == '2' && spec[-2] == '3' && spec[-3] == 'I') + { + spec[-3] = spec[0]; + spec[-2] = 0; + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, unsigned int)); + snprintf_checked(buf, end - buf, spec + 1); + break; + } + + if (spec[-1] == 'I') spec[-1] = 'z'; + if (spec[-1] == 'j') + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, uintmax_t)); + else if (spec[-1] == 'z') + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, size_t)); + else if (spec[-1] == 't') + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, ptrdiff_t)); + else if (spec[-1] == 'l' && spec[-2] == 'l') + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, long long int)); + else if (spec[-1] == 'l') + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, long int)); + else + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, int)); + break; + case 's': + case 'S': + if (spec[-1] == 'l' || spec[-1] == 'w' || (spec[0] == 'S' && spec[-1] != 'h')) + { + WCHAR *wstr = va_arg(args, WCHAR *); + while (*wstr && p--) + { + if (*wstr >= ' ' && *wstr <= '~') snprintf_checked(buf, end - buf, "%c", *wstr++); + else snprintf_checked(buf, end - buf, "\\U%04x", *wstr++); + } + snprintf_checked(buf, end - buf, spec + 1); + } + else + { + char *str = va_arg(args, char *); + if (spec[-1] != 'l' && spec[-1] != 'w') + snprintf_dispatch(buf, end - buf, fmt, str); + else + { + spec[-1] = 's'; + spec[0] = 0; + snprintf_dispatch(buf, end - buf, fmt, str); + snprintf_checked(buf, end - buf, spec + 1); + } + } + break; + case 'Z': + if (spec[-1] == 'l' || spec[-1] == 'w') + { + UNICODE_STRING *ptr = va_arg(args, UNICODE_STRING *); + WCHAR *wstr = ptr->Buffer; + USHORT len = ptr->Length; + while (len--) + { + if (*wstr >= ' ' && *wstr <= '~') snprintf_checked(buf, end - buf, "%c", *wstr++); + else snprintf_checked(buf, end - buf, "\\U%04x", *wstr++); + } + snprintf_checked(buf, end - buf, spec + 1); + } + else + { + ANSI_STRING *ptr = va_arg(args, ANSI_STRING *); + char *str = ptr->Buffer; + USHORT len = ptr->Length; + snprintf_checked(buf, end - buf, "%.*s", len, str); + snprintf_checked(buf, end - buf, spec + 1); + } + break; + case 'p': + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, void *)); + break; + case 'A': + case 'a': + case 'e': + case 'E': + case 'f': + case 'F': + case 'g': + case 'G': + if (spec[-1] == 'l') spec[-1] = 'L'; + if (spec[-1] == 'L') + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, long double)); + else + snprintf_dispatch(buf, end - buf, fmt, va_arg(args, double)); + break; + case '%': + case '\0': + snprintf_checked(buf, end - buf, fmt); + break; + case 'n': + default: + fprintf(stderr, "wine_dbg_vsnprintf: unsupported format string: %s\n", fmt); + break; + } + +#undef snprintf_dispatch +#undef snprintf_checked +#undef append_checked + + *tmp = old; + fmt = tmp; + } + + return buf - buffer; +} + /*********************************************************************** * dbg_init */ diff --git a/dlls/ntdll/unix/loader.c b/dlls/ntdll/unix/loader.c index bc5b627cbc9..b044378732a 100644 --- a/dlls/ntdll/unix/loader.c +++ b/dlls/ntdll/unix/loader.c @@ -1416,8 +1416,9 @@ static struct unix_funcs unix_funcs = unwind_builtin_dll, __wine_dbg_get_channel_flags, __wine_dbg_strdup, - __wine_dbg_output, __wine_dbg_header, + __wine_dbg_vprintf, + __wine_dbg_vsnprintf, }; diff --git a/dlls/ntdll/unixlib.h b/dlls/ntdll/unixlib.h index d6cd4ed403e..6e0ac84e0c5 100644 --- a/dlls/ntdll/unixlib.h +++ b/dlls/ntdll/unixlib.h @@ -96,9 +96,10 @@ struct unix_funcs /* debugging functions */ unsigned char (CDECL *dbg_get_channel_flags)( struct __wine_debug_channel *channel ); const char * (CDECL *dbg_strdup)( const char *str ); - int (CDECL *dbg_output)( const char *str ); int (CDECL *dbg_header)( enum __wine_debug_class cls, struct __wine_debug_channel *channel, const char *function ); + int (CDECL *dbg_vprintf)( const char *format, __ms_va_list args ); + int (CDECL *dbg_vsnprintf)( char *buffer, size_t length, const char *format, __ms_va_list args ); }; #endif /* __NTDLL_UNIXLIB_H */ diff --git a/dlls/winecrt0/debug.c b/dlls/winecrt0/debug.c index cb07c7835d4..ecf711761e6 100644 --- a/dlls/winecrt0/debug.c +++ b/dlls/winecrt0/debug.c @@ -32,7 +32,8 @@ WINE_DECLARE_DEBUG_CHANNEL(pid); 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 int (__cdecl *p__wine_dbg_vprintf)( const char *format, __ms_va_list args ); +static int (__cdecl *p__wine_dbg_vsnprintf)( char *buffer, size_t length, const char *format, __ms_va_list args ); 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, @@ -169,15 +170,22 @@ static const char * __cdecl fallback__wine_dbg_strdup( const char *str ) return ret; } -static int __cdecl fallback__wine_dbg_output( const char *str ) +static int __cdecl fallback__wine_dbg_vprintf( const char *format, __ms_va_list args ) { - size_t len = strlen( str ); + char str[1024]; + size_t len; + __wine_dbg_vsnprintf(str, sizeof(str), format, args); - if (!len) return 0; + if (!(len = strlen( str ))) return 0; InterlockedExchange( (LONG *)&partial_line_tid, str[len - 1] != '\n' ? GetCurrentThreadId() : 0 ); return fwrite( str, 1, len, stderr ); } +static int __cdecl fallback__wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ) +{ + return vsnprintf( buffer, length, format, args ); +} + static int __cdecl fallback__wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_channel *channel, const char *function ) @@ -230,10 +238,16 @@ const char * __cdecl __wine_dbg_strdup( const char *str ) return p__wine_dbg_strdup( str ); } -int __cdecl __wine_dbg_output( const char *str ) +int __cdecl __wine_dbg_vprintf( const char *format, __ms_va_list args ) +{ + LOAD_FUNC( __wine_dbg_vprintf ); + return p__wine_dbg_vprintf( format, args ); +} + +int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ) { - LOAD_FUNC( __wine_dbg_output ); - return p__wine_dbg_output( str ); + LOAD_FUNC( __wine_dbg_vsnprintf ); + return p__wine_dbg_vsnprintf( buffer, length, format, args ); } unsigned char __cdecl __wine_dbg_get_channel_flags( struct __wine_debug_channel *channel ) diff --git a/include/wine/debug.h b/include/wine/debug.h index 912d61a90af..4e2c606bfd4 100644 --- a/include/wine/debug.h +++ b/include/wine/debug.h @@ -145,9 +145,10 @@ struct __wine_debug_channel extern unsigned char __cdecl __wine_dbg_get_channel_flags( struct __wine_debug_channel *channel ); 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 ); +extern int __cdecl __wine_dbg_vprintf( const char *format, __ms_va_list args ); +extern int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ); /* * Exported definitions and macros @@ -157,51 +158,37 @@ extern int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine quotes. The string will be valid for some time, but not indefinitely as strings are re-used. */ -#if (defined(__x86_64__) || defined(__aarch64__)) && defined(__GNUC__) && defined(__WINE_USE_MSVCRT) -# define __wine_dbg_cdecl __cdecl -# define __wine_dbg_va_list __builtin_ms_va_list -# define __wine_dbg_va_start(list,arg) __builtin_ms_va_start(list,arg) -# define __wine_dbg_va_end(list) __builtin_ms_va_end(list) -#else -# define __wine_dbg_cdecl -# define __wine_dbg_va_list va_list -# define __wine_dbg_va_start(list,arg) va_start(list,arg) -# define __wine_dbg_va_end(list) va_end(list) -#endif - -static const char * __wine_dbg_cdecl wine_dbg_sprintf( const char *format, ... ) __WINE_PRINTF_ATTR(1,2); -static inline const char * __wine_dbg_cdecl wine_dbg_sprintf( const char *format, ... ) +static const char * __cdecl wine_dbg_sprintf( const char *format, ... ) __WINE_PRINTF_ATTR(1,2); +static inline const char * __cdecl wine_dbg_sprintf( const char *format, ... ) { char buffer[200]; - __wine_dbg_va_list args; + __ms_va_list args; - __wine_dbg_va_start( args, format ); - vsnprintf( buffer, sizeof(buffer), format, args ); - __wine_dbg_va_end( args ); + __ms_va_start( args, format ); + __wine_dbg_vsnprintf( buffer, sizeof(buffer), format, args ); + __ms_va_end( args ); return __wine_dbg_strdup( buffer ); } -static int __wine_dbg_cdecl wine_dbg_printf( const char *format, ... ) __WINE_PRINTF_ATTR(1,2); -static inline int __wine_dbg_cdecl wine_dbg_printf( const char *format, ... ) +static int __cdecl wine_dbg_printf( const char *format, ... ) __WINE_PRINTF_ATTR(1,2); +static inline int __cdecl wine_dbg_printf( const char *format, ... ) { - char buffer[1024]; - __wine_dbg_va_list args; - - __wine_dbg_va_start( args, format ); - vsnprintf( buffer, sizeof(buffer), format, args ); - __wine_dbg_va_end( args ); - return __wine_dbg_output( buffer ); + __ms_va_list args; + int ret; + __ms_va_start( args, format ); + ret = __wine_dbg_vprintf( format, args ); + __ms_va_end( args ); + return ret; } -static int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, +static int __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, +static inline int __cdecl wine_dbg_log( enum __wine_debug_class cls, struct __wine_debug_channel *channel, const char *function, const char *format, ... ) { - char buffer[1024]; - __wine_dbg_va_list args; + __ms_va_list args; int ret; if (*format == '\1') /* special magic to avoid standard prefix */ @@ -211,14 +198,13 @@ static inline int __wine_dbg_cdecl wine_dbg_log( enum __wine_debug_class cls, } if ((ret = __wine_dbg_header( cls, channel, function )) == -1) return ret; - __wine_dbg_va_start( args, format ); - vsnprintf( buffer, sizeof(buffer), format, args ); - __wine_dbg_va_end( args ); - ret += __wine_dbg_output( buffer ); + __ms_va_start( args, format ); + ret += __wine_dbg_vprintf( format, args ); + __ms_va_end( args ); return ret; } -static inline const char *wine_dbgstr_an( const char *str, int n ) +static inline const char *__cdecl wine_dbgstr_an( const char *str, int n ) { static const char hex[16] = {'0','1','2','3','4','5','6','7','8','9','a','b','c','d','e','f'}; char buffer[300], *dst = buffer; @@ -260,7 +246,7 @@ static inline const char *wine_dbgstr_an( const char *str, int n ) return __wine_dbg_strdup( buffer ); } -static inline const char *wine_dbgstr_wn( const WCHAR *str, int n ) +static inline const char *__cdecl wine_dbgstr_wn( const WCHAR *str, int n ) { static const char hex[16] = {'0','1','2','3','4','5','6','7','8','9','a','b','c','d','e','f'}; char buffer[300], *dst = buffer; @@ -304,17 +290,17 @@ static inline const char *wine_dbgstr_wn( const WCHAR *str, int n ) return __wine_dbg_strdup( buffer ); } -static inline const char *wine_dbgstr_a( const char *s ) +static inline const char *__cdecl wine_dbgstr_a( const char *s ) { return wine_dbgstr_an( s, -1 ); } -static inline const char *wine_dbgstr_w( const WCHAR *s ) +static inline const char *__cdecl wine_dbgstr_w( const WCHAR *s ) { return wine_dbgstr_wn( s, -1 ); } -static inline const char *wine_dbgstr_guid( const GUID *id ) +static inline const char *__cdecl wine_dbgstr_guid( const GUID *id ) { if (!id) return "(null)"; if (!((ULONG_PTR)id >> 16)) return wine_dbg_sprintf( "", (WORD)(ULONG_PTR)id ); @@ -324,20 +310,20 @@ static inline const char *wine_dbgstr_guid( const GUID *id ) id->Data4[4], id->Data4[5], id->Data4[6], id->Data4[7] ); } -static inline const char *wine_dbgstr_point( const POINT *pt ) +static inline const char *__cdecl wine_dbgstr_point( const POINT *pt ) { if (!pt) return "(null)"; return wine_dbg_sprintf( "(%d,%d)", pt->x, pt->y ); } -static inline const char *wine_dbgstr_rect( const RECT *rect ) +static inline const char *__cdecl wine_dbgstr_rect( const RECT *rect ) { if (!rect) return "(null)"; return wine_dbg_sprintf( "(%d,%d)-(%d,%d)", rect->left, rect->top, rect->right, rect->bottom ); } -static inline const char *wine_dbgstr_longlong( ULONGLONG ll ) +static inline const char *__cdecl wine_dbgstr_longlong( ULONGLONG ll ) { if (sizeof(ll) > sizeof(unsigned long) && ll >> 32) return wine_dbg_sprintf( "%lx%08lx", (unsigned long)(ll >> 32), (unsigned long)ll ); @@ -346,7 +332,7 @@ static inline const char *wine_dbgstr_longlong( ULONGLONG ll ) #if defined(__oaidl_h__) && defined(V_VT) -static inline const char *wine_dbgstr_vt( VARTYPE vt ) +static inline const char *__cdecl wine_dbgstr_vt( VARTYPE vt ) { static const char *const variant_types[] = { @@ -394,7 +380,7 @@ static inline const char *wine_dbgstr_vt( VARTYPE vt ) return wine_dbg_sprintf( "vt(invalid %x)", vt ); } -static inline const char *wine_dbgstr_variant( const VARIANT *v ) +static inline const char *__cdecl wine_dbgstr_variant( const VARIANT *v ) { if (!v) return "(null)"; @@ -501,15 +487,15 @@ static inline const char *wine_dbgstr_variant( const VARIANT *v ) #ifdef __WINESRC__ /* Wine uses shorter names that are very likely to conflict with other software */ -static inline const char *debugstr_an( const char * s, int n ) { return wine_dbgstr_an( s, n ); } -static inline const char *debugstr_wn( const WCHAR *s, int n ) { return wine_dbgstr_wn( s, n ); } -static inline const char *debugstr_guid( const struct _GUID *id ) { return wine_dbgstr_guid(id); } -static inline const char *debugstr_a( const char *s ) { return wine_dbgstr_an( s, -1 ); } -static inline const char *debugstr_w( const WCHAR *s ) { return wine_dbgstr_wn( s, -1 ); } +static inline const char *__cdecl debugstr_an( const char * s, int n ) { return wine_dbgstr_an( s, n ); } +static inline const char *__cdecl debugstr_wn( const WCHAR *s, int n ) { return wine_dbgstr_wn( s, n ); } +static inline const char *__cdecl debugstr_guid( const struct _GUID *id ) { return wine_dbgstr_guid(id); } +static inline const char *__cdecl debugstr_a( const char *s ) { return wine_dbgstr_an( s, -1 ); } +static inline const char *__cdecl debugstr_w( const WCHAR *s ) { return wine_dbgstr_wn( s, -1 ); } #if defined(__oaidl_h__) && defined(V_VT) -static inline const char *debugstr_vt( VARTYPE vt ) { return wine_dbgstr_vt( vt ); } -static inline const char *debugstr_variant( const VARIANT *v ) { return wine_dbgstr_variant( v ); } +static inline const char *__cdecl debugstr_vt( VARTYPE vt ) { return wine_dbgstr_vt( vt ); } +static inline const char *__cdecl debugstr_variant( const VARIANT *v ) { return wine_dbgstr_variant( v ); } #endif #define TRACE WINE_TRACE -- 2.28.0 From 9d2a628d462defd4f1d23889d2659f6fae17c9a7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?R=C3=A9mi=20Bernon?= Date: Fri, 18 Sep 2020 13:44:33 +0200 Subject: [PATCH 2/4] ntdll: Implement debugstr_a/w(n) format extensions. This makes it possible to write TRACE("%p(astr)", "string") and get the equivalent of TRACE("%s", debugstr_a("string")), respectively with "%p(wstr)" and debugstr_w(...). The width format specifier (including '*') can be used to control the length (GCC format checker doesn't like precision specifier on %p). Note that the format extension is just here to illustrate, we could think of any other syntax. The main issue is to pass GCC format checker, and as done in the Linux kernel, %p suffixes seems to be the best fit. --- dlls/ntdll/unix/debug.c | 98 ++++++++++++++++++++++++++++++++++++++++- 1 file changed, 97 insertions(+), 1 deletion(-) diff --git a/dlls/ntdll/unix/debug.c b/dlls/ntdll/unix/debug.c index 117dc9153bb..ec15b1bdc38 100644 --- a/dlls/ntdll/unix/debug.c +++ b/dlls/ntdll/unix/debug.c @@ -292,6 +292,92 @@ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_ return append_output( info, buffer, strlen( buffer )); } +static size_t sprintf_dbgstr_an( char *buffer, size_t length, const char *str, int n ) +{ + static const char hex[16] = {'0','1','2','3','4','5','6','7','8','9','a','b','c','d','e','f'}; + char *dst = buffer; + + if (!str) { if (length >= 7) strcpy(buffer, "(null)"); return 6; } + if (!((ULONG_PTR)str >> 16)) return snprintf( buffer, length, "#%04x", LOWORD(str) ); + if (IsBadStringPtrA( str, n )) { if (length >= 10) strcpy(buffer, "(invalid)"); return 9; } + if (n == -1) for (n = 0; str[n]; n++) ; + *dst++ = '"'; + while (n-- > 0 && dst <= buffer + length - 9) + { + unsigned char c = *str++; + switch (c) + { + case '\n': *dst++ = '\\'; *dst++ = 'n'; break; + case '\r': *dst++ = '\\'; *dst++ = 'r'; break; + case '\t': *dst++ = '\\'; *dst++ = 't'; break; + case '"': *dst++ = '\\'; *dst++ = '"'; break; + case '\\': *dst++ = '\\'; *dst++ = '\\'; break; + default: + if (c < ' ' || c >= 127) + { + *dst++ = '\\'; + *dst++ = 'x'; + *dst++ = hex[(c >> 4) & 0x0f]; + *dst++ = hex[c & 0x0f]; + } + else *dst++ = c; + } + } + *dst++ = '"'; + if (n > 0) + { + *dst++ = '.'; + *dst++ = '.'; + *dst++ = '.'; + } + *dst = 0; + return dst - buffer; +} + +static size_t sprintf_dbgstr_wn( char *buffer, size_t length, const WCHAR *str, int n ) +{ + static const char hex[16] = {'0','1','2','3','4','5','6','7','8','9','a','b','c','d','e','f'}; + char *dst = buffer; + + if (!str) { if (length >= 7) strcpy(buffer, "(null)"); return 6; } + if (!((ULONG_PTR)str >> 16)) return snprintf( buffer, length, "#%04x", LOWORD(str) ); + if (IsBadStringPtrW( str, n )) { if (length >= 10) strcpy(buffer, "(invalid)"); return 9; } + if (n == -1) for (n = 0; str[n]; n++) ; + *dst++ = 'L'; + *dst++ = '"'; + while (n-- > 0 && dst <= buffer + length - 10) + { + WCHAR c = *str++; + switch (c) + { + case '\n': *dst++ = '\\'; *dst++ = 'n'; break; + case '\r': *dst++ = '\\'; *dst++ = 'r'; break; + case '\t': *dst++ = '\\'; *dst++ = 't'; break; + case '"': *dst++ = '\\'; *dst++ = '"'; break; + case '\\': *dst++ = '\\'; *dst++ = '\\'; break; + default: + if (c < ' ' || c >= 127) + { + *dst++ = '\\'; + *dst++ = hex[(c >> 12) & 0x0f]; + *dst++ = hex[(c >> 8) & 0x0f]; + *dst++ = hex[(c >> 4) & 0x0f]; + *dst++ = hex[c & 0x0f]; + } + else *dst++ = (char)c; + } + } + *dst++ = '"'; + if (n > 0) + { + *dst++ = '.'; + *dst++ = '.'; + *dst++ = '.'; + } + *dst = 0; + return dst - buffer; +} + int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ) { char fmtbuf[1024]; @@ -438,7 +524,17 @@ int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *forma } break; case 'p': - snprintf_dispatch(buf, end - buf, fmt, va_arg(args, void *)); + if (!strncmp(spec, "p(astr)", 7)) /* debugstr_a / debugstr_an */ + { + append_checked(buf, end - buf, sprintf_dbgstr_an(buf, end - buf, va_arg(args, const char *), w)); + snprintf_checked(buf, end - buf, spec + 7); + } + else if (!strncmp(spec, "p(wstr)", 7)) /* debugstr_w / debugstr_wn */ + { + append_checked(buf, end - buf, sprintf_dbgstr_wn(buf, end - buf, va_arg(args, const WCHAR *), w)); + snprintf_checked(buf, end - buf, spec + 7); + } + else snprintf_dispatch(buf, end - buf, fmt, va_arg(args, void *)); break; case 'A': case 'a': -- 2.28.0 From d45884e4abeac8e5e910089d973524c968383af0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?R=C3=A9mi=20Bernon?= Date: Fri, 18 Sep 2020 16:06:49 +0200 Subject: [PATCH 3/4] ntdll: Implement debugstr_us/as format extensions. Using %p(us) / %p(as) respectively for UNICODE_STRING* and ANSI_STRING*. --- dlls/ntdll/unix/debug.c | 22 ++++++++++++++++++++++ 1 file changed, 22 insertions(+) diff --git a/dlls/ntdll/unix/debug.c b/dlls/ntdll/unix/debug.c index ec15b1bdc38..41089edf466 100644 --- a/dlls/ntdll/unix/debug.c +++ b/dlls/ntdll/unix/debug.c @@ -378,6 +378,18 @@ static size_t sprintf_dbgstr_wn( char *buffer, size_t length, const WCHAR *str, return dst - buffer; } +static size_t sprintf_dbgstr_us( char *buffer, size_t length, const UNICODE_STRING *us ) +{ + if (!us) { if (length >= 7) strcpy(buffer, ""); return 6; } + return sprintf_dbgstr_wn( buffer, length, us->Buffer, us->Length / sizeof(WCHAR) ); +} + +static size_t sprintf_dbgstr_as( char *buffer, size_t length, const ANSI_STRING *as ) +{ + if (!as) { if (length >= 7) strcpy(buffer, ""); return 6; } + return sprintf_dbgstr_an( buffer, length, as->Buffer, as->Length ); +} + int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ) { char fmtbuf[1024]; @@ -534,6 +546,16 @@ int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *forma append_checked(buf, end - buf, sprintf_dbgstr_wn(buf, end - buf, va_arg(args, const WCHAR *), w)); snprintf_checked(buf, end - buf, spec + 7); } + else if (!strncmp(spec, "p(us)", 5)) /* debugstr_us */ + { + append_checked(buf, end - buf, sprintf_dbgstr_us(buf, end - buf, va_arg(args, const UNICODE_STRING *))); + snprintf_checked(buf, end - buf, spec + 5); + } + else if (!strncmp(spec, "p(as)", 5)) + { + append_checked(buf, end - buf, sprintf_dbgstr_as(buf, end - buf, va_arg(args, const ANSI_STRING *))); + snprintf_checked(buf, end - buf, spec + 5); + } else snprintf_dispatch(buf, end - buf, fmt, va_arg(args, void *)); break; case 'A': -- 2.28.0 From a916d7d6920288278a4e50c8fbd1318d91108ffe Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?R=C3=A9mi=20Bernon?= Date: Fri, 18 Sep 2020 13:55:25 +0200 Subject: [PATCH 4/4] ntdll: Implement debugstr_guid/point/rect extensions. As previously, this adds support for %p(guid), %p(point) and %p(rect) format specifiers. --- dlls/ntdll/unix/debug.c | 38 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 38 insertions(+) diff --git a/dlls/ntdll/unix/debug.c b/dlls/ntdll/unix/debug.c index 41089edf466..37069e4ea7b 100644 --- a/dlls/ntdll/unix/debug.c +++ b/dlls/ntdll/unix/debug.c @@ -390,6 +390,29 @@ static size_t sprintf_dbgstr_as( char *buffer, size_t length, const ANSI_STRING return sprintf_dbgstr_an( buffer, length, as->Buffer, as->Length ); } +static size_t sprintf_dbgstr_guid( char *buffer, size_t length, const GUID *id ) +{ + if (!id) { if (length >= 7) strcpy(buffer, "(null)"); return 6; } + if (!((ULONG_PTR)id >> 16)) return snprintf( buffer, length, "", (WORD)(ULONG_PTR)id ); + return snprintf( buffer, length, "{%08x-%04x-%04x-%02x%02x-%02x%02x%02x%02x%02x%02x}", + id->Data1, id->Data2, id->Data3, + id->Data4[0], id->Data4[1], id->Data4[2], id->Data4[3], + id->Data4[4], id->Data4[5], id->Data4[6], id->Data4[7] ); +} + +static size_t sprintf_dbgstr_point( char *buffer, size_t length, const POINT *pt ) +{ + if (!pt) { if (length >= 7) strcpy(buffer, "(null)"); return 6; } + return snprintf( buffer, length, "(%d,%d)", pt->x, pt->y ); +} + +static size_t sprintf_dbgstr_rect( char *buffer, size_t length, const RECT *rect ) +{ + if (!rect) { if (length >= 7) strcpy(buffer, "(null)"); return 6; } + return snprintf( buffer, length, "(%d,%d)-(%d,%d)", rect->left, rect->top, + rect->right, rect->bottom ); +} + int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *format, __ms_va_list args ) { char fmtbuf[1024]; @@ -556,6 +579,21 @@ int __cdecl __wine_dbg_vsnprintf( char *buffer, size_t length, const char *forma append_checked(buf, end - buf, sprintf_dbgstr_as(buf, end - buf, va_arg(args, const ANSI_STRING *))); snprintf_checked(buf, end - buf, spec + 5); } + else if (!strncmp(spec, "p(guid)", 7)) /* debugstr_guid */ + { + append_checked(buf, end - buf, sprintf_dbgstr_guid(buf, end - buf, va_arg(args, const GUID *))); + snprintf_checked(buf, end - buf, spec + 7); + } + else if (!strncmp(spec, "p(point)", 8)) /* debugstr_point */ + { + append_checked(buf, end - buf, sprintf_dbgstr_point(buf, end - buf, va_arg(args, const POINT *))); + snprintf_checked(buf, end - buf, spec + 8); + } + else if (!strncmp(spec, "p(rect)", 7)) /* debugstr_rect */ + { + append_checked(buf, end - buf, sprintf_dbgstr_rect(buf, end - buf, va_arg(args, const RECT *))); + snprintf_checked(buf, end - buf, spec + 7); + } else snprintf_dispatch(buf, end - buf, fmt, va_arg(args, void *)); break; case 'A': -- 2.28.0