if (descr->magic != RELAY_DESCR_MAGIC || !(data = descr->private)) return proc; /* no relay data */ if (!data->entry_points[ordinal].orig_func) return proc; /* not a relayed function */ if (check_from_module( debug_from_relay_includelist, debug_from_relay_excludelist, user )) return proc; /* we want to relay it */ return data->entry_points[ordinal].orig_func; }
Wine-dbg>disass proc 0x7e8d7cf0: push esp 0x7e8d7cf1: push 0x10130 0x7e8d7cf6: call 0x7e8dae44 __wine_spec_get_pc_thunk_eax in user32 0x7e8d7cfb: lea eax, [eax+0xd9fcd] 0x7e8d7d01: push eax 0x7e8d7d02: call dword [eax+0x4] 0x7e8d7d05: ret 0x4 Wine-dbg>p 0x7e8d7cfb+0xd9fcd+0x4 0x7e9b1ccc Wine-dbg>x /4x 0x7e9b1ccc 0x7e9b1ccc: 7bc76c2c 7bc77270 00124640 7e8d615d Wine-dbg>disass 0x7bc76c2c 0x7bc76c2c relay_call in ntdll: push ebp 0x7bc76c2d relay_call+0x1 in ntdll: mov ebp, esp 0x7bc76c2f relay_call+0x3 in ntdll: push esi 0x7bc76c30 relay_call+0x4 in ntdll: push edi 0x7bc76c31 relay_call+0x5 in ntdll: push ecx 0x7bc76c32 relay_call+0x6 in ntdll: push dword [ebp+0x10] 0x7bc76c35 relay_call+0x9 in ntdll: push dword [ebp+0xc] 0x7bc76c38 relay_call+0xc in ntdll: push dword [ebp+0x8] 0x7bc76c3b relay_call+0xf in ntdll: call 0x7bc76835 relay_trace_entry [../wine_git/dlls/ntdll/relay.c:334] in ntdll 0x7bc76c40 relay_call+0x14 in ntdll: movzx ecx, byte [ebp+0xe] ...
原始的 GetMenu 地址:
Wine-dbg>info local 0x7bc772f4 RELAY_GetProcAddress+0x75: (0033eac8) HMODULE module=0x7e8d0000 (parameter [EBP+8]) IMAGE_EXPORT_DIRECTORY* exports=0x7e9ad19c (parameter [EBP+12]) DWORD exp_size=0x4b2c (parameter [EBP+16]) FARPROC proc=0x7e8d7cf0 (parameter [EBP+20]) DWORD ordinal=0x130 (parameter [EBP+24]) WCHAR* user=0x0(nil) (parameter [EBP+28]) struct relay_private_data* data=0x124640 (local [EBP-12]) struct relay_descr* descr=0x7e9b1cc8 (local [EBP-16]) Wine-dbg>p *descr {magic=0xdeb90001, relay_call=0x7bc76c2c, relay_call_regs=0x7bc77270, private=0x124640, entry_point_base="恌怲h", entry_point_offsets=0x7e9744f8, arg_types=0x7e975048} Wine-dbg>x /14x 0x124640 0x00124640: 7e8d0000 00000001 72657375 00003233 0x00124650: 00000000 00000000 00000000 00000000 0x00124660: 00000000 00000000 00000000 00000000 0x00124670: 7e913010 7e9aee17 Wine-dbg>x /10x 0x00124670+0x130*8 0x00124ff0: 7e928890 7e9b018c 7e92c6d0 7e9b0194 0x00125000: 7e927fc0 7e9b01a3 7e92cc30 7e9b01be 0x00125010: 7e92b680 7e9b01d3 Wine-dbg>x /10c 0x7e9b018c 0x7e9b018c: G e t M e n u G e Wine-dbg>disass 0x7e928890 0x7e928890 GetMenu [../wine_git/dlls/user32/menu.c:4208] in user32: lea ecx, [esp+0x4] 0x7e928894 GetMenu+0x4 [../wine_git/dlls/user32/menu.c:4208] in user32: and esp, 0xfffffff0 0x7e928897 GetMenu+0x7 [../wine_git/dlls/user32/menu.c:4208] in user32: push dword [ecx-0x4] 0x7e92889a GetMenu+0xa [../wine_git/dlls/user32/menu.c:4208] in user32: push ebp 0x7e92889b GetMenu+0xb [../wine_git/dlls/user32/menu.c:4208] in user32: mov ebp, esp 0x7e92889d GetMenu+0xd [../wine_git/dlls/user32/menu.c:4208] in user32: push edi 0x7e92889e GetMenu+0xe [../wine_git/dlls/user32/menu.c:4208] in user32: push esi 0x7e92889f GetMenu+0xf [../wine_git/dlls/user32/menu.c:4208] in user32: push ebx 0x7e9288a0 GetMenu+0x10 [../wine_git/dlls/user32/menu.c:4208] in user32: push ecx 0x7e9288a1 GetMenu+0x11 [../wine_git/dlls/user32/menu.c:4208] in user32: call 0x7e8d5b60 __x86.get_pc_thunk.bx in user32 ...
输出调试日志是调试程序的一种常见方法,尤其是处理那些难以捉摸的多线程错误、随机崩溃等问题时 。通过在合适的位置输出调试日志,可以帮助我们更快地定位问题所在。
对于不熟悉的代码,经常打日志也有助于快速理解代码的执行流程和功能。在大型项目中,通常会先实现一套自己的调试日志框架,主要有两个目的:
Wine 项目也不例外,它也实现了一套自己的日志系统。这套系统非常简洁,下面我们就来详细介绍。
Wine 的调试日志实现
调试通道(debug channel)
Wine 定义了调试通道的概念来分类日志,将日志的记录和实际的输出分离,无需重新编译 Wine,就能动态地灵活控制 Wine 运行时的日志输出。
__wine_debug_channel
的结构体,刚好16个字节,非常符合 UNIX 简单原则的哲学理念:{
unsigned char flags;
char name[15];
};
include/wine/debug.h
;WINE_DEFAULT_DEBUG_CHANNEL
或WINE_DEFAULT_DEBUG_CHANNEL
宏来声明。git grep _DEBUG_CHANNEL
。向调试通道发送日志
Wine 把日志分成了4个级别,从高到低依次是:fixme/ err(or)/ warn/ trace,对应的提供了4个宏来输出不同级别的日志到调试通道:FIXME/ ERR/ WARN/ TRACE,非常简单、清晰。
do { if(__WINE_GET_DEBUGGING(dbcl,(dbch))) { \
struct __wine_debug_channel * const __dbch = (dbch); \
const enum __wine_debug_class __dbcl = __WINE_DBCL##dbcl; \
__WINE_DBG_LOG
#define __WINE_DBG_LOG(args...) \
wine_dbg_log( __dbcl, __dbch, __FUNCTION__, args); } } while(0)
#define TRACE __WINE_DPRINTF(_TRACE,__wine_dbch___default)
#define TRACE_(ch) __WINE_DPRINTF(_TRACE,&__wine_dbch_##ch)
#define TRACE_ON(ch) __WINE_IS_DEBUG_ON(_TRACE,&__wine_dbch_##ch)
#define WARN __WINE_DPRINTF(_WARN,__wine_dbch___default)
#define WARN_(ch) __WINE_DPRINTF(_WARN,&__wine_dbch_##ch)
#define WARN_ON(ch) __WINE_IS_DEBUG_ON(_WARN,&__wine_dbch_##ch)
#define FIXME __WINE_DPRINTF(_FIXME,__wine_dbch___default)
#define FIXME_(ch) __WINE_DPRINTF(_FIXME,&__wine_dbch_##ch)
#define FIXME_ON(ch) __WINE_IS_DEBUG_ON(_FIXME,&__wine_dbch_##ch)
#define ERR __WINE_DPRINTF(_ERR,__wine_dbch___default)
#define ERR_(ch) __WINE_DPRINTF(_ERR,&__wine_dbch_##ch)
#define ERR_ON(ch) __WINE_IS_DEBUG_ON(_ERR,&__wine_dbch_##ch)
最终都是调用函数 wine_dbg_log 来打日志:
const char *func, const char *format, ... )
{
int ret;
va_list valist;
if (!(__wine_dbg_get_channel_flags( channel ) & (1 << cls))) return -1;
va_start(valist, format);
ret = funcs.dbg_vlog( cls, channel, func, format, valist );
va_end(valist);
return ret;
}
其中的 funcs.dbg_vlog 初始化时会指向 default_dbg_vlog:
const char *func, const char *format, va_list args )
在Wine线程创建成功后 funcs.dbg_vlog 会指向 ntdll/debugtools.c 的
const char *function, const char *format, va_list args )
程序运行前开启调试通道
用这样的格式定义环境变量:
WINEDEBUG=[class][+/-]channel[,[class2][+/-]channel2]
其中:
例:
WINEDEBUG=warn+dll,+heap
WINEDEBUG=fixme-all,warn+cursor,+relay
如果没有定义
WINEDEBUG
环境变量,发给每个调试通道的 fixme 和 err 级别的日志都会输出;Wine 默认同时开启运行的调试通道是 256个,由这个宏MAX_DEBUG_OPTIONS
决定。关键代码如下:
{
__WINE_DBCL_FIXME,
__WINE_DBCL_ERR,
__WINE_DBCL_WARN,
__WINE_DBCL_TRACE,
__WINE_DBCL_INIT = 7 /* lazy init flag, bit7 */
};
static unsigned char default_flags = (1 << __WINE_DBCL_ERR) | (1
仅标记作用的调试通道
比较特殊的高级调试通道
0009:trace:seh:raise_exception info[0]=00000000
0009:trace:seh:raise_exception eax=00000006 ebx=0b6f4f58 ecx=08b44020 edx=0033d15c esi=0dfde520 edi=0df80020
0009:trace:seh:raise_exception ebp=0033d0d0 esp=0033d0c0 cs=0023 ds=002b es=002b fs=0063 gs=006b flags=00210206
0017:Call KERNEL32.CreateFileA(7ea8e936 "CONIN$",c0000000,00000003,00000000,00000003,00000000,00000000) ret=7ea323fd
0017:Ret KERNEL32.CreateFileA() retval=00000023 ret=7ea323fd
...
snoop:无需修改代码,记录程序对第三方 native 模块的所有导出函数的调用参数和返回值。
Snoop 是自己检查 stack 数据和反汇编来探测函数调用约定、参数和返回地址的, 如果探测错了会影响程序的稳定,甚至导致程序崩溃,建议仅在非常规情况下使用。
trace:snoop:SNOOP_SetupDLL hmod=0x4ae90000, name=gdiplus.dll
0043:CALL MSVCR100_CLR0400.wcscpy_s(04b7c808,0000000c,0033d188 L"gdiplus.dll") ret=79203d6b
0043:RET MSVCR100_CLR0400.wcscpy_s() retval=00000000 ret=79203d6b
0043:CALL MSVCR100_CLR0400.memset(0033dc9c,00000000,00000010) ret=792bd727
0043:RET MSVCR100_CLR0400.memset() retval=0033dc9c ret=792bd727
0043:CALL gdiplus.GdiplusStartup() ret=04b8e775
0043:RET gdiplus.GdiplusStartup(03c00ae0,0033dc9c,0033dcec) retval=00000000 ret=04b8e775
...
0043:CALL gdiplus.GdipCreateFromHWND() ret=04b8e8b3
0043:RET gdiplus.GdipCreateFromHWND(0004003a,0033e988) retval=00000000 ret=04b8e8b3
...
Relay 和 snoop 的缺点是记录的日志巨大导致程序反应非常慢,只建议在没有任何思路、一筹莫展时使用。
程序运行中动态开关调试通道
WINEDEBUG
环境变量里面列出的调试通道。Winedbg 的 set 命令也只能设置在
WINEDEBUG
已经开启了的调试通道。如果没有在WINEDEBUG
里面定义的,就会提示:Unable to find debug channel xxx
。debug_options
和nb_debug_options
的数据。因为debug_options
是按照调试通道名称字符串比较排序的,所以开启多个通道需要手动排序。这个方法适合运行程序时忘记设置WINEDEBUG
,但是想查看某个调试通道日志时又不想重新运行程序的时候使用。Unable to find debug channel win
Wine-dbg>p debug_options[0]
{flags=0, name=""}
Wine-dbg);set debug_options[0].flags=0xf
Wine-dbg>p debug_options[0]
{flags=f, name=""}
Wine-dbg>set debug_options[0].name[0]='w'
Wine-dbg>set debug_options[0].name[1]='i'
Wine-dbg>set debug_options[0].name[2]='n'
Wine-dbg>set debug_options[0].name[3]= 0
Wine-dbg>p debug_options[0]
{flags=f, name="楷n"}
Wine-dbg>p &debug_options[0]
0xf77092d0
Wine-dbg>x /s 0xf77092d1
win
Wine-dbg>p nb_debug_options
0
Wine-dbg>set nb_debug_options=1
debug_options
和nb_debug_options
的地址。166: 00005030 223 FUNC GLOBAL DEFAULT 12 __wine_dbg_get_channel_fl@@WINE_1.0
172: 00005390 253 FUNC GLOBAL DEFAULT 12 __wine_dbg_set_functions@@WINE_1.0
Module Address Debug info Name (23 modules)
...
ELF f75d5000-f778c000 Dwarf libwine.so.1 @,/opt/cxoffice/bin/../lib/libwine.so.1
...
0xf75da030 __wine_dbg_get_channel_flags in libwine.so.1: push ebp
0xf75da031 __wine_dbg_get_channel_flags+0x1 in libwine.so.1: mov ebp, esp
0xf75da033 __wine_dbg_get_channel_flags+0x3 in libwine.so.1: push edi
0xf75da034 __wine_dbg_get_channel_flags+0x4 in libwine.so.1: push esi
0xf75da035 __wine_dbg_get_channel_flags+0x5 in libwine.so.1: push ebx
0xf75da036 __wine_dbg_get_channel_flags+0x6 in libwine.so.1: call 0xf75d81a0
0xf75da03b __wine_dbg_get_channel_flags+0xb in libwine.so.1: add ebx, 0x19dfc5
0xf75da041 __wine_dbg_get_channel_flags+0x11 in libwine.so.1: sub esp, 0x1c
0xf75da044 __wine_dbg_get_channel_flags+0x14 in libwine.so.1: mov ecx, [ebx+0x134] --> nb_debug_options
0xf75da04a __wine_dbg_get_channel_flags+0x1a in libwine.so.1: cmp ecx, 0xffffffff
0xf75da04d __wine_dbg_get_channel_flags+0x1d in libwine.so.1: jz 0xf75da0f0
0xf75da053 __wine_dbg_get_channel_flags+0x23 in libwine.so.1: test ecx, ecx
0xf75da055 __wine_dbg_get_channel_flags+0x25 in libwine.so.1: jz 0xf75da0c0
0xf75da057 __wine_dbg_get_channel_flags+0x27 in libwine.so.1: mov eax, [ebp+0x8]
0xf75da05a __wine_dbg_get_channel_flags+0x2a in libwine.so.1: mov edi, ecx
0xf75da05c __wine_dbg_get_channel_flags+0x2c in libwine.so.1: mov dword [ebp-0x1c], 0x0
0xf75da063 __wine_dbg_get_channel_flags+0x33 in libwine.so.1: add eax, 0x1
0xf75da066 __wine_dbg_get_channel_flags+0x36 in libwine.so.1: mov [ebp-0x24], eax
0xf75da069 __wine_dbg_get_channel_flags+0x39 in libwine.so.1: lea eax, [ebx+0x260] --> debug_options
0xf75da06f __wine_dbg_get_channel_flags+0x3f in libwine.so.1: mov [ebp-0x28], eax
0xf75da072 __wine_dbg_get_channel_flags+0x42 in libwine.so.1: jmp 0xf75da07f __wine_dbg_get_channel_flags+0x4f in libwine.so.1
0xf75d3074 __wine_dbg_get_channel_flags+0x44 in libwine.so.1: lea esi, [esi]
...
0xf75d81a0: mov ebx, [esp]
0xf75d81a3: ret
GCC 习惯通过 ebx 寄存器来引用全局变量,所以
nb_debug_options
的地址是:0xf75d303b+0x19dfc5+0x134
;debug_options
的地址是:0xf75d303b+0x19dfc5+0x260
;然后参考方法 2 的 set 命令修改内存即可。Relay 调试通道实现原理
在 LoadLibrary 内部,如果检查到已经开启了 relay 通道,并且已加载 Wine 内建的 DLL 文件,那么就调用 RELAY_SetupDLL 来解析 DLL 的导出函数表(IMAGE_DIRECTORY_ENTRY_EXPORT)。对于导出表中的 AddressOfFunctions 数组中的每个条目,先备份原始值,然后将每个条目值修改为可跳转 relay_call 函数的 hack 函数地址。hack 函数在 faked PE 模块中,固定为 24 字节大小,形式如下:
0x7e7a4211: push 0x50000
0x7e7a4216: call 0x7e7a6a40 __wine_spec_get_pc_thunk_eax in gdi32
0x7e7a421b: lea eax, [eax+0xadd31]
0x7e7a4221: push eax
0x7e7a4222: call dword [eax+0x4] --> relay_call
0x7e7a4225: ret 0x14
不同的 API 变化的只是里面的数字常量。在 GetProcAddress 内部检查是否开启了 relay 通道,如已开启就调用 RELAY_GetProcAddress 返回 hack 的函数地址。以 user32 模块的GetMenu 举例,返回的 hack 的 GetMenu 函数如下:
DWORD exp_size, FARPROC proc, DWORD ordinal, const WCHAR *user )
{
struct relay_private_data *data;
const struct relay_descr *descr = (const struct relay_descr *)((const char *)exports + exp_size);
if (descr->magic != RELAY_DESCR_MAGIC || !(data = descr->private)) return proc; /* no relay data */
if (!data->entry_points[ordinal].orig_func) return proc; /* not a relayed function */
if (check_from_module( debug_from_relay_includelist, debug_from_relay_excludelist, user ))
return proc; /* we want to relay it */
return data->entry_points[ordinal].orig_func;
}
Wine-dbg>disass proc
0x7e8d7cf0: push esp
0x7e8d7cf1: push 0x10130
0x7e8d7cf6: call 0x7e8dae44 __wine_spec_get_pc_thunk_eax in user32
0x7e8d7cfb: lea eax, [eax+0xd9fcd]
0x7e8d7d01: push eax
0x7e8d7d02: call dword [eax+0x4]
0x7e8d7d05: ret 0x4
Wine-dbg>p 0x7e8d7cfb+0xd9fcd+0x4
0x7e9b1ccc
Wine-dbg>x /4x 0x7e9b1ccc
0x7e9b1ccc: 7bc76c2c 7bc77270 00124640 7e8d615d
Wine-dbg>disass 0x7bc76c2c
0x7bc76c2c relay_call in ntdll: push ebp
0x7bc76c2d relay_call+0x1 in ntdll: mov ebp, esp
0x7bc76c2f relay_call+0x3 in ntdll: push esi
0x7bc76c30 relay_call+0x4 in ntdll: push edi
0x7bc76c31 relay_call+0x5 in ntdll: push ecx
0x7bc76c32 relay_call+0x6 in ntdll: push dword [ebp+0x10]
0x7bc76c35 relay_call+0x9 in ntdll: push dword [ebp+0xc]
0x7bc76c38 relay_call+0xc in ntdll: push dword [ebp+0x8]
0x7bc76c3b relay_call+0xf in ntdll: call 0x7bc76835 relay_trace_entry [../wine_git/dlls/ntdll/relay.c:334] in ntdll
0x7bc76c40 relay_call+0x14 in ntdll: movzx ecx, byte [ebp+0xe]
...
原始的 GetMenu 地址:
0x7bc772f4 RELAY_GetProcAddress+0x75: (0033eac8)
HMODULE module=0x7e8d0000 (parameter [EBP+8])
IMAGE_EXPORT_DIRECTORY* exports=0x7e9ad19c (parameter [EBP+12])
DWORD exp_size=0x4b2c (parameter [EBP+16])
FARPROC proc=0x7e8d7cf0 (parameter [EBP+20])
DWORD ordinal=0x130 (parameter [EBP+24])
WCHAR* user=0x0(nil) (parameter [EBP+28])
struct relay_private_data* data=0x124640 (local [EBP-12])
struct relay_descr* descr=0x7e9b1cc8 (local [EBP-16])
Wine-dbg>p *descr
{magic=0xdeb90001, relay_call=0x7bc76c2c, relay_call_regs=0x7bc77270,
private=0x124640, entry_point_base="恌怲h", entry_point_offsets=0x7e9744f8, arg_types=0x7e975048}
Wine-dbg>x /14x 0x124640
0x00124640: 7e8d0000 00000001 72657375 00003233
0x00124650: 00000000 00000000 00000000 00000000
0x00124660: 00000000 00000000 00000000 00000000
0x00124670: 7e913010 7e9aee17
Wine-dbg>x /10x 0x00124670+0x130*8
0x00124ff0: 7e928890 7e9b018c 7e92c6d0 7e9b0194
0x00125000: 7e927fc0 7e9b01a3 7e92cc30 7e9b01be
0x00125010: 7e92b680 7e9b01d3
Wine-dbg>x /10c 0x7e9b018c
0x7e9b018c: G e t M e n u G e
Wine-dbg>disass 0x7e928890
0x7e928890 GetMenu [../wine_git/dlls/user32/menu.c:4208] in user32: lea ecx, [esp+0x4]
0x7e928894 GetMenu+0x4 [../wine_git/dlls/user32/menu.c:4208] in user32: and esp, 0xfffffff0
0x7e928897 GetMenu+0x7 [../wine_git/dlls/user32/menu.c:4208] in user32: push dword [ecx-0x4]
0x7e92889a GetMenu+0xa [../wine_git/dlls/user32/menu.c:4208] in user32: push ebp
0x7e92889b GetMenu+0xb [../wine_git/dlls/user32/menu.c:4208] in user32: mov ebp, esp
0x7e92889d GetMenu+0xd [../wine_git/dlls/user32/menu.c:4208] in user32: push edi
0x7e92889e GetMenu+0xe [../wine_git/dlls/user32/menu.c:4208] in user32: push esi
0x7e92889f GetMenu+0xf [../wine_git/dlls/user32/menu.c:4208] in user32: push ebx
0x7e9288a0 GetMenu+0x10 [../wine_git/dlls/user32/menu.c:4208] in user32: push ecx
0x7e9288a1 GetMenu+0x11 [../wine_git/dlls/user32/menu.c:4208] in user32: call 0x7e8d5b60 __x86.get_pc_thunk.bx in user32
...
Relay_call 里面调用 relay_trace_entry/relay_trace_exit 来记录函数的进和出,以及调用真实的API。
Snoop 调试通道的实现原理
结束
解决实际问题的时候, 我们先收集日志,然后重点看 err:、fixme:、seh: 的日志,一般能从中找到问题的相关线索。
相关阅读:
想开启 Wine 开发?看这篇就够了!
如何简单实现Windows应用在Linux系统上的无缝运行?