Endpoint reference after destroy caused by cocurrent handshake done and timeout #8744
Description
Currently, we create a timer to track handshake deadline, and when the timeout is passed. The tcp endpoint is shutdown to trigger the lower layer handshake read/write failures and thus terminate the handshake. When the handshake is done, the timer is cancelled in the callback.
If the handshake is failed and timed-out around the same time, the done callback may be at a point where the endpoint is already destroyed. At this time if the timeout callback is running in another thread (by completion_queue_next, it will try to shutdown the tcp.
sample log:
==35526==ERROR: AddressSanitizer: heap-use-after-free on address 0x61600012e780 at pc 0x0000007b10b6 bp 0x7f43406af8d0 sp 0x7f43406af8c8
READ of size 8 at 0x61600012e780 thread T7268
#0 0x7b10b5 in grpc_endpoint_shutdown /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/endpoint.c:58:7
#1 0xc93e1d in on_timeout /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/security/transport/handshake.c:320:5
#2 0x7b0c21 in grpc_closure_run /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/closure.c:120:5
#3 0x7bbae1 in grpc_exec_ctx_flush /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/exec_ctx.c:71:9
#4 0x8399d7 in pollset_work /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/ev_poll_posix.c:1038:22
#5 0x7ba833 in grpc_pollset_work /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/ev_posix.c:205:10
#6 0x7f8114 in grpc_completion_queue_pluck /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/surface/completion_queue.c:640:25
#7 0x889141 in grpc::CoreCodegen::grpc_completion_queue_pluck(grpc_completion_queue*, void*, gpr_timespec, void*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/cpp/common/core_codegen.cc:70:10
#8 0x4f2aed in grpc::CompletionQueue::Pluck(grpc::CompletionQueueTag*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/include/grpc++/impl/codegen/completion_queue.h:208:15
#9 0x6d1893 in grpc::Status grpc::BlockingUnaryCall<grpc::testing::SimpleRequest, grpc::testing::SimpleResponse>(grpc::ChannelInterface*, grpc::RpcMethod const&, grpc::ClientContext*, grpc::testing::SimpleRequest const&, grpc::testing::SimpleResponse*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/include/grpc++/impl/codegen/client_unary_call.h:72:3
#10 0x6cb6d7 in grpc::testing::BenchmarkService::Stub::UnaryCall(grpc::ClientContext*, grpc::testing::SimpleRequest const&, grpc::testing::SimpleResponse*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/gens/src/proto/grpc/testing/services.grpc.pb.cc:35:10
#11 0x7962d2 in grpc::testing::SynchronousUnaryClient::ThreadFunc(grpc::testing::HistogramEntry*, unsigned long) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/test/cpp/qps/client_sync.cc:131:9
#12 0x76e1b2 in grpc::testing::Client::Thread::ThreadFunc() /usr/local/google/home/dgq/grpc/forks/tmp/grpc/./test/cpp/qps/client.h:317:38
#13 0x7730ce in void std::_Mem_fn<void (grpc::testing::Client::Thread::*)()>::operator()<, void>(grpc::testing::Client::Thread*) const /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/functional:601:11
#14 0x772ef4 in void std::_Bind_simple<std::_Mem_fn<void (grpc::testing::Client::Thread::*)()> (grpc::testing::Client::Thread*)>::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/functional:1731:18
#15 0x772e4f in std::_Bind_simple<std::_Mem_fn<void (grpc::testing::Client::Thread::*)()> (grpc::testing::Client::Thread*)>::operator()() /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/functional:1720:16
#16 0x772846 in std::thread::_Impl<std::_Bind_simple<std::_Mem_fn<void (grpc::testing::Client::Thread::*)()> (grpc::testing::Client::Thread*)> >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/thread:115:13
#17 0x7f4640f90a5f in execute_native_thread_routine /build/gcc-4.8-mW1ufQ/gcc-4.8-4.8.4/build/x86_64-linux-gnu/libstdc++-v3/src/c++11/../../../../../src/libstdc++-v3/src/c++11/thread.cc:84
#18 0x7f464140b183 in start_thread /build/eglibc-oGUzwX/eglibc-2.19/nptl/pthread_create.c:312
#19 0x7f46409fe37c in clone /build/eglibc-oGUzwX/eglibc-2.19/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:111
0x61600012e780 is located 0 bytes inside of 520-byte region [0x61600012e780,0x61600012e988)
freed by thread T7268 here:
#0 0x4bcb7b in free /home/development/llvm/3.8.0/final/llvm.src/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:38:3
#1 0x8f5cb8 in gpr_free /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/support/alloc.c:68:3
#2 0x7d9fe6 in tcp_free /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/tcp_posix.c:127:3
#3 0x7d4a83 in tcp_unref /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/tcp_posix.c:155:5
#4 0x7d5d40 in tcp_destroy /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/tcp_posix.c:166:3
#5 0x7b11a2 in grpc_endpoint_destroy /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/endpoint.c:62:3
#6 0xc94323 in security_handshake_done /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/security/transport/handshake.c:135:7
#7 0xc921e1 in on_handshake_data_sent_to_peer /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/security/transport/handshake.c:300:7
#8 0x7b0c21 in grpc_closure_run /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/closure.c:120:5
#9 0x7bbae1 in grpc_exec_ctx_flush /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/exec_ctx.c:71:9
#10 0x8399d7 in pollset_work /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/ev_poll_posix.c:1038:22
#11 0x7ba833 in grpc_pollset_work /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/iomgr/ev_posix.c:205:10
#12 0x7f8114 in grpc_completion_queue_pluck /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/core/lib/surface/completion_queue.c:640:25
#13 0x889141 in grpc::CoreCodegen::grpc_completion_queue_pluck(grpc_completion_queue*, void*, gpr_timespec, void*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/src/cpp/common/core_codegen.cc:70:10
#14 0x4f2aed in grpc::CompletionQueue::Pluck(grpc::CompletionQueueTag*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/include/grpc++/impl/codegen/completion_queue.h:208:15
#15 0x6d1893 in grpc::Status grpc::BlockingUnaryCall<grpc::testing::SimpleRequest, grpc::testing::SimpleResponse>(grpc::ChannelInterface*, grpc::RpcMethod const&, grpc::ClientContext*, grpc::testing::SimpleRequest const&, grpc::testing::SimpleResponse*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/include/grpc++/impl/codegen/client_unary_call.h:72:3
#16 0x6cb6d7 in grpc::testing::BenchmarkService::Stub::UnaryCall(grpc::ClientContext*, grpc::testing::SimpleRequest const&, grpc::testing::SimpleResponse*) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/gens/src/proto/grpc/testing/services.grpc.pb.cc:35:10
#17 0x7962d2 in grpc::testing::SynchronousUnaryClient::ThreadFunc(grpc::testing::HistogramEntry*, unsigned long) /usr/local/google/home/dgq/grpc/forks/tmp/grpc/test/cpp/qps/client_sync.cc:131:9
#18 0x76e1b2 in grpc::testing::Client::Thread::ThreadFunc() /usr/local/google/home/dgq/grpc/forks/tmp/grpc/./test/cpp/qps/client.h:317:38
#19 0x7730ce in void std::_Mem_fn<void (grpc::testing::Client::Thread::*)()>::operator()<, void>(grpc::testing::Client::Thread*) const /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/functional:601:11
#20 0x772ef4 in void std::_Bind_simple<std::_Mem_fn<void (grpc::testing::Client::Thread::*)()> (grpc::testing::Client::Thread*)>::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/functional:1731:18
#21 0x772e4f in std::_Bind_simple<std::_Mem_fn<void (grpc::testing::Client::Thread::*)()> (grpc::testing::Client::Thread*)>::operator()() /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/functional:1720:16
#22 0x772846 in std::thread::_Impl<std::_Bind_simple<std::_Mem_fn<void (grpc::testing::Client::Thread::*)()> (grpc::testing::Client::Thread*)> >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../include/c++/4.8/thread:115:13
#23 0x7f4640f90a5f in execute_native_thread_routine /build/gcc-4.8-mW1ufQ/gcc-4.8-4.8.4/build/x86_64-linux-gnu/libstdc++-v3/src/c++11/../../../../../src/libstdc++-v3/src/c++11/thread.cc:84