diff options
author | Amirsaman Memaripour <amirsaman.memaripour@mongodb.com> | 2020-10-02 02:40:31 +0000 |
---|---|---|
committer | Evergreen Agent <no-reply@evergreen.mongodb.com> | 2020-10-14 15:29:48 +0000 |
commit | 1f0009a389042c24360509625d50a9e3812658c7 (patch) | |
tree | dfd754ceb4fa7c0a92ddd919e9759f9fe307528c /src/mongo/db | |
parent | 687a70903fc5f10de9066ac92e1b9e0806924327 (diff) | |
download | mongo-1f0009a389042c24360509625d50a9e3812658c7.tar.gz |
SERVER-47446 Measure cpu time taken by operations
Diffstat (limited to 'src/mongo/db')
-rw-r--r-- | src/mongo/db/SConscript | 2 | ||||
-rw-r--r-- | src/mongo/db/client.cpp | 7 | ||||
-rw-r--r-- | src/mongo/db/operation_cpu_timer.cpp | 173 | ||||
-rw-r--r-- | src/mongo/db/operation_cpu_timer.h | 71 | ||||
-rw-r--r-- | src/mongo/db/operation_cpu_timer_test.cpp | 171 |
5 files changed, 424 insertions, 0 deletions
diff --git a/src/mongo/db/SConscript b/src/mongo/db/SConscript index 3b17ae7a09e..5f86b4cbd21 100644 --- a/src/mongo/db/SConscript +++ b/src/mongo/db/SConscript @@ -453,6 +453,7 @@ env.Library( 'default_baton.cpp', 'operation_context.cpp', 'operation_context_group.cpp', + 'operation_cpu_timer.cpp', 'operation_key_manager.cpp', 'service_context.cpp', 'server_recovery.cpp', @@ -2247,6 +2248,7 @@ envWithAsio.CppUnitTest( 'op_observer_impl_test.cpp', 'op_observer_registry_test.cpp', 'operation_context_test.cpp', + 'operation_cpu_timer_test.cpp', 'operation_time_tracker_test.cpp', 'persistent_task_store_test.cpp', 'range_arithmetic_test.cpp', diff --git a/src/mongo/db/client.cpp b/src/mongo/db/client.cpp index a9678bee962..53fdaf2052c 100644 --- a/src/mongo/db/client.cpp +++ b/src/mongo/db/client.cpp @@ -42,6 +42,7 @@ #include "mongo/base/status.h" #include "mongo/db/lasterror.h" #include "mongo/db/operation_context.h" +#include "mongo/db/operation_cpu_timer.h" #include "mongo/db/service_context.h" #include "mongo/stdx/thread.h" #include "mongo/util/concurrency/thread_name.h" @@ -156,12 +157,18 @@ bool haveClient() { ServiceContext::UniqueClient Client::releaseCurrent() { invariant(haveClient()); + if (auto opCtx = currentClient->_opCtx) + if (auto timer = OperationCPUTimer::get(opCtx)) + timer->onThreadDetach(); return std::move(currentClient); } void Client::setCurrent(ServiceContext::UniqueClient client) { invariantNoCurrentClient(); currentClient = std::move(client); + if (auto opCtx = currentClient->_opCtx) + if (auto timer = OperationCPUTimer::get(opCtx)) + timer->onThreadAttach(); } /** diff --git a/src/mongo/db/operation_cpu_timer.cpp b/src/mongo/db/operation_cpu_timer.cpp new file mode 100644 index 00000000000..7627c8af11c --- /dev/null +++ b/src/mongo/db/operation_cpu_timer.cpp @@ -0,0 +1,173 @@ +/** + * Copyright (C) 2020-present MongoDB, Inc. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the Server Side Public License, version 1, + * as published by MongoDB, Inc. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * Server Side Public License for more details. + * + * You should have received a copy of the Server Side Public License + * along with this program. If not, see + * <http://www.mongodb.com/licensing/server-side-public-license>. + * + * As a special exception, the copyright holders give permission to link the + * code of portions of this program with the OpenSSL library under certain + * conditions as described in each individual source file and distribute + * linked combinations including the program with the OpenSSL library. You + * must comply with the Server Side Public License in all respects for + * all of the code used other than as permitted herein. If you modify file(s) + * with this exception, you may extend this exception to your version of the + * file(s), but you are not obligated to do so. If you do not wish to do so, + * delete this exception statement from your version. If you delete this + * exception statement from all source files in the program, then also delete + * it in the license file. + */ + +#include <boost/optional.hpp> +#include <fmt/format.h> + +#if defined(__linux__) +#include <time.h> +#endif // defined(__linux__) + +#include "mongo/db/operation_cpu_timer.h" + +#include "mongo/base/error_codes.h" +#include "mongo/db/client.h" +#include "mongo/db/operation_context.h" +#include "mongo/stdx/thread.h" +#include "mongo/util/assert_util.h" +#include "mongo/util/errno_util.h" +#include "mongo/util/fail_point.h" + +namespace mongo { + +#if defined(__linux__) + +namespace { + +using namespace fmt::literals; + +MONGO_FAIL_POINT_DEFINE(hangCPUTimerAfterOnThreadAttach); +MONGO_FAIL_POINT_DEFINE(hangCPUTimerAfterOnThreadDetach); + +class PosixTimer final : public OperationCPUTimer { +public: + Nanoseconds getElapsed() const override; + + void start() override; + void stop() override; + + void onThreadAttach() override; + void onThreadDetach() override; + +private: + bool _timerIsRunning() const; + bool _isAttachedToCurrentThread() const; + + // Returns the elapsed time since the creation of the current thread. + Nanoseconds _getThreadTime() const; + + // Holds the value returned by `_getThreadTime()` at the time of starting/resuming the timer. + boost::optional<Nanoseconds> _startedOn; + boost::optional<stdx::thread::id> _threadId; + Nanoseconds _elapsedBeforeInterrupted = Nanoseconds(0); +}; + +Nanoseconds PosixTimer::getElapsed() const { + invariant(_isAttachedToCurrentThread(), "Not attached to current thread"); + auto elapsed = _elapsedBeforeInterrupted; + if (_timerIsRunning()) + elapsed += _getThreadTime() - _startedOn.get(); + return elapsed; +} + +bool PosixTimer::_timerIsRunning() const { + return _startedOn.has_value(); +} + +bool PosixTimer::_isAttachedToCurrentThread() const { + return _threadId.has_value() && _threadId.get() == stdx::this_thread::get_id(); +} + +void PosixTimer::start() { + invariant(!_timerIsRunning(), "Timer has already started"); + + _startedOn = _getThreadTime(); + _threadId = stdx::this_thread::get_id(); + _elapsedBeforeInterrupted = Nanoseconds(0); +} + +void PosixTimer::stop() { + invariant(_timerIsRunning(), "Timer is not running"); + invariant(_isAttachedToCurrentThread()); + + _elapsedBeforeInterrupted = getElapsed(); + _startedOn.reset(); +} + +void PosixTimer::onThreadAttach() { + if (!_timerIsRunning()) + return; + + invariant(!_threadId.has_value(), "Timer has already been attached"); + _threadId = stdx::this_thread::get_id(); + _startedOn = _getThreadTime(); + + hangCPUTimerAfterOnThreadAttach.pauseWhileSet(); +} + +void PosixTimer::onThreadDetach() { + if (!_timerIsRunning()) + return; + + invariant(_threadId.has_value(), "Timer is not attached"); + _threadId.reset(); + _elapsedBeforeInterrupted = _getThreadTime() - _startedOn.get(); + + hangCPUTimerAfterOnThreadDetach.pauseWhileSet(); +} + +Nanoseconds PosixTimer::_getThreadTime() const { + struct timespec t; + if (auto ret = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &t); ret != 0) { + int ec = errno; + internalAssert(Status(ErrorCodes::InternalError, + "Unable to get time: {}"_format(errnoWithDescription(ec)))); + } + return Seconds(t.tv_sec) + Nanoseconds(t.tv_nsec); +} + +static auto getCPUTimer = OperationContext::declareDecoration<PosixTimer>(); + +} // namespace + +OperationCPUTimer* OperationCPUTimer::get(OperationContext* opCtx) { + invariant(Client::getCurrent() && Client::getCurrent()->getOperationContext() == opCtx, + "Operation not attached to the current thread"); + + // Checks for time support on POSIX platforms. In particular, it checks for support in presence + // of SMP systems. + static bool isTimeSupported = [] { + clockid_t cid; + return clock_getcpuclockid(0, &cid) == 0; + }(); + + if (!isTimeSupported) + return nullptr; + return &getCPUTimer(opCtx); +} + +#else // not defined(__linux__) + +OperationCPUTimer* OperationCPUTimer::get(OperationContext*) { + return nullptr; +} + +#endif // defined(__linux__) + +} // namespace mongo diff --git a/src/mongo/db/operation_cpu_timer.h b/src/mongo/db/operation_cpu_timer.h new file mode 100644 index 00000000000..0cd0b88acba --- /dev/null +++ b/src/mongo/db/operation_cpu_timer.h @@ -0,0 +1,71 @@ +/** + * Copyright (C) 2020-present MongoDB, Inc. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the Server Side Public License, version 1, + * as published by MongoDB, Inc. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * Server Side Public License for more details. + * + * You should have received a copy of the Server Side Public License + * along with this program. If not, see + * <http://www.mongodb.com/licensing/server-side-public-license>. + * + * As a special exception, the copyright holders give permission to link the + * code of portions of this program with the OpenSSL library under certain + * conditions as described in each individual source file and distribute + * linked combinations including the program with the OpenSSL library. You + * must comply with the Server Side Public License in all respects for + * all of the code used other than as permitted herein. If you modify file(s) + * with this exception, you may extend this exception to your version of the + * file(s), but you are not obligated to do so. If you do not wish to do so, + * delete this exception statement from your version. If you delete this + * exception statement from all source files in the program, then also delete + * it in the license file. + */ + +#pragma once + +#include "mongo/util/duration.h" + +namespace mongo { + +class OperationContext; + +/** + * Implements the CPU timer for platforms that support CPU consumption tracking. Consider the + * following when using the timer: + * + * All methods may only be invoked on the thread associated with the operation. + * + * To access the timer, the operation must be associated with a client, and the client must be + * attached to the current thread. + * + * The timer is initially stopped, measures elapsed time between the invocations of `start()` + * and `stop()`, and resets on consequent invocations of `start()`. + * + * To reset a timer, it should be stopped first and then started again. + * + * The timer is paused when the operation's client is detached from the current thread, and will + * not resume until the client is reattached to a thread. + */ +class OperationCPUTimer { +public: + /** + * Returns `nullptr` if the platform does not support tracking of CPU consumption. + */ + static OperationCPUTimer* get(OperationContext*); + + virtual Nanoseconds getElapsed() const = 0; + + virtual void start() = 0; + virtual void stop() = 0; + + virtual void onThreadAttach() = 0; + virtual void onThreadDetach() = 0; +}; + +} // namespace mongo diff --git a/src/mongo/db/operation_cpu_timer_test.cpp b/src/mongo/db/operation_cpu_timer_test.cpp new file mode 100644 index 00000000000..e498ce168b6 --- /dev/null +++ b/src/mongo/db/operation_cpu_timer_test.cpp @@ -0,0 +1,171 @@ +/** + * Copyright (C) 2020-present MongoDB, Inc. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the Server Side Public License, version 1, + * as published by MongoDB, Inc. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * Server Side Public License for more details. + * + * You should have received a copy of the Server Side Public License + * along with this program. If not, see + * <http://www.mongodb.com/licensing/server-side-public-license>. + * + * As a special exception, the copyright holders give permission to link the + * code of portions of this program with the OpenSSL library under certain + * conditions as described in each individual source file and distribute + * linked combinations including the program with the OpenSSL library. You + * must comply with the Server Side Public License in all respects for + * all of the code used other than as permitted herein. If you modify file(s) + * with this exception, you may extend this exception to your version of the + * file(s), but you are not obligated to do so. If you do not wish to do so, + * delete this exception statement from your version. If you delete this + * exception statement from all source files in the program, then also delete + * it in the license file. + */ + +#include "mongo/db/operation_cpu_timer.h" +#include "mongo/db/service_context_test_fixture.h" +#include "mongo/platform/atomic_word.h" +#include "mongo/stdx/thread.h" +#include "mongo/unittest/barrier.h" +#include "mongo/unittest/death_test.h" +#include "mongo/unittest/unittest.h" +#include "mongo/util/time_support.h" + +namespace mongo { + +class OperationCPUTimerTest : public ServiceContextTest { +public: + auto makeClient() const { + return getGlobalServiceContext()->makeClient("AlternativeClient"); + } + + auto getTimer() const { + return OperationCPUTimer::get(_opCtx.get()); + } + + void setUp() { + _opCtx = getGlobalServiceContext()->makeOperationContext(Client::getCurrent()); + } + + void busyWait(Nanoseconds delay) const { + AtomicWord<bool> mayJoin{false}; + stdx::thread blocker([&] { + sleepFor(delay); + mayJoin.store(true); + }); + while (!mayJoin.load()) { + // Busy wait for the blocker thread. + } + blocker.join(); + } + +private: + ServiceContext::UniqueOperationContext _opCtx; +}; + +#if defined(__linux__) + +TEST_F(OperationCPUTimerTest, TestTimer) { + auto timer = getTimer(); + + timer->start(); + busyWait(Nanoseconds(100)); // A small delay to make sure the timer advances. + ASSERT_GT(timer->getElapsed(), Nanoseconds(0)); + timer->stop(); + + const auto elapsedAfterStop = timer->getElapsed(); + busyWait(Microseconds(1)); // A relatively longer delay to ensure the timer doesn't proceed. + const auto elapsedAfterSleep = timer->getElapsed(); + ASSERT_EQ(elapsedAfterStop, elapsedAfterSleep); +} + +TEST_F(OperationCPUTimerTest, TestReset) { + auto timer = getTimer(); + + timer->start(); + busyWait(Microseconds(1)); // Introducing some delay for the timer to measure. + timer->stop(); + auto elapsedAfterStop = timer->getElapsed(); + ASSERT_GTE(elapsedAfterStop, Microseconds(1)); + + timer->start(); + auto elapsedAfterReset = timer->getElapsed(); + ASSERT_LT(elapsedAfterReset, elapsedAfterStop); +} + +TEST_F(OperationCPUTimerTest, TestTimerDetachAndAttachHandlers) { + unittest::Barrier failPointsReady{2}; + stdx::thread observer([&] { + FailPointEnableBlock fpAttach("hangCPUTimerAfterOnThreadAttach"); + { + FailPointEnableBlock fpDetach("hangCPUTimerAfterOnThreadDetach"); + failPointsReady.countDownAndWait(); + fpDetach->waitForTimesEntered(1); + } + fpAttach->waitForTimesEntered(1); + }); + + auto timer = getTimer(); + timer->start(); + + failPointsReady.countDownAndWait(); + { + auto client = makeClient(); + AlternativeClientRegion acr(client); + } + + timer->stop(); + observer.join(); +} + +DEATH_TEST_F(OperationCPUTimerTest, + AccessTimerForDetachedOperation, + "Operation not attached to the current thread") { + auto client = Client::releaseCurrent(); + getTimer(); +} + +DEATH_TEST_F(OperationCPUTimerTest, StopTimerBeforeStart, "Timer is not running") { + getTimer()->stop(); +} + +DEATH_TEST_F(OperationCPUTimerTest, StartTimerMultipleTimes, "Timer has already started") { + getTimer()->start(); + getTimer()->start(); +} + +DEATH_TEST_F(OperationCPUTimerTest, OnAttachForAttachedTimer, "Timer has already been attached") { + auto timer = getTimer(); + timer->start(); + timer->onThreadAttach(); +} + +DEATH_TEST_F(OperationCPUTimerTest, OnDetachForDetachedTimer, "Timer is not attached") { + auto timer = getTimer(); + timer->start(); + auto client = Client::releaseCurrent(); + timer->onThreadDetach(); +} + +DEATH_TEST_F(OperationCPUTimerTest, GetElapsedForPausedTimer, "Not attached to current thread") { + auto timer = getTimer(); + timer->start(); + auto client = Client::releaseCurrent(); + timer->getElapsed(); +} + +#else + +TEST_F(OperationCPUTimerTest, TimerNotSetIfNotSupported) { + auto timer = getTimer(); + ASSERT(timer == nullptr); +} + +#endif // defined(__linux__) + +} // namespace mongo |