diff --git a/src/core/lib/iomgr/executor/mpmcqueue.cc b/src/core/lib/iomgr/executor/mpmcqueue.cc index fff078035c8..78a3aa1306f 100644 --- a/src/core/lib/iomgr/executor/mpmcqueue.cc +++ b/src/core/lib/iomgr/executor/mpmcqueue.cc @@ -25,6 +25,8 @@ namespace grpc_core { DebugOnlyTraceFlag thread_pool(false, "thread_pool_trace"); inline void* InfLenFIFOQueue::PopFront() { + // Caller should already checked queue is not empty and has already hold the + // mutex. This function will only do the job of removal. void* result = queue_head_->content; Node* head_to_remove = queue_head_; queue_head_ = queue_head_->next; @@ -33,29 +35,29 @@ inline void* InfLenFIFOQueue::PopFront() { if (GRPC_TRACE_FLAG_ENABLED(thread_pool)) { gpr_timespec wait_time = - gpr_time_sub(gpr_now(GPR_CLOCK_PRECISE), head_to_remove->insert_time); + gpr_time_sub(gpr_now(GPR_CLOCK_MONOTONIC), head_to_remove->insert_time); // Updates Stats info stats_.num_completed++; - stats_.total_queue_cycles = - gpr_time_add(stats_.total_queue_cycles, wait_time); - stats_.max_queue_cycles = gpr_time_max( - gpr_convert_clock_type(stats_.max_queue_cycles, GPR_TIMESPAN), + stats_.total_queue_time = + gpr_time_add(stats_.total_queue_time, wait_time); + stats_.max_queue_time = gpr_time_max( + gpr_convert_clock_type(stats_.max_queue_time, GPR_TIMESPAN), wait_time); if (count_.Load(MemoryOrder::RELAXED) == 0) { - stats_.busy_time_cycles = - gpr_time_add(stats_.busy_time_cycles, - gpr_time_sub(gpr_now(GPR_CLOCK_PRECISE), busy_time)); + stats_.busy_queue_time = + gpr_time_add(stats_.busy_queue_time, + gpr_time_sub(gpr_now(GPR_CLOCK_MONOTONIC), busy_time)); } gpr_log(GPR_INFO, - "[InfLenFIFOQueue Get] num_completed: %" PRIu64 - " total_queue_cycles: %" PRId32 " max_queue_cycles: %" PRId32 - " busy_time_cycles: %" PRId32, - stats_.num_completed, gpr_time_to_millis(stats_.total_queue_cycles), - gpr_time_to_millis(stats_.max_queue_cycles), - gpr_time_to_millis(stats_.busy_time_cycles)); + "[InfLenFIFOQueue PopFront] num_completed: %" PRIu64 + " total_queue_time: %f max_queue_time: %f busy_queue_time: %f", + stats_.num_completed, + gpr_timespec_to_micros(stats_.total_queue_time), + gpr_timespec_to_micros(stats_.max_queue_time), + gpr_timespec_to_micros(stats_.busy_queue_time)); } Delete(head_to_remove); @@ -81,7 +83,7 @@ void InfLenFIFOQueue::Put(void* elem) { Node* new_node = New(elem); if (count_.Load(MemoryOrder::RELAXED) == 0) { if (GRPC_TRACE_FLAG_ENABLED(thread_pool)) { - busy_time = gpr_now(GPR_CLOCK_PRECISE); + busy_time = gpr_now(GPR_CLOCK_MONOTONIC); } queue_head_ = queue_tail_ = new_node; } else { diff --git a/src/core/lib/iomgr/executor/mpmcqueue.h b/src/core/lib/iomgr/executor/mpmcqueue.h index 6b071a2fd68..208038498c9 100644 --- a/src/core/lib/iomgr/executor/mpmcqueue.h +++ b/src/core/lib/iomgr/executor/mpmcqueue.h @@ -52,8 +52,7 @@ class MPMCQueueInterface { class InfLenFIFOQueue : public MPMCQueueInterface { public: - // Creates a new MPMC Queue. The queue created - // will have infinite length. + // Creates a new MPMC Queue. The queue created will have infinite length. InfLenFIFOQueue(); // Releases all resources hold by the queue. The queue must be empty, and no @@ -92,24 +91,24 @@ class InfLenFIFOQueue : public MPMCQueueInterface { }; // Stats of queue. This will only be collect when debug trace mode is on. - // All printed stats info will have time measurement in millisecond. + // All printed stats info will have time measurement in microsecond. struct Stats { uint64_t num_started; // Number of elements have been added to queue uint64_t num_completed; // Number of elements have been removed from // the queue - gpr_timespec total_queue_cycles; // Total waiting time that all the - // removed elements have spent in queue - gpr_timespec max_queue_cycles; // Max waiting time among all removed - // elements - gpr_timespec busy_time_cycles; // Accumulated amount of time that queue - // was not empty + gpr_timespec total_queue_time; // Total waiting time that all the + // removed elements have spent in queue + gpr_timespec max_queue_time; // Max waiting time among all removed + // elements + gpr_timespec busy_queue_time; // Accumulated amount of time that queue + // was not empty Stats() { num_started = 0; num_completed = 0; - total_queue_cycles = gpr_time_0(GPR_TIMESPAN); - max_queue_cycles = gpr_time_0(GPR_TIMESPAN); - busy_time_cycles = gpr_time_0(GPR_TIMESPAN); + total_queue_time = gpr_time_0(GPR_TIMESPAN); + max_queue_time = gpr_time_0(GPR_TIMESPAN); + busy_queue_time = gpr_time_0(GPR_TIMESPAN); } };