搜索论坛 帖子排序:  Oldest to newest Newest to oldest

2015-09-20, 13:15 下午 CutlerMao 注册: 2015-09-19 发 贴: 4 求解，printf一去不复返的问题。 问题描述： 我的服务端程序是windows平台的程序，运行于Windows Server 2008 R2 SP1 x64系统上。执行一段时间后（多久不确定，有时候几天，有时候一个月也说不定），会出现printf无法输出问题。 此时，卡住的printf调用堆栈如下：   57  Id: 2024.249c Suspend: 0 Teb: 7ef00000 Unfrozen ChildEBP RetAddr  Args to Child               0fdce050 762e1314 00000007 0fdce0e8 00000042 kernel32!WriteConsoleInternal+0x15 0fdce06c 762e12f5 00000007 0fdce0e8 00000042 kernel32!WriteConsoleA+0x18 0fdce088 71547819 00000007 0fdce0e8 00000042 kernel32!WriteFileImplementation+0x6f 0fdcfba0 7154711f 00000001 00533e98 00000040 msvcr110!_write_nolock+0x501 0fdcfbe4 7153dffc 00000001 00533e98 00000040 msvcr110!_write+0x90 0fdcfc04 7157081c 715e4020 00000001 0fdcfc60 msvcr110!_flush+0x37 0fdcfc14 7159d254 00000001 715e4020 715e4020 msvcr110!_ftbuf+0x1c 0fdcfc60 6e4653b9 6e478c50 0b75ceb8 d92cf0d8 msvcr110!printf+0x7f 0fdcfe08 6e4641e1 0b6ab290 0b75a040 0fdcff48 VcyAudio!CManager::GetFreeSession+0x999 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 1178] 0fdcff48 715959aa 0b7ebb90 daa42bbf 00000000 VcyAudio!CManager::CreateTCPThread+0x151 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 792] 0fdcff80 71595a6d 0fdcff94 762e33ca 0b7a2998 msvcr110!_beginthread+0xba 0fdcff88 762e33ca 0b7a2998 0fdcffd4 77939ed2 msvcr110!_endthread+0x81 0fdcff94 77939ed2 0b7a2998 7503e3e4 00000000 kernel32!BaseThreadInitThunk+0xe 0fdcffd4 77939ea5 71595a17 0b7a2998 ffffffff ntdll!__RtlUserThreadStart+0x70 0fdcffec 00000000 71595a17 0b7a2998 00000000 ntdll!_RtlUserThreadStart+0x1b 由于我的程序是x86的，而printf最终会进入系统内核，又因为其运行于x64系统上，所以还有一个wow64转换的调用堆栈，如下： 57  Id: 2024.249c Suspend: 0 Teb: 00000000`7eefe000 Unfrozen RetAddr           : Args to Child                                                           : Call Site 00000000`753df5a1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!ZwRequestWaitReplyPort+0xa 00000000`753ddb37 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`753df5a1 : wow64win!ConsoleClientCallServer+0x99 00000000`753b577f : 00000000`0fdce058 00000000`7540f2cd 00000000`7eefe000 00000000`7541bee8 : wow64win!WriteConsoleInternal+0x123 00000000`7540cf87 : 00000000`0fdcf730 00000000`0fdce09c 00000000`0000004f 00000000`00000000 : wow64win!whWriteConsoleInternal+0x23 00000000`75392776 : 00000000`779101c4 00000000`00000023 00000000`00000246 00000000`0fdcfff0 : wow64!Wow64SystemServiceEx+0xd7 00000000`7540d07e : 00000000`00000000 00000000`75391920 00000000`00000000 00000000`00000000 : wow64cpu!TurboDispatchJumpAddressEnd+0x2d 00000000`7540c549 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : wow64!RunCpuSimulation+0xa 00000000`7779e707 : 00000000`00000000 00000000`7efdf000 00000000`7eefe000 00000000`00000000 : wow64!Wow64LdrpInitialize+0x429 00000000`7774c32e : 00000000`0fccf820 00000000`00000000 00000000`7efdf000 00000000`00000000 : ntdll! ?? ::FNODOBFM::`string'+0x29364 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!LdrInitializeThunk+0xe 可见r3的printf最终会把请求通过LPC方式传递给内核，最终形成系统调用ZwRequestWaitReplyPort，但问题是，这次调用一直不会返回。 与此同时，其他调用printf的线程，都在等待着57号线程的printf完成，可57号线程一直不返回。调用堆栈如下： 58  Id: 2024.2578 Suspend: 0 Teb: 7eefa000 Unfrozen ChildEBP RetAddr  Args to Child               1052fb7c 77938dd4 00000380 00000000 00000000 ntdll!ZwWaitForSingleObject+0x15 1052fbe0 77938cb8 00000000 00000000 0b7a2998 ntdll!RtlpWaitOnCriticalSection+0x13e 1052fc08 7152ec93 715e6d28 00000000 1052fc24 ntdll!RtlEnterCriticalSection+0x150 1052fc18 71533e12 00000011 1052fc60 7159d212 msvcr110!_lock+0x31 1052fc24 7159d212 00000001 715e4020 c52a285f msvcr110!_lock_file2+0x14 1052fc60 6e4653b9 6e478c50 0b75ca80 c6a2f0d8 msvcr110!printf+0x3d 1052fe08 6e4641e1 0b6ab3a8 0b75a040 1052ff48 VcyAudio!CManager::GetFreeSession+0x999 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 1178] 1052ff48 715959aa 0b7ebb60 c52a2bbf 00000000 VcyAudio!CManager::CreateTCPThread+0x151 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 792] 1052ff80 71595a6d 1052ff94 762e33ca 0b7a2998 msvcr110!_beginthread+0xba 1052ff88 762e33ca 0b7a2998 1052ffd4 77939ed2 msvcr110!_endthread+0x81 1052ff94 77939ed2 0b7a2998 6a8de3e4 00000000 kernel32!BaseThreadInitThunk+0xe 1052ffd4 77939ea5 71595a17 0b7a2998 ffffffff ntdll!__RtlUserThreadStart+0x70 1052ffec 00000000 71595a17 0b7a2998 00000000 ntdll!_RtlUserThreadStart+0x1b   59  Id: 2024.2624 Suspend: 0 Teb: 7eef7000 Unfrozen ChildEBP RetAddr  Args to Child               1106fb7c 77938dd4 00000380 00000000 00000000 ntdll!ZwWaitForSingleObject+0x15 1106fbe0 77938cb8 00000000 00000000 0b7a2998 ntdll!RtlpWaitOnCriticalSection+0x13e 1106fc08 7152ec93 715e6d28 00000000 1106fc24 ntdll!RtlEnterCriticalSection+0x150 1106fc18 71533e12 00000011 1106fc60 7159d212 msvcr110!_lock+0x31 1106fc24 7159d212 00000001 715e4020 c47e285f msvcr110!_lock_file2+0x14 1106fc60 6e4653b9 6e478c50 0b75ccc0 c7f6f0d8 msvcr110!printf+0x3d 1106fe08 6e4641e1 0b6ab5d8 0b75a040 1106ff48 VcyAudio!CManager::GetFreeSession+0x999 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 1178] 1106ff48 715959aa 0b7ebb78 c47e2bbf 00000000 VcyAudio!CManager::CreateTCPThread+0x151 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 792] 1106ff80 71595a6d 1106ff94 762e33ca 0b7a2998 msvcr110!_beginthread+0xba 1106ff88 762e33ca 0b7a2998 1106ffd4 77939ed2 msvcr110!_endthread+0x81 1106ff94 77939ed2 0b7a2998 6bd9e3e4 00000000 kernel32!BaseThreadInitThunk+0xe 1106ffd4 77939ea5 71595a17 0b7a2998 ffffffff ntdll!__RtlUserThreadStart+0x70 1106ffec 00000000 71595a17 0b7a2998 00000000 ntdll!_RtlUserThreadStart+0x1b   60  Id: 2024.2584 Suspend: 0 Teb: 7eef4000 Unfrozen ChildEBP RetAddr  Args to Child               111afb7c 77938dd4 00000380 00000000 00000000 ntdll!ZwWaitForSingleObject+0x15 111afbe0 77938cb8 00000000 00000000 0b7a2998 ntdll!RtlpWaitOnCriticalSection+0x13e 111afc08 7152ec93 715e6d28 00000000 111afc24 ntdll!RtlEnterCriticalSection+0x150 111afc18 71533e12 00000011 111afc60 7159d212 msvcr110!_lock+0x31 111afc24 7159d212 00000001 715e4020 c462285f msvcr110!_lock_file2+0x14 111afc60 6e4653b9 6e478c50 0b75ce28 c7eaf0d8 msvcr110!printf+0x3d 111afe08 6e4641e1 0b6ab808 0b75a040 111aff48 VcyAudio!CManager::GetFreeSession+0x999 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 1178] 111aff48 715959aa 0b7ebba8 c4622bbf 00000000 VcyAudio!CManager::CreateTCPThread+0x151 [e:\workcode\vd_new\vcydialog1\src\vxiclient\vcyaudio\vcyaudio.cpp @ 792] 111aff80 71595a6d 111aff94 762e33ca 0b7a2998 msvcr110!_beginthread+0xba 111aff88 762e33ca 0b7a2998 111affd4 77939ed2 msvcr110!_endthread+0x81 111aff94 77939ed2 0b7a2998 6bc5e3e4 00000000 kernel32!BaseThreadInitThunk+0xe 111affd4 77939ea5 71595a17 0b7a2998 ffffffff ntdll!__RtlUserThreadStart+0x70 可见，58 59 60号线程都在等待同一个Object，而这个Object就是57号线程锁住的Object，我曾想过出现问题的时候抓取内核态dump来分析这次调用到底卡在内核的哪个位置上，但似乎x64系统并不能生成full dump。 一开始我想，这会不会是Microsoft的printf实现有bug。但仔细思考应该不是，分析如下： 0:000> da 6e478c50 6e478c50  ".carid : %s." 0:000> da 0b75ceb8  0b75ceb8  "user:18601387007&poi:113.271884," 0b75ced8  "23.131306&program:d2sc" 57号线程卡住时，printf参数没有问题，此时一共两个参数，都没有问题，也就是我作为开发者，调用printf的方法并没有出错。 另外一点，57号线程的调用堆栈表明，这次printf请求已经进入内核，所以printf的r3实现部分 应该是没有问题的，只是不知道这个请求进入内核后为什么一直完不成。即便是系统有bug，那这个bug也应该是系统内核内部的，或者真正负责完成printf实质性请求的系统其他模块。 经过大量的原理性研究后和调试验证后，我发现printf进入系统时，调用的函数ZwRequestWaitReplyPort是LPC通信函数，这个请求会被csrss.exe进程处理，也就是把字符串绘制到cmd窗口上，当它完成工作后，会调用NtReplyWaitReceivePort通知ZwRequestWaitReplyPort，说你的请求已经完成，然后发起请求的线程层层返回，printf调用完毕。目前看来卡住的地方有可能是这次LPC通信，可能这个请求csrss.exe并没有接收到，所以没有给出应答，而造成printf卡住。还有可能是csrss.exe收到了这次请求，但由于某原因，一直处于等待状态，而造成没有给出应答。 后来又发现了一个关键点，被卡住的printf，当cmd窗口获得了焦点，敲击一下回车键，printf就返回了。其他的线程printf就可以继续输出了，从这点看来，上述两种情况，应该属于后者了，也就是csrss.exe接收到了请求，但由于某种原因一直处于等待状态。 我目前分析出来的就这么多，我尝试着去重现这个问题，就是如何做才能让一次printf调用卡住，但没有找到方法，如果能重现，估计也就好解决了。实在不行估计还得调试csrss.exe了。但问题是这个进程负责了太多的功能，不仅仅为我的进程提供服务，调试csrss.exe将看到大批量的各种请求，想找到我那次printf调用的请求，估计还是很费力的。 所以，跑到这里向张老师和论坛的各位大牛求助，帮忙分析一下问题。谢谢。 IP 地址: 已记录   报告

2015-11-01, 15:44 下午 irp 注册: 2006-10-19 发 贴: 5 Re: 求解，printf一去不复返的问题。 估计不是csrss, vista以前是csrss, 现在console input应该都在conhost.exe里面处理了。 0:000> k Child-SP          RetAddr           Call Site 00000000`01effad8 00000000`ff86110d ntdll!NtReplyWaitReceivePort 00000000`01effae0 00000000`77725a4d conhost!ConsoleLpcThread+0x195 00000000`01effe60 00000000`7795b831 kernel32!BaseThreadInitThunk+0xd 00000000`01effe90 00000000`00000000 ntdll!RtlUserThreadStart+0x1d 如果再碰到卡住的问题，收集所有的conhost.exe的dump应该有帮助。最好记住自己的printf和哪个conhost关联， 一般看cpu usage, printf打印的conhost cpu相对其他conhost较高。 IP 地址: 已记录   报告

2016-09-30, 11:02 上午 悬崖遛马 注册: 2012-07-24 发 贴: 30 Re: 求解，printf一去不复返的问题。 可能是运行过程中 cmd窗口激活时按下了 break键了吧 哈哈 IP 地址: 已记录   报告

2016-10-07, 15:29 下午 格蠹老雷 注册: 2005-12-19 发 贴: 1,303 Re: 求解，printf一去不复返的问题。 有道理的:-) IP 地址: 已记录   报告

高端调试 » 软件调试 » C/C++本地代码调试 » Re: 求解，printf一去不复返的问题。

请选择 论坛首页 |- 论坛搜索 |- 热门主题 |- 未回复的主题 用户选项 |- 登录 |- 注册 |- 找回密码 软件调试 |- Windows内核调试 |- C/C++本地代码调试 |- .Net程序调试 |- 脚本程序调试 |- Java程序调试 |- Linux内核调试 |- 《程序员》杂志调试专栏 |- WinDbg |- GDB |- 远程调试 |- 调试ACPI和BIOS |- 特殊的调试任务 |- 转储分析 |- GDK7 内核探秘 |- Windows内核 |- Linux内核 系统架构 |- CPU架构 |- PCI/PCI Express架构 程序人生 |- 软件物语 |- 社区活动 |- 名人逸事 联盟论坛 |- 欢迎使用CnForums 没有银弹 |- BUG也精彩 |- 豆腐工程 |- 软件圈里十大怪 Windows Vista |- 用调试利剑剖析VISTA内幕 |- 老专家如何破解新问题 |- 我的电脑谁说了算？ |- 资源 Office开发 |- Visio 驱动程序开发 |- Windows驱动开发 |- Linux驱动开发 |- Windows CE驱动开发 用户态开发 |- Windows本地代码（native）高级开发 |- Web应用开发 |- WinFX和.Net |- Office开发 本站建设 |- 高端调试团队 |- 版面布局 |- 活动建议 |- 网站维护 64位计算 |- 64-bit Windows |- 64-bit CPU 图书 |- 《软件调试》的示例程序 |- 《软件调试》的工具 |- 《软件调试》书友 |- 《软件调试》答疑 |- 《软件调试》勘误和意见 |- 《格蠹汇编》 |- 《软件调试》第二版卷1 |- 《软件调试》第二版卷2 云计算 |- IaaS |- 云存储 |- 大数据 |- PaaS和SaaS GPU |- CUDA |- OpenCL |- HSA |- 游戏开发与调试