From: "Rémi Bernon" Subject: [PATCH 1/6] ntdll: Redirect wine_dbg_log/printf formatting to ntdll.so. Message-Id: <20201121201913.1177092-1-rbernon@codeweavers.com> Date: Sat, 21 Nov 2020 21:19:08 +0100 This adds a new __wine_dbg_vprintf internal export to format and output a debug message at once, using ms_abi varargs calling convention in all cases. We convert format specifiers for the MSVC extensions, and translate the calling convention by passing format specifiers and their arguments to glibc snprintf one by one. Signed-off-by: Rémi Bernon --- As it was mentionned on IRC earlier, I figured I could clean these up a bit and more formally submit them. Also it looks like that +msvcrt is now completely broken, probably because it now traces itself over and over (where it was only tracing the TRACE from PE modules previously, which was already a bit annoying). These changes also have the nice property of reducing the eventual SSE register spilling induced by the debug helpers being previously sysv_abi in non-PE modules, when called within ms_abi functions. This is solved in all cases by making them ms_abi and doing the calling convention conversion within ntdll.so. Having the format string parsing in ntdll.so 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 and ntdll.so transitions, this is illustrated in the last 3 patches of the series, and the format specifiers could be made different of course. dlls/ntdll/ntdll.spec | 1 + dlls/ntdll/thread.c | 7 ++ dlls/ntdll/unix/debug.c | 198 +++++++++++++++++++++++++++++++++++++++ dlls/ntdll/unix/loader.c | 1 + dlls/ntdll/unixlib.h | 3 +- dlls/winecrt0/debug.c | 14 +++ include/wine/debug.h | 40 ++++---- 7 files changed, 242 insertions(+), 22 deletions(-) diff --git a/dlls/ntdll/ntdll.spec b/dlls/ntdll/ntdll.spec index 248ae72a011..3a7adc92752 100644 --- a/dlls/ntdll/ntdll.spec +++ b/dlls/ntdll/ntdll.spec @@ -1616,6 +1616,7 @@ @ 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) # Virtual memory @ cdecl -syscall __wine_locked_recvmsg(long ptr long) diff --git a/dlls/ntdll/thread.c b/dlls/ntdll/thread.c index 578c7a5436c..a7231d008c6 100644 --- a/dlls/ntdll/thread.c +++ b/dlls/ntdll/thread.c @@ -74,6 +74,13 @@ int __cdecl __wine_dbg_output( const char *str ) return unix_funcs->dbg_output( str ); } +/*********************************************************************** + * __wine_dbg_vprintf (NTDLL.@) + */ +int __cdecl __wine_dbg_vprintf( const char *format, __ms_va_list args ) +{ + return unix_funcs->dbg_vprintf( format, args ); +} /******************************************************************* * KiUserApcDispatcher (NTDLL.@) diff --git a/dlls/ntdll/unix/debug.c b/dlls/ntdll/unix/debug.c index 368baac46f4..fe5c3c64272 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 @@ -287,6 +289,202 @@ int __cdecl __wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_ return append_output( info, buffer, strlen( buffer )); } +static 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 old, *spec, *width = NULL, *prec = NULL; + 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[0] != '%') prec = width = NULL; + else if (fmt[1] == '-' || fmt[1] == '+' || fmt[1] == ' ' || fmt[1] == '#' || fmt[1] == '0') width = fmt + 2; + else width = fmt + 1; + + if (!width) w = -1; + else if (*width == '*') w = va_arg( args, int ); + else if (!(w = atoi( width ))) w = -1; + + if (fmt[0] != '%' || !(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) + + /* dispatch width / precision arguments for all possible %*.* format specifiers */ +#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 )))) +#define snprintf_checked( b, l, ... ) append_checked( b, l, snprintf( b, l, ## __VA_ARGS__ ) ) + + 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_checked +#undef snprintf_dispatch +#undef append_checked + + *tmp = old; + fmt = tmp; + } + + return buf - buffer; +} + +/*********************************************************************** + * __wine_dbg_vprintf (NTDLL.@) + */ +int __cdecl __wine_dbg_vprintf( const char *format, __ms_va_list args ) +{ + char buffer[1024]; + wine_dbg_vsnprintf( buffer, sizeof(buffer), format, args ); + return __wine_dbg_output( buffer ); +} + + /*********************************************************************** * dbg_init */ diff --git a/dlls/ntdll/unix/loader.c b/dlls/ntdll/unix/loader.c index c2b6ea603e3..310a4dab93c 100644 --- a/dlls/ntdll/unix/loader.c +++ b/dlls/ntdll/unix/loader.c @@ -1546,6 +1546,7 @@ static struct unix_funcs unix_funcs = __wine_dbg_strdup, __wine_dbg_output, __wine_dbg_header, + __wine_dbg_vprintf, }; diff --git a/dlls/ntdll/unixlib.h b/dlls/ntdll/unixlib.h index 7ed3148e4c4..1e98700a3fd 100644 --- a/dlls/ntdll/unixlib.h +++ b/dlls/ntdll/unixlib.h @@ -27,7 +27,7 @@ struct _DISPATCHER_CONTEXT; /* increment this when you change the function table */ -#define NTDLL_UNIXLIB_VERSION 106 +#define NTDLL_UNIXLIB_VERSION 107 struct unix_funcs { @@ -98,6 +98,7 @@ struct unix_funcs 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 ); }; #endif /* __NTDLL_UNIXLIB_H */ diff --git a/dlls/winecrt0/debug.c b/dlls/winecrt0/debug.c index cb07c7835d4..5dc93acbecb 100644 --- a/dlls/winecrt0/debug.c +++ b/dlls/winecrt0/debug.c @@ -33,6 +33,7 @@ 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 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, @@ -178,6 +179,13 @@ static int __cdecl fallback__wine_dbg_output( const char *str ) return fwrite( str, 1, len, stderr ); } +static int __cdecl fallback__wine_dbg_vprintf( const char *format, __ms_va_list args ) +{ + char str[1024]; + vsnprintf( str, sizeof(str), format, args ); + return __wine_dbg_output( str ); +} + static int __cdecl fallback__wine_dbg_header( enum __wine_debug_class cls, struct __wine_debug_channel *channel, const char *function ) @@ -236,6 +244,12 @@ int __cdecl __wine_dbg_output( const char *str ) return p__wine_dbg_output( 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 ); +} + unsigned char __cdecl __wine_dbg_get_channel_flags( struct __wine_debug_channel *channel ) { LOAD_FUNC( __wine_dbg_get_channel_flags ); diff --git a/include/wine/debug.h b/include/wine/debug.h index e064aaefb8e..7024ef270fc 100644 --- a/include/wine/debug.h +++ b/include/wine/debug.h @@ -148,6 +148,7 @@ 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 ); /* * Exported definitions and macros @@ -181,27 +182,25 @@ static inline const char * __wine_dbg_cdecl wine_dbg_sprintf( const char *format 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, - 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; + __ms_va_list args; int ret; if (*format == '\1') /* special magic to avoid standard prefix */ @@ -211,10 +210,9 @@ 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; } -- 2.29.2