Merge pull request #2883 from yahoo/havardpe/set-appropriate-request-start-time

sample request start time when creating lazy request source

7 files changed, 57 insertions, 27 deletions

diff --git a/searchlib/src/tests/engine/transportserver/transportserver_test.cpp b/searchlib/src/tests/engine/transportserver/transportserver_test.cpp
index 228c30409c9..a15e80da0a4 100644
--- a/searchlib/src/tests/engine/transportserver/transportserver_test.cpp
+++ b/searchlib/src/tests/engine/transportserver/transportserver_test.cpp
@@ -7,6 +7,8 @@
 #include <vespa/vespalib/util/stringfmt.h>
 #include <vespa/fnet/fnet.h>
 #include <vespa/searchlib/engine/errorcodes.h>
+#include <thread>
+#include <chrono>
 #include <vespa/log/log.h>
 LOG_SETUP("transportserver_test");
 
@@ -34,6 +36,11 @@ public:
 SearchReply::UP
 SyncServer::search(SearchRequest::Source request, SearchClient &)
 {
+    // fastos should use steady clock (this may fail)
+    std::this_thread::sleep_for(std::chrono::milliseconds(20));
+    fastos::TimeStamp my_time = fastos::ClockSystem::now();
+    std::this_thread::sleep_for(std::chrono::milliseconds(20));
+    EXPECT_GREATER_EQUAL(my_time.val(), request->getStartTime());
     const SearchRequest &req = *request.get();
     SearchReply::UP reply(new SearchReply());
     SearchReply &ret = *reply;
@@ -46,6 +53,11 @@ SyncServer::search(SearchRequest::Source request, SearchClient &)
 DocsumReply::UP
 SyncServer::getDocsums(DocsumRequest::Source request, DocsumClient &)
 {
+    // fastos should use steady clock (this may fail)
+    std::this_thread::sleep_for(std::chrono::milliseconds(20));
+    fastos::TimeStamp my_time = fastos::ClockSystem::now();
+    std::this_thread::sleep_for(std::chrono::milliseconds(20));
+    EXPECT_GREATER_EQUAL(my_time.val(), request->getStartTime());
     DocsumReply::UP reply(new DocsumReply());
     DocsumReply &ret = *reply;
     ret.request = request.release();
diff --git a/searchlib/src/vespa/searchlib/engine/docsumrequest.cpp b/searchlib/src/vespa/searchlib/engine/docsumrequest.cpp
index 057709e2988..92eddb7f21f 100644
--- a/searchlib/src/vespa/searchlib/engine/docsumrequest.cpp
+++ b/searchlib/src/vespa/searchlib/engine/docsumrequest.cpp
@@ -7,24 +7,30 @@ namespace search {
 namespace engine {
 
 DocsumRequest::DocsumRequest()
-    : DocsumRequest(false)
-{ }
+    : DocsumRequest(false) {}
 
-DocsumRequest::~DocsumRequest() {}
+DocsumRequest::DocsumRequest(const fastos::TimeStamp &start_time)
+    : DocsumRequest(start_time, false) {}
 
 DocsumRequest::DocsumRequest(bool useRootSlime_)
-    : _flags(0u),
+    : DocsumRequest(fastos::ClockSystem::now(), useRootSlime_) {}
+
+DocsumRequest::DocsumRequest(const fastos::TimeStamp &start_time, bool useRootSlime_)
+    : Request(start_time),
+      _flags(0u),
       resultClassName(),
       useWideHits(false),
       _useRootSlime(useRootSlime_),
       hits()
-{ }
+{
+}
 
+DocsumRequest::~DocsumRequest() {}
 
 void DocsumRequest::Source::lazyDecode() const
 {
     if ((_request.get() == NULL) && (_fs4Packet != NULL)) {
-        _request.reset(new DocsumRequest());
+        _request.reset(new DocsumRequest(_start));
         PacketConverter::toDocsumRequest(*_fs4Packet, *_request);
         _fs4Packet->Free();
         _fs4Packet = NULL;
diff --git a/searchlib/src/vespa/searchlib/engine/docsumrequest.h b/searchlib/src/vespa/searchlib/engine/docsumrequest.h
index badba429bb4..1ac497961be 100644
--- a/searchlib/src/vespa/searchlib/engine/docsumrequest.h
+++ b/searchlib/src/vespa/searchlib/engine/docsumrequest.h
@@ -26,16 +26,18 @@ public:
         mutable FS4Packet_GETDOCSUMSX *_fs4Packet;
         void lazyDecode() const;
         const SourceDescription _desc;
+        const fastos::TimeStamp _start;
     public:
 
-        Source(DocsumRequest * request) : _request(request), _fs4Packet(NULL), _desc(0) {}
-        Source(DocsumRequest::UP request) : _request(std::move(request)), _fs4Packet(NULL), _desc(0) {}
-        Source(FS4Packet_GETDOCSUMSX *query, SourceDescription desc) : _request(), _fs4Packet(query), _desc(desc) { }
+        Source(DocsumRequest * request) : _request(request), _fs4Packet(NULL), _desc(0), _start(_request->getStartTime()) {}
+        Source(DocsumRequest::UP request) : _request(std::move(request)), _fs4Packet(NULL), _desc(0), _start(_request->getStartTime()) {}
+        Source(FS4Packet_GETDOCSUMSX *query, SourceDescription desc) : _request(), _fs4Packet(query), _desc(desc), _start(fastos::ClockSystem::now()) { }
 
         Source(Source && rhs)
           : _request(std::move(rhs._request)),
             _fs4Packet(rhs._fs4Packet),
-            _desc(std::move(rhs._desc))
+            _desc(std::move(rhs._desc)),
+            _start(rhs._start)
         {
             rhs._fs4Packet = NULL;
         }
@@ -81,8 +83,10 @@ public:
     std::vector<char> sessionId;
 
     DocsumRequest();
-    ~DocsumRequest();
+    explicit DocsumRequest(const fastos::TimeStamp &start_time);
     explicit DocsumRequest(bool useRootSlime_);
+    DocsumRequest(const fastos::TimeStamp &start_time, bool useRootSlime_);
+    ~DocsumRequest();
 
     bool useRootSlime() const { return _useRootSlime; }
 };
diff --git a/searchlib/src/vespa/searchlib/engine/request.cpp b/searchlib/src/vespa/searchlib/engine/request.cpp
index f502ed191b5..e74152872b5 100644
--- a/searchlib/src/vespa/searchlib/engine/request.cpp
+++ b/searchlib/src/vespa/searchlib/engine/request.cpp
@@ -5,15 +5,15 @@
 namespace search {
 namespace engine {
 
-Request::Request() :
-    _startTime(fastos::ClockSystem::now()),
-    _timeOfDoom(fastos::TimeStamp(fastos::TimeStamp::FUTURE)),
-    ranking(),
-    queryFlags(0),
-    location(),
-    propertiesMap(),
-    stackItems(0),
-    stackDump()
+Request::Request(const fastos::TimeStamp &start_time)
+    : _startTime(start_time),
+      _timeOfDoom(fastos::TimeStamp(fastos::TimeStamp::FUTURE)),
+      ranking(),
+      queryFlags(0),
+      location(),
+      propertiesMap(),
+      stackItems(0),
+      stackDump()
 {
 }
 
diff --git a/searchlib/src/vespa/searchlib/engine/request.h b/searchlib/src/vespa/searchlib/engine/request.h
index 364dd7cc2e2..f4eeea226a6 100644
--- a/searchlib/src/vespa/searchlib/engine/request.h
+++ b/searchlib/src/vespa/searchlib/engine/request.h
@@ -12,10 +12,10 @@ namespace engine {
 class Request
 {
 public:
-    Request();
+    Request(const fastos::TimeStamp &start_time);
     virtual ~Request();
     void setTimeout(const fastos::TimeStamp & timeout);
-    fastos::TimeStamp  getStartTime() const { return _startTime; }
+    fastos::TimeStamp getStartTime() const { return _startTime; }
     fastos::TimeStamp getTimeOfDoom() const { return _timeOfDoom; }
     fastos::TimeStamp getTimeout() const { return _timeOfDoom -_startTime; }
     fastos::TimeStamp getTimeUsed() const;
diff --git a/searchlib/src/vespa/searchlib/engine/searchrequest.cpp b/searchlib/src/vespa/searchlib/engine/searchrequest.cpp
index 31c74e92bcf..dd432e7b390 100644
--- a/searchlib/src/vespa/searchlib/engine/searchrequest.cpp
+++ b/searchlib/src/vespa/searchlib/engine/searchrequest.cpp
@@ -7,7 +7,10 @@ namespace search {
 namespace engine {
 
 SearchRequest::SearchRequest()
-    : Request(),
+    : SearchRequest(fastos::ClockSystem::now()) {}
+
+SearchRequest::SearchRequest(const fastos::TimeStamp &start_time)
+    : Request(start_time),
       offset(0),
       maxhits(10),
       sortSpec(),
@@ -20,7 +23,7 @@ SearchRequest::~SearchRequest() {}
 void SearchRequest::Source::lazyDecode() const
 {
     if ((_request.get() == NULL) && (_fs4Packet != NULL)) {
-        _request.reset(new SearchRequest());
+        _request.reset(new SearchRequest(_start));
         PacketConverter::toSearchRequest(*_fs4Packet, *_request);
         _fs4Packet->Free();
         _fs4Packet = NULL;
diff --git a/searchlib/src/vespa/searchlib/engine/searchrequest.h b/searchlib/src/vespa/searchlib/engine/searchrequest.h
index a3d4926b742..bb5cd376df5 100644
--- a/searchlib/src/vespa/searchlib/engine/searchrequest.h
+++ b/searchlib/src/vespa/searchlib/engine/searchrequest.h
@@ -23,24 +23,28 @@ public:
         mutable FS4Packet_QUERYX *_fs4Packet;
         void lazyDecode() const;
         const SourceDescription _desc;
+        const fastos::TimeStamp _start;
     public:
 
         Source(SearchRequest * request)
           : _request(request),
             _fs4Packet(NULL),
-            _desc(0)
+            _desc(0),
+            _start(_request->getStartTime())
         { }
 
         Source(FS4Packet_QUERYX *query, SourceDescription desc)
           : _request(),
             _fs4Packet(query),
-            _desc(desc)
+            _desc(desc),
+            _start(fastos::ClockSystem::now())
         { }
 
         Source(Source && rhs)
           : _request(std::move(rhs._request)),
             _fs4Packet(rhs._fs4Packet),
-            _desc(std::move(rhs._desc))
+            _desc(std::move(rhs._desc)),
+            _start(rhs._start)
         {
             rhs._fs4Packet = NULL;
         }
@@ -72,6 +76,7 @@ public:
     std::vector<char> sessionId;
 
     SearchRequest();
+    explicit SearchRequest(const fastos::TimeStamp &start_time);
     ~SearchRequest();
 };