Log thread and process CPU time

youtube · Aug 16, 2024 · 04e407c · 04e407c
1 parent fe733e9
commit 04e407c
Show file tree

Hide file tree

Showing 3 changed files with 55 additions and 8 deletions.
diff --git a/cobalt/script/v8c/v8c_script_debugger.cc b/cobalt/script/v8c/v8c_script_debugger.cc
@@ -14,6 +14,8 @@
 
 #include "cobalt/script/v8c/v8c_script_debugger.h"
 
+#include <pthread.h>
+
 #include <memory>
 #include <sstream>
 #include <string>
@@ -27,11 +29,31 @@
 #include "cobalt/script/v8c/conversion_helpers.h"
 #include "cobalt/script/v8c/v8c_tracing_controller.h"
 #include "include/inspector/Runtime.h"  // generated
+#include "starboard/common/string.h"
 #include "v8/include/libplatform/v8-tracing.h"
 #include "v8/include/v8-inspector.h"
 #include "v8/third_party/inspector_protocol/crdtp/json.h"
 #include "v8/third_party/inspector_protocol/crdtp/protocol_core.h"
 
+namespace {
+static clockid_t clockid = 0;
+std::string print_clock(const char* msg, clockid_t cid) {
+  struct timespec ts;
+  if (clock_gettime(cid, &ts) != -1)
+    return starboard::FormatString(" %s %ld.%06ld", msg, ts.tv_sec,
+                                   ts.tv_nsec / 1000);
+  return std::string();
+}
+
+std::string print_clocks() {
+  if (clockid == 0) {
+    pthread_getcpuclockid(pthread_self(), &clockid);
+  }
+  return print_clock("thread", clockid) +
+         print_clock("process", CLOCK_PROCESS_CPUTIME_ID);
+}
+}  // namespace
+
 namespace v8_crdtp {
 template <typename T>
 struct ProtocolTypeTraits<
@@ -381,22 +403,25 @@ void V8cScriptDebugger::consoleAPIMessage(
   std::string msg(FromStringView(message));
   switch (level) {
     case v8::Isolate::kMessageLog:
-      LOG(INFO) << "[console.log()" << source << "] " << msg;
+      LOG(INFO) << print_clocks() << "[console.log()" << source << "] " << msg;
       break;
     case v8::Isolate::kMessageDebug:
-      LOG(INFO) << "[console.debug()" << source << "] " << msg;
+      LOG(INFO) << print_clocks() << "[console.debug()" << source << "] "
+                << msg;
       break;
     case v8::Isolate::kMessageInfo:
-      LOG(INFO) << "[console.info()" << source << "] " << msg;
+      LOG(INFO) << print_clocks() << "[console.info()" << source << "] " << msg;
       break;
     case v8::Isolate::kMessageError:
-      LOG(ERROR) << "[console.error()" << source << "] " << msg;
+      LOG(ERROR) << print_clocks() << "[console.error()" << source << "] "
+                 << msg;
       break;
     case v8::Isolate::kMessageWarning:
-      LOG(WARNING) << "[console.warn()" << source << "] " << msg;
+      LOG(WARNING) << print_clocks() << "[console.warn()" << source << "] "
+                   << msg;
       break;
     case v8::Isolate::kMessageAll:
-      NOTIMPLEMENTED() << "Invalid MessageErrorLevel";
+      NOTIMPLEMENTED() << print_clocks() << "Invalid MessageErrorLevel";
       break;
   }
 }

diff --git a/net/http/http_stream_factory_job_controller.cc b/net/http/http_stream_factory_job_controller.cc
@@ -4,6 +4,7 @@
 
 #include "net/http/http_stream_factory_job_controller.h"
 
+#include <pthread.h>
 #include <string>
 #include <utility>
 
@@ -33,6 +34,7 @@
 #include "net/log/net_log_with_source.h"
 #include "net/proxy_resolution/proxy_resolution_request.h"
 #include "net/spdy/spdy_session.h"
+#include "starboard/common/string.h"
 #include "url/gurl.h"
 #include "url/scheme_host_port.h"
 #include "url/third_party/mozilla/url_parse.h"
@@ -130,6 +132,25 @@ base::Value::Dict NetLogAltSvcParams(const AlternativeServiceInfo* alt_svc_info,
   return dict;
 }
 
+namespace {
+static clockid_t clockid = 0;
+std::string print_clock(const char* msg, clockid_t cid) {
+  struct timespec ts;
+  if (clock_gettime(cid, &ts) != -1)
+    return starboard::FormatString(" %s %ld.%06ld", msg, ts.tv_sec,
+                                   ts.tv_nsec / 1000);
+  return std::string();
+}
+
+std::string print_clocks() {
+  if (clockid == 0) {
+    pthread_getcpuclockid(pthread_self(), &clockid);
+  }
+  return print_clock("thread", clockid) +
+         print_clock("process", CLOCK_PROCESS_CPUTIME_ID);
+}
+}  // namespace
+
 HttpStreamFactory::JobController::JobController(
     HttpStreamFactory* factory,
     HttpStreamRequest::Delegate* delegate,
@@ -311,7 +332,7 @@ void HttpStreamFactory::JobController::OnStreamReady(
   {
     const char* jobtypename[] = {"main", "alternative", "dns_alpn_h3", "preconnect",
                            "preconnect_dns_alpn_h3"};
-    LOG(INFO) << __FUNCTION__ << " negotiated_protocol = "
+    LOG(INFO) << __FUNCTION__ << print_clocks() << " negotiated_protocol = "
               << NextProtoToString(job->negotiated_protocol())
               << " was_alpn_negotiated=" << job->was_alpn_negotiated()
               << " using_spdy=" << job->using_spdy()
@@ -1224,7 +1245,7 @@ HttpStreamFactory::JobController::GetAlternativeServiceInfoInternal(
 // Leave the port restriction only in production builds to simplify testing
 #if defined(COBALT_BUILD_TYPE_GOLD)
     if (origin.port() == kDefaultQUICServerPort) {
-#endif      
+#endif
       quic::ParsedQuicVersionVector versions = quic::AllSupportedVersions();
       return AlternativeServiceInfo::CreateQuicAlternativeServiceInfo(
           AlternativeService(net::kProtoQUIC, origin.host(),

diff --git a/net/http/http_stream_factory_job_controller.h b/net/http/http_stream_factory_job_controller.h
@@ -379,6 +379,7 @@ class HttpStreamFactory::JobController
   const NetLogWithSource net_log_;
 
   base::WeakPtrFactory<JobController> ptr_factory_{this};
+
 };
 
 }  // namespace net