You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@mesos.apache.org by al...@apache.org on 2018/10/16 12:17:41 UTC

[mesos] branch master updated (6f87faf -> 9203d09)

This is an automated email from the ASF dual-hosted git repository.

alexr pushed a change to branch master
in repository https://gitbox.apache.org/repos/asf/mesos.git.


    from 6f87faf  Moved import of '../lib' from new CLI bootstrap to pip-requirements.txt.
     new 6ab80da  Added 'received' timestamp into `process::Request`.
     new 7df7e4d  Introduced `logResponse` for http handlers.
     new 9203d09  Logged request processing time for some endpoints.

The 3 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails.  The revisions
listed as "add" were already present in the repository and have only
been added to this reference.


Summary of changes:
 3rdparty/libprocess/include/process/http.hpp |  5 ++++-
 src/common/http.cpp                          | 15 +++++++++++++++
 src/common/http.hpp                          | 11 +++++++++++
 src/master/master.cpp                        | 25 ++++++++++++++++++++-----
 src/slave/slave.cpp                          | 10 ++++++++--
 5 files changed, 58 insertions(+), 8 deletions(-)


[mesos] 02/03: Introduced `logResponse` for http handlers.

Posted by al...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

alexr pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/mesos.git

commit 7df7e4d35ec1c6cce87c629fac0b32149a4830d2
Author: Alexander Rukletsov <al...@apache.org>
AuthorDate: Thu Oct 11 15:40:37 2018 +0200

    Introduced `logResponse` for http handlers.
    
    Currently we use `logRequest` function to log requests to endpoints
    in Mesos `MasterProcess`, `SlaveProcess`, and `FilesProcess`. Each
    request is logged when it is first fetched from the actor mailbox.
    However this obviously does not allow for logging the request
    processing time.
    
    This patch introduces a `logResponse` function which logs the request
    together with the corresponding response status and the time spent
    generating the response.
    
    Review: https://reviews.apache.org/r/68993
---
 src/common/http.cpp | 15 +++++++++++++++
 src/common/http.hpp | 11 +++++++++++
 2 files changed, 26 insertions(+)

diff --git a/src/common/http.cpp b/src/common/http.cpp
index 9070071..80848aa 100644
--- a/src/common/http.cpp
+++ b/src/common/http.cpp
@@ -32,6 +32,7 @@
 #include <mesos/quota/quota.hpp>
 
 #include <process/authenticator.hpp>
+#include <process/clock.hpp>
 #include <process/collect.hpp>
 #include <process/dispatch.hpp>
 #include <process/future.hpp>
@@ -1186,4 +1187,18 @@ void logRequest(const process::http::Request& request)
                 : "");
 }
 
+
+void logResponse(
+    const process::http::Request& request,
+    const process::http::Response& response)
+{
+  LOG(INFO) << "HTTP " << request.method << " for " << request.url
+            << (request.client.isSome()
+                ? " from " + stringify(request.client.get())
+                : "")
+            << ": '" << response.status << "'"
+            << " after " << (process::Clock::now() - request.received).ms()
+            << Milliseconds::units();
+}
+
 }  // namespace mesos {
diff --git a/src/common/http.hpp b/src/common/http.hpp
index 4f994a0..6ca54a6 100644
--- a/src/common/http.hpp
+++ b/src/common/http.hpp
@@ -345,6 +345,17 @@ Try<Nothing> initializeHttpAuthenticators(
 // desired request handler to get consistent request logging.
 void logRequest(const process::http::Request& request);
 
+
+// Log the response for the corresponding request together with the request
+// processing time. Route handlers can compose this with the desired request
+// handler to get consistent request/response logging.
+//
+// TODO(alexr): Consider taking `response` as a future to allow logging for
+// cases when response has not been generated.
+void logResponse(
+    const process::http::Request& request,
+    const process::http::Response& response);
+
 } // namespace mesos {
 
 #endif // __COMMON_HTTP_HPP__


[mesos] 03/03: Logged request processing time for some endpoints.

Posted by al...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

alexr pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/mesos.git

commit 9203d099da60b3333fa2e2d2a7fcefe8065fa7e1
Author: Alexander Rukletsov <al...@apache.org>
AuthorDate: Thu Oct 11 15:58:41 2018 +0200

    Logged request processing time for some endpoints.
    
    This patch leverages `logResponse()` function to print response status
    code together with the request processing time for some endpoints on
    the master and agent. Not all endpoints are participating to avoid
    unnecessary log pollution; only these that are know to be "slow" in
    generating the response.
    
    Note that requests are still logged when they are fetched from the
    actor mailbox, i.e., affected endpoints now log twice per request:
    when the processing starts and when the response is ready to be sent.
    
    Review: https://reviews.apache.org/r/68994
---
 src/master/master.cpp | 25 ++++++++++++++++++++-----
 src/slave/slave.cpp   | 10 ++++++++--
 2 files changed, 28 insertions(+), 7 deletions(-)

diff --git a/src/master/master.cpp b/src/master/master.cpp
index 06d769a..868787b 100644
--- a/src/master/master.cpp
+++ b/src/master/master.cpp
@@ -909,7 +909,10 @@ void Master::initialize()
         [this](const process::http::Request& request,
                const Option<Principal>& principal) {
           logRequest(request);
-          return http.frameworks(request, principal);
+          return http.frameworks(request, principal)
+            .onReady([request](const process::http::Response& response) {
+              logResponse(request, response);
+            });
         });
   route("/flags",
         READONLY_HTTP_AUTHENTICATION_REALM,
@@ -959,7 +962,10 @@ void Master::initialize()
         [this](const process::http::Request& request,
                const Option<Principal>& principal) {
           logRequest(request);
-          return http.slaves(request, principal);
+          return http.slaves(request, principal)
+            .onReady([request](const process::http::Response& response) {
+              logResponse(request, response);
+            });
         });
   route("/state",
         READONLY_HTTP_AUTHENTICATION_REALM,
@@ -967,7 +973,10 @@ void Master::initialize()
         [this](const process::http::Request& request,
                const Option<Principal>& principal) {
           logRequest(request);
-          return http.state(request, principal);
+          return http.state(request, principal)
+            .onReady([request](const process::http::Response& response) {
+              logResponse(request, response);
+            });
         });
   route("/state-summary",
         READONLY_HTTP_AUTHENTICATION_REALM,
@@ -975,7 +984,10 @@ void Master::initialize()
         [this](const process::http::Request& request,
                const Option<Principal>& principal) {
           logRequest(request);
-          return http.stateSummary(request, principal);
+          return http.stateSummary(request, principal)
+            .onReady([request](const process::http::Response& response) {
+              logResponse(request, response);
+            });
         });
   route("/tasks",
         READONLY_HTTP_AUTHENTICATION_REALM,
@@ -983,7 +995,10 @@ void Master::initialize()
         [this](const process::http::Request& request,
                const Option<Principal>& principal) {
           logRequest(request);
-          return http.tasks(request, principal);
+          return http.tasks(request, principal)
+            .onReady([request](const process::http::Response& response) {
+              logResponse(request, response);
+            });
         });
   route("/maintenance/schedule",
         READWRITE_HTTP_AUTHENTICATION_REALM,
diff --git a/src/slave/slave.cpp b/src/slave/slave.cpp
index 9d84dcb..7bb2b29 100644
--- a/src/slave/slave.cpp
+++ b/src/slave/slave.cpp
@@ -798,7 +798,10 @@ void Slave::initialize()
         [this](const http::Request& request,
                const Option<Principal>& principal) {
           logRequest(request);
-          return http.state(request, principal);
+          return http.state(request, principal)
+            .onReady([request](const process::http::Response& response) {
+              logResponse(request, response);
+            });
         });
   route("/flags",
         READONLY_HTTP_AUTHENTICATION_REALM,
@@ -827,7 +830,10 @@ void Slave::initialize()
         [this](const http::Request& request,
                const Option<Principal>& principal) {
           logRequest(request);
-          return http.containers(request, principal);
+          return http.containers(request, principal)
+            .onReady([request](const process::http::Response& response) {
+              logResponse(request, response);
+            });
         });
 
   const PID<Slave> slavePid = self();


[mesos] 01/03: Added 'received' timestamp into `process::Request`.

Posted by al...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

alexr pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/mesos.git

commit 6ab80da5b2770a96802f7893ac092d6c8a92a824
Author: Alexander Rukletsov <al...@apache.org>
AuthorDate: Mon Aug 13 20:05:26 2018 +0200

    Added 'received' timestamp into `process::Request`.
    
    This allows us to note when a request comes in and
    hence calculate request processing time.
    
    Review: https://reviews.apache.org/r/68992
---
 3rdparty/libprocess/include/process/http.hpp | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/3rdparty/libprocess/include/process/http.hpp b/3rdparty/libprocess/include/process/http.hpp
index bbcd0ba..029605e 100644
--- a/3rdparty/libprocess/include/process/http.hpp
+++ b/3rdparty/libprocess/include/process/http.hpp
@@ -27,6 +27,7 @@
 #include <boost/functional/hash.hpp>
 
 #include <process/address.hpp>
+#include <process/clock.hpp>
 #include <process/future.hpp>
 #include <process/owned.hpp>
 #include <process/pid.hpp>
@@ -519,7 +520,7 @@ public:
 struct Request
 {
   Request()
-    : keepAlive(false), type(BODY) {}
+    : keepAlive(false), type(BODY), received(Clock::now()) {}
 
   std::string method;
 
@@ -564,6 +565,8 @@ struct Request
   std::string body;
   Option<Pipe::Reader> reader;
 
+  Time received;
+
   /**
    * Returns whether the encoding is considered acceptable in the
    * response. See RFC 2616 section 14.3 for details.