diff options
25 files changed, 109 insertions, 141 deletions
diff --git a/config/src/tests/trace/trace.cpp b/config/src/tests/trace/trace.cpp index 33e25fa7ba2..fdb40d40893 100644 --- a/config/src/tests/trace/trace.cpp +++ b/config/src/tests/trace/trace.cpp @@ -2,7 +2,6 @@ #include <vespa/vespalib/testkit/test_kit.h> #include <vespa/config/common/trace.h> -#include <vespa/vespalib/trace/tracenode.h> using namespace config; @@ -11,9 +10,9 @@ using namespace vespalib::slime; struct FixedClock : public Clock { - FixedClock() : currentTime(0) { } - int64_t currentTime; - int64_t currentTimeMillis() const override { return currentTime; } + FixedClock() : _currentTime(duration::zero()) { } + vespalib::system_time _currentTime; + vespalib::system_time currentTime() const override { return _currentTime; } }; TEST("that trace can be serialized and deserialized") { @@ -38,7 +37,7 @@ TEST("that trace can be serialized and deserialized") { } TEST_F("that trace level is taken into account", FixedClock) { - f1.currentTime = 3; + f1._currentTime = vespalib::system_time(3ms); Trace trace(4, f1); trace.trace(4, "foo"); trace.trace(5, "bar"); @@ -58,11 +57,13 @@ TEST("that trace can be copied") { EXPECT_EQUAL(trace.toString(), trace2.toString()); } +constexpr vespalib::system_time epoch(duration::zero()); + TEST("ensure that system clock is used by default") { Trace trace(2); trace.trace(1, "foo"); TraceNode child(trace.getRoot().getChild(0)); - EXPECT_TRUE(child.getTimestamp() > 0); + EXPECT_TRUE(child.getTimestamp() > epoch); } TEST_MAIN() { TEST_RUN_ALL(); } diff --git a/config/src/vespa/config/common/trace.cpp b/config/src/vespa/config/common/trace.cpp index e6183a9fec1..d1bb154eda9 100644 --- a/config/src/vespa/config/common/trace.cpp +++ b/config/src/vespa/config/common/trace.cpp @@ -2,7 +2,6 @@ #include "trace.h" #include <vespa/vespalib/trace/slime_trace_serializer.h> #include <vespa/vespalib/trace/slime_trace_deserializer.h> -#include <vespa/fastos/timestamp.h> using namespace vespalib; using namespace vespalib::slime; @@ -11,8 +10,8 @@ namespace config { struct SystemClock : public Clock { - int64_t currentTimeMillis() const override { - return fastos::ClockSystem::now().timeSinceEpoch().ms(); + vespalib::system_time currentTime() const override { + return vespalib::system_clock::now(); } }; @@ -73,7 +72,7 @@ void Trace::trace(uint32_t level, const vespalib::string & message) { if (shouldTrace(level)) { - _root.addChild(message, _clock.currentTimeMillis()); + _root.addChild(message, _clock.currentTime()); } } diff --git a/config/src/vespa/config/common/trace.h b/config/src/vespa/config/common/trace.h index 9cfd2b1f88e..772cdb6f31e 100644 --- a/config/src/vespa/config/common/trace.h +++ b/config/src/vespa/config/common/trace.h @@ -12,7 +12,7 @@ namespace config { * Clock interface for acquiring time. */ struct Clock { - virtual int64_t currentTimeMillis() const = 0; + virtual vespalib::system_time currentTime() const = 0; virtual ~Clock() {} }; diff --git a/fastos/src/vespa/fastos/timestamp.cpp b/fastos/src/vespa/fastos/timestamp.cpp index deceaee4c65..977af69049c 100644 --- a/fastos/src/vespa/fastos/timestamp.cpp +++ b/fastos/src/vespa/fastos/timestamp.cpp @@ -76,7 +76,6 @@ ClockSteady::now() const SteadyTimeStamp SteadyTimeStamp::ZERO; const SteadyTimeStamp SteadyTimeStamp::FUTURE(TimeStamp::FUTURE); const UTCTimeStamp UTCTimeStamp::ZERO; -const UTCTimeStamp UTCTimeStamp::FUTURE(TimeStamp::FUTURE); UTCTimeStamp SteadyTimeStamp::toUTC() const { diff --git a/fastos/src/vespa/fastos/timestamp.h b/fastos/src/vespa/fastos/timestamp.h index 79d6ef5eed6..f1a40272938 100644 --- a/fastos/src/vespa/fastos/timestamp.h +++ b/fastos/src/vespa/fastos/timestamp.h @@ -61,7 +61,6 @@ inline TimeStamp operator *(double a, TimeStamp b) { return TimeStamp(static_cas class UTCTimeStamp { public: static const UTCTimeStamp ZERO; - static const UTCTimeStamp FUTURE; UTCTimeStamp() : _timeStamp() { } explicit UTCTimeStamp(TimeStamp timeStamp) : _timeStamp(timeStamp) { } @@ -92,7 +91,7 @@ public: friend bool operator >= (UTCTimeStamp a, UTCTimeStamp b) { return a._timeStamp >= b._timeStamp; } - TimeStamp timeSinceEpoch() const { return _timeStamp - ZERO._timeStamp; } + TimeStamp time_since_epoch() const { return _timeStamp - ZERO._timeStamp; } std::string toString() const { return _timeStamp.toString(); }; private: TimeStamp _timeStamp; diff --git a/searchcore/src/tests/proton/attribute/attributeflush_test.cpp b/searchcore/src/tests/proton/attribute/attributeflush_test.cpp index c41ac3a3a1c..ea3d2c335fb 100644 --- a/searchcore/src/tests/proton/attribute/attributeflush_test.cpp +++ b/searchcore/src/tests/proton/attribute/attributeflush_test.cpp @@ -516,21 +516,21 @@ Test::requireThatLastFlushTimeIsReported() EXPECT_EQUAL(fastos::UTCTimeStamp::ZERO, ft->getLastFlushTime()); ft->initFlush(200)->run(); EXPECT_TRUE(FastOS_File::Stat("flush/a9/snapshot-200", &stat)); - EXPECT_EQUAL(stat._modifiedTime, ft->getLastFlushTime().timeSinceEpoch().time()); + EXPECT_EQUAL(stat._modifiedTime, ft->getLastFlushTime().time_since_epoch().time()); } { // snapshot flushed AttributeManagerFixture amf(f); AttributeManager &am = amf._m; amf.addAttribute("a9"); IFlushTarget::SP ft = am.getFlushable("a9"); - EXPECT_EQUAL(stat._modifiedTime, ft->getLastFlushTime().timeSinceEpoch().time()); + EXPECT_EQUAL(stat._modifiedTime, ft->getLastFlushTime().time_since_epoch().time()); { // updated flush time after nothing to flush std::this_thread::sleep_for(8000ms); - fastos::TimeStamp now = fastos::ClockSystem::now().timeSinceEpoch(); + fastos::TimeStamp now = fastos::ClockSystem::now().time_since_epoch(); Executor::Task::UP task = ft->initFlush(200); EXPECT_TRUE(task.get() == NULL); - EXPECT_LESS(stat._modifiedTime, ft->getLastFlushTime().timeSinceEpoch().time()); - EXPECT_APPROX(now.time(), ft->getLastFlushTime().timeSinceEpoch().time(), 8); + EXPECT_LESS(stat._modifiedTime, ft->getLastFlushTime().time_since_epoch().time()); + EXPECT_APPROX(now.time(), ft->getLastFlushTime().time_since_epoch().time(), 8); } } } diff --git a/searchcore/src/tests/proton/index/indexmanager_test.cpp b/searchcore/src/tests/proton/index/indexmanager_test.cpp index 51e12e70dda..1941e82a2db 100644 --- a/searchcore/src/tests/proton/index/indexmanager_test.cpp +++ b/searchcore/src/tests/proton/index/indexmanager_test.cpp @@ -280,7 +280,7 @@ TEST_F(IndexManagerTest, require_that_memory_index_is_flushed) runAsMaster([&]() { flushTask = target.initFlush(1); }); flushTask->run(); EXPECT_TRUE(FastOS_File::Stat("test_data/index.flush.1", &stat)); - EXPECT_EQ(stat._modifiedTime, target.getLastFlushTime().timeSinceEpoch().time()); + EXPECT_EQ(stat._modifiedTime, target.getLastFlushTime().time_since_epoch().time()); sources = get_source_collection(); EXPECT_EQ(2u, sources->getSourceCount()); @@ -298,17 +298,17 @@ TEST_F(IndexManagerTest, require_that_memory_index_is_flushed) { // verify last flush time when loading disk index resetIndexManager(); IndexFlushTarget target(_index_manager->getMaintainer()); - EXPECT_EQ(stat._modifiedTime, target.getLastFlushTime().timeSinceEpoch().time()); + EXPECT_EQ(stat._modifiedTime, target.getLastFlushTime().time_since_epoch().time()); // updated serial number & flush time when nothing to flush std::this_thread::sleep_for(8s); - fastos::TimeStamp now = fastos::ClockSystem::now().timeSinceEpoch(); + fastos::TimeStamp now = fastos::ClockSystem::now().time_since_epoch(); vespalib::Executor::Task::UP task; runAsMaster([&]() { task = target.initFlush(2); }); EXPECT_TRUE(task.get() == nullptr); EXPECT_EQ(2u, target.getFlushedSerialNum()); - EXPECT_LT(stat._modifiedTime, target.getLastFlushTime().timeSinceEpoch().time()); - EXPECT_NEAR(now.time(), target.getLastFlushTime().timeSinceEpoch().time(), 8); + EXPECT_LT(stat._modifiedTime, target.getLastFlushTime().time_since_epoch().time()); + EXPECT_NEAR(now.time(), target.getLastFlushTime().time_since_epoch().time(), 8); } } diff --git a/searchcore/src/vespa/searchcore/proton/attribute/flushableattribute.cpp b/searchcore/src/vespa/searchcore/proton/attribute/flushableattribute.cpp index 66d1c27a5b5..0e0e96aa871 100644 --- a/searchcore/src/vespa/searchcore/proton/attribute/flushableattribute.cpp +++ b/searchcore/src/vespa/searchcore/proton/attribute/flushableattribute.cpp @@ -211,7 +211,7 @@ FlushableAttribute::internalInitFlush(SerialNum currentSerial) if (syncToken <= getFlushedSerialNum()) { writer->setLastFlushTime(fastos::ClockSystem::now()); LOG(debug,"No attribute vector to flush. Update flush time to current: lastFlushTime(%f)", - getLastFlushTime().timeSinceEpoch().sec()); + getLastFlushTime().time_since_epoch().sec()); return Task::UP(); } return std::make_unique<Flusher>(*this, syncToken, *writer); diff --git a/searchcore/src/vespa/searchcore/proton/common/attribute_updater.cpp b/searchcore/src/vespa/searchcore/proton/common/attribute_updater.cpp index fcca1c2a737..eaf76ebdc8f 100644 --- a/searchcore/src/vespa/searchcore/proton/common/attribute_updater.cpp +++ b/searchcore/src/vespa/searchcore/proton/common/attribute_updater.cpp @@ -22,7 +22,6 @@ #include <vespa/searchlib/attribute/changevector.hpp> #include <vespa/searchlib/attribute/predicate_attribute.h> #include <vespa/searchlib/attribute/reference_attribute.h> -#include <vespa/searchlib/common/base.h> #include <vespa/searchlib/tensor/tensor_attribute.h> #include <vespa/vespalib/util/stringfmt.h> #include <sstream> diff --git a/searchcore/src/vespa/searchcore/proton/documentmetastore/documentmetastoreflushtarget.cpp b/searchcore/src/vespa/searchcore/proton/documentmetastore/documentmetastoreflushtarget.cpp index 2cadedd0f59..71274bf444e 100644 --- a/searchcore/src/vespa/searchcore/proton/documentmetastore/documentmetastoreflushtarget.cpp +++ b/searchcore/src/vespa/searchcore/proton/documentmetastore/documentmetastoreflushtarget.cpp @@ -223,7 +223,7 @@ DocumentMetaStoreFlushTarget::initFlush(SerialNum currentSerial) if (syncToken <= getFlushedSerialNum()) { writer->setLastFlushTime(fastos::ClockSystem::now()); LOG(debug, "No document meta store to flush. Update flush time to current: lastFlushTime(%f)", - getLastFlushTime().timeSinceEpoch().sec()); + getLastFlushTime().time_since_epoch().sec()); return Task::UP(); } return std::make_unique<Flusher>(*this, syncToken, *writer); diff --git a/searchcore/src/vespa/searchcore/proton/server/memoryflush.cpp b/searchcore/src/vespa/searchcore/proton/server/memoryflush.cpp index 8ea9e095385..86e818e0fe3 100644 --- a/searchcore/src/vespa/searchcore/proton/server/memoryflush.cpp +++ b/searchcore/src/vespa/searchcore/proton/server/memoryflush.cpp @@ -140,7 +140,7 @@ MemoryFlush::getFlushTargets(const FlushContext::List &targetList, config.maxGlobalMemory, config.maxGlobalTlsSize, config.globalDiskBloatFactor, config.maxMemoryGain, config.diskBloatFactor, config.maxTimeGain.sec(), - _startTime.timeSinceEpoch().sec()); + _startTime.time_since_epoch().sec()); for (size_t i(0), m(targetList.size()); i < m; i++) { const IFlushTarget & target(*targetList[i]->getTarget()); const IFlushHandler & handler(*targetList[i]->getHandler()); @@ -183,8 +183,8 @@ MemoryFlush::getFlushTargets(const FlushContext::List &targetList, target.getFlushedSerialNum(), localLastSerial, serialDiff, - lastFlushTime.timeSinceEpoch().sec(), - now.timeSinceEpoch().sec(), + lastFlushTime.time_since_epoch().sec(), + now.time_since_epoch().sec(), timeDiff.sec(), getOrderName(order).c_str()); } diff --git a/searchcore/src/vespa/searchcore/proton/server/pruneremoveddocumentsjob.cpp b/searchcore/src/vespa/searchcore/proton/server/pruneremoveddocumentsjob.cpp index b5a430b3bcb..8bf96b4d370 100644 --- a/searchcore/src/vespa/searchcore/proton/server/pruneremoveddocumentsjob.cpp +++ b/searchcore/src/vespa/searchcore/proton/server/pruneremoveddocumentsjob.cpp @@ -67,7 +67,7 @@ PruneRemovedDocumentsJob::run() uint64_t tshz = 1000000; fastos::UTCTimeStamp now = fastos::ClockSystem::now(); const Timestamp ageLimit(static_cast<Timestamp::Type> - ((now.timeSinceEpoch().sec() - _cfgAgeLimit) * tshz)); + ((now.time_since_epoch().sec() - _cfgAgeLimit) * tshz)); DocId lid(_nextLid); const DocId olid(lid); const DocId docIdLimit(_metaStore.getCommittedDocIdLimit()); diff --git a/searchcorespi/src/vespa/searchcorespi/index/indexmaintainer.cpp b/searchcorespi/src/vespa/searchcorespi/index/indexmaintainer.cpp index da3058e9bbd..e2ab5f5ff1f 100644 --- a/searchcorespi/src/vespa/searchcorespi/index/indexmaintainer.cpp +++ b/searchcorespi/src/vespa/searchcorespi/index/indexmaintainer.cpp @@ -944,7 +944,7 @@ IndexMaintainer::initFlush(SerialNum serialNum, searchcorespi::FlushStats * stat _lastFlushTime = fastos::ClockSystem::now(); LOG(debug, "No memory index to flush. Update serial number and flush time to current: " "flushSerialNum(%" PRIu64 "), lastFlushTime(%f)", - _flush_serial_num, _lastFlushTime.timeSinceEpoch().sec()); + _flush_serial_num, _lastFlushTime.time_since_epoch().sec()); return FlushTask::UP(); } SerialNum realSerialNum = args.flush_serial_num; diff --git a/searchlib/src/tests/docstore/logdatastore/logdatastore_test.cpp b/searchlib/src/tests/docstore/logdatastore/logdatastore_test.cpp index 4e2450dccc9..9ec5cc8857b 100644 --- a/searchlib/src/tests/docstore/logdatastore/logdatastore_test.cpp +++ b/searchlib/src/tests/docstore/logdatastore/logdatastore_test.cpp @@ -764,7 +764,7 @@ TEST("requireThatFlushTimeIsAvailableAfterFlush") { MyTlSyncer tlSyncer; LogDataStore store(executor, testDir.getDir(), config, GrowStrategy(), TuneFileSummary(), fileHeaderContext, tlSyncer, nullptr); - EXPECT_EQUAL(0, store.getLastFlushTime().timeSinceEpoch().time()); + EXPECT_EQUAL(0, store.getLastFlushTime().time_since_epoch().time()); uint64_t flushToken = store.initFlush(5); EXPECT_EQUAL(5u, flushToken); store.flush(flushToken); diff --git a/searchlib/src/vespa/searchlib/docstore/logdatastore.cpp b/searchlib/src/vespa/searchlib/docstore/logdatastore.cpp index 19b945ddd9c..95c02e57dd1 100644 --- a/searchlib/src/vespa/searchlib/docstore/logdatastore.cpp +++ b/searchlib/src/vespa/searchlib/docstore/logdatastore.cpp @@ -656,7 +656,7 @@ LogDataStore::createWritableFile(FileId fileId, SerialNum serialNum, NameId name FileChunk::UP LogDataStore::createWritableFile(FileId fileId, SerialNum serialNum) { - return createWritableFile(fileId, serialNum, NameId(fastos::ClockSystem::now().timeSinceEpoch())); + return createWritableFile(fileId, serialNum, NameId(fastos::ClockSystem::now().time_since_epoch())); } namespace { diff --git a/storage/src/tests/visiting/memory_bounded_trace_test.cpp b/storage/src/tests/visiting/memory_bounded_trace_test.cpp index 0cfd3dad4c3..124730cf093 100644 --- a/storage/src/tests/visiting/memory_bounded_trace_test.cpp +++ b/storage/src/tests/visiting/memory_bounded_trace_test.cpp @@ -7,6 +7,8 @@ using namespace ::testing; namespace storage { +constexpr vespalib::system_time epoch(vespalib::duration::zero()); + TEST(MemoryBoundedTraceTest, no_memory_reported_used_when_empty) { MemoryBoundedTrace trace(100); EXPECT_EQ(0, trace.getApproxMemoryUsed()); @@ -14,7 +16,7 @@ TEST(MemoryBoundedTraceTest, no_memory_reported_used_when_empty) { TEST(MemoryBoundedTraceTest, memory_used_is_string_length_for_leaf_node) { MemoryBoundedTrace trace(100); - EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", 0))); + EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", epoch))); EXPECT_EQ(11, trace.getApproxMemoryUsed()); } @@ -29,7 +31,7 @@ TEST(MemoryBoundedTraceTest, memory_used_is_accumulated_recursively_for_non_leaf TEST(MemoryBoundedTraceTest, trace_nodes_can_be_moved_and_implicitly_cleared) { MemoryBoundedTrace trace(100); - EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", 0))); + EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", epoch))); mbus::TraceNode target; trace.moveTraceTo(target); EXPECT_EQ(1, target.getNumChildren()); @@ -49,7 +51,7 @@ TEST(MemoryBoundedTraceTest, trace_nodes_can_be_moved_and_implicitly_cleared) { */ TEST(MemoryBoundedTraceTest, moved_trace_tree_is_marked_as_strict) { MemoryBoundedTrace trace(100); - EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", 0))); + EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", epoch))); mbus::TraceNode target; trace.moveTraceTo(target); EXPECT_EQ(1, target.getNumChildren()); @@ -60,11 +62,11 @@ TEST(MemoryBoundedTraceTest, can_not_add_more_nodes_when_memory_used_exceeds_upp // Note: we allow one complete node tree to exceed the bounds, but as soon // as the bound is exceeded no further nodes can be added. MemoryBoundedTrace trace(10); - EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", 0))); + EXPECT_TRUE(trace.add(mbus::TraceNode("hello world", epoch))); EXPECT_EQ(11, trace.getApproxMemoryUsed()); EXPECT_FALSE(trace.add(mbus::TraceNode("the quick red fox runs across " - "the freeway", 0))); + "the freeway", epoch))); EXPECT_EQ(11, trace.getApproxMemoryUsed()); mbus::TraceNode target; @@ -77,8 +79,8 @@ TEST(MemoryBoundedTraceTest, can_not_add_more_nodes_when_memory_used_exceeds_upp TEST(MemoryBoundedTraceTest, moved_tree_includes_stats_node_when_nodes_omitted) { MemoryBoundedTrace trace(5); - EXPECT_TRUE(trace.add(mbus::TraceNode("abcdef", 0))); - EXPECT_FALSE(trace.add(mbus::TraceNode("ghijkjlmn", 0))); + EXPECT_TRUE(trace.add(mbus::TraceNode("abcdef", epoch))); + EXPECT_FALSE(trace.add(mbus::TraceNode("ghijkjlmn", epoch))); mbus::TraceNode target; trace.moveTraceTo(target); diff --git a/vespalib/src/tests/trace/trace.cpp b/vespalib/src/tests/trace/trace.cpp index f4ed0b15a27..f2141fbf995 100644 --- a/vespalib/src/tests/trace/trace.cpp +++ b/vespalib/src/tests/trace/trace.cpp @@ -1,54 +1,14 @@ // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. -#include <vespa/log/log.h> -LOG_SETUP("trace_test"); #include <vespa/vespalib/testkit/testapp.h> #include <vespa/vespalib/trace/trace.h> #include <vespa/vespalib/trace/tracevisitor.h> -using namespace vespalib; - -class Test : public vespalib::TestApp { -private: - void testEncodeDecode(); - void testReservedChars(); - void testConstruct(); - void testAdd(); - void testSort(); - void testStrict(); - void testTraceLevel(); - void testCompact(); - void testNormalize(); - void testTraceDump(); - void testVisiting(); - void testTimestamp(); - -public: - int Main() override; -}; - -TEST_APPHOOK(Test); +#include <vespa/log/log.h> +LOG_SETUP("trace_test"); -int -Test::Main() -{ - TEST_INIT("trace_test"); - testEncodeDecode(); - testReservedChars(); - testAdd(); - testConstruct(); - testSort(); - testStrict(); - testTraceLevel(); - testCompact(); - testNormalize(); - testTraceDump(); - testVisiting(); - testTimestamp(); - TEST_DONE(); -} +using namespace vespalib; -void -Test::testEncodeDecode() +TEST("testEncodeDecode") { EXPECT_EQUAL("()", TraceNode::decode("").encode()); EXPECT_EQUAL("()", TraceNode::decode("[xyz").encode()); @@ -134,8 +94,7 @@ Test::testEncodeDecode() } } -void -Test::testReservedChars() +TEST("testReservedChars") { TraceNode t; t.addChild("abc(){}[]\\xyz"); @@ -154,8 +113,7 @@ Test::testReservedChars() } } -void -Test::testAdd() +TEST("testAdd") { TraceNode t1 = TraceNode::decode("([x])"); TraceNode t2 = TraceNode::decode("([y])"); @@ -175,16 +133,14 @@ Test::testAdd() EXPECT_EQUAL("([y]([y])([y]([y])))", t2.encode()); } -void -Test::testStrict() +TEST("testStrict") { EXPECT_EQUAL("{}", TraceNode::decode("()").setStrict(false).encode()); EXPECT_EQUAL("{[x]}", TraceNode::decode("([x])").setStrict(false).encode()); EXPECT_EQUAL("{[x][y]}", TraceNode::decode("([x][y])").setStrict(false).encode()); } -void -Test::testTraceLevel() +TEST("testTraceLevel") { Trace t; t.setLevel(4); @@ -211,8 +167,7 @@ Test::testTraceLevel() EXPECT_EQUAL(5u, t.getRoot().getNumChildren()); } -void -Test::testCompact() +TEST("testCompact") { EXPECT_EQUAL("()", TraceNode::decode("()").compact().encode()); EXPECT_EQUAL("()", TraceNode::decode("(())").compact().encode()); @@ -242,8 +197,7 @@ Test::testCompact() EXPECT_EQUAL("({[a][b][c][d][e][f]})", TraceNode::decode("({({[a][b]})({[c][d]})({[e][f]})})").compact().encode()); } -void -Test::testSort() +TEST("testSort") { EXPECT_EQUAL("([b][a][c])", TraceNode::decode("([b][a][c])").sort().encode()); EXPECT_EQUAL("({[a][b][c]})", TraceNode::decode("({[b][a][c]})").sort().encode()); @@ -253,8 +207,7 @@ Test::testSort() EXPECT_EQUAL("({([b]){[a][c]}})", TraceNode::decode("({{[c][a]}([b])})").sort().encode()); } -void -Test::testNormalize() +TEST("testNormalize") { TraceNode t1 = TraceNode::decode("({([a][b]{[x][y]([p][q])})([c][d])([e][f])})"); TraceNode t2 = TraceNode::decode("({([a][b]{[y][x]([p][q])})([c][d])([e][f])})"); @@ -295,8 +248,7 @@ Test::testNormalize() EXPECT_EQUAL("({([c][d])([e][f])([a][b]{[x][y]([p][q])})})", t1.normalize().encode()); } -void -Test::testTraceDump() +TEST("testTraceDump") { { Trace big; @@ -363,8 +315,7 @@ struct EncoderVisitor : public TraceVisitor } }; -void -Test::testVisiting() +TEST("testVisiting") { TraceNode b1; TraceNode b2; @@ -383,27 +334,30 @@ Test::testVisiting() EXPECT_EQUAL(encoder.str, b1.encode()); } -void -Test::testTimestamp() +constexpr system_time zero(duration::zero()); +constexpr system_time as_ms(long ms) { return system_time(std::chrono::milliseconds(ms)); } + +TEST("testTimestamp") { TraceNode root; - root.addChild("foo", 1234); + root.addChild("foo", as_ms(1234)); root.addChild("bar"); - EXPECT_EQUAL(root.getTimestamp(), 0); - EXPECT_EQUAL(root.getChild(0).getTimestamp(), 1234); - EXPECT_EQUAL(root.getChild(1).getTimestamp(), 0); + EXPECT_EQUAL(root.getTimestamp(), zero); + EXPECT_EQUAL(root.getChild(0).getTimestamp(), as_ms(1234)); + EXPECT_EQUAL(root.getChild(1).getTimestamp(), zero); } -void -Test::testConstruct() +TEST("testConstruct") { - TraceNode leaf1("foo", 123); + TraceNode leaf1("foo", as_ms(123)); EXPECT_TRUE(leaf1.hasNote()); EXPECT_EQUAL("foo", leaf1.getNote()); - EXPECT_EQUAL(123, leaf1.getTimestamp()); + EXPECT_EQUAL(as_ms(123), leaf1.getTimestamp()); - TraceNode leaf2(124); + TraceNode leaf2(as_ms(124)); EXPECT_FALSE(leaf2.hasNote()); EXPECT_EQUAL("", leaf2.getNote()); - EXPECT_EQUAL(124, leaf2.getTimestamp()); + EXPECT_EQUAL(as_ms(124), leaf2.getTimestamp()); } + +TEST_MAIN() { TEST_RUN_ALL(); } diff --git a/vespalib/src/tests/trace/trace_serialization.cpp b/vespalib/src/tests/trace/trace_serialization.cpp index c176ca9fcf9..9ba6cdb512b 100644 --- a/vespalib/src/tests/trace/trace_serialization.cpp +++ b/vespalib/src/tests/trace/trace_serialization.cpp @@ -1,11 +1,12 @@ // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. -#include <vespa/log/log.h> -LOG_SETUP("trace_test"); #include <vespa/vespalib/testkit/test_kit.h> #include <vespa/vespalib/trace/tracenode.h> #include <vespa/vespalib/trace/slime_trace_serializer.h> #include <vespa/vespalib/trace/slime_trace_deserializer.h> +#include <vespa/log/log.h> +LOG_SETUP("trace_test"); + using namespace vespalib; using namespace vespalib::slime; @@ -20,10 +21,14 @@ TEST("that a single trace node is serialized") { EXPECT_FALSE(i["payload"].valid()); } +constexpr system_time zero_system_time(duration::zero()); +constexpr system_time as_ms(long ms) { return system_time(std::chrono::milliseconds(ms)); } + + TEST("that a trace node with children is serialized") { TraceNode node; - node.addChild("foo", 1234); - node.addChild("bar", 1235); + node.addChild("foo", as_ms(1234)); + node.addChild("bar", as_ms(1235)); Slime slime; SlimeTraceSerializer serializer(slime.setObject()); node.accept(serializer); @@ -47,7 +52,7 @@ TEST("that an empty root trace node can be deserialized") { SlimeTraceDeserializer deserializer(root); TraceNode node(deserializer.deserialize()); EXPECT_FALSE(node.hasNote()); - EXPECT_EQUAL(0, node.getTimestamp()); + EXPECT_EQUAL(zero_system_time, node.getTimestamp()); } @@ -58,7 +63,7 @@ TEST("that a single trace node can be deserialized") { root.setString("payload", "hello"); SlimeTraceDeserializer deserializer(root); TraceNode node(deserializer.deserialize()); - EXPECT_EQUAL(1234, node.getTimestamp()); + EXPECT_EQUAL(as_ms(1234), node.getTimestamp()); EXPECT_TRUE(node.hasNote()); EXPECT_EQUAL("hello", node.getNote()); } @@ -95,7 +100,7 @@ TEST("that a trace node with children can be deserialized") { TEST("test serialization and deserialization") { TraceNode root; - root.addChild("foo", 45); + root.addChild("foo", as_ms(45)); root.addChild("bar"); root.addChild(TraceNode()); Slime slime; diff --git a/vespalib/src/vespa/vespalib/testkit/test_comparators.cpp b/vespalib/src/vespa/vespalib/testkit/test_comparators.cpp index 92ec51268d2..d00ad8d954c 100644 --- a/vespalib/src/vespa/vespalib/testkit/test_comparators.cpp +++ b/vespalib/src/vespa/vespalib/testkit/test_comparators.cpp @@ -2,6 +2,13 @@ #include "test_comparators.h" +namespace std::chrono { + +ostream & operator << (ostream & os, system_clock::time_point ts) { + return os << ts.time_since_epoch() << "ns"; +} + +} namespace vespalib { } // namespace vespalib diff --git a/vespalib/src/vespa/vespalib/testkit/test_comparators.h b/vespalib/src/vespa/vespalib/testkit/test_comparators.h index 5119aaebea6..161c125757b 100644 --- a/vespalib/src/vespa/vespalib/testkit/test_comparators.h +++ b/vespalib/src/vespa/vespalib/testkit/test_comparators.h @@ -13,6 +13,9 @@ ostream & operator << (ostream & os, duration<rep, period> ts) { return os << ts.count(); } +ostream & operator << (ostream & os, system_clock::time_point ts); + + } namespace vespalib { diff --git a/vespalib/src/vespa/vespalib/trace/slime_trace_deserializer.cpp b/vespalib/src/vespa/vespalib/trace/slime_trace_deserializer.cpp index 44e79de5248..eea59f2164f 100644 --- a/vespalib/src/vespa/vespalib/trace/slime_trace_deserializer.cpp +++ b/vespalib/src/vespa/vespalib/trace/slime_trace_deserializer.cpp @@ -29,7 +29,7 @@ SlimeTraceDeserializer::deserialize(const Inspector & inspector) TraceNode SlimeTraceDeserializer::deserializeTraceNode(const Inspector & inspector) { - int64_t timestamp(decodeTimestamp(inspector)); + system_time timestamp(std::chrono::milliseconds(decodeTimestamp(inspector))); if (hasPayload(inspector)) { std::string note(decodePayload(inspector)); return TraceNode(note, timestamp); diff --git a/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.cpp b/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.cpp index cdc952464dd..ccf5d50517a 100644 --- a/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.cpp +++ b/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.cpp @@ -32,7 +32,7 @@ SlimeTraceSerializer::visit(const TraceNode & node) void SlimeTraceSerializer::addTimestamp(Cursor & current, const TraceNode & node) { - current.setLong(TIMESTAMP, node.getTimestamp()); + current.setLong(TIMESTAMP, count_ms(node.getTimestamp().time_since_epoch())); } void diff --git a/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.h b/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.h index d2ca00ba81a..1d5b5638f48 100644 --- a/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.h +++ b/vespalib/src/vespa/vespalib/trace/slime_trace_serializer.h @@ -22,8 +22,8 @@ public: static const Memory PAYLOAD; static const Memory CHILDREN; private: - void addTimestamp(slime::Cursor & current, const TraceNode & node); - void addPayload(slime::Cursor & current, const TraceNode & node); + static void addTimestamp(slime::Cursor & current, const TraceNode & node); + static void addPayload(slime::Cursor & current, const TraceNode & node); void addChildrenCursors(slime::Cursor & current, const TraceNode & node); void addChildrenCursorsToStack(slime::Cursor & childrenArray, const TraceNode & node); std::stack<slime::Cursor *> _cursors; diff --git a/vespalib/src/vespa/vespalib/trace/tracenode.cpp b/vespalib/src/vespa/vespalib/trace/tracenode.cpp index bce184312f4..d34b45025d3 100644 --- a/vespalib/src/vespa/vespalib/trace/tracenode.cpp +++ b/vespalib/src/vespa/vespalib/trace/tracenode.cpp @@ -46,7 +46,7 @@ TraceNode::TraceNode() : _hasNote(false), _note(""), _children(), - _timestamp(0) + _timestamp() { } TraceNode::TraceNode(const TraceNode &rhs) : @@ -65,7 +65,7 @@ TraceNode & TraceNode::operator =(const TraceNode &) = default; TraceNode::~TraceNode() = default; -TraceNode::TraceNode(const string ¬e, int64_t timestamp) : +TraceNode::TraceNode(const string ¬e, system_time timestamp) : _parent(nullptr), _strict(true), _hasNote(true), @@ -74,7 +74,7 @@ TraceNode::TraceNode(const string ¬e, int64_t timestamp) : _timestamp(timestamp) { } -TraceNode::TraceNode(int64_t timestamp) : +TraceNode::TraceNode(system_time timestamp) : _parent(nullptr), _strict(true), _hasNote(false), @@ -109,7 +109,7 @@ TraceNode::clear() _hasNote = false; _note.clear(); _children.clear(); - _timestamp = 0; + _timestamp = system_time(); return *this; } @@ -177,11 +177,11 @@ TraceNode::normalize() TraceNode & TraceNode::addChild(const string ¬e) { - return addChild(TraceNode(note, 0)); + return addChild(TraceNode(note, system_time())); } TraceNode & -TraceNode::addChild(const string ¬e, int64_t timestamp) +TraceNode::addChild(const string ¬e, system_time timestamp) { return addChild(TraceNode(note, timestamp)); } @@ -245,8 +245,7 @@ TraceNode::encode() const string ret = ""; if (_hasNote) { ret.append("["); - for (uint32_t i = 0, len = _note.size(); i < len; ++i) { - char c = _note[i]; + for (char c : _note) { if (c == '\\' || c == ']') { ret.append("\\"); } @@ -296,7 +295,7 @@ TraceNode::decode(const string &str) node = &node->_children.back(); node->setStrict(c == '('); } else if (c == ')' || c == '}') { - if (node == NULL) { + if (node == nullptr) { LOG(warning, "Unexpected closing brace in trace '%s' at " "position %d.", str.c_str(), i); return TraceNode(); diff --git a/vespalib/src/vespa/vespalib/trace/tracenode.h b/vespalib/src/vespa/vespalib/trace/tracenode.h index b44881b99b4..63e7bcd6dc0 100644 --- a/vespalib/src/vespa/vespalib/trace/tracenode.h +++ b/vespalib/src/vespa/vespalib/trace/tracenode.h @@ -2,6 +2,7 @@ #pragma once #include <vespa/vespalib/stllike/string.h> +#include <vespa/vespalib/util/time.h> #include <vector> namespace vespalib { @@ -27,7 +28,7 @@ private: bool _hasNote; string _note; std::vector<TraceNode> _children; - int64_t _timestamp; + system_time _timestamp; public: /** @@ -40,13 +41,13 @@ public: * @param note The note for this node. * @param timestamp The timestamp to give to node. */ - explicit TraceNode(const string ¬e, int64_t timestamp); + explicit TraceNode(const string ¬e, system_time timestamp); /** * Create a leaf node with no note and a time stamp. * @param timestamp The timestamp to give to node. */ - explicit TraceNode(int64_t timestamp); + explicit TraceNode(system_time timestamp); TraceNode & operator =(const TraceNode &); TraceNode(TraceNode &&) noexcept; @@ -104,7 +105,7 @@ public: * * @return True if this has no parent. */ - bool isRoot() const { return _parent == NULL; } + bool isRoot() const { return _parent == nullptr; } /** * Check whether or not this is a leaf node. @@ -155,7 +156,7 @@ public: * * @return The timestamp. */ - int64_t getTimestamp() const { return _timestamp; } + system_time getTimestamp() const { return _timestamp; } /** @@ -189,7 +190,7 @@ public: * @param timestamp The timestamp to give this child. * @return This, to allow chaining. */ - TraceNode &addChild(const string ¬e, int64_t timestamp); + TraceNode &addChild(const string ¬e, system_time timestamp); /** * Adds a child node to this. |