-
Type: Bug
-
Resolution: Fixed
-
Priority: Major - P3
-
Affects Version/s: None
-
Component/s: Aggregation Framework, Replication
-
None
-
Fully Compatible
-
ALL
-
Repl 2017-10-23
We observed the following failure in a patch build:
[js_test:resume_change_stream] 2017-10-06T20:47:48.302+0000 s20766| 2017-10-06T20:47:48.302+0000 I CONTROL [eventTerminate] shutdown event signaled, will terminate after current cmd ends [js_test:resume_change_stream] 2017-10-06T20:47:48.367+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\db\operation_time_tracker.cpp(47) mongo::OperationTimeTracker::get+0x47 [js_test:resume_change_stream] 2017-10-06T20:47:48.367+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\db\s\sharding_task_executor.cpp(131) mongo::executor::ShardingTaskExecutor::scheduleRemoteCommand+0x2f4 [js_test:resume_change_stream] 2017-10-06T20:47:48.367+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\s\query\async_results_merger.cpp(625) mongo::AsyncResultsMerger::_scheduleKillCursors+0x265 [js_test:resume_change_stream] 2017-10-06T20:47:48.367+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\s\query\async_results_merger.cpp(477) mongo::AsyncResultsMerger::_handleBatchResponse+0x184 [js_test:resume_change_stream] 2017-10-06T20:47:48.367+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\s\query\async_results_merger.cpp(338) <lambda_0592613baefcb14a5dd5fe4f8bea1d23>::operator()<mongo::executor::TaskExecutor::RemoteCommandCallbackArgs>+0x55 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\util\scopeguard.h(101) mongo::ScopeGuardImplBase::SafeExecute<mongo::ScopeGuardImpl0<<lambda_32c65947af3f6a22c5432c91e6bdc4de> > >+0x2f [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\db\s\sharding_task_executor.cpp(187) <lambda_8237be9b9359e368a6b189c1a8637f35>::operator()+0x6cc [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\thread_pool_task_executor.cpp(371) mongo::executor::`anonymous namespace'::remoteCommandFinished+0x5d [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\thread_pool_task_executor.cpp(570) mongo::executor::ThreadPoolTaskExecutor::runCallback+0x20e [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\functional(214) std::_Func_impl<<lambda_fd72d344d6cb81d1a43b54487a279e4d>,std::allocator<int>,void>::_Do_call+0x3c [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_thread_pool.cpp(161) mongo::executor::NetworkInterfaceThreadPool::consumeTasks+0x20a [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_thread_pool.cpp(115) mongo::executor::NetworkInterfaceThreadPool::schedule+0x104 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\thread_pool_task_executor.cpp(547) mongo::executor::ThreadPoolTaskExecutor::scheduleIntoPool_inlock+0x1ce [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\thread_pool_task_executor.cpp(525) mongo::executor::ThreadPoolTaskExecutor::scheduleIntoPool_inlock+0x54 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\thread_pool_task_executor.cpp(425) <lambda_ca5636a7da31f060d579d5ca1902dc0d>::operator()+0x2d3 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio.cpp(318) <lambda_f556bc5cba165f8c14667230cfaf39e7>::operator()+0x507 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\functional(214) std::_Func_impl<<lambda_f556bc5cba165f8c14667230cfaf39e7>,std::allocator<int>,void,mongo::StatusWith<std::unique_ptr<mongo::executor::ConnectionPool::ConnectionInterface,mongo::executor::ConnectionPool::ConnectionHandleDeleter> > >::_Do_call+0x46 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\connection_pool.cpp(551) mongo::executor::ConnectionPool::SpecificPool::fulfillRequests+0x2fd [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\connection_pool.cpp(456) mongo::executor::ConnectionPool::SpecificPool::addToReady+0xdc [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\connection_pool.cpp(607) <lambda_940e8e7c4c6d8a967654812a0eee2a97>::operator()+0xc2 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\functional(214) std::_Func_impl<<lambda_940e8e7c4c6d8a967654812a0eee2a97>,std::allocator<int>,void,mongo::executor::ConnectionPool::ConnectionInterface * __ptr64,mongo::Status>::_Do_call+0x24 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\connection_pool_asio.cpp(224) <lambda_6f4cde77d823523b921311cbd0b65d75>::operator()+0x104 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\functional(214) std::_Func_impl<<lambda_6f4cde77d823523b921311cbd0b65d75>,std::allocator<int>,void,mongo::executor::ConnectionPool::ConnectionInterface * __ptr64,mongo::Status>::_Do_call+0x24 [js_test:resume_change_stream] 2017-10-06T20:47:48.368+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\connection_pool_asio.cpp(186) <lambda_18927f8d3a98fc7f7d5fd434d67e2da4>::operator()+0xd9 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio_operation.cpp(195) mongo::executor::NetworkInterfaceASIO::AsyncOp::finish+0x384 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio_command.cpp(249) mongo::executor::NetworkInterfaceASIO::_beginCommunication+0x285 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio_command.cpp(453) mongo::executor::NetworkInterfaceASIO::_runConnectionHook+0x115 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio_auth.cpp(175) mongo::executor::NetworkInterfaceASIO::_authenticate+0x49 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio_auth.cpp(158) <lambda_5213d615de3f65b5ce4fc7b7fb7c6dd9>::operator()+0x795 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio.h(438) mongo::executor::NetworkInterfaceASIO::_validateAndRun<<lambda_5213d615de3f65b5ce4fc7b7fb7c6dd9> const >+0x299 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\functional(214) std::_Func_impl<<lambda_5900bf3e6b4036eb349b92b2a7ed514a>,std::allocator<int>,void,std::error_code,unsigned __int64>::_Do_call+0x22 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\functional(214) std::_Func_impl<<lambda_294b2e0cd4997adefa4499d16edc4099>,std::allocator<int>,void,std::error_code,unsigned __int64>::_Do_call+0x34 [js_test:resume_change_stream] 2017-10-06T20:47:48.369+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\handler_invoke_hook.hpp(69) asio::asio_handler_invoke<asio::detail::binder2<std::function<void __cdecl(std::error_code,unsigned __int64)>,std::error_code,unsigned __int64> >+0x45 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\detail\impl\strand_service.hpp(61) asio::detail::strand_service::dispatch<asio::detail::binder2<std::function<void __cdecl(std::error_code,unsigned __int64)>,std::error_code,unsigned __int64> >+0x62 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\impl\read.hpp(284) asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp>,asio::mutable_buffers_1,asio::mutable_buffer const * __ptr64,asio::detail::transfer_all_t,asio::detail::wrapped_handler<asio::io_context::strand,std::function<void __cdecl(std::error_code,unsigned __int64)>,asio::detail::is_continuation_if_running> >::operator()+0x8d [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.367+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\detail\completion_handler.hpp(69) asio::detail::completion_handler<asio::detail::rewrapped_handler<asio::detail::binder2<asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp>,asio::mutable_buffers_1,asio::mutable_buffer const * __ptr64,asio::detail::transfer_all_t,asio::detail::wrapped_handler<asio::io_context::strand,std::function<void __cdecl(std::error_code,unsigned __int64)>,asio::detail::is_continuation_if_running> >,std::error_code,unsigned __int64>,std::function<void __cdecl(std::error_code,unsigned __int64)> > >::do_complete+0xeb [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\detail\impl\strand_service.hpp(87) asio::detail::strand_service::dispatch<asio::detail::rewrapped_handler<asio::detail::binder2<asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp>,asio::mutable_buffers_1,asio::mutable_buffer const * __ptr64,asio::detail::transfer_all_t,asio::detail::wrapped_handler<asio::io_context::strand,std::function<void __cdecl(std::error_code,unsigned __int64)>,asio::detail::is_continuation_if_running> >,std::error_code,unsigned __int64>,std::function<void __cdecl(std::error_code,unsigned __int64)> > >+0x126 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\detail\wrapped_handler.hpp(231) asio::detail::asio_handler_invoke<asio::detail::binder2<asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp>,asio::mutable_buffers_1,asio::mutable_buffer const * __ptr64,asio::detail::transfer_all_t,asio::detail::wrapped_handler<asio::io_context::strand,std::function<void __cdecl(std::error_code,unsigned __int64)>,asio::detail::is_continuation_if_running> >,std::error_code,unsigned __int64>,asio::io_context::strand,std::function<void __cdecl(std::error_code,unsigned __int64)>,asio::detail::is_continuation_if_running>+0x7c [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\detail\win_iocp_socket_recv_op.hpp(98) asio::detail::win_iocp_socket_recv_op<asio::mutable_buffers_1,asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp>,asio::mutable_buffers_1,asio::mutable_buffer const * __ptr64,asio::detail::transfer_all_t,asio::detail::wrapped_handler<asio::io_context::strand,std::function<void __cdecl(std::error_code,unsigned __int64)>,asio::detail::is_continuation_if_running> > >::do_complete+0x131 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\detail\impl\win_iocp_io_context.ipp(420) asio::detail::win_iocp_io_context::do_one+0x2c7 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\third_party\asio-master\asio\include\asio\detail\impl\win_iocp_io_context.ipp(162) asio::detail::win_iocp_io_context::run+0xcd [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe ...\src\mongo\executor\network_interface_asio.cpp(161) <lambda_a678c1c670cd02b221669c08448e9932>::operator()+0x2d7 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\thr\xthread(247) std::_LaunchPad<std::unique_ptr<std::tuple<<lambda_a678c1c670cd02b221669c08448e9932> >,std::default_delete<std::tuple<<lambda_a678c1c670cd02b221669c08448e9932> > > > >::_Run+0x77 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] mongos.exe c:\program files (x86)\microsoft visual studio 14.0\vc\include\thr\xthread(210) std::_Pad::_Call_func+0x9 [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] ucrtbase.DLL crt_at_quick_exit+0x7d [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] kernel32.dll BaseThreadInitThunk+0xd [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I - [NetworkInterfaceASIO-TaskExecutorPool-11-0] [js_test:resume_change_stream] 2017-10-06T20:47:48.371+0000 s20766| 2017-10-06T20:47:48.368+0000 I CONTROL [NetworkInterfaceASIO-TaskExecutorPool-11-0] writing minidump diagnostic file C:\data\mci\130f707eef17b908a3edc5dcc20393cb\src\mongos.2017-10-06T20-47-48.mdmp
We have been unable to reproduce it thus far, but have some working theories.