From 52369882d8209ef5b7a0c7baf6ab474d7783fa8c Mon Sep 17 00:00:00 2001 From: Craig Tiller Date: Tue, 19 Sep 2023 11:49:12 -0700 Subject: [PATCH] [promises] Add tracing to seq, join variants (#34401) Co-authored-by: ctiller --- CMakeLists.txt | 18 + build_autogenerated.yaml | 34 ++ src/core/BUILD | 4 + src/core/lib/promise/detail/join_state.h | 486 +++++++++++++++++++++++ src/core/lib/promise/detail/seq_state.h | 418 +++++++++++++++++++ test/core/promise/seq_test.cc | 1 + tools/codegen/core/gen_join.py | 11 + tools/codegen/core/gen_seq.py | 16 +- 8 files changed, 987 insertions(+), 1 deletion(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 32b41e65245..ef322870677 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -5549,7 +5549,9 @@ endif() if(gRPC_BUILD_TESTS) add_executable(activity_test + src/core/lib/debug/trace.cc src/core/lib/promise/activity.cc + src/core/lib/promise/trace.cc test/core/promise/activity_test.cc ) target_compile_features(activity_test PUBLIC cxx_std_14) @@ -8762,6 +8764,7 @@ add_executable(chunked_vector_test src/core/lib/iomgr/executor.cc src/core/lib/iomgr/iomgr_internal.cc src/core/lib/promise/activity.cc + src/core/lib/promise/trace.cc src/core/lib/resource_quota/arena.cc src/core/lib/resource_quota/memory_quota.cc src/core/lib/resource_quota/periodic_update.cc @@ -11866,6 +11869,7 @@ add_executable(flow_control_test src/core/lib/iomgr/executor.cc src/core/lib/iomgr/iomgr_internal.cc src/core/lib/promise/activity.cc + src/core/lib/promise/trace.cc src/core/lib/resource_quota/memory_quota.cc src/core/lib/resource_quota/periodic_update.cc src/core/lib/resource_quota/resource_quota.cc @@ -14486,7 +14490,9 @@ endif() if(gRPC_BUILD_TESTS) add_executable(inter_activity_pipe_test + src/core/lib/debug/trace.cc src/core/lib/promise/activity.cc + src/core/lib/promise/trace.cc test/core/promise/inter_activity_pipe_test.cc ) target_compile_features(inter_activity_pipe_test PUBLIC cxx_std_14) @@ -14837,6 +14843,8 @@ endif() if(gRPC_BUILD_TESTS) add_executable(join_test + src/core/lib/debug/trace.cc + src/core/lib/promise/trace.cc test/core/promise/join_test.cc ) target_compile_features(join_test PUBLIC cxx_std_14) @@ -14863,6 +14871,7 @@ target_link_libraries(join_test ${_gRPC_ALLTARGETS_LIBRARIES} gtest absl::type_traits + absl::statusor gpr ) @@ -15393,6 +15402,8 @@ endif() if(gRPC_BUILD_TESTS) add_executable(loop_test + src/core/lib/debug/trace.cc + src/core/lib/promise/trace.cc test/core/promise/loop_test.cc ) target_compile_features(loop_test PUBLIC cxx_std_14) @@ -20884,6 +20895,8 @@ endif() if(gRPC_BUILD_TESTS) add_executable(seq_test + src/core/lib/debug/trace.cc + src/core/lib/promise/trace.cc test/core/promise/seq_test.cc ) target_compile_features(seq_test PUBLIC cxx_std_14) @@ -20910,6 +20923,7 @@ target_link_libraries(seq_test ${_gRPC_ALLTARGETS_LIBRARIES} gtest absl::type_traits + absl::statusor gpr ) @@ -25168,6 +25182,8 @@ endif() if(gRPC_BUILD_TESTS) add_executable(try_join_test + src/core/lib/debug/trace.cc + src/core/lib/promise/trace.cc test/core/promise/try_join_test.cc ) target_compile_features(try_join_test PUBLIC cxx_std_14) @@ -25237,6 +25253,8 @@ endif() if(gRPC_BUILD_TESTS) add_executable(try_seq_test + src/core/lib/debug/trace.cc + src/core/lib/promise/trace.cc test/core/promise/try_seq_test.cc ) target_compile_features(try_seq_test PUBLIC cxx_std_14) diff --git a/build_autogenerated.yaml b/build_autogenerated.yaml index a709fed35d6..de1b24c5e55 100644 --- a/build_autogenerated.yaml +++ b/build_autogenerated.yaml @@ -4842,6 +4842,7 @@ targets: run: false language: c++ headers: + - src/core/lib/debug/trace.h - src/core/lib/gprpp/atomic_utils.h - src/core/lib/gprpp/bitset.h - src/core/lib/gprpp/orphanable.h @@ -4860,10 +4861,13 @@ targets: - src/core/lib/promise/poll.h - src/core/lib/promise/promise.h - src/core/lib/promise/seq.h + - src/core/lib/promise/trace.h - src/core/lib/promise/wait_set.h - test/core/promise/test_wakeup_schedulers.h src: + - src/core/lib/debug/trace.cc - src/core/lib/promise/activity.cc + - src/core/lib/promise/trace.cc - test/core/promise/activity_test.cc deps: - gtest @@ -6746,6 +6750,7 @@ targets: - src/core/lib/promise/poll.h - src/core/lib/promise/race.h - src/core/lib/promise/seq.h + - src/core/lib/promise/trace.h - src/core/lib/resource_quota/arena.h - src/core/lib/resource_quota/memory_quota.h - src/core/lib/resource_quota/periodic_update.h @@ -6786,6 +6791,7 @@ targets: - src/core/lib/iomgr/executor.cc - src/core/lib/iomgr/iomgr_internal.cc - src/core/lib/promise/activity.cc + - src/core/lib/promise/trace.cc - src/core/lib/resource_quota/arena.cc - src/core/lib/resource_quota/memory_quota.cc - src/core/lib/resource_quota/periodic_update.cc @@ -8537,6 +8543,7 @@ targets: - src/core/lib/promise/poll.h - src/core/lib/promise/race.h - src/core/lib/promise/seq.h + - src/core/lib/promise/trace.h - src/core/lib/resource_quota/memory_quota.h - src/core/lib/resource_quota/periodic_update.h - src/core/lib/resource_quota/resource_quota.h @@ -8581,6 +8588,7 @@ targets: - src/core/lib/iomgr/executor.cc - src/core/lib/iomgr/iomgr_internal.cc - src/core/lib/promise/activity.cc + - src/core/lib/promise/trace.cc - src/core/lib/resource_quota/memory_quota.cc - src/core/lib/resource_quota/periodic_update.cc - src/core/lib/resource_quota/resource_quota.cc @@ -9987,6 +9995,7 @@ targets: build: test language: c++ headers: + - src/core/lib/debug/trace.h - src/core/lib/gprpp/atomic_utils.h - src/core/lib/gprpp/orphanable.h - src/core/lib/gprpp/ref_counted.h @@ -10001,9 +10010,12 @@ targets: - src/core/lib/promise/inter_activity_pipe.h - src/core/lib/promise/poll.h - src/core/lib/promise/seq.h + - src/core/lib/promise/trace.h - test/core/promise/test_wakeup_schedulers.h src: + - src/core/lib/debug/trace.cc - src/core/lib/promise/activity.cc + - src/core/lib/promise/trace.cc - test/core/promise/inter_activity_pipe_test.cc deps: - gtest @@ -10245,17 +10257,22 @@ targets: build: test language: c++ headers: + - src/core/lib/debug/trace.h - src/core/lib/gprpp/bitset.h - src/core/lib/promise/detail/join_state.h - src/core/lib/promise/detail/promise_like.h - src/core/lib/promise/join.h - src/core/lib/promise/map.h - src/core/lib/promise/poll.h + - src/core/lib/promise/trace.h src: + - src/core/lib/debug/trace.cc + - src/core/lib/promise/trace.cc - test/core/promise/join_test.cc deps: - gtest - absl/meta:type_traits + - absl/status:statusor - gpr uses_polling: false - name: json_object_loader_test @@ -10556,6 +10573,7 @@ targets: build: test language: c++ headers: + - src/core/lib/debug/trace.h - src/core/lib/promise/detail/basic_seq.h - src/core/lib/promise/detail/promise_factory.h - src/core/lib/promise/detail/promise_like.h @@ -10563,7 +10581,10 @@ targets: - src/core/lib/promise/loop.h - src/core/lib/promise/poll.h - src/core/lib/promise/seq.h + - src/core/lib/promise/trace.h src: + - src/core/lib/debug/trace.cc + - src/core/lib/promise/trace.cc - test/core/promise/loop_test.cc deps: - gtest @@ -14021,17 +14042,22 @@ targets: build: test language: c++ headers: + - src/core/lib/debug/trace.h - src/core/lib/promise/detail/basic_seq.h - src/core/lib/promise/detail/promise_factory.h - src/core/lib/promise/detail/promise_like.h - src/core/lib/promise/detail/seq_state.h - src/core/lib/promise/poll.h - src/core/lib/promise/seq.h + - src/core/lib/promise/trace.h src: + - src/core/lib/debug/trace.cc + - src/core/lib/promise/trace.cc - test/core/promise/seq_test.cc deps: - gtest - absl/meta:type_traits + - absl/status:statusor - gpr uses_polling: false - name: sequential_connectivity_test @@ -16678,13 +16704,17 @@ targets: build: test language: c++ headers: + - src/core/lib/debug/trace.h - src/core/lib/gprpp/bitset.h - src/core/lib/promise/detail/join_state.h - src/core/lib/promise/detail/promise_like.h - src/core/lib/promise/map.h - src/core/lib/promise/poll.h + - src/core/lib/promise/trace.h - src/core/lib/promise/try_join.h src: + - src/core/lib/debug/trace.cc + - src/core/lib/promise/trace.cc - test/core/promise/try_join_test.cc deps: - gtest @@ -16709,14 +16739,18 @@ targets: build: test language: c++ headers: + - src/core/lib/debug/trace.h - src/core/lib/promise/detail/basic_seq.h - src/core/lib/promise/detail/promise_factory.h - src/core/lib/promise/detail/promise_like.h - src/core/lib/promise/detail/seq_state.h - src/core/lib/promise/detail/status.h - src/core/lib/promise/poll.h + - src/core/lib/promise/trace.h - src/core/lib/promise/try_seq.h src: + - src/core/lib/debug/trace.cc + - src/core/lib/promise/trace.cc - test/core/promise/try_seq_test.cc deps: - gtest diff --git a/src/core/BUILD b/src/core/BUILD index 4e59c1dc97c..c15c37e3c74 100644 --- a/src/core/BUILD +++ b/src/core/BUILD @@ -630,8 +630,10 @@ grpc_cc_library( "construct_destruct", "poll", "promise_like", + "promise_trace", "//:gpr", "//:gpr_platform", + "//:grpc_trace", ], ) @@ -702,7 +704,9 @@ grpc_cc_library( "poll", "promise_factory", "promise_like", + "promise_trace", "//:gpr", + "//:grpc_trace", ], ) diff --git a/src/core/lib/promise/detail/join_state.h b/src/core/lib/promise/detail/join_state.h index 369d98302a4..84a3f37188b 100644 --- a/src/core/lib/promise/detail/join_state.h +++ b/src/core/lib/promise/detail/join_state.h @@ -25,10 +25,12 @@ #include +#include "src/core/lib/debug/trace.h" #include "src/core/lib/gprpp/bitset.h" #include "src/core/lib/gprpp/construct_destruct.h" #include "src/core/lib/promise/detail/promise_like.h" #include "src/core/lib/promise/poll.h" +#include "src/core/lib/promise/trace.h" namespace grpc_core { namespace promise_detail { @@ -91,7 +93,16 @@ struct JoinState { typename Traits::template ResultType>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/2", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/2 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -101,9 +112,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/2 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/2", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/2 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -113,6 +135,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/2 already ready", this); } if (ready.all()) { return Result{std::make_tuple(std::move(result0), std::move(result1))}; @@ -195,7 +219,16 @@ struct JoinState { std::tuple>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/3", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/3 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -205,9 +238,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/3 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/3", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/3 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -217,9 +261,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/3 already ready", this); } if (!ready.is_set(2)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 3/3", this); + } auto poll = promise2(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 3/3 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(2); @@ -229,6 +284,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 3/3 already ready", this); } if (ready.all()) { return Result{std::make_tuple(std::move(result0), std::move(result1), @@ -330,7 +387,16 @@ struct JoinState { std::tuple>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/4", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/4 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -340,9 +406,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/4 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/4", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/4 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -352,9 +429,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/4 already ready", this); } if (!ready.is_set(2)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 3/4", this); + } auto poll = promise2(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 3/4 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(2); @@ -364,9 +452,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 3/4 already ready", this); } if (!ready.is_set(3)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 4/4", this); + } auto poll = promise3(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 4/4 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(3); @@ -376,6 +475,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 4/4 already ready", this); } if (ready.all()) { return Result{std::make_tuple(std::move(result0), std::move(result1), @@ -496,7 +597,16 @@ struct JoinState { std::tuple>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/5", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/5 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -506,9 +616,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/5 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/5", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/5 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -518,9 +639,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/5 already ready", this); } if (!ready.is_set(2)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 3/5", this); + } auto poll = promise2(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 3/5 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(2); @@ -530,9 +662,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 3/5 already ready", this); } if (!ready.is_set(3)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 4/5", this); + } auto poll = promise3(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 4/5 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(3); @@ -542,9 +685,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 4/5 already ready", this); } if (!ready.is_set(4)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 5/5", this); + } auto poll = promise4(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 5/5 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(4); @@ -554,6 +708,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 5/5 already ready", this); } if (ready.all()) { return Result{std::make_tuple(std::move(result0), std::move(result1), @@ -693,7 +849,16 @@ struct JoinState { std::tuple>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/6", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/6 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -703,9 +868,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/6 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/6", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/6 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -715,9 +891,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/6 already ready", this); } if (!ready.is_set(2)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 3/6", this); + } auto poll = promise2(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 3/6 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(2); @@ -727,9 +914,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 3/6 already ready", this); } if (!ready.is_set(3)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 4/6", this); + } auto poll = promise3(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 4/6 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(3); @@ -739,9 +937,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 4/6 already ready", this); } if (!ready.is_set(4)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 5/6", this); + } auto poll = promise4(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 5/6 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(4); @@ -751,9 +960,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 5/6 already ready", this); } if (!ready.is_set(5)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 6/6", this); + } auto poll = promise5(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 6/6 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(5); @@ -763,6 +983,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 6/6 already ready", this); } if (ready.all()) { return Result{std::make_tuple(std::move(result0), std::move(result1), @@ -920,7 +1142,16 @@ struct JoinState { Result0, Result1, Result2, Result3, Result4, Result5, Result6>>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/7", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/7 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -930,9 +1161,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/7 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/7", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/7 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -942,9 +1184,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/7 already ready", this); } if (!ready.is_set(2)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 3/7", this); + } auto poll = promise2(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 3/7 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(2); @@ -954,9 +1207,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 3/7 already ready", this); } if (!ready.is_set(3)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 4/7", this); + } auto poll = promise3(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 4/7 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(3); @@ -966,9 +1230,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 4/7 already ready", this); } if (!ready.is_set(4)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 5/7", this); + } auto poll = promise4(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 5/7 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(4); @@ -978,9 +1253,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 5/7 already ready", this); } if (!ready.is_set(5)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 6/7", this); + } auto poll = promise5(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 6/7 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(5); @@ -990,9 +1276,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 6/7 already ready", this); } if (!ready.is_set(6)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 7/7", this); + } auto poll = promise6(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 7/7 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(6); @@ -1002,6 +1299,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 7/7 already ready", this); } if (ready.all()) { return Result{std::make_tuple(std::move(result0), std::move(result1), @@ -1179,7 +1478,16 @@ struct JoinState { Result0, Result1, Result2, Result3, Result4, Result5, Result6, Result7>>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/8", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -1189,9 +1497,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/8 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/8", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -1201,9 +1520,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/8 already ready", this); } if (!ready.is_set(2)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 3/8", this); + } auto poll = promise2(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 3/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(2); @@ -1213,9 +1543,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 3/8 already ready", this); } if (!ready.is_set(3)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 4/8", this); + } auto poll = promise3(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 4/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(3); @@ -1225,9 +1566,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 4/8 already ready", this); } if (!ready.is_set(4)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 5/8", this); + } auto poll = promise4(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 5/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(4); @@ -1237,9 +1589,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 5/8 already ready", this); } if (!ready.is_set(5)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 6/8", this); + } auto poll = promise5(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 6/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(5); @@ -1249,9 +1612,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 6/8 already ready", this); } if (!ready.is_set(6)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 7/8", this); + } auto poll = promise6(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 7/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(6); @@ -1261,9 +1635,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 7/8 already ready", this); } if (!ready.is_set(7)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 8/8", this); + } auto poll = promise7(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 8/8 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(7); @@ -1273,6 +1658,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 8/8 already ready", this); } if (ready.all()) { return Result{std::make_tuple(std::move(result0), std::move(result1), @@ -1469,7 +1856,16 @@ struct JoinState { Result7, Result8>>; Poll PollOnce() { if (!ready.is_set(0)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 1/9", this); + } auto poll = promise0(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 1/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(0); @@ -1479,9 +1875,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 1/9 already ready", this); } if (!ready.is_set(1)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 2/9", this); + } auto poll = promise1(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 2/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(1); @@ -1491,9 +1898,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 2/9 already ready", this); } if (!ready.is_set(2)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 3/9", this); + } auto poll = promise2(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 3/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(2); @@ -1503,9 +1921,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 3/9 already ready", this); } if (!ready.is_set(3)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 4/9", this); + } auto poll = promise3(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 4/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(3); @@ -1515,9 +1944,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 4/9 already ready", this); } if (!ready.is_set(4)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 5/9", this); + } auto poll = promise4(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 5/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(4); @@ -1527,9 +1967,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 5/9 already ready", this); } if (!ready.is_set(5)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 6/9", this); + } auto poll = promise5(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 6/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(5); @@ -1539,9 +1990,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 6/9 already ready", this); } if (!ready.is_set(6)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 7/9", this); + } auto poll = promise6(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 7/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(6); @@ -1551,9 +2013,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 7/9 already ready", this); } if (!ready.is_set(7)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 8/9", this); + } auto poll = promise7(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 8/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(7); @@ -1563,9 +2036,20 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 8/9 already ready", this); } if (!ready.is_set(8)) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint 9/9", this); + } auto poll = promise8(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint 9/9 %s", this, + p != nullptr ? (Traits::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(8); @@ -1575,6 +2059,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint 9/9 already ready", this); } if (ready.all()) { return Result{std::make_tuple( diff --git a/src/core/lib/promise/detail/seq_state.h b/src/core/lib/promise/detail/seq_state.h index c5be81b11f0..5ee32418a53 100644 --- a/src/core/lib/promise/detail/seq_state.h +++ b/src/core/lib/promise/detail/seq_state.h @@ -27,10 +27,12 @@ #include +#include "src/core/lib/debug/trace.h" #include "src/core/lib/gprpp/construct_destruct.h" #include "src/core/lib/promise/detail/promise_factory.h" #include "src/core/lib/promise/detail/promise_like.h" #include "src/core/lib/promise/poll.h" +#include "src/core/lib/promise/trace.h" // A sequence under some traits for some set of callables P, Fs. // P should be a promise-like object that yields a value. @@ -137,8 +139,18 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/2", this); + } auto result = prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/2 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -154,7 +166,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/2", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 2/2 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -251,8 +270,18 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/3", this); + } auto result = prior.prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/3 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -267,8 +296,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/3", this); + } auto result = prior.current_promise(); PromiseResult1* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 2/3 gets %s", this, + p != nullptr + ? (PromiseResultTraits1::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits1::IsOk(*p)) { return PromiseResultTraits1::template ReturnValue( @@ -284,7 +323,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState2: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 3/3", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 3/3 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -408,8 +454,18 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/4", this); + } auto result = prior.prior.prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/4 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -424,8 +480,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/4", this); + } auto result = prior.prior.current_promise(); PromiseResult1* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 2/4 gets %s", this, + p != nullptr + ? (PromiseResultTraits1::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits1::IsOk(*p)) { return PromiseResultTraits1::template ReturnValue( @@ -440,8 +506,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState2: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 3/4", this); + } auto result = prior.current_promise(); PromiseResult2* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 3/4 gets %s", this, + p != nullptr + ? (PromiseResultTraits2::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits2::IsOk(*p)) { return PromiseResultTraits2::template ReturnValue( @@ -457,7 +533,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState3: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 4/4", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 4/4 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -608,8 +691,18 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/5", this); + } auto result = prior.prior.prior.prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/5 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -624,8 +717,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/5", this); + } auto result = prior.prior.prior.current_promise(); PromiseResult1* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 2/5 gets %s", this, + p != nullptr + ? (PromiseResultTraits1::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits1::IsOk(*p)) { return PromiseResultTraits1::template ReturnValue( @@ -640,8 +743,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState2: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 3/5", this); + } auto result = prior.prior.current_promise(); PromiseResult2* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 3/5 gets %s", this, + p != nullptr + ? (PromiseResultTraits2::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits2::IsOk(*p)) { return PromiseResultTraits2::template ReturnValue( @@ -656,8 +769,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState3: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 4/5", this); + } auto result = prior.current_promise(); PromiseResult3* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 4/5 gets %s", this, + p != nullptr + ? (PromiseResultTraits3::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits3::IsOk(*p)) { return PromiseResultTraits3::template ReturnValue( @@ -673,7 +796,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState4: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 5/5", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 5/5 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -861,8 +991,18 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/6", this); + } auto result = prior.prior.prior.prior.prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/6 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -878,8 +1018,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/6", this); + } auto result = prior.prior.prior.prior.current_promise(); PromiseResult1* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 2/6 gets %s", this, + p != nullptr + ? (PromiseResultTraits1::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits1::IsOk(*p)) { return PromiseResultTraits1::template ReturnValue( @@ -894,8 +1044,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState2: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 3/6", this); + } auto result = prior.prior.prior.current_promise(); PromiseResult2* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 3/6 gets %s", this, + p != nullptr + ? (PromiseResultTraits2::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits2::IsOk(*p)) { return PromiseResultTraits2::template ReturnValue( @@ -910,8 +1070,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState3: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 4/6", this); + } auto result = prior.prior.current_promise(); PromiseResult3* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 4/6 gets %s", this, + p != nullptr + ? (PromiseResultTraits3::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits3::IsOk(*p)) { return PromiseResultTraits3::template ReturnValue( @@ -926,8 +1096,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState4: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 5/6", this); + } auto result = prior.current_promise(); PromiseResult4* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 5/6 gets %s", this, + p != nullptr + ? (PromiseResultTraits4::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits4::IsOk(*p)) { return PromiseResultTraits4::template ReturnValue( @@ -943,7 +1123,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState5: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 6/6", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 6/6 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -1164,8 +1351,18 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/7", this); + } auto result = prior.prior.prior.prior.prior.prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/7 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -1181,8 +1378,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/7", this); + } auto result = prior.prior.prior.prior.prior.current_promise(); PromiseResult1* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 2/7 gets %s", this, + p != nullptr + ? (PromiseResultTraits1::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits1::IsOk(*p)) { return PromiseResultTraits1::template ReturnValue( @@ -1198,8 +1405,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState2: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 3/7", this); + } auto result = prior.prior.prior.prior.current_promise(); PromiseResult2* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 3/7 gets %s", this, + p != nullptr + ? (PromiseResultTraits2::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits2::IsOk(*p)) { return PromiseResultTraits2::template ReturnValue( @@ -1214,8 +1431,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState3: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 4/7", this); + } auto result = prior.prior.prior.current_promise(); PromiseResult3* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 4/7 gets %s", this, + p != nullptr + ? (PromiseResultTraits3::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits3::IsOk(*p)) { return PromiseResultTraits3::template ReturnValue( @@ -1230,8 +1457,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState4: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 5/7", this); + } auto result = prior.prior.current_promise(); PromiseResult4* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 5/7 gets %s", this, + p != nullptr + ? (PromiseResultTraits4::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits4::IsOk(*p)) { return PromiseResultTraits4::template ReturnValue( @@ -1246,8 +1483,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState5: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 6/7", this); + } auto result = prior.current_promise(); PromiseResult5* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 6/7 gets %s", this, + p != nullptr + ? (PromiseResultTraits5::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits5::IsOk(*p)) { return PromiseResultTraits5::template ReturnValue( @@ -1263,7 +1510,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState6: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 7/7", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 7/7 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -1517,9 +1771,19 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/8", this); + } auto result = prior.prior.prior.prior.prior.prior.prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/8 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -1536,8 +1800,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/8", this); + } auto result = prior.prior.prior.prior.prior.prior.current_promise(); PromiseResult1* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 2/8 gets %s", this, + p != nullptr + ? (PromiseResultTraits1::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits1::IsOk(*p)) { return PromiseResultTraits1::template ReturnValue( @@ -1553,8 +1827,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState2: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 3/8", this); + } auto result = prior.prior.prior.prior.prior.current_promise(); PromiseResult2* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 3/8 gets %s", this, + p != nullptr + ? (PromiseResultTraits2::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits2::IsOk(*p)) { return PromiseResultTraits2::template ReturnValue( @@ -1570,8 +1854,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState3: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 4/8", this); + } auto result = prior.prior.prior.prior.current_promise(); PromiseResult3* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 4/8 gets %s", this, + p != nullptr + ? (PromiseResultTraits3::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits3::IsOk(*p)) { return PromiseResultTraits3::template ReturnValue( @@ -1586,8 +1880,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState4: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 5/8", this); + } auto result = prior.prior.prior.current_promise(); PromiseResult4* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 5/8 gets %s", this, + p != nullptr + ? (PromiseResultTraits4::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits4::IsOk(*p)) { return PromiseResultTraits4::template ReturnValue( @@ -1602,8 +1906,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState5: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 6/8", this); + } auto result = prior.prior.current_promise(); PromiseResult5* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 6/8 gets %s", this, + p != nullptr + ? (PromiseResultTraits5::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits5::IsOk(*p)) { return PromiseResultTraits5::template ReturnValue( @@ -1618,8 +1932,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState6: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 7/8", this); + } auto result = prior.current_promise(); PromiseResult6* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 7/8 gets %s", this, + p != nullptr + ? (PromiseResultTraits6::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits6::IsOk(*p)) { return PromiseResultTraits6::template ReturnValue( @@ -1635,7 +1959,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState7: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 8/8", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 8/8 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -1923,9 +2254,19 @@ struct SeqState { Poll PollOnce() { switch (state) { case State::kState0: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 1/9", this); + } auto result = prior.prior.prior.prior.prior.prior.prior.prior.current_promise(); PromiseResult0* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 1/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits0::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits0::IsOk(*p)) { return PromiseResultTraits0::template ReturnValue( @@ -1943,9 +2284,19 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState1: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 2/9", this); + } auto result = prior.prior.prior.prior.prior.prior.prior.current_promise(); PromiseResult1* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 2/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits1::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits1::IsOk(*p)) { return PromiseResultTraits1::template ReturnValue( @@ -1962,8 +2313,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState2: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 3/9", this); + } auto result = prior.prior.prior.prior.prior.prior.current_promise(); PromiseResult2* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 3/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits2::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits2::IsOk(*p)) { return PromiseResultTraits2::template ReturnValue( @@ -1979,8 +2340,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState3: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 4/9", this); + } auto result = prior.prior.prior.prior.prior.current_promise(); PromiseResult3* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 4/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits3::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits3::IsOk(*p)) { return PromiseResultTraits3::template ReturnValue( @@ -1996,8 +2367,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState4: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 5/9", this); + } auto result = prior.prior.prior.prior.current_promise(); PromiseResult4* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 5/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits4::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits4::IsOk(*p)) { return PromiseResultTraits4::template ReturnValue( @@ -2012,8 +2393,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState5: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 6/9", this); + } auto result = prior.prior.prior.current_promise(); PromiseResult5* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 6/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits5::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits5::IsOk(*p)) { return PromiseResultTraits5::template ReturnValue( @@ -2028,8 +2419,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState6: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 7/9", this); + } auto result = prior.prior.current_promise(); PromiseResult6* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 7/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits6::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits6::IsOk(*p)) { return PromiseResultTraits6::template ReturnValue( @@ -2044,8 +2445,18 @@ struct SeqState { } ABSL_FALLTHROUGH_INTENDED; case State::kState7: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 8/9", this); + } auto result = prior.current_promise(); PromiseResult7* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log( + GPR_DEBUG, "seq[%p]: poll step 8/9 gets %s", this, + p != nullptr + ? (PromiseResultTraits7::IsOk(*p) ? "ready" : "early-error") + : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits7::IsOk(*p)) { return PromiseResultTraits7::template ReturnValue( @@ -2061,7 +2472,14 @@ struct SeqState { ABSL_FALLTHROUGH_INTENDED; default: case State::kState8: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step 9/9", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step 9/9 gets %s", this, + result.ready() ? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); diff --git a/test/core/promise/seq_test.cc b/test/core/promise/seq_test.cc index 7e5bd9695b8..8bfd4fadbc8 100644 --- a/test/core/promise/seq_test.cc +++ b/test/core/promise/seq_test.cc @@ -16,6 +16,7 @@ #include +#include #include #include #include diff --git a/tools/codegen/core/gen_join.py b/tools/codegen/core/gen_join.py index ab081e4af8f..cc978eba285 100755 --- a/tools/codegen/core/gen_join.py +++ b/tools/codegen/core/gen_join.py @@ -69,7 +69,15 @@ struct JoinState { Poll PollOnce() { % for i in range(0,n): if (!ready.is_set(${i})) { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: begin poll joint ${i+1}/${n}", this); + } auto poll = promise${i}(); + if (grpc_trace_promise_primitives.enabled()) { + auto* p = poll.value_if_ready(); + gpr_log(GPR_DEBUG, "join[%p]: joint ${i+1}/${n} %s", this, + p != nullptr? (Traits::IsOk(*p)? "ready" : "early-error") : "pending"); + } if (auto* p = poll.value_if_ready()) { if (Traits::IsOk(*p)) { ready.set(${i}); @@ -79,6 +87,8 @@ struct JoinState { return Traits::template EarlyReturn(std::move(*p)); } } + } else if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "join[%p]: joint ${i+1}/${n} already ready", this); } % endfor if (ready.all()) { @@ -106,6 +116,7 @@ front_matter = """ #include #include #include +#include "src/core/lib/promise/trace.h" namespace grpc_core { namespace promise_detail { diff --git a/tools/codegen/core/gen_seq.py b/tools/codegen/core/gen_seq.py index 555f1202fa0..cfe0f045906 100755 --- a/tools/codegen/core/gen_seq.py +++ b/tools/codegen/core/gen_seq.py @@ -139,11 +139,18 @@ tail${i}: switch (state) { % for i in range(0,n-1): case State::kState${i}: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step ${i+1}/${n}", this); + } auto result = ${"prior."*(n-1-i)}current_promise(); PromiseResult${i}* p = result.value_if_ready(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step ${i+1}/${n} gets %s", this, + p != nullptr? (PromiseResultTraits${i}::IsOk(*p)? "ready" : "early-error") : "pending"); + } if (p == nullptr) return Pending{}; if (!PromiseResultTraits${i}::IsOk(*p)) { - return PromiseResultTraits${i}::template ReturnValue(std::move(*p)); + return PromiseResultTraits${i}::template ReturnValue(std::move(*p)); } Destruct(&${"prior."*(n-1-i)}current_promise); auto next_promise = PromiseResultTraits${i}::CallFactory(&${"prior."*(n-1-i)}next_factory, std::move(*p)); @@ -155,7 +162,13 @@ tail${i}: % endfor default: case State::kState${n-1}: { + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: begin poll step ${n}/${n}", this); + } auto result = current_promise(); + if (grpc_trace_promise_primitives.enabled()) { + gpr_log(GPR_DEBUG, "seq[%p]: poll step ${n}/${n} gets %s", this, result.ready()? "ready" : "pending"); + } auto* p = result.value_if_ready(); if (p == nullptr) return Pending{}; return Result(std::move(*p)); @@ -185,6 +198,7 @@ front_matter = """ #include "src/core/lib/promise/detail/promise_factory.h" #include "src/core/lib/promise/detail/promise_like.h" #include "src/core/lib/promise/poll.h" +#include "src/core/lib/promise/trace.h" // A sequence under some traits for some set of callables P, Fs. // P should be a promise-like object that yields a value.