Skip to content

Add grpc_insecure_channel_create_internal, for channels created from within core#20572

Closed
apolcyn wants to merge 1 commit intogrpc:masterfrom
apolcyn:channel_create_internal
Closed

Add grpc_insecure_channel_create_internal, for channels created from within core#20572
apolcyn wants to merge 1 commit intogrpc:masterfrom
apolcyn:channel_create_internal

Conversation

@apolcyn
Copy link
Copy Markdown
Contributor

@apolcyn apolcyn commented Oct 11, 2019

While working on a test exercising the ALTS handshaker code and running under TSAN, I got this TSAN warning during the test's shutdown:

==================
WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=19)
  Cycle in lock order graph: M563367029106029600 (0x000000000000) => M562803941713156712 (0x000000000000) => M202 (0x7f950d936848) => M563367029106029600

  Mutex M562803941713156712 acquired here while holding mutex M563367029106029600 in thread T73:
    #0 pthread_mutex_lock /tmp/clang-build/src/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4137:3 (alts_with_fake_handshake_server_test+0x46fc66)
    #1 gpr_mu_lock /proc/self/cwd/src/core/lib/gpr/sync_posix.cc:65:3 (liblibgpr_Ubase.so+0xe642)
    #2 chttp2_connector_connect(grpc_connector*, grpc_connect_in_args const*, grpc_connect_out_args*, grpc_closure*) /proc/self/cwd/src/core/ext/transport/chttp2/client/chttp2_connector.cc:206:3 (liblibgrpc_Utransport_Uchttp2_Uclient_Uconnector.so+0x5061)
    #3 grpc_connector_connect(grpc_connector*, grpc_connect_in_args const*, grpc_connect_out_args*, grpc_closure*) /proc/self/cwd/src/core/ext/filters/client_channel/connector.cc:36:3 (liblibgrpc_Uclient_Uchannel.so+0xb94b0)
    #4 grpc_core::Subchannel::ContinueConnectingLocked() /proc/self/cwd/src/core/ext/filters/client_channel/subchannel.cc:983:3 (liblibgrpc_Uclient_Uchannel.so+0xf34ba)
    #5 grpc_core::Subchannel::MaybeStartConnectingLocked() /proc/self/cwd/src/core/ext/filters/client_channel/subchannel.cc:930:5 (liblibgrpc_Uclient_Uchannel.so+0xf2bc5)
    #6 grpc_core::Subchannel::AttemptToConnect() /proc/self/cwd/src/core/ext/filters/client_channel/subchannel.cc:823:3 (liblibgrpc_Uclient_Uchannel.so+0xf2a38)
    #7 grpc_core::(anonymous namespace)::ChannelData::SubchannelWrapper::AttemptToConnect() /proc/self/cwd/src/core/ext/filters/client_channel/client_channel.cc:921:51 (liblibgrpc_Uclient_Uchannel.so+0x96953)
    #8 grpc_core::(anonymous namespace)::PickFirst::AttemptToConnectUsingLatestUpdateArgsLocked() /proc/self/cwd/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc:236:52 (liblibgrpc_Ulb_Upolicy_Upick_Ufirst.so+0xe6ad)
    #9 grpc_core::(anonymous namespace)::PickFirst::UpdateLocked(grpc_core::LoadBalancingPolicy::UpdateArgs) /proc/self/cwd/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc:280:5 (liblibgrpc_Ulb_Upolicy_Upick_Ufirst.so+0xda59)
    #10 grpc_core::ResolvingLoadBalancingPolicy::CreateOrUpdateLbPolicyLocked(char const*, grpc_core::RefCountedPtr<grpc_core::LoadBalancingPolicy::Config>, grpc_core::Resolver::Result, grpc_core::InlinedVector<char*, 3ul>*) /proc/self/cwd/src/core/ext/filters/client_channel/resolving_lb_policy.cc:364:21 (liblibgrpc_Uclient_Uchannel.so+0xde78e)
    #11 grpc_core::ResolvingLoadBalancingPolicy::OnResolverResultChangedLocked(grpc_core::Resolver::Result) /proc/self/cwd/src/core/ext/filters/client_channel/resolving_lb_policy.cc:479:5 (liblibgrpc_Uclient_Uchannel.so+0xdf51e)
    #12 grpc_core::ResolvingLoadBalancingPolicy::ResolverResultHandler::ReturnResult(grpc_core::Resolver::Result) /proc/self/cwd/src/core/ext/filters/client_channel/resolving_lb_policy.cc:87:14 (liblibgrpc_Uclient_Uchannel.so+0xe13dc)
    #13 grpc_core::(anonymous namespace)::AresDnsResolver::OnResolvedLocked(void*, grpc_error*) /proc/self/cwd/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc:347:26 (liblibgrpc_Uresolver_Udns_Uares.so+0x1224f)
    #14 grpc_combiner_continue_exec_ctx() /proc/self/cwd/src/core/lib/iomgr/combiner.cc:267:5 (liblibgrpc_Ubase_Uc.so+0x9c16b)
    #15 grpc_core::ExecCtx::Flush() /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:161:17 (liblibgrpc_Ubase_Uc.so+0xc31ea)
    #16 grpc_core::ExecCtx::~ExecCtx() /proc/self/cwd/./src/core/lib/iomgr/exec_ctx.h:124:5 (liblibgrpc++.so+0x2891c)
    #17 grpc_call_start_batch /proc/self/cwd/src/core/lib/surface/call.cc:1974:3 (liblibgrpc_Ubase_Uc.so+0x11f1d6)
    #18 (anonymous namespace)::perform_rpc_and_get_status(char const*, char const*, void const*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:134:11 (alts_with_fake_handshake_server_test+0x4c200a)
    #19 (anonymous namespace)::run_one_rpc_handshake_fails_fast(void*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:366:29 (alts_with_fake_handshake_server_test+0x4c14f2)
    #20 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:139:27 (liblibgpr_Ubase.so+0x17088)
    #21 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:109:25 (liblibgpr_Ubase.so+0x16ea8)

  Mutex M563367029106029600 previously acquired by the same thread here:
    #0 pthread_mutex_lock /tmp/clang-build/src/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4137:3 (alts_with_fake_handshake_server_test+0x46fc66)
    #1 gpr_mu_lock /proc/self/cwd/src/core/lib/gpr/sync_posix.cc:65:3 (liblibgpr_Ubase.so+0xe642)
    #2 grpc_core::MutexLock::MutexLock(grpc_core::Mutex*) /proc/self/cwd/./src/core/lib/gprpp/sync.h:58:52 (liblibgrpc++_Ubase.so+0x118998)
    #3 grpc_core::Subchannel::AttemptToConnect() /proc/self/cwd/src/core/ext/filters/client_channel/subchannel.cc:822:13 (liblibgrpc_Uclient_Uchannel.so+0xf2a2a)
    #4 grpc_core::(anonymous namespace)::ChannelData::SubchannelWrapper::AttemptToConnect() /proc/self/cwd/src/core/ext/filters/client_channel/client_channel.cc:921:51 (liblibgrpc_Uclient_Uchannel.so+0x96953)
    #5 grpc_core::(anonymous namespace)::PickFirst::AttemptToConnectUsingLatestUpdateArgsLocked() /proc/self/cwd/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc:236:52 (liblibgrpc_Ulb_Upolicy_Upick_Ufirst.so+0xe6ad)
    #6 grpc_core::(anonymous namespace)::PickFirst::UpdateLocked(grpc_core::LoadBalancingPolicy::UpdateArgs) /proc/self/cwd/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc:280:5 (liblibgrpc_Ulb_Upolicy_Upick_Ufirst.so+0xda59)
    #7 grpc_core::ResolvingLoadBalancingPolicy::CreateOrUpdateLbPolicyLocked(char const*, grpc_core::RefCountedPtr<grpc_core::LoadBalancingPolicy::Config>, grpc_core::Resolver::Result, grpc_core::InlinedVector<char*, 3ul>*) /proc/self/cwd/src/core/ext/filters/client_channel/resolving_lb_policy.cc:364:21 (liblibgrpc_Uclient_Uchannel.so+0xde78e)
    #8 grpc_core::ResolvingLoadBalancingPolicy::OnResolverResultChangedLocked(grpc_core::Resolver::Result) /proc/self/cwd/src/core/ext/filters/client_channel/resolving_lb_policy.cc:479:5 (liblibgrpc_Uclient_Uchannel.so+0xdf51e)
    #9 grpc_core::ResolvingLoadBalancingPolicy::ResolverResultHandler::ReturnResult(grpc_core::Resolver::Result) /proc/self/cwd/src/core/ext/filters/client_channel/resolving_lb_policy.cc:87:14 (liblibgrpc_Uclient_Uchannel.so+0xe13dc)
    #10 grpc_core::(anonymous namespace)::AresDnsResolver::OnResolvedLocked(void*, grpc_error*) /proc/self/cwd/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc:347:26 (liblibgrpc_Uresolver_Udns_Uares.so+0x1224f)
    #11 grpc_combiner_continue_exec_ctx() /proc/self/cwd/src/core/lib/iomgr/combiner.cc:267:5 (liblibgrpc_Ubase_Uc.so+0x9c16b)
    #12 grpc_core::ExecCtx::Flush() /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:161:17 (liblibgrpc_Ubase_Uc.so+0xc31ea)
    #13 grpc_core::ExecCtx::~ExecCtx() /proc/self/cwd/./src/core/lib/iomgr/exec_ctx.h:124:5 (liblibgrpc++.so+0x2891c)
    #14 grpc_call_start_batch /proc/self/cwd/src/core/lib/surface/call.cc:1974:3 (liblibgrpc_Ubase_Uc.so+0x11f1d6)
    #15 (anonymous namespace)::perform_rpc_and_get_status(char const*, char const*, void const*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:134:11 (alts_with_fake_handshake_server_test+0x4c200a)
    #16 (anonymous namespace)::run_one_rpc_handshake_fails_fast(void*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:366:29 (alts_with_fake_handshake_server_test+0x4c14f2)
    #17 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:139:27 (liblibgpr_Ubase.so+0x17088)
    #18 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:109:25 (liblibgpr_Ubase.so+0x16ea8)

  Mutex M202 acquired here while holding mutex M562803941713156712 in thread T73:
    #0 pthread_mutex_lock /tmp/clang-build/src/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4137:3 (alts_with_fake_handshake_server_test+0x46fc66)
    #1 gpr_mu_lock /proc/self/cwd/src/core/lib/gpr/sync_posix.cc:65:3 (liblibgpr_Ubase.so+0xe642)
    #2 grpc_core::MutexLock::MutexLock(pthread_mutex_t*) /proc/self/cwd/./src/core/lib/gprpp/sync.h:59:46 (liblibgrpc.so+0x5082)
    #3 grpc_init /proc/self/cwd/src/core/lib/surface/init.cc:129:24 (liblibgrpc.so+0x4238)
    #4 grpc_channel_create(char const*, grpc_channel_args const*, grpc_channel_stack_type, grpc_transport*, grpc_resource_user*) /proc/self/cwd/src/core/lib/surface/channel.cc:264:5 (liblibgrpc_Ubase_Uc.so+0x12cd56)
    #5 grpc_core::(anonymous namespace)::CreateChannel(char const*, grpc_channel_args const*) /proc/self/cwd/src/core/ext/transport/chttp2/client/insecure/channel_create.cc:67:7 (liblibgrpc_Utransport_Uchttp2_Uclient_Uinsecure.so+0x3943)
    #6 grpc_insecure_channel_create /proc/self/cwd/src/core/ext/transport/chttp2/client/insecure/channel_create.cc:104:27 (liblibgrpc_Utransport_Uchttp2_Uclient_Uinsecure.so+0x36b5)
    #7 alts_tsi_handshaker_create(grpc_alts_credentials_options const*, char const*, char const*, bool, grpc_pollset_set*, tsi_handshaker**) /proc/self/cwd/src/core/tsi/alts/handshaker/alts_tsi_handshaker.cc:438:13 (liblibtsi.so+0x1c55f)
    #8 (anonymous namespace)::grpc_alts_channel_security_connector::add_handshakers(grpc_channel_args const*, grpc_pollset_set*, grpc_core::HandshakeManager*) /proc/self/cwd/src/core/lib/security/security_connector/alts/alts_security_connector.cc:89:5 (liblibgrpc_Usecure.so+0x69351)
    #9 grpc_core::(anonymous namespace)::ClientSecurityHandshakerFactory::AddHandshakers(grpc_channel_args const*, grpc_pollset_set*, grpc_core::HandshakeManager*) /proc/self/cwd/src/core/lib/security/transport/security_handshaker.cc:477:27 (liblibgrpc_Usecure.so+0x8826b)
    #10 grpc_core::(anonymous namespace)::HandshakerFactoryList::AddHandshakers(grpc_channel_args const*, grpc_pollset_set*, grpc_core::HandshakeManager*) /proc/self/cwd/src/core/lib/channel/handshaker_registry.cc:68:25 (liblibgrpc_Ubase_Uc.so+0x845bf)
    #11 grpc_core::HandshakerRegistry::AddHandshakers(grpc_core::HandshakerType, grpc_channel_args const*, grpc_pollset_set*, grpc_core::HandshakeManager*) /proc/self/cwd/src/core/lib/channel/handshaker_registry.cc:114:16 (liblibgrpc_Ubase_Uc.so+0x844ba)
    #12 start_handshake_locked(chttp2_connector*) /proc/self/cwd/src/core/ext/transport/chttp2/client/chttp2_connector.cc:161:3 (liblibgrpc_Utransport_Uchttp2_Uclient_Uconnector.so+0x590f)
    #13 connected(void*, grpc_error*) /proc/self/cwd/src/core/ext/transport/chttp2/client/chttp2_connector.cc:193:5 (liblibgrpc_Utransport_Uchttp2_Uclient_Uconnector.so+0x57df)
    #14 exec_ctx_run(grpc_closure*, grpc_error*) /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:40:3 (liblibgrpc_Ubase_Uc.so+0xc3487)
    #15 grpc_core::ExecCtx::Flush() /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:158:9 (liblibgrpc_Ubase_Uc.so+0xc31ce)
    #16 pollset_work(grpc_pollset*, grpc_pollset_worker**, long) /proc/self/cwd/src/core/lib/iomgr/ev_epollex_linux.cc:1126:34 (liblibgrpc_Ubase_Uc.so+0xada1b)
    #17 pollset_work(grpc_pollset*, grpc_pollset_worker**, long) /proc/self/cwd/src/core/lib/iomgr/ev_posix.cc:324:21 (liblibgrpc_Ubase_Uc.so+0xc1820)
    #18 grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, long) /proc/self/cwd/src/core/lib/iomgr/pollset.cc:48:10 (liblibgrpc_Ubase_Uc.so+0xcf4aa)
    #19 cq_next(grpc_completion_queue*, gpr_timespec, void*) /proc/self/cwd/src/core/lib/surface/completion_queue.cc:1037:23 (liblibgrpc_Ubase_Uc.so+0x133e49)
    #20 grpc_completion_queue_next /proc/self/cwd/src/core/lib/surface/completion_queue.cc:1113:10 (liblibgrpc_Ubase_Uc.so+0x132713)
    #21 cq_verify(cq_verifier*) /proc/self/cwd/test/core/end2end/cq_verifier.cc:254:21 (libtest_Score_Send2end_Slibcq_Uverifier.so+0x19d2)
    #22 (anonymous namespace)::perform_rpc_and_get_status(char const*, char const*, void const*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:138:3 (alts_with_fake_handshake_server_test+0x4c20c5)
    #23 (anonymous namespace)::run_one_rpc_handshake_fails_fast(void*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:366:29 (alts_with_fake_handshake_server_test+0x4c14f2)
    #24 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:139:27 (liblibgpr_Ubase.so+0x17088)
    #25 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:109:25 (liblibgpr_Ubase.so+0x16ea8)

  Mutex M562803941713156712 previously acquired by the same thread here:
    #0 pthread_mutex_lock /tmp/clang-build/src/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4137:3 (alts_with_fake_handshake_server_test+0x46fc66)
    #1 gpr_mu_lock /proc/self/cwd/src/core/lib/gpr/sync_posix.cc:65:3 (liblibgpr_Ubase.so+0xe642)
    #2 connected(void*, grpc_error*) /proc/self/cwd/src/core/ext/transport/chttp2/client/chttp2_connector.cc:173:3 (liblibgrpc_Utransport_Uchttp2_Uclient_Uconnector.so+0x54b3)
    #3 exec_ctx_run(grpc_closure*, grpc_error*) /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:40:3 (liblibgrpc_Ubase_Uc.so+0xc3487)
    #4 grpc_core::ExecCtx::Flush() /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:158:9 (liblibgrpc_Ubase_Uc.so+0xc31ce)
    #5 pollset_work(grpc_pollset*, grpc_pollset_worker**, long) /proc/self/cwd/src/core/lib/iomgr/ev_epollex_linux.cc:1126:34 (liblibgrpc_Ubase_Uc.so+0xada1b)
    #6 pollset_work(grpc_pollset*, grpc_pollset_worker**, long) /proc/self/cwd/src/core/lib/iomgr/ev_posix.cc:324:21 (liblibgrpc_Ubase_Uc.so+0xc1820)
    #7 grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, long) /proc/self/cwd/src/core/lib/iomgr/pollset.cc:48:10 (liblibgrpc_Ubase_Uc.so+0xcf4aa)
    #8 cq_next(grpc_completion_queue*, gpr_timespec, void*) /proc/self/cwd/src/core/lib/surface/completion_queue.cc:1037:23 (liblibgrpc_Ubase_Uc.so+0x133e49)
    #9 grpc_completion_queue_next /proc/self/cwd/src/core/lib/surface/completion_queue.cc:1113:10 (liblibgrpc_Ubase_Uc.so+0x132713)
    #10 cq_verify(cq_verifier*) /proc/self/cwd/test/core/end2end/cq_verifier.cc:254:21 (libtest_Score_Send2end_Slibcq_Uverifier.so+0x19d2)
    #11 (anonymous namespace)::perform_rpc_and_get_status(char const*, char const*, void const*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:138:3 (alts_with_fake_handshake_server_test+0x4c20c5)
    #12 (anonymous namespace)::run_one_rpc_handshake_fails_fast(void*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:366:29 (alts_with_fake_handshake_server_test+0x4c14f2)
    #13 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:139:27 (liblibgpr_Ubase.so+0x17088)
    #14 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:109:25 (liblibgpr_Ubase.so+0x16ea8)

  Mutex M563367029106029600 acquired here while holding mutex M202 in thread T156:
    #0 pthread_mutex_lock /tmp/clang-build/src/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4137:3 (alts_with_fake_handshake_server_test+0x46fc66)
    #1 gpr_mu_lock /proc/self/cwd/src/core/lib/gpr/sync_posix.cc:65:3 (liblibgpr_Ubase.so+0xe642)
    #2 grpc_core::ReleasableMutexLock::ReleasableMutexLock(grpc_core::Mutex*) /proc/self/cwd/./src/core/lib/gprpp/sync.h:71:62 (liblibgrpc++_Ubase.so+0x118b6c)
    #3 grpc_core::Subchannel::OnRetryAlarm(void*, grpc_error*) /proc/self/cwd/src/core/ext/filters/client_channel/subchannel.cc:952:23 (liblibgrpc_Uclient_Uchannel.so+0xf3550)
    #4 exec_ctx_run(grpc_closure*, grpc_error*) /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:40:3 (liblibgrpc_Ubase_Uc.so+0xc3487)
    #5 grpc_core::ExecCtx::Flush() /proc/self/cwd/src/core/lib/iomgr/exec_ctx.cc:158:9 (liblibgrpc_Ubase_Uc.so+0xc31ce)
    #6 grpc_iomgr_shutdown() /proc/self/cwd/src/core/lib/iomgr/iomgr.cc:115:36 (liblibgrpc_Ubase_Uc.so+0xcc54c)
    #7 grpc_shutdown_internal_locked() /proc/self/cwd/src/core/lib/surface/init.cc:182:5 (liblibgrpc.so+0x47b4)
    #8 grpc_shutdown_internal(void*) /proc/self/cwd/src/core/lib/surface/init.cc:208:3 (liblibgrpc.so+0x4974)
    #9 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:139:27 (liblibgpr_Ubase.so+0x17088)
    #10 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:109:25 (liblibgpr_Ubase.so+0x16ea8)

  Mutex M202 previously acquired by the same thread here:
    #0 pthread_mutex_lock /tmp/clang-build/src/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4137:3 (alts_with_fake_handshake_server_test+0x46fc66)
    #1 gpr_mu_lock /proc/self/cwd/src/core/lib/gpr/sync_posix.cc:65:3 (liblibgpr_Ubase.so+0xe642)
    #2 grpc_core::MutexLock::MutexLock(pthread_mutex_t*) /proc/self/cwd/./src/core/lib/gprpp/sync.h:59:46 (liblibgrpc.so+0x5082)
    #3 grpc_shutdown_internal(void*) /proc/self/cwd/src/core/lib/surface/init.cc:202:24 (liblibgrpc.so+0x4931)
    #4 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::operator()(void*) const /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:139:27 (liblibgpr_Ubase.so+0x17088)
    #5 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::'lambda'(void*)::__invoke(void*) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:109:25 (liblibgpr_Ubase.so+0x16ea8)

  Thread T14 (tid=93, finished) created by main thread at:
    #0 pthread_create /tmp/clang-build/src/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:967:3 (alts_with_fake_handshake_server_test+0x451a0b)
    #1 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:108:10 (liblibgpr_Ubase.so+0x16a50)
    #2 grpc_core::(anonymous namespace)::ThreadInternalsPosix* grpc_core::New<grpc_core::(anonymous namespace)::ThreadInternalsPosix, char const*&, void (*&)(void*), void*&, bool*, grpc_core::Thread::Options const&>(char const*&, void (*&)(void*), void*&, bool*&&, grpc_core::Thread::Options const&) /proc/self/cwd/./src/core/lib/gprpp/memory.h:37:18 (liblibgpr_Ubase.so+0x16448)
    #3 grpc_core::Thread::Thread(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:185:11 (liblibgpr_Ubase.so+0x161bf)
    #4 grpc_core::Thread* grpc_core::New<grpc_core::Thread, char const (&) [33], void (&)(void*), (anonymous namespace)::run_one_rpc_handshake_fails_fast_args*>(char const (&) [33], void (&)(void*), (anonymous namespace)::run_one_rpc_handshake_fails_fast_args*&&) /proc/self/cwd/./src/core/lib/gprpp/memory.h:37:18 (alts_with_fake_handshake_server_test+0x4c1745)
    #5 std::unique_ptr<grpc_core::Thread, grpc_core::DefaultDelete> grpc_core::MakeUnique<grpc_core::Thread, char const (&) [33], void (&)(void*), (anonymous namespace)::run_one_rpc_handshake_fails_fast_args*>(char const (&) [33], void (&)(void*), (anonymous namespace)::run_one_rpc_handshake_fails_fast_args*&&) /proc/self/cwd/./src/core/lib/gprpp/memory.h:81:23 (alts_with_fake_handshake_server_test+0x4c140d)
    #6 (anonymous namespace)::test_handshake_fails_fast_when_peer_endpoint_closes_connection_after_accepting(char const*) /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:407:22 (alts_with_fake_handshake_server_test+0x4c038e)
    #7 main /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:444:7 (alts_with_fake_handshake_server_test+0x4bfee1)

  Thread T89 'grpc_shutdown' (tid=176, running) created by main thread at:
    #0 pthread_create /tmp/clang-build/src/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:967:3 (alts_with_fake_handshake_server_test+0x451a0b)
    #1 grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:108:10 (liblibgpr_Ubase.so+0x16a50)
    #2 grpc_core::(anonymous namespace)::ThreadInternalsPosix* grpc_core::New<grpc_core::(anonymous namespace)::ThreadInternalsPosix, char const*&, void (*&)(void*), void*&, bool*, grpc_core::Thread::Options const&>(char const*&, void (*&)(void*), void*&, bool*&&, grpc_core::Thread::Options const&) /proc/self/cwd/./src/core/lib/gprpp/memory.h:37:18 (liblibgpr_Ubase.so+0x16448)
    #3 grpc_core::Thread::Thread(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&) /proc/self/cwd/src/core/lib/gprpp/thd_posix.cc:185:11 (liblibgpr_Ubase.so+0x161bf)
    #4 grpc_shutdown /proc/self/cwd/src/core/lib/surface/init.cc:219:23 (liblibgrpc.so+0x4b08)
    #5 main /proc/self/cwd/test/core/tsi/alts/handshaker/alts_with_fake_handshaker_test.cc:449:3 (alts_with_fake_handshake_server_test+0x4bff78)

SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) /proc/self/cwd/src/core/lib/gpr/sync_posix.cc:65:3 in gpr_mu_lock

It seems TSAN complains because the shutdown thread acquires:
g_init_mu (M202) -> a subchannel mutex (M563367029106029600)

A different thread acquired these locks while creating a TCP connection and subsequently doing an ALTS handshake:
M563367029106029600 -> M562803941713156712 (connector mutex) -> M202 (while ALTS handshaker created it's inner grpc channel)

I'm not 100% sure about the real danger of TSAN warning, since I believe M563367029106029600 should always be unlocked before locking M562803941713156712. However, one thing pointed out by this warning is that it seems risky for the ALTS handshake code to be using grpc_insecure_channel_create:

  • it seems this may, for example, possibly risk calling grpc_init again from within the shutdown_internal_locked thread.
  • ExecCtx stacking

So this PR creates an internal variant of grpc_insecure_channel_create, mainly for use by the ALTS handshaker (fixes the TSAN warning).

@apolcyn apolcyn added lang/core release notes: no Indicates if PR should not be in release notes labels Oct 11, 2019
Copy link
Copy Markdown
Member

@markdroth markdroth left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Stepping back a bit, I'm not really convinced that this is the right fix for this problem. The whole point of calling grpc_init() at channel creation and grpc_shutdown() at channel destruction was to ensure that all channels are destroyed before shutting down, and this would eliminate that safety check.

I think a better approach might be to change the ALTS handshaker to call grpc_insecure_channel_create() from a callback that runs on the ExecCtx rather than doing it inline.

/* The same as grpc_insecure_channel_create expect for:
* - doesn't create a new ExecCtx
* - doesn't call grpc_init or grpc_shutdown internally */
grpc_channel* grpc_insecure_channel_create_internal(
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of duplicating this code, how about just having the ALTS handshaker set the channel arg before it calls grpc_insecure_channel_create()?

I don't actually care about the ExecCtx stacking. The code can currently handle that, and we're trying to make ExecCtx go away completely in the long run anyway.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't actually care about the ExecCtx stacking. The code can currently handle that, and we're trying to make ExecCtx go away completely in the long run anyway.

A little late response but not sure I understand here BTW. Speaking generally, my view is that ExecCtx stacking is error prone due to re-entrant locking risk. #20596 actually tries hard to avoid it.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@vjpai or @yashykt can comment in more detail, but it's my understanding that the ExecCtx code automatically detects when this stacking is happening and basically shunts all of the queued closures to the "root" ExecCtx instance, so there should not be any risk of deadlock. At this point, I'd rather be putting effort into making ExecCtx go away instead of jumping through hoops trying to avoid stacking.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Currently, ExecCtx can get stacked on top of one another. Closures are always queued to the most recent/top ExecCtx.

Also, it doesn't look like ExecCtx is gonna go away :)

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we need to put effort into either eliminating the stacking functionality or removing ExecCtx altogether. We'll have to do some experiments to see which way we'll go.

// grpc_shutdown() when the channel is actually destroyed, thus
// ensuring that shutdown is deferred until that point.
grpc_init();
if (!grpc_channel_args_find_bool(
Copy link
Copy Markdown
Member

@markdroth markdroth Oct 11, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of calling grpc_channel_args_find_bool() multiple times, please call it once and save the result in a local bool, which can be checked multiple times.

@apolcyn
Copy link
Copy Markdown
Contributor Author

apolcyn commented Oct 11, 2019

Stepping back a bit, I'm not really convinced that this is the right fix for this problem. The whole point of calling grpc_init() at channel creation and grpc_shutdown() at channel destruction was to ensure that all channels are destroyed before shutting down, and this would eliminate that safety check.

I think a better approach might be to change the ALTS handshaker to call grpc_insecure_channel_create() from a callback that runs on the ExecCtx rather than doing it inline.

Working on trying out the other approach.

Note that one main motivation for this though is related to but not the same as the issue in the TSAN warning: I can't see what theoretically prevents accidentally running grpc_init (due to channel creation) from within the shutdown_internal_locked thread, i.e. accidentally doing a re-entrant mutex lock on g_inint_mu

WDYT?

@markdroth
Copy link
Copy Markdown
Member

I think that we should never wind up creating a new channel from inside of shutdown_internal_locked. If we are, then there's a bug somewhere, because the only things that should still be running at that point are callbacks to clean things up, not create new objects.

@apolcyn
Copy link
Copy Markdown
Contributor Author

apolcyn commented Oct 11, 2019

Makes sense, thanks. In that case, since the planned changes are now in the ALTS handshaker code, I will probably lump those changes to create the ALTS channel from an ExecCtx callback into the other changes involving the mentioned ALTS test.

@apolcyn
Copy link
Copy Markdown
Contributor Author

apolcyn commented Oct 22, 2019

I think a better approach might be to change the ALTS handshaker to call grpc_insecure_channel_create() from a callback that runs on the ExecCtx rather than doing it inline.

I've taken roughly this approach in #20596 FYI. Thanks for the comments, I'll close this PR in favor of #20596 though.

@apolcyn apolcyn closed this Oct 22, 2019
@lock lock bot locked as resolved and limited conversation to collaborators Jan 28, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Labels

lang/core release notes: no Indicates if PR should not be in release notes

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants