New issue
Advanced search Search tips

Issue 787515 link

Starred by 2 users

Issue metadata

Status: Available
Owner: ----
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug



Sign in to add a comment

crash with logging enabled

Project Member Reported by wfh@chromium.org, Nov 21 2017

Issue description

Chrome Version: 62.0.3202.94 (Official Build) (64-bit) (cohort: Stable)
OS: Win10

What steps will reproduce the problem?
(1) execute:

"c:\Program Files (x86)\google\chrome\Application\chrome.exe" --enable-logging=stderr --v=5 > c:\src\log.txt 2>&1

Sometimes no tab appears, and a crash instead inside first child (GPU) process. The stack is:

5:045> kn
 # Child-SP          RetAddr           Call Site
00 000000aa`6e7fc160 00007ff9`533bbed6 chrome_child!`anonymous namespace'::InvalidParameter+0x18 [c:\b\c\b\win64_pgo\src\base\win\process_startup_helper.cc @ 21]
01 000000aa`6e7fc190 00007ff9`533bbf4d chrome_child!_invalid_parameter+0x52 [minkernel\crts\ucrt\src\appcrt\misc\invalid_parameter.cpp @ 113]
02 000000aa`6e7fc1d0 00007ff9`533dcf5c chrome_child!_invalid_parameter_noinfo+0x19 [minkernel\crts\ucrt\src\appcrt\misc\invalid_parameter.cpp @ 118]
03 000000aa`6e7fc210 00007ff9`533e342d chrome_child!_isatty+0x58 [minkernel\crts\ucrt\src\appcrt\lowio\isatty.cpp @ 17]
04 000000aa`6e7fc240 00007ff9`533c0d14 chrome_child!__acrt_stdio_begin_temporary_buffering_nolock+0x19 [minkernel\crts\ucrt\src\appcrt\stdio\_sftbuf.cpp @ 43]
05 (Inline Function) --------`-------- chrome_child!__acrt_stdio_temporary_buffering_guard::{ctor}+0x8 [minkernel\crts\ucrt\inc\corecrt_internal_stdio.h @ 399]
06 000000aa`6e7fc270 00007ff9`533c0cda chrome_child!<lambda_96f4279ff90247a4c5c5d9824f56f8c1>::operator()+0x20 [minkernel\crts\ucrt\src\appcrt\stdio\fwrite.cpp @ 39]
07 000000aa`6e7fc2a0 00007ff9`533c0f6f chrome_child!__crt_seh_guarded_call<unsigned __int64>::operator()<<lambda_bdbcead8b570fa3d5ec6d9679862a6e5>,<lambda_96f4279ff90247a4c5c5d9824f56f8c1> & __ptr64,<lambda_4606be27f17b5e5579e09050fab91818> >+0x26 [minkernel\crts\ucrt\devdiv\vcruntime\inc\internal_shared.h @ 204]
08 (Inline Function) --------`-------- chrome_child!__acrt_lock_stream_and_call+0x39 [minkernel\crts\ucrt\inc\corecrt_internal_stdio.h @ 252]
09 000000aa`6e7fc2d0 00007ff9`52dd533e chrome_child!fwrite+0x7f [minkernel\crts\ucrt\src\appcrt\stdio\fwrite.cpp @ 35]
0a 000000aa`6e7fc340 00007ff9`54c72115 chrome_child!logging::LogMessage::~LogMessage+0xd6 [c:\b\c\b\win64_pgo\src\base\logging.cc @ 720]
0b 000000aa`6e7fc8b0 00007ff9`54d5e69f chrome_child!gpu::gles2::GLES2DecoderImpl::Initialize+0xae1 [c:\b\c\b\win64_pgo\src\gpu\command_buffer\service\gles2_cmd_decoder.cc @ 3424]
0c 000000aa`6e7fd050 00007ff9`54d5d725 chrome_child!gpu::GpuCommandBufferStub::Initialize+0xa1b [c:\b\c\b\win64_pgo\src\gpu\ipc\service\gpu_command_buffer_stub.cc @ 807]
0d 000000aa`6e7fdc90 00007ff9`54d57d96 chrome_child!gpu::GpuCommandBufferStub::Create+0xa1 [c:\b\c\b\win64_pgo\src\gpu\ipc\service\gpu_command_buffer_stub.cc @ 236]
0e 000000aa`6e7fdcf0 00007ff9`54d589a6 chrome_child!gpu::GpuChannel::CreateCommandBuffer+0x162 [c:\b\c\b\win64_pgo\src\gpu\ipc\service\gpu_channel.cc @ 1152]
0f 000000aa`6e7fdd90 00007ff9`54d56e65 chrome_child!gpu::GpuChannel::OnCreateCommandBuffer+0xda [c:\b\c\b\win64_pgo\src\gpu\ipc\service\gpu_channel.cc @ 1078]
10 (Inline Function) --------`-------- chrome_child!base::DispatchToMethodImpl+0x65 [c:\b\c\b\win64_pgo\src\base\tuple.h @ 96]
11 000000aa`6e7fe1a0 00007ff9`54d56b6c chrome_child!base::DispatchToMethod<gpu::GpuChannel * __ptr64,void (__cdecl gpu::GpuChannel::*)(GPUCreateCommandBufferConfig const & __ptr64,int,base::SharedMemoryHandle,bool * __ptr64,gpu::Capabilities * __ptr64) __ptr64,std::tuple<GPUCreateCommandBufferConfig,int,base::SharedMemoryHandle>,std::tuple<bool,gpu::Capabilities> >+0x69 [c:\b\c\b\win64_pgo\src\base\tuple.h @ 108]
12 000000aa`6e7fe210 00007ff9`54d58895 chrome_child!IPC::MessageT<GpuChannelMsg_CreateCommandBuffer_Meta,std::tuple<GPUCreateCommandBufferConfig,int,base::SharedMemoryHandle>,std::tuple<bool,gpu::Capabilities> >::Dispatch<gpu::GpuChannel,gpu::GpuChannel,void,void (__cdecl gpu::GpuChannel::*)(GPUCreateCommandBufferConfig const & __ptr64,int,base::SharedMemoryHandle,bool * __ptr64,gpu::Capabilities * __ptr64) __ptr64>+0x178 [c:\b\c\b\win64_pgo\src\ipc\ipc_message_templates.h @ 205]
13 000000aa`6e7fe5a0 00007ff9`54d583da chrome_child!gpu::GpuChannel::OnControlMessageReceived+0x1b5 [c:\b\c\b\win64_pgo\src\gpu\ipc\service\gpu_channel.cc @ 965]
14 000000aa`6e7fe6c0 00007ff9`54d5ac0e chrome_child!gpu::GpuChannel::HandleMessageHelper+0x22 [c:\b\c\b\win64_pgo\src\gpu\ipc\service\gpu_channel.cc @ 1036]
15 (Inline Function) --------`-------- chrome_child!base::internal::FunctorTraits<void (__cdecl gpu::GpuChannel::*)(IPC::Message const &),void>::Invoke+0x23 [c:\b\c\b\win64_pgo\src\base\bind_internal.h @ 194]
16 (Inline Function) --------`-------- chrome_child!base::internal::InvokeHelper<1,void>::MakeItSo+0x32 [c:\b\c\b\win64_pgo\src\base\bind_internal.h @ 297]
17 (Inline Function) --------`-------- chrome_child!base::internal::Invoker<base::internal::BindState<void (__cdecl gpu::GpuChannel::*)(IPC::Message const &),base::WeakPtr<gpu::GpuChannel>,IPC::Message>,void __cdecl(void)>::RunImpl+0x36 [c:\b\c\b\win64_pgo\src\base\bind_internal.h @ 349]
18 000000aa`6e7fe6f0 00007ff9`52d7b0bb chrome_child!base::internal::Invoker<base::internal::BindState<void (__cdecl gpu::GpuChannel::*)(IPC::Message const & __ptr64) __ptr64,base::WeakPtr<gpu::GpuChannel>,IPC::Message>,void __cdecl(void)>::RunOnce+0x42 [c:\b\c\b\win64_pgo\src\base\bind_internal.h @ 334]
19 000000aa`6e7fe730 00007ff9`52d7b034 chrome_child!base::OnceCallback<void __cdecl(void)>::Run+0x13 [c:\b\c\b\win64_pgo\src\base\callback.h @ 64]
1a 000000aa`6e7fe760 00007ff9`52d79364 chrome_child!base::debug::TaskAnnotator::RunTask+0x124 [c:\b\c\b\win64_pgo\src\base\debug\task_annotator.cc @ 67]
1b 000000aa`6e7fe910 00007ff9`52d7b873 chrome_child!base::MessageLoop::RunTask+0xc0 [c:\b\c\b\win64_pgo\src\base\message_loop\message_loop.cc @ 407]
1c (Inline Function) --------`-------- chrome_child!base::MessageLoop::DeferOrRunPendingTask+0x6f [c:\b\c\b\win64_pgo\src\base\message_loop\message_loop.cc @ 417]
1d 000000aa`6e7fea40 00007ff9`52d77d0b chrome_child!base::MessageLoop::DoWork+0x2af [c:\b\c\b\win64_pgo\src\base\message_loop\message_loop.cc @ 524]
1e 000000aa`6e7febf0 00007ff9`52e86aac chrome_child!base::MessagePumpDefault::Run+0x2b [c:\b\c\b\win64_pgo\src\base\message_loop\message_pump_default.cc @ 34]
1f 000000aa`6e7fecb0 00007ff9`52f259be chrome_child!base::RunLoop::Run+0x64 [c:\b\c\b\win64_pgo\src\base\run_loop.cc @ 124]
20 000000aa`6e7fed60 00007ff9`5304f43e chrome_child!content::GpuMain+0x2e2 [c:\b\c\b\win64_pgo\src\content\gpu\gpu_main.cc @ 302]
21 000000aa`6e7ff380 00007ff9`5304f341 chrome_child!content::RunNamedProcessTypeMain+0xb6 [c:\b\c\b\win64_pgo\src\content\app\content_main_runner.cc @ 444]
22 000000aa`6e7ff4d0 00007ff9`5304d6e4 chrome_child!content::ContentMainRunnerImpl::Run+0xb9 [c:\b\c\b\win64_pgo\src\content\app\content_main_runner.cc @ 709]
23 000000aa`6e7ff560 00007ff9`52ca599b chrome_child!service_manager::Main+0x1e8 [c:\b\c\b\win64_pgo\src\services\service_manager\embedder\main.cc @ 458]
24 000000aa`6e7ff6f0 00007ff9`52ca5944 chrome_child!content::ContentMain+0x27 [c:\b\c\b\win64_pgo\src\content\app\content_main.cc @ 19]
25 000000aa`6e7ff760 00007ff7`3da0761f chrome_child!ChromeMain+0x198 [c:\b\c\b\win64_pgo\src\chrome\app\chrome_main.cc @ 124]
26 000000aa`6e7ff830 00007ff7`3da02621 chrome!MainDllLoader::Launch+0x397 [c:\b\c\b\win64_pgo\src\chrome\app\main_dll_loader_win.cc @ 201]
27 000000aa`6e7ff960 00007ff7`3dacf553 chrome!wWinMain+0x2f5 [c:\b\c\b\win64_pgo\src\chrome\app\chrome_exe_main_win.cc @ 276]
28 (Inline Function) --------`-------- chrome!invoke_main+0x21 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 113]
29 000000aa`6e7ffb90 00007ff9`ad4c8364 chrome!__scrt_common_main_seh+0x117 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 253]
2a 000000aa`6e7ffbd0 00007ff9`aefa7091 KERNEL32!BaseThreadInitThunk+0x14
2b 000000aa`6e7ffc00 00000000`00000000 ntdll!RtlUserThreadStart+0x21

If you run with --disable-gpu then you get stack

4:047> kn
 # Child-SP          RetAddr           Call Site
00 00000020`22bfe3a0 00007ff9`4f3ebed6 chrome_child!`anonymous namespace'::InvalidParameter+0x18 [c:\b\c\b\win64_pgo\src\base\win\process_startup_helper.cc @ 21]
01 00000020`22bfe3d0 00007ff9`4f3ebf4d chrome_child!_invalid_parameter+0x52 [minkernel\crts\ucrt\src\appcrt\misc\invalid_parameter.cpp @ 113]
02 00000020`22bfe410 00007ff9`4f40cf5c chrome_child!_invalid_parameter_noinfo+0x19 [minkernel\crts\ucrt\src\appcrt\misc\invalid_parameter.cpp @ 118]
03 00000020`22bfe450 00007ff9`4f41342d chrome_child!_isatty+0x58 [minkernel\crts\ucrt\src\appcrt\lowio\isatty.cpp @ 17]
04 00000020`22bfe480 00007ff9`4f3f0d14 chrome_child!__acrt_stdio_begin_temporary_buffering_nolock+0x19 [minkernel\crts\ucrt\src\appcrt\stdio\_sftbuf.cpp @ 43]
05 (Inline Function) --------`-------- chrome_child!__acrt_stdio_temporary_buffering_guard::{ctor}+0x8 [minkernel\crts\ucrt\inc\corecrt_internal_stdio.h @ 399]
06 00000020`22bfe4b0 00007ff9`4f3f0cda chrome_child!<lambda_96f4279ff90247a4c5c5d9824f56f8c1>::operator()+0x20 [minkernel\crts\ucrt\src\appcrt\stdio\fwrite.cpp @ 39]
07 00000020`22bfe4e0 00007ff9`4f3f0f6f chrome_child!__crt_seh_guarded_call<unsigned __int64>::operator()<<lambda_bdbcead8b570fa3d5ec6d9679862a6e5>,<lambda_96f4279ff90247a4c5c5d9824f56f8c1> & __ptr64,<lambda_4606be27f17b5e5579e09050fab91818> >+0x26 [minkernel\crts\ucrt\devdiv\vcruntime\inc\internal_shared.h @ 204]
08 (Inline Function) --------`-------- chrome_child!__acrt_lock_stream_and_call+0x39 [minkernel\crts\ucrt\inc\corecrt_internal_stdio.h @ 252]
09 00000020`22bfe510 00007ff9`4ee0533e chrome_child!fwrite+0x7f [minkernel\crts\ucrt\src\appcrt\stdio\fwrite.cpp @ 35]
0a 00000020`22bfe580 00007ff9`4f5fed93 chrome_child!logging::LogMessage::~LogMessage+0xd6 [c:\b\c\b\win64_pgo\src\base\logging.cc @ 720]
0b 00000020`22bfeaf0 00007ff9`4f1ef611 chrome_child!rtc::DiagnosticLogMessage::~DiagnosticLogMessage+0x40f777 [c:\b\c\b\win64_pgo\src\third_party\webrtc_overrides\webrtc\rtc_base\logging.cc @ 206]
0c 00000020`22bfec60 00007ff9`4f1ef5a3 chrome_child!internal::DetectNumberOfCores+0x61 [c:\b\c\b\win64_pgo\src\third_party\webrtc\system_wrappers\source\cpu_info.cc @ 52]
0d 00000020`22bfede0 00007ff9`4f1ef56d chrome_child!webrtc::CpuInfo::DetectNumberOfCores+0x13 [c:\b\c\b\win64_pgo\src\third_party\webrtc\system_wrappers\source\cpu_info.cc @ 65]
0e 00000020`22bfee10 00007ff9`4effc801 chrome_child!InitializeWebRtcModule+0x9 [c:\b\c\b\win64_pgo\src\third_party\webrtc_overrides\init_webrtc.cc @ 87]
0f 00000020`22bfee40 00007ff9`4f07f43e chrome_child!content::RendererMain+0x155 [c:\b\c\b\win64_pgo\src\content\renderer\renderer_main.cc @ 199]
10 00000020`22bfefd0 00007ff9`4f07f341 chrome_child!content::RunNamedProcessTypeMain+0xb6 [c:\b\c\b\win64_pgo\src\content\app\content_main_runner.cc @ 444]
11 00000020`22bff120 00007ff9`4f07d6e4 chrome_child!content::ContentMainRunnerImpl::Run+0xb9 [c:\b\c\b\win64_pgo\src\content\app\content_main_runner.cc @ 709]
12 00000020`22bff1b0 00007ff9`4ecd599b chrome_child!service_manager::Main+0x1e8 [c:\b\c\b\win64_pgo\src\services\service_manager\embedder\main.cc @ 458]
13 00000020`22bff340 00007ff9`4ecd5944 chrome_child!content::ContentMain+0x27 [c:\b\c\b\win64_pgo\src\content\app\content_main.cc @ 19]
14 00000020`22bff3b0 00007ff7`3da0761f chrome_child!ChromeMain+0x198 [c:\b\c\b\win64_pgo\src\chrome\app\chrome_main.cc @ 124]
15 00000020`22bff480 00007ff7`3da02621 chrome!MainDllLoader::Launch+0x397 [c:\b\c\b\win64_pgo\src\chrome\app\main_dll_loader_win.cc @ 201]
16 00000020`22bff5b0 00007ff7`3dacf553 chrome!wWinMain+0x2f5 [c:\b\c\b\win64_pgo\src\chrome\app\chrome_exe_main_win.cc @ 276]
17 (Inline Function) --------`-------- chrome!invoke_main+0x21 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 113]
18 00000020`22bff7e0 00007ff9`ad4c8364 chrome!__scrt_common_main_seh+0x117 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 253]
19 00000020`22bff820 00007ff9`aefa7091 KERNEL32!BaseThreadInitThunk+0x14
1a 00000020`22bff850 00000000`00000000 ntdll!RtlUserThreadStart+0x21

So something to do with logging initialization early on?

For graphics-related bugs, please copy/paste the contents of the about:gpu
page at the end of this report.

 
Status: Available (was: Untriaged)
I can repro this. To get this to repro you need a windows mode debugger (e.g. no cdb or ntsd).

Investigation thus far...

4:019> u chrome_child!_isatty chrome_child!_isatty+0x58+1
chrome_child!_isatty [minkernel\crts\ucrt\src\appcrt\lowio\isatty.cpp @ 15]:
00007ffb`0bd064dc 4883ec28        sub     rsp,28h
00007ffb`0bd064e0 83f9fe          cmp     ecx,0FFFFFFFEh
00007ffb`0bd064e3 750d            jne     chrome_child!_isatty+0x16 (00007ffb`0bd064f2)
00007ffb`0bd064e5 e81ee6fdff      call    chrome_child!_errno (00007ffb`0bce4b08)
00007ffb`0bd064ea c70009000000    mov     dword ptr [rax],9
00007ffb`0bd064f0 eb42            jmp     chrome_child!_isatty+0x58 (00007ffb`0bd06534)
00007ffb`0bd064f2 85c9            test    ecx,ecx
00007ffb`0bd064f4 782e            js      chrome_child!_isatty+0x48 (00007ffb`0bd06524) <---- Jump to Invalid Parameter Handler
00007ffb`0bd064f6 3b0d7441d900    cmp     ecx,dword ptr [chrome_child!_nhandle (00007ffb`0ca9a670)]
00007ffb`0bd064fc 7326            jae     chrome_child!_isatty+0x48 (00007ffb`0bd06524) <---- Jump to Invalid Parameter Handler
00007ffb`0bd064fe 4863c9          movsxd  rcx,ecx
00007ffb`0bd06501 488d15683dd900  lea     rdx,[chrome_child!__pioinfo (00007ffb`0ca9a270)]
00007ffb`0bd06508 488bc1          mov     rax,rcx
00007ffb`0bd0650b 83e13f          and     ecx,3Fh
00007ffb`0bd0650e 48c1f806        sar     rax,6
00007ffb`0bd06512 48c1e106        shl     rcx,6
00007ffb`0bd06516 488b04c2        mov     rax,qword ptr [rdx+rax*8]
00007ffb`0bd0651a 0fb6440838      movzx   eax,byte ptr [rax+rcx+38h]
00007ffb`0bd0651f 83e040          and     eax,40h
00007ffb`0bd06522 eb12            jmp     chrome_child!_isatty+0x5a (00007ffb`0bd06536)
00007ffb`0bd06524 e8dfe5fdff      call    chrome_child!_errno (00007ffb`0bce4b08)
00007ffb`0bd06529 c70009000000    mov     dword ptr [rax],9
00007ffb`0bd0652f e8a4c9fdff      call    chrome_child!_invalid_parameter_noinfo (00007ffb`0bce2ed8) <---- Die Here
00007ffb`0bd06534 33c0            xor     eax,eax
00007ffb`0bd06536 4883c428        add     rsp,28h
00007ffb`0bd0653a c3              ret
00007ffb`0bd0653b cc              int     3

Right before we execute the failure handler, ecx is 00000000ffffffff, which definitely looks wrong.

Comment 2 by wfh@chromium.org, Nov 21 2017

seems to be something something to do with sandbox logging, as disabling the sandbox caused it to stop reproducing. it also seems to be some kind of race because I can only get it to happen sometimes...

Comment 3 by wfh@chromium.org, Nov 21 2017

Components: Internals
This repros for us on Windows Server 2016 as well. Stacktrace is similar, cause was identifies as well - on windows non-null stderr has to be provided, otherwise chrome crashes trying to write into it. We were launching chrome using nodejs child_process and were not providing stdio since we didn't care about its output.
Please refer to this, which explains this problem better
https://stackoverflow.com/questions/45391027/redirect-stdout-stderr-to-null-vs2017-c
In order to repro evaluate this in nodejs
child_process.spawn("C:\\Program Files (x86)\\Google\\Chrome\\Application\\chrome.exe", ["maps.google.com", "--enable-logging"], {stdio:"ignore"})

OS: Windows Server 2016 Datacenter
Chrome: Version 67.0.3396.99 (Official Build) (64-bit)
Note that providing stdio:[0, 1, 2] fixes this problem since chrome is provided with stdin/stdout/stderr this way.
I've been also able to repro this on Windows 10 with hardware acceleration off in chrome

Sign in to add a comment