Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-31475

Investigate and fix windows crash with sharded change stream

    XMLWordPrintable

    Details

    • Backwards Compatibility:
      Fully Compatible
    • Operating System:
      ALL
    • Epic Link:
    • Sprint:
      Repl 2017-10-23

      Description

      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.

        Attachments

          Activity

            People

            Assignee:
            david.storch David Storch
            Reporter:
            charlie.swanson Charlie Swanson
            Participants:
            Votes:
            0 Vote for this issue
            Watchers:
            8 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: