diff options
Diffstat (limited to 'vespalib')
9 files changed, 74 insertions, 32 deletions
diff --git a/vespalib/src/tests/btree/iteratespeed.cpp b/vespalib/src/tests/btree/iteratespeed.cpp index 82aa9bb5f54..e20e9537f7f 100644 --- a/vespalib/src/tests/btree/iteratespeed.cpp +++ b/vespalib/src/tests/btree/iteratespeed.cpp @@ -14,9 +14,9 @@ #include <vespa/vespalib/btree/btree.hpp> #include <vespa/vespalib/btree/btreestore.hpp> #include <vespa/vespalib/util/rand48.h> +#include <vespa/vespalib/util/time.h> #include <vespa/fastos/app.h> -#include <vespa/fastos/timestamp.h> #include <vespa/log/log.h> LOG_SETUP("iteratespeed"); @@ -83,7 +83,7 @@ IterateSpeed::workLoop(int loops, bool enableForward, bool enableBackwards, assert(numEntries == tree.size()); assert(tree.isValid()); for (int l = 0; l < loops; ++l) { - fastos::StopWatch stopWatch; + vespalib::Timer timer; uint64_t sum = 0; for (size_t innerl = 0; innerl < numInnerLoops; ++innerl) { if (iterateMethod == IterateMethod::FORWARD) { @@ -106,7 +106,7 @@ IterateSpeed::workLoop(int loops, bool enableForward, bool enableBackwards, [&](int key) { sum += key; } ); } } - double used = stopWatch.elapsed().sec(); + double used = vespalib::to_s(timer.elapsed()); printf("Elapsed time for iterating %ld steps is %8.5f, " "direction=%s, fanout=%u,%u, sum=%" PRIu64 "\n", numEntries * numInnerLoops, diff --git a/vespalib/src/tests/closure/closure_test.cpp b/vespalib/src/tests/closure/closure_test.cpp index 5ba6ecf2a56..9faabb56fc5 100644 --- a/vespalib/src/tests/closure/closure_test.cpp +++ b/vespalib/src/tests/closure/closure_test.cpp @@ -6,7 +6,6 @@ using std::shared_ptr; using std::unique_ptr; -using std::string; using namespace vespalib; namespace { diff --git a/vespalib/src/tests/executor/stress_test.cpp b/vespalib/src/tests/executor/stress_test.cpp index bbe754be2bd..615e7addfd5 100644 --- a/vespalib/src/tests/executor/stress_test.cpp +++ b/vespalib/src/tests/executor/stress_test.cpp @@ -4,7 +4,6 @@ #include <vespa/vespalib/util/executor.h> #include <vespa/vespalib/util/threadstackexecutor.h> #include <vespa/vespalib/locale/c.h> -#include <vespa/fastos/timestamp.h> using namespace vespalib; using namespace std::literals; @@ -60,28 +59,28 @@ uint32_t Test::calibrate(double wanted_ms) { uint32_t n = 0; - fastos::StopWatch t0; - fastos::StopWatch t1; + vespalib::Timer t0; + vespalib::Timer t1; { // calibration of calibration loop uint32_t result = 0; - double ms; + vespalib::duration dur; do { result += doStuff(++n); - t1.restart(); - ms = (t1.elapsed().ms() - t0.elapsed().ms()); - } while (ms < 1000.0); + t1 = vespalib::Timer(); + dur = (t1.elapsed() - t0.elapsed()); + } while (dur < 1s); _result += result; } { // calibrate loop - t0.restart(); + t0 = vespalib::Timer(); uint32_t result = 0; for (uint32_t i = 0; i < n; ++i) { result += doStuff(i); } _result += result; - t1.restart(); + t1 = vespalib::Timer(); } - double ms = (t1.elapsed().ms() - t0.elapsed().ms()); + double ms = vespalib::count_ms(t1.elapsed() - t0.elapsed()); double size = (((double)n) / ms) * wanted_ms; return (uint32_t) std::round(size); } @@ -121,7 +120,7 @@ Test::Main() fprintf(stderr, "all threads have been accounted for...\n"); } { - fastos::StopWatch t0; + vespalib::Timer t0; fprintf(stderr, "starting task submission...\n"); uint32_t result = 0; for (uint32_t i = 0; i < tasks; ++i) { @@ -133,7 +132,7 @@ Test::Main() } } executor.sync(); - double ms = t0.elapsed().ms(); + double ms = vespalib::count_ms(t0.elapsed()); fprintf(stderr, "total execution wall time: %g ms\n", ms); _result += result; } diff --git a/vespalib/src/tests/left_right_heap/left_right_heap_bench.cpp b/vespalib/src/tests/left_right_heap/left_right_heap_bench.cpp index 7567e8426ae..6c643696615 100644 --- a/vespalib/src/tests/left_right_heap/left_right_heap_bench.cpp +++ b/vespalib/src/tests/left_right_heap/left_right_heap_bench.cpp @@ -3,7 +3,6 @@ #include <vespa/vespalib/util/left_right_heap.h> #include <vespa/vespalib/util/stringfmt.h> #include <vespa/vespalib/util/inline.h> -#include <vespa/fastos/timestamp.h> using vespalib::RightArrayHeap; using vespalib::RightHeap; @@ -41,11 +40,11 @@ struct MyInvCmp { struct Timer { double minTime; - fastos::StopWatch timer; + vespalib::Timer timer; Timer() : minTime(1.0e10), timer() {} - void start() { timer.restart(); } + void start() { timer = vespalib::Timer(); } void stop() { - double ms = timer.elapsed().ms(); + double ms = vespalib::count_ms(timer.elapsed()); minTime = std::min(minTime, ms); } }; diff --git a/vespalib/src/tests/simple_thread_bundle/threading_speed_test.cpp b/vespalib/src/tests/simple_thread_bundle/threading_speed_test.cpp index d67c417b71a..71bae66ed2f 100644 --- a/vespalib/src/tests/simple_thread_bundle/threading_speed_test.cpp +++ b/vespalib/src/tests/simple_thread_bundle/threading_speed_test.cpp @@ -2,7 +2,6 @@ #include <vespa/vespalib/testkit/test_kit.h> #include <vespa/vespalib/util/simple_thread_bundle.h> #include <vespa/vespalib/util/box.h> -#include <vespa/fastos/timestamp.h> using namespace vespalib; @@ -57,11 +56,11 @@ TEST("estimate cost of thread bundle fork/join") { } double minTime = 1000000.0; for (size_t samples = 0; samples < 32; ++samples) { - fastos::StopWatch timer; + vespalib::Timer timer; for (size_t n = 0; n < fork; ++n) { threadBundle.run(targets); } - double time = timer.elapsed().ms(); + double time = vespalib::count_ms(timer.elapsed()); if (time < minTime) { minTime = time; } diff --git a/vespalib/src/tests/slime/summary-feature-benchmark/summary-feature-benchmark.cpp b/vespalib/src/tests/slime/summary-feature-benchmark/summary-feature-benchmark.cpp index 61ba2593eb3..dc31f4b8b42 100644 --- a/vespalib/src/tests/slime/summary-feature-benchmark/summary-feature-benchmark.cpp +++ b/vespalib/src/tests/slime/summary-feature-benchmark/summary-feature-benchmark.cpp @@ -2,7 +2,6 @@ #include <vespa/vespalib/testkit/test_kit.h> #include <vespa/vespalib/util/stringfmt.h> #include <vespa/vespalib/data/slime/slime.h> -#include <vespa/fastos/timestamp.h> using namespace vespalib; using namespace vespalib::slime::convenience; @@ -47,12 +46,12 @@ TEST_F("slime -> json speed", FeatureFixture()) { double minTime = 1000000.0; MyBuffer buffer; for (size_t i = 0; i < 16; ++i) { - fastos::StopWatch timer; + vespalib::Timer timer; for (size_t j = 0; j < 256; ++j) { buffer.used = 0; slime::JsonFormat::encode(f1.slime, buffer, true); } - minTime = std::min(minTime, timer.elapsed().ms() / 256.0); + minTime = std::min(minTime, vespalib::count_ms(timer.elapsed()) / 256.0); size = buffer.used; } fprintf(stderr, "time: %g ms (size: %zu bytes)\n", minTime, size); @@ -63,12 +62,12 @@ TEST_F("slime -> binary speed", FeatureFixture()) { double minTime = 1000000.0; MyBuffer buffer; for (size_t i = 0; i < 16; ++i) { - fastos::StopWatch timer; + vespalib::Timer timer; for (size_t j = 0; j < 256; ++j) { buffer.used = 0; slime::BinaryFormat::encode(f1.slime, buffer); } - minTime = std::min(minTime, timer.elapsed().ms() / 256.0); + minTime = std::min(minTime, vespalib::count_ms(timer.elapsed()) / 256.0); size = buffer.used; } fprintf(stderr, "time: %g ms (size: %zu bytes)\n", minTime, size); diff --git a/vespalib/src/tests/time/time_test.cpp b/vespalib/src/tests/time/time_test.cpp index 40542b6ca62..352835ea101 100644 --- a/vespalib/src/tests/time/time_test.cpp +++ b/vespalib/src/tests/time/time_test.cpp @@ -40,10 +40,11 @@ TEST(TimeTest, timeval_conversion_works_as_expected) { } TEST(TimeTest, unit_counting_works_as_expected) { - auto d = 3ms + 5us + 7ns; - EXPECT_EQ(count_ns(d), 3005007); - EXPECT_EQ(count_us(d), 3005); - EXPECT_EQ(count_ms(d), 3); + auto d = 7s + 3ms + 5us + 7ns; + EXPECT_EQ(count_ns(d), 7003005007); + EXPECT_EQ(count_us(d), 7003005); + EXPECT_EQ(count_ms(d), 7003); + EXPECT_EQ(count_s(d), 7); } GTEST_MAIN_RUN_ALL_TESTS() diff --git a/vespalib/src/vespa/vespalib/util/time.cpp b/vespalib/src/vespa/vespalib/util/time.cpp index fdd13849287..15dc8b4c781 100644 --- a/vespalib/src/vespa/vespalib/util/time.cpp +++ b/vespalib/src/vespa/vespalib/util/time.cpp @@ -1,6 +1,8 @@ // Copyright 2019 Oath Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. #include "time.h" +#include <thread> +#include <immintrin.h> namespace vespalib { @@ -11,6 +13,42 @@ to_utc(steady_time ts) { return system_time(nowUtc.time_since_epoch() - nowSteady.time_since_epoch() + ts.time_since_epoch()); } +namespace { + +string +to_string(duration dur) { + time_t timeStamp = std::chrono::duration_cast<std::chrono::seconds>(dur).count(); + struct tm timeStruct; + gmtime_r(&timeStamp, &timeStruct); + char timeString[128]; + strftime(timeString, sizeof(timeString), "%F %T", &timeStruct); + char retval[160]; + uint32_t milliSeconds = count_ms(dur) % 1000; + snprintf(retval, sizeof(retval), "%s.%03u UTC", timeString, milliSeconds); + return std::string(retval); +} + +} + +string +to_string(system_time time) { + return to_string(time.time_since_epoch()); +} + Timer::~Timer() = default; +void +Timer::waitAtLeast(duration dur, bool busyWait) { + if (busyWait) { + steady_clock::time_point deadline = steady_clock::now() + dur; + while (steady_clock::now() < deadline) { + for (int i = 0; i < 1000; i++) { + _mm_pause(); + } + } + } else { + std::this_thread::sleep_for(dur); + } +} + } diff --git a/vespalib/src/vespa/vespalib/util/time.h b/vespalib/src/vespa/vespalib/util/time.h index f3348d643e1..719bb112c15 100644 --- a/vespalib/src/vespa/vespalib/util/time.h +++ b/vespalib/src/vespa/vespalib/util/time.h @@ -3,6 +3,7 @@ #pragma once #include <chrono> +#include <vespa/vespalib/stllike/string.h> #include <sys/time.h> // Guidelines: @@ -46,6 +47,10 @@ constexpr duration from_s(double seconds) { return std::chrono::duration_cast<duration>(std::chrono::duration<double>(seconds)); } +constexpr int64_t count_s(duration d) { + return std::chrono::duration_cast<std::chrono::seconds>(d).count(); +} + constexpr int64_t count_ms(duration d) { return std::chrono::duration_cast<std::chrono::milliseconds>(d).count(); } @@ -62,6 +67,8 @@ constexpr duration from_timeval(const timeval & tv) { return duration(tv.tv_sec*1000000000L + tv.tv_usec*1000L); } +vespalib::string to_string(system_time time); + /** * Simple utility class used to measure how much time has elapsed * since it was constructed. @@ -74,6 +81,7 @@ public: Timer() : _start(steady_clock::now()) {} ~Timer(); duration elapsed() const { return (steady_clock::now() - _start); } + static void waitAtLeast(duration dur, bool busyWait); }; } |