赞
踩
前一篇文章介绍了如何配置符号,这一篇文章我们来个实战。
在我们的程序中利用robocopy
进行文件的复制。但是QA反馈,只要进行了备份操作,整个进程就会卡住。但是奇怪的是只有他的机器能发现。刚开始的时候我没有太重视这个问题。随着内部反馈的人多了,我开始对这个现象感兴趣了。
首先我们是利用的python的脚本启动robocopy
,下面是伪代码:
proc = subprocess.Popen("robocopy %s %s /E /MT:32 /XD .* /XF *.gmp *.zip" % (src, dst), shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
_, _ = proc.communicate()
robocopy
是windows自带的一个复制程序,我觉得可靠性应该是很高的。所以一开始我觉得出问题的肯定 是在我们的内部程序,我仔细检查了每个参数一无所获。
目标只能转移到robocopy
本身,刚开始觉得卡住可能是因为需要复制的文件过多,导致线程卡住,但是执行了10分钟还是纹丝不动。我就意识到估计死锁或者等待某个事件。
但是需要证据,此时我让QA的同事立马生成robocopy
的dump文件。
拿到dump之后,立马使用WinDbg打开。
首先就执行了!runaway
看看哪个线程跑的最欢。
发现0s和5s排在前面。0号线程其实是UI线程(windows中0号线程默认是UI线程),用时最长可以理解。但是仔细分析就发现5号线程其实还没有开始执行就已经卡住了。看来我们刚开始的猜测是有出入的。robocopy
刚启动就被按住不动了。
即使卡住了,看看是不是有上锁了,执行!cs -l
,查看发现就没有任何的锁。
再执行.exr -1
看看是不是出现了什么异常。发现最近的异常还是断点异常。说明也没有异常。
思考片刻,决定还是看看每个线程的 堆栈情况如何。执行~*k
,查看所有线程的堆栈,还好线程不多。
因为涉及到一些敏感信息,我把关键点使用softwareXXX来代替。
# Child-SP RetAddr Call Site 00 00000092`21d3f088 00007ffb`ddfc1c4e ntdll!NtWaitForSingleObject+0x14 01 00000092`21d3f090 00007ff7`4c9009fa KERNELBASE!WaitForSingleObjectEx+0x8e 02 00000092`21d3f130 00007ff7`4c90296d Robocopy!WaitMultiThreaded+0x50e 03 00000092`21d3f1b0 00007ff7`4c90f3ad Robocopy!wmain+0x681 04 00000092`21d3f970 00007ffb`dec37344 Robocopy!__wmainCRTStartup+0x14d 05 00000092`21d3f9b0 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14 06 00000092`21d3f9e0 00000000`00000000 ntdll!RtlUserThreadStart+0x21 0:000> ~*k; . 0 Id: 5bf8.4ee4 Suspend: 0 Teb: 00000092`21f62000 Unfrozen # Child-SP RetAddr Call Site 00 00000092`21d3f088 00007ffb`ddfc1c4e ntdll!NtWaitForSingleObject+0x14 01 00000092`21d3f090 00007ff7`4c9009fa KERNELBASE!WaitForSingleObjectEx+0x8e 02 00000092`21d3f130 00007ff7`4c90296d Robocopy!WaitMultiThreaded+0x50e 03 00000092`21d3f1b0 00007ff7`4c90f3ad Robocopy!wmain+0x681 04 00000092`21d3f970 00007ffb`dec37344 Robocopy!__wmainCRTStartup+0x14d 05 00000092`21d3f9b0 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14 06 00000092`21d3f9e0 00000000`00000000 ntdll!RtlUserThreadStart+0x21 1 Id: 5bf8.4c68 Suspend: 0 Teb: 00000092`21f6a000 Unfrozen # Child-SP RetAddr Call Site 00 00000092`2217fca8 00007ffb`ddfc1c4e ntdll!NtWaitForSingleObject+0x14 01 00000092`2217fcb0 00007ffb`d9776e2b KERNELBASE!WaitForSingleObjectEx+0x8e 02 00000092`2217fd50 00007ffb`dec37344 softwareXXX+0x76e2b 03 00000092`2217fd80 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14 04 00000092`2217fdb0 00000000`00000000 ntdll!RtlUserThreadStart+0x21 2 Id: 5bf8.5930 Suspend: 0 Teb: 00000092`21f6c000 Unfrozen # Child-SP RetAddr Call Site 00 00000092`221ff478 00007ffb`ddffbea0 ntdll!NtWaitForMultipleObjects+0x14 01 00000092`221ff480 00007ffb`ddffbd9e KERNELBASE!WaitForMultipleObjectsEx+0xf0 02 00000092`221ff770 00007ffb`d977a9c0 KERNELBASE!WaitForMultipleObjects+0xe 03 00000092`221ff7b0 00007ffb`dec37344 softwareXXX+0x7a9c0 04 00000092`221ff810 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14 05 00000092`221ff840 00000000`00000000 ntdll!RtlUserThreadStart+0x21 3 Id: 5bf8.5dbc Suspend: 0 Teb: 00000092`21f6e000 Unfrozen # Child-SP RetAddr Call Site 00 00000092`2227f648 00007ffb`e051d407 ntdll!NtWaitForWorkViaWorkerFactory+0x14 01 00000092`2227f650 00007ffb`dec37344 ntdll!TppWorkerThread+0x2f7 02 00000092`2227f950 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14 03 00000092`2227f980 00000000`00000000 ntdll!RtlUserThreadStart+0x21 4 Id: 5bf8.7f4 Suspend: 0 Teb: 00000092`21f70000 Unfrozen # Child-SP RetAddr Call Site 00 00000092`222ff7d8 00007ffb`e051d407 ntdll!NtWaitForWorkViaWorkerFactory+0x14 01 00000092`222ff7e0 00007ffb`dec37344 ntdll!TppWorkerThread+0x2f7 02 00000092`222ffae0 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14 03 00000092`222ffb10 00000000`00000000 ntdll!RtlUserThreadStart+0x21 5 Id: 5bf8.3694 Suspend: 0 Teb: 00000092`21f7a000 Unfrozen # Child-SP RetAddr Call Site 00 00000092`224fd878 00007ffb`ddfc1c4e ntdll!NtWaitForSingleObject+0x14 01 00000092`224fd880 00007ffb`d978abed KERNELBASE!WaitForSingleObjectEx+0x8e 02 00000092`224fd920 00007ff7`4c90c25f softwareXXX+0x8abed 03 00000092`224fe2a0 00007ff7`4c8ff78f Robocopy!CZEnt::CopyData+0x467 04 00000092`224ff390 00007ff7`4c90014e Robocopy!RoboCopy+0x18b 05 00000092`224ff400 00007ffb`e0533730 Robocopy!RoboCopyWorker+0x6e 06 00000092`224ff430 00007ffb`e051d79a ntdll!TppWorkpExecuteCallback+0x130 07 00000092`224ff480 00007ffb`dec37344 ntdll!TppWorkerThread+0x68a 08 00000092`224ff780 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14 09 00000092`224ff7b0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
接下来就是仔细分析每个线程的堆栈情况了。可以看到0,1,2,以及5号线程都在等待某个内核对象。
3,4号线程就是windows内部的线程池,这里我们暂且不关注。
先分析0号线程,我们查了函数原型NtWaitForSingleObject
,第一个参数就是需要等待的内核对象,第二个参数是否可中断,第三个参数超时时间。根据x64调用协议,前四个非浮点数且小于64位参数都是寄存器rcx
,rdx
,r8
,r9
中。
NTSTATUS NtWaitForSingleObject(
[in] HANDLE Handle,
[in] BOOLEAN Alertable,
[in] PLARGE_INTEGER Timeout
);
我们试着找出这个参数,在WinDbg命令中执行r rcx
,就是打印出rcx寄存器中的值。
找到这个值之后,我们需要验证这个值是不是内核对象。再执行!handle xxx f
,此时就会打印出关于此内核对象的具体信息。
如法炮制,分析切换到1,2,5号线程。比如我们切换到1号线程:
这里需要说下2号线程调用的函数NtWaitForMultipleObjects
,这个函数在微软的文档并未公布函数原型。但是我们可以到此线程的第二帧调用的函数KERNELBASE!WaitForMultipleObjectsEx
,而这个函数原型是有的。
从名字可以大致猜出此函数应该是等待多个内核对象。第一个参数就是等待的个数,第二个就是类似数组里面保存了句柄,第三个和第四含义和之前是一样的。
DWORD WaitForMultipleObjects(
[in] DWORD nCount,
[in] const HANDLE *lpHandles,
[in] BOOL bWaitAll,
[in] DWORD dwMilliseconds
);
我们利用WinDbg来找下句柄值。
一共等待两个句柄值0x128
, 0x130
。我们在验证下找得对不对。看如下的截图发现我们找得没有错。
这里我把句柄做成表格进行对比。
线程 | 句柄 | 信息 |
---|---|---|
0 | 0x194 | |
1 | x128 | |
2 | 0x128, 0x130 | |
5 | 0x738 |
从表格中我们大致可以看到等待的句柄是Event类型,以及权限,当前Event的状态信息。
从上面的表格分析,此时线程中并没有出现明显的相互等待的现象。此时有点穷途末路的感觉。
我在想是不是还有蛛丝马迹被我忽略了。
对,还有3,4号线程我并没有分析。我立马着手在msdn搜索函数原型,可惜这两个函数在msdn未公布任何信息。但是我还不死心继续Google上搜索关于这个函数的信息,从网络搜索的信息也是相当的少,都是一笔带过简单的连参数信息都没有提及。
我开始深入思考,到底还有什么信息被我遗漏了 。
坐着已经让我无法思考了,需要走两步清空下大脑。
转了一圈回来之后,发现还是需要从基础的堆栈分析,一个帧一个帧过滤下。从上面的堆栈中可以看到5号线程堆栈是最长的。我们再看下5号线程的堆栈信息。
0:000> ~5k;
# Child-SP RetAddr Call Site
00 00000092`224fd878 00007ffb`ddfc1c4e ntdll!NtWaitForSingleObject+0x14
01 00000092`224fd880 00007ffb`d978abed KERNELBASE!WaitForSingleObjectEx+0x8e
02 00000092`224fd920 00007ff7`4c90c25f softwareXXX+0x8abed
03 00000092`224fe2a0 00007ff7`4c8ff78f Robocopy!CZEnt::CopyData+0x467
04 00000092`224ff390 00007ff7`4c90014e Robocopy!RoboCopy+0x18b
05 00000092`224ff400 00007ffb`e0533730 Robocopy!RoboCopyWorker+0x6e
06 00000092`224ff430 00007ffb`e051d79a ntdll!TppWorkpExecuteCallback+0x130
07 00000092`224ff480 00007ffb`dec37344 ntdll!TppWorkerThread+0x68a
08 00000092`224ff780 00007ffb`e051cc91 kernel32!BaseThreadInitThunk+0x14
09 00000092`224ff7b0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
5号线程刚开始Robocopy!CZEnt::CopyData
就被按住了。我们反汇编看下Robocopy!CZEnt::CopyData
代码。
反汇编的函数大概有1m A4纸那么长,该怎么看呢。
我们可以直接从02帧那里看到返回值地址00007ff74c90c25f
,这个返回值就是softwareXXX+0x8abed
执行完后返回到Robocopy!CZEnt::CopyData
再从Robocopy!CZEnt::CopyData
反汇编的函数搜索此地址。
搜索的结果如下:
结果发现了点异常,上面的一条语句好像不大对劲。反汇编这里的函数是Robocopy!_imp_CopyFile2
,而实际堆栈里面显示的却另外一个模块的代码。
再看softwareXXX
这个模块加上了一个相当大的偏移0x8abed
,这是不同寻常的,很有可能找的符号不对。
而这个模块的代码在Robocopy
中根本就没有。这是从哪里来的?相当的奇怪,突然感觉有点意思。
看下这个模块的信息,在命令中执行lmvm softwareXXX
,发现了端倪,原来是个杀软,把这个dll注入了robocopy
中,很有可能对函数进行了拦截,导致了这个函数一直无法返回。
0:000> lmvm softwareXXX Browse full module list start end module name 00007ffb`d9700000 00007ffb`d9a93000 softwareXXX (no symbols) Loaded symbol image file: softwareXXX.dll Image path: C:\Program Files\softwareXXX\softwareXXX.dll Image name: softwareXXX.dll Browse all global symbols functions data Timestamp: Tue Mar 26 22:56:55 2024 (6602E237) CheckSum: 0038B6E1 ImageSize: 00393000 File version: 1.0.1.622 Product version: 1.0.1.622 File flags: 0 (Mask 3F) File OS: 40004 NT Win32 File type: 2.0 Dll File date: 00000000.00000000 Translations: 0804.04b0 Information from resource tables: CompanyName: https://www.softwareXXX.cn/ ProductName: XDR InternalName: softwareXXX.dll OriginalFilename: softwareXXX.dll ProductVersion: 1.0.1.622 FileVersion: 1.0.1.622 FileDescription: softwareXXX 应用程序监控模块 LegalCopyright: Copyright (C) 2021
再回过头看上面的堆栈信息,此dll对系统的其他的关键函数也进行了拦截处理。
接下来就是找IT部门,让他们把robocopy
加入白名单,再进行测试。经过协商之后,我们在进行测试问题就解决了。
Copyright © 2003-2013 www.wpsshop.cn 版权所有,并保留所有权利。