收集API调用日志的快速的方法

调试问题时可能面临的一个常见任务是记录有关对一个或多个函数的调用的信息。如果你想知道你的程序中有一个你有源代码的函数,你可以添加一些调试打印和重建程序,有时这是不实际的。例如,您可能不总是能够重现一个问题,因此可能不可行的是,必须重新启动调试生成,因为您可能会吹走您的重现。或者,更重要的是,您可能需要记录对没有源代码的函数的调用(或者不作为程序的一部分构建,或者不想修改)。
例如,您可能希望记录对各种Windows api的调用,以便获得有关正在排除故障的问题的信息。现在,根据您正在做的工作,您可以在每次调用特定API之前和之后添加调试打印来完成这项工作。但是,这通常不太方便,如果您不是要记录的函数的直接调用方,那么无论如何,您都不能走这条路。
有许多API spy/API日志记录软件包(Windows发行版的调试工具甚至附带了一个名为Logger的软件包,尽管它往往相当脆弱——就我个人而言,我经常遇到它崩溃,而不是实际工作中遇到的问题)。尽管您可以使用其中的一个,但是“收缩包装”日志工具的一个很大的限制是,它们不知道如何正确地记录对自定义函数的调用,或者日志工具不知道的函数。更好的日志工具在一定程度上是用户可扩展的,因为它们通常提供某种脚本语言或编程语言,允许用户(即您)描述函数参数和调用约定,以便对它们进行日志记录。
但是,通常很难(甚至不可能)向这些工具描述许多类型的函数,例如包含指向包含指向其他结构的指针的结构的指针的函数,或其他此类不重要的结构。因此,在许多情况下,我倾向于建议不要在需要记录对函数的调用的情况下使用所谓的“收缩包装”API日志工具。

但是,如果在源代码中实现调试打印不是一个可行的解决方案,那么表面上看,这会使一个没有可用的解决方案来记录调用。事实上并非如此——事实证明,通过谨慎地使用所谓的“条件断点”,您可以经常使用调试器(例如WinDbg/ntsd/cdb/kd,这是本文其余部分将要提到的)来提供这种调用日志记录。使用调试器有许多优点;例如,您可以“动态”执行此类API日志记录,并且在可以在进程启动后附加调试器的情况下,您甚至不需要特别启动程序来记录它。然而,更好的是,调试器对以有意义的形式向用户显示数据有广泛的支持。
如果你仔细想想,向用户显示数据实际上是调试器的主要功能之一。这也是调试器通过扩展具有高度可扩展性的主要原因之一,这样复杂的数据结构就可以以有意义的方式显示和解释。通过使用调试器来执行API日志记录,您可以利用丰富的功能来显示已烘焙到调试器中的数据(及其扩展,甚至是您自己编写的任何自定义扩展),从而兼作调用日志记录功能。
更好的是,因为调试器可以基于符号文件(如果您有私有符号,例如您编译或提供的程序)以有意义的方式读取和显示许多数据类型,而这些数据类型没有用于显示它们的特定调试器扩展名(如!把手!错误(错误代码)!devobj和soforth),通常可以利用调试器基于符号中的类型信息格式化数据的能力。这通常是通过dt命令完成的,并且通常为大多数自定义数据类型提供一个可行的显示,而不必像处理日志程序那样进行任何复杂的“训练”。(某些数据结构(如树和列表)可能需要比dt中提供的更多的智能来显示数据结构的所有部分。对于“container”数据类型,这通常是正确的,尽管即使对于那些类型,您仍然可以经常使用dt以有意义的方式显示容器中的实际成员。)利用符号文件(通过调试器)中包含的信息进行API日志记录也使您不必确保日志记录程序对所有结构和其他类型的定义与您的程序同步正在调试,因为调试器自动接收基于符号的正确定义(如果使用的符号服务器包含自己内部符号的索引版本,调试器甚至可以自己找到符号)。

这种方法的另一个优点是,如果您对调试器相当熟悉,那么您可能不必像使用API日志程序那样学习新的描述语言。这是因为您可能已经熟悉了调试器从每天的调试器使用中为显示数据而提供的许多命令。(即使您对调试器不太熟悉,但默认情况下调试器附带的大量文档说明了如何通过各种调试器命令格式化和显示数据。此外,还有许多示例描述了如何在Internet上使用大多数重要或有用的调试器命令。)
好吧,关于为什么要考虑使用调试器来执行调用日志记录已经足够了。下一次,快速浏览并逐步介绍如何做到这一点(正如前面提到的那样,这非常简单),以及一些可能需要注意的注意事项和问题。

使用调试器执行调用日志记录并没有那么困难。所涉及的基本思想是在您感兴趣的函数的开头设置一个“条件”断点(例如,通过bp命令)。从那里,断点可以有显示输入参数的命令。但是,在某些情况下(例如,显示返回值、输出参数中的值等),您也可以变得更聪明一些,尽管根据正在调试的程序的特性,这可能是问题,也可能不是问题。
举一个简单的例子,我的意思是,有一个经典的“显示通过Win32 CreateFile打开的所有文件”。为此,方法是在kernel32!CreateFileW上设置一个断点。(请记住,大多数“A”win32api都会跳到“W”api,因此您通常可以仅在“W”版本上设置一个断点来同时获取这两个api。当然,这并不总是正确的(有些bizzare api,比如WinInet,实际上是从“W”到“A”的重击),但作为一般的经验法则,情况往往是这样的。)kernel32断点需要具备如何根据所讨论例程的调用约定显示第一个参数的知识。因为CreateFile是stdcall,所以应该是[esp+4](对于x86)和rcx(对于x64)。

在最基本的情况下,breakpoint命令可能如下所示:

0:001> bp kernel32!CreateFileW "du poi(@esp+4) ; gc"

(注意,gc命令与g类似,只是它是专门为在条件断点中使用而设计的。如果您跟踪到用gc控制执行的断点,它将以用户控制程序的方式恢复执行,而不是无条件地正常恢复。使用g的断点和使用gc的断点的区别在于,如果跟踪到gc断点,则跟踪到下一条指令;而如果跟踪到g断点,则控件将全速恢复,您将失去位置。)

此断点的调试器输出(命中时)列出传递给kernel32的名称!CreateFileW,与此类似(如果我在cmd.exe中设置此断点,然后输入“C:\ readme.txt”,则调试器输出中可能会出现此情况):

00657ff0  "C:\\readme.txt"

(“注意到,当断点显示字符串转移到函数时,如果程序使用相对路径,它将是一个相对路径。”)

从专业翻译人员、公司、网页及可自由查看的翻译库中学习。就本案而言,这可能是一个很好的想法,显示返回的句柄和最后的错误码。这可以通过在第一参数倒置后将断点移到函数返回点来完成,然后显示附加信息。为了做到这一点,我们可以使用以下断点:

0:001> bp kernel32!CreateFileW "du poi(@esp+4) ; g @$ra ; !handle @eax f ; !gle ; g"

此断点的要点是在函数返回后显示返回的句柄(和最后一个错误状态)。这是通过指示调试器继续执行直到返回地址被命中,然后对返回值(!handle @eax f)和最后一个错误状态(!gle)。(@$ra符号是一个伪寄存器,它以独立于平台的方式引用当前函数的返回地址。实际上,g @$ra命令运行程序,直到返回地址被命中为止。)

此断点的输出可能如下:
0016f0f0  "coffbase.txt"
Handle 60
  Type             File
  Attributes       0
  GrantedAccess    0x120089:
         ReadControl,Synch
         Read/List,ReadEA,ReadAttr
  HandleCount      2
  PointerCount     3
  No Object Specific Information available
LastErrorValue: (Win32) 0 (0) - The operation
  completed successfully.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

但是,如果我们无法打开文件,则结果不太理想:

00657ff0  "c:\\readme.txt"
Handle 4
  Type             Directory
[...] enumeration of all handles follows [...]
21 Handles
Type               Count
Event              3
File               4
Directory          3
Mutant             1
WindowStation      1
Semaphore          2
Key                6
Thread             1
LastErrorValue: (Win32) 0x2 (2) - The system
  cannot find the file specified.
LastStatusValue: (NTSTATUS) 0xc0000034 -
  Object Name not found.

出什么事了?好吧,那个!handle命令本质上扩展为“!handle -1 f“,因为CreateFile返回了无效的句柄值(-1)。这种模式的!handle扩展枚举进程中的所有句柄,这不是我们想要的。不过,只要稍微聪明一点,我们就可以改进这一点。断点处的第二次可能如下所示:

0:001> bp kernel32!CreateFileW "du poi(@esp+4) ; g @$ra ; .if (@eax != -1) { .printf \"Opened handle %p\\n\", @eax ; !handle @eax f } .else { .echo Failed to open file, error: ; !gle } ; g"

虽然这个命令一开始看起来有点吓人,但实际上它相当直截了当。与此断点的前一版本一样,它实现的实质是显示传递给kernel32!CreateFileW然后继续执行,直到CreateFile返回。然后,根据函数是否返回INVALID_HANDLE_VALUE (-1),显示句柄或最后一个错误状态。改进的断点的输出可能如下所示(例如,成功打开文件,但未能打开文件):

Success:

0016f0f0  "coffbase.txt"
Opened handle 00000060
Handle 60
  Type             File
  Attributes       0
  GrantedAccess    0x120089:
         ReadControl,Synch
         Read/List,ReadEA,ReadAttr
  HandleCount      2
  PointerCount     3
  No Object Specific Information available

Failure:

00657ff0  "C:\\readme.txt"
Failed to open file, error:
LastErrorValue: (Win32) 0x2 (2) - The system
  cannot find the file specified.
LastStatusValue: (NTSTATUS) 0xc0000034 -
  Object Name not found.

好多了。断点中的一点智能允许我们跳过在失败情况下转储整个进程句柄表的不良行为,甚至可以跳过在成功情况下显示最后一个错误代码。
正如人们可能想象的那样,一旦考虑到条件断点提供的灵活性,这里还有一系列其他的可能性。然而,这种方法也有一些缺点,必须加以考虑。更多关于其他一些更高级的条件断点,以便在以后的文章中进行日志记录(以及仔细查看使用调试器而不是专用程序的一些限制和缺点,以及使用这种方法可能遇到的一些“问题”)。

 
尽管像我之前描述的那样记录断点(即显示函数输入参数和返回值)确实很方便,但是您可能已经想出了一些场景,在这些场景中,像我提供的样式的断点不会提供跟踪问题所需的内容。
最值得注意的例子是,在进行函数调用之后,需要检查由函数调用填充的out参数。这就带来了一个问题,因为在函数调用返回后访问堆栈上的函数参数通常是不可靠的(在Windows上使用的基于堆栈和寄存器的调用约定中,被调用函数可以根据需要自由修改参数位置,这在启用优化时非常常见)。因此,我们真正需要的是能够跨函数调用保存一些状态,以便在函数返回后访问函数的一些参数。

幸运的是,这在调试器中是可行的,尽管方式相当迂回。这里的关键是使用所谓的用户定义伪寄存器,它们在概念上是独立于平台的额外存储位置(就表达式求值器而言,像常规寄存器一样访问,因此称为伪寄存器)。这些伪寄存器本质上只是常规编程意义上的变量,尽管可用的伪寄存器数量有限(当前版本中为20个)。因此,使用它们可以完成的任务有一些限制,但在大多数情况下,20个就足够了。如果您发现自己需要跟踪更多的状态,则应强烈考虑使用C语言编写调试器扩展,而不是使用调试器脚本语言。
(顺便说一句,几年前在Driver DevCon上,我记得我坐在一个面向WinDbg的会话中,演示者曾经浏览过一个用(当时相对较新的)扩展的调试器脚本语言编写的大型程序,并额外支持条件和错误处理。我还是忍不住把调试器脚本程序看作是将Perl最丑陋的部分与cmd.exe样式的批处理脚本结合在一起(尽管公平地说,调试器表达式求值器比批处理脚本更强大一些,而且它最初也从未打算用于比简单表达式更强大的部分)。老实说,我仍然强烈建议不要在可能的情况下编写高度复杂的调试器脚本程序;它们是维护的噩梦之一。在这种情况下,编写调试器扩展(或完全驱动调试器的程序)是更好的选择。不过,我离题了;回到通话记录的话题。)
调试器的用户定义伪寄存器功能提供了一种存储状态的有效方法(如果可能有点笨拙的话),这可以用于保存函数调用中的参数值。例如,我们可能想要记录对read file的所有调用,这样我们就需要一个正在读取的文件数据的转储。为了完成这个任务,我们需要转储输出缓冲区的内容(并使用bytes transferred count,另一个out参数)。这可以像这样完成(在本例中,为了简洁起见,我假设程序在同步I/O模式下使用ReadFile):

0:000> bp kernel32!ReadFile "r @$t0 = poi(@esp+8) ; r @$t1 = poi(@esp+10) ; g @$ra ; .if (@eax != 0) { .printf \"Read %lu bytes: \\n\", dwo(@$t1) ; db @$t0 ldwo(@$t1) } .else { .echo Read failed! ; !gle } ; g "

此命令的输出可能如下:

Read 22 bytes: 
0016ec3c  54 68 69 73 20 69 73 20-61 20 74 65 78 74 20 66
              This is a text f
0016ec4c  69 6c 65 2e 0d 0a
              ile...

这个命令本质上是昨天示例的逻辑扩展,添加了一些在调用中共享的状态。具体来说,@$t0和@$t1用户定义的伪寄存器用于在函数执行期间将lpBuffer([esp+08h])和lpNumberOfBytesRead([esp+10h])参数保存到ReadFile调用。当在返回地址停止执行时,通过取消对由@t0和@t1引用的值的引用,将转储刚刚读取的文件数据的内容。

虽然这种跨执行的状态保存是有用的,但也有缺点。首先,这种类型的断点从根本上讲与多个线程是不兼容的(至少在多个线程同时命中有问题的断点的情况下)。这是因为调试器没有提供“expression local”或“thread local”状态——可以这么说,多个线程同时命中断点可以互相踩脚。(这个问题也可能发生在任何类型的断点上,这些断点包括在“g<address>”命令创建隐式断点之前继续执行,尽管“有状态”断点可能更严重。)
调试器中的这种限制可以通过在g命令中通过线程说明符使断点线程特定来以有限的方式解决,尽管这通常很难做到。许多调用日志程序本机将考虑多线程,并且不需要任何特殊工作来适应多线程函数调用。(请注意,这个问题通常没有听起来那么严重——在许多情况下,甚至在多线程程序中,通常只有一个函数调用您感兴趣的函数,或者线程冲突的可能性足够小,以至于它绝大多数时间都能正常工作。但是,在某些情况下,如果问题函数经常从多个线程调用,并且需要在函数返回后检查数据,则这些样式的断点就不能很好地工作。)
使用调试器进行调用日志记录(与专用程序相反)的另一个重要限制是,调试器通常比执行日志记录的去延迟程序非常慢。这里的原因是,对于每个断点事件,实际上程序中的所有线程都被冻结,各种状态信息从程序复制到调试器,然后在调试器端计算断点表达式。另外,与专用程序不同的是,日志断点的结果是实时显示的,而不是(比如)存储在二进制日志缓冲区中,以便以后格式化和显示。这意味着,由于需要在每个断点上更新调试器UI,因此会产生更多的开销。因此,如果在频繁命中的函数上设置条件断点,则可能会注意到程序速度明显减慢,甚至可能到无法使用的程度。专用日志程序可以采用各种技术来规避调试器的这些限制,这些限制主要是调试器主要设计为调试器而不是高速API监视器这一事实的产物。
这在内核调试器的情况下更为明显,因为在KD模式下转换到调试器的速度非常慢,以至于即使每秒几次转换也足以使系统在实际中几乎不可用。因此,在选择在内核调试器中设置条件日志断点的位置时需要格外小心(可能将它们放在函数的中间、特定的有趣代码路径中,而不是放在开始时,以便捕获所有调用)。
考虑到这些限制,有必要对问题进行一些分析,以确定调试器或专用日志程序是否是最佳选择。这两种方法都有优点和缺点,尽管调试器非常灵活(并且通常非常方便),但它未必是每一种可能场景中的最佳选择。换言之,用最好的工具来做这项工作。但是,在某些情况下,唯一的选择是使用调试器,例如内核模式调用日志记录,因此我建议您至少掌握一些如何使用调试器完成日志记录任务的基本知识,即使您通常总是使用专用的日志记录程序。(不过,在内核模式调试的情况下,同样,调试器转换的缓慢性使得选择“低流量”位置作为断点非常重要。)
尽管如此,有效地调试和解决问题的一个重要部分是了解您的选项以及何时(何时)使用它们。使用调试器执行调用日志记录应该只是“调试工具包”中许多这样的选项之一。

posted on 2020-01-07 10:20  活着的虫子  阅读(1655)  评论(0编辑  收藏  举报

导航