perf_hooks: fix start_time of perf_hooks

nodejs · theanarkh · May 12, 2022 · May 18, 2022 · 6a314e684eb7057efe90c51aa94deebbd0b9a093
commit 6a314e684eb7057efe90c51aa94deebbd0b9a093
diff --git a/lib/_http_client.js b/lib/_http_client.js
@@ -79,6 +79,8 @@ const {
   hasObserver,
 } = require('internal/perf/observe');
 
+const { now } = require('internal/perf/utils');
+
 const kClientRequestStatistics = Symbol('ClientRequestStatistics');
 
 const { addAbortSignal, finished } = require('stream');
@@ -345,7 +347,7 @@ ClientRequest.prototype._finish = function _finish() {
   FunctionPrototypeCall(OutgoingMessage.prototype._finish, this);
   if (hasObserver('http')) {
     this[kClientRequestStatistics] = {
-      startTime: process.hrtime(),
+      startTime: now(),
       type: 'HttpClient',
     };
   }

diff --git a/lib/_http_server.js b/lib/_http_server.js
@@ -96,6 +96,8 @@ const {
   hasObserver,
 } = require('internal/perf/observe');
 
+const { now } = require('internal/perf/utils');
+
 const STATUS_CODES = {
   100: 'Continue',                   // RFC 7231 6.2.1
   101: 'Switching Protocols',        // RFC 7231 6.2.2
@@ -194,7 +196,7 @@ function ServerResponse(req) {
 
   if (hasObserver('http')) {
     this[kServerResponseStatistics] = {
-      startTime: process.hrtime(),
+      startTime: now(),
       type: 'HttpRequest',
     };
   }

diff --git a/lib/internal/http.js b/lib/internal/http.js
@@ -16,6 +16,8 @@ const {
   hasObserver,
 } = require('internal/perf/observe');
 
+const { now } = require('internal/perf/utils');
+
 let utcCache;
 
 function utcDate() {
@@ -36,12 +38,11 @@ function resetCache() {
 function emitStatistics(statistics) {
   if (!hasObserver('http') || statistics == null) return;
   const startTime = statistics.startTime;
-  const diff = process.hrtime(startTime);
   const entry = new InternalPerformanceEntry(
     statistics.type,
     'http',
-    startTime[0] * 1000 + startTime[1] / 1e6,
-    diff[0] * 1000 + diff[1] / 1e6,
+    startTime,
+    now() - startTime,
     undefined,
   );
   enqueue(entry);

diff --git a/lib/internal/perf/observe.js b/lib/internal/perf/observe.js
@@ -63,6 +63,8 @@ const {
 
 const { inspect } = require('util');
 
+const { now } = require('internal/perf/utils');
+
 const kDispatch = Symbol('kDispatch');
 const kMaybeBuffer = Symbol('kMaybeBuffer');
 const kDeprecatedFields = Symbol('kDeprecatedFields');
@@ -461,7 +463,7 @@ function startPerf(target, key, context = {}) {
   if (hasObserver(context.type)) {
     target[key] = {
       ...context,
-      startTime: process.hrtime(),
+      startTime: now(),
     };
   }
 }
@@ -470,12 +472,11 @@ function stopPerf(target, key, context = {}) {
   const ctx = target[key];
   if (ctx && hasObserver(ctx.type)) {
     const startTime = ctx.startTime;
-    const diff = process.hrtime(startTime);
     const entry = new InternalPerformanceEntry(
       ctx.name,
       ctx.type,
-      startTime[0] * 1000 + startTime[1] / 1e6,
-      diff[0] * 1000 + diff[1] / 1e6,
+      startTime,
+      now() - startTime,
       { ...ctx.detail, ...context.detail },
     );
     enqueue(entry);

diff --git a/src/node_http2.cc b/src/node_http2.cc
@@ -640,7 +640,7 @@ void Http2Stream::EmitStatistics() {
   std::unique_ptr<Http2StreamPerformanceEntry> entry =
       std::make_unique<Http2StreamPerformanceEntry>(
           "Http2Stream",
-          start,
+          start - (node::performance::timeOrigin / 1e6),
           duration,
           statistics_);
 
@@ -660,7 +660,7 @@ void Http2Session::EmitStatistics() {
   std::unique_ptr<Http2SessionPerformanceEntry> entry =
       std::make_unique<Http2SessionPerformanceEntry>(
           "Http2Session",
-          start,
+          start - (node::performance::timeOrigin / 1e6),
           duration,
           statistics_);
 

diff --git a/src/node_perf.cc b/src/node_perf.cc
@@ -167,9 +167,8 @@ void MarkGarbageCollectionEnd(
           "gc",
           start_time,
           duration,
-          GCPerformanceEntry::Details(
-            static_cast<PerformanceGCKind>(type),
-            static_cast<PerformanceGCFlags>(flags)));
+          GCPerformanceEntry::Details(static_cast<PerformanceGCKind>(type),
+                                      static_cast<PerformanceGCFlags>(flags)));
 
   env->SetImmediate([entry = std::move(entry)](Environment* env) {
     entry->Notify(env);