[inspector] console.timeEnd formats ms in the same way as JS formats double

BUG=chromium:680801
R=dgozman@chromium.org,pfeldman@chromium.org,alph@chromium.org

Review-Url: https://codereview.chromium.org/2631553003
Cr-Commit-Position: refs/heads/master@{#42427}

src/inspector/v8-console.cc

@@ -431,7 +431,7 @@ static void timeEndFunction(const v8::FunctionCallbackInfo<v8::Value>& info,
     double elapsed = client->currentTimeMS() -
                      helper.getDoubleFromMap(timeMap, protocolTitle, 0.0);
     String16 message =
-        protocolTitle + ": " + String16::fromDouble(elapsed, 3) + "ms";
+        protocolTitle + ": " + String16::fromDouble(elapsed) + "ms";
     helper.reportCallWithArgument(ConsoleAPIType::kTimeEnd, message);
   }
 }

test/inspector/inspector-impl.cc

@@ -138,7 +138,13 @@ v8::Local<v8::Context> InspectorClientImpl::ensureDefaultContextInGroup(int) {
   return context_.Get(isolate_);
 }
 
+void InspectorClientImpl::setCurrentTimeMSForTest(double time) {
+  current_time_ = time;
+  current_time_set_for_test_ = true;
+}
+
 double InspectorClientImpl::currentTimeMS() {
+  if (current_time_set_for_test_) return current_time_;
   return v8::base::OS::TimeCurrentMillis();
 }
 

test/inspector/inspector-impl.h

@@ -28,6 +28,8 @@ class InspectorClientImpl : public v8_inspector::V8InspectorClient {
   static v8_inspector::V8Inspector* InspectorFromContext(
       v8::Local<v8::Context> context);
 
+  void setCurrentTimeMSForTest(double time);
+
  private:
   // V8InspectorClient implementation.
   v8::Local<v8::Context> ensureDefaultContextInGroup(
@@ -54,6 +56,9 @@ class InspectorClientImpl : public v8_inspector::V8InspectorClient {
   TaskRunner* task_runner_;
   FrontendChannel* frontend_channel_;
 
+  bool current_time_set_for_test_ = false;
+  double current_time_ = 0.0;
+
   DISALLOW_COPY_AND_ASSIGN(InspectorClientImpl);
 };
 

test/inspector/inspector-test.cc

@@ -54,7 +54,8 @@ class UtilsExtension : public v8::Extension {
                       "native function quit();"
                       "native function setlocale();"
                       "native function load();"
-                      "native function compileAndRunWithOrigin();") {}
+                      "native function compileAndRunWithOrigin();"
+                      "native function setCurrentTimeMSForTest();") {}
   virtual v8::Local<v8::FunctionTemplate> GetNativeFunctionTemplate(
       v8::Isolate* isolate, v8::Local<v8::String> name) {
     v8::Local<v8::Context> context = isolate->GetCurrentContext();
@@ -88,6 +89,13 @@ class UtilsExtension : public v8::Extension {
                    .FromJust()) {
       return v8::FunctionTemplate::New(isolate,
                                        UtilsExtension::CompileAndRunWithOrigin);
+    } else if (name->Equals(context, v8::String::NewFromUtf8(
+                                         isolate, "setCurrentTimeMSForTest",
+                                         v8::NewStringType::kNormal)
+                                         .ToLocalChecked())
+                   .FromJust()) {
+      return v8::FunctionTemplate::New(isolate,
+                                       UtilsExtension::SetCurrentTimeMSForTest);
     }
     return v8::Local<v8::FunctionTemplate>();
   }
@@ -96,8 +104,13 @@ class UtilsExtension : public v8::Extension {
     backend_runner_ = runner;
   }
 
+  static void set_inspector_client(InspectorClientImpl* client) {
+    inspector_client_ = client;
+  }
+
  private:
   static TaskRunner* backend_runner_;
+  static InspectorClientImpl* inspector_client_;
 
   static void Print(const v8::FunctionCallbackInfo<v8::Value>& args) {
     for (int i = 0; i < args.Length(); i++) {
@@ -180,9 +193,20 @@ class UtilsExtension : public v8::Extension {
         ToVector(args[0].As<v8::String>()), args[1].As<v8::String>(),
         args[2].As<v8::Int32>(), args[3].As<v8::Int32>(), nullptr, nullptr));
   }
+
+  static void SetCurrentTimeMSForTest(
+      const v8::FunctionCallbackInfo<v8::Value>& args) {
+    if (args.Length() != 1 || !args[0]->IsNumber()) {
+      fprintf(stderr, "Internal error: setCurrentTimeMSForTest(time).");
+      Exit();
+    }
+    inspector_client_->setCurrentTimeMSForTest(
+        args[0].As<v8::Number>()->Value());
+  }
 };
 
 TaskRunner* UtilsExtension::backend_runner_ = nullptr;
+InspectorClientImpl* UtilsExtension::inspector_client_ = nullptr;
 
 class SetTimeoutTask : public AsyncTask {
  public:
@@ -415,6 +439,7 @@ int main(int argc, char* argv[]) {
   InspectorClientImpl inspector_client(&backend_runner, &frontend_channel,
                                        &ready_semaphore);
   ready_semaphore.Wait();
+  UtilsExtension::set_inspector_client(&inspector_client);
 
   task_runners.push_back(&frontend_runner);
   task_runners.push_back(&backend_runner);

test/inspector/runtime/console-time-end-format-expected.txt

+Checks format of console.timeEnd output
+
+Running test: zero
+js: 0ms
+timeEnd: 0ms
+
+Running test: verySmall
+js: 1e-15ms
+timeEnd: 1e-15ms
+
+Running test: small
+js: 0.001ms
+timeEnd: 0.001ms
+
+Running test: regular
+js: 1.2345ms
+timeEnd: 1.2345ms
+
+Running test: big
+js: 10000.2345ms
+timeEnd: 10000.2345ms
+
+Running test: veryBig
+js: 1000000000000000.2ms
+timeEnd: 1000000000000000.2ms
+
+Running test: huge
+js: 1e+42ms
+timeEnd: 1e+42ms

test/inspector/runtime/console-time-end-format.js

+// Copyright 2017 the V8 project authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+print('Checks format of console.timeEnd output');
+
+Protocol.Runtime.enable();
+Protocol.Runtime.onConsoleAPICalled(message => {
+  InspectorTest.log(message.params.args[0].value);
+});
+
+InspectorTest.runTestSuite([
+  function zero(next) {
+    checkInterval(0.0).then(next);
+  },
+  function verySmall(next) {
+    checkInterval(1e-15).then(next);
+  },
+  function small(next) {
+    checkInterval(0.001).then(next);
+  },
+  function regular(next) {
+    checkInterval(1.2345).then(next);
+  },
+  function big(next) {
+    checkInterval(10000.2345).then(next);
+  },
+  function veryBig(next) {
+    checkInterval(1e+15 + 0.2345).then(next);
+  },
+  function huge(next) {
+    checkInterval(1e+42).then(next);
+  }
+]);
+
+function checkInterval(time) {
+  setCurrentTimeMSForTest(0.0);
+  return Protocol.Runtime.evaluate({
+    expression: `console.log('js: ' + ${time} + 'ms')`})
+    .then(() => Protocol.Runtime.evaluate({
+      expression: 'console.time(\'timeEnd\')'}))
+    .then(() => setCurrentTimeMSForTest(time))
+    .then(() => Protocol.Runtime.evaluate({
+      expression: 'console.timeEnd(\'timeEnd\')'}));
+}

test/inspector/runtime/protocol-works-with-different-locale-expected.txt

+
 Running test: consoleLogWithDefaultLocale
 {
     method : Runtime.consoleAPICalled
@@ -34,14 +35,14 @@ set locale to fr_CA.UTF-8 (has comma as separator)
         args : [
             [0] : {
                 type : string
-                value : a: x.xms
+                value : a: 0.001ms
             }
         ]
         executionContextId : <executionContextId>
         stackTrace : {
             callFrames : [
                 [0] : {
-                    columnNumber : 27
+                    columnNumber : 8
                     functionName : 
                     lineNumber : 0
                     scriptId : <scriptId>
@@ -117,14 +118,14 @@ set locale to fr_CA.UTF-8 (has comma as separator)
         args : [
             [0] : {
                 type : string
-                value : a: x.xms
+                value : a: 0.001ms
             }
         ]
         executionContextId : <executionContextId>
         stackTrace : {
             callFrames : [
                 [0] : {
-                    columnNumber : 27
+                    columnNumber : 8
                     functionName : 
                     lineNumber : 0
                     scriptId : <scriptId>

test/inspector/runtime/protocol-works-with-different-locale.js

@@ -4,7 +4,7 @@
 
 Protocol.Runtime.enable();
 
-Protocol.Runtime.onConsoleAPICalled(dumpConsoleApiCalled);
+Protocol.Runtime.onConsoleAPICalled(InspectorTest.logMessage);
 
 InspectorTest.runTestSuite([
   function consoleLogWithDefaultLocale(next) {
@@ -14,7 +14,11 @@ InspectorTest.runTestSuite([
   function consoleTimeWithCommaAsSeparator(next) {
     InspectorTest.log("set locale to fr_CA.UTF-8 (has comma as separator)");
     setlocale("fr_CA.UTF-8");
-    Protocol.Runtime.evaluate({ expression: "console.time(\"a\"); console.timeEnd(\"a\")"}).then(next);
+    setCurrentTimeMSForTest(0.0);
+    Protocol.Runtime.evaluate({ expression: "console.time(\"a\");"})
+      .then(() => setCurrentTimeMSForTest(0.001))
+      .then(() => Protocol.Runtime.evaluate({ expression: "console.timeEnd(\"a\");"}))
+      .then(next);
   },
 
   function consoleLogWithCommaAsSeparator(next) {
@@ -27,14 +31,10 @@ InspectorTest.runTestSuite([
     InspectorTest.log("set locale to fr_CA.UTF-8 (has comma as separator)");
     setlocale("fr_CA.UTF-8");
     Protocol.Runtime.evaluate({ expression: "console.log(239) "})
-      .then(() => Protocol.Runtime.evaluate({ expression: "console.time(\"a\"); console.timeEnd(\"a\")"}))
+      .then(() => setCurrentTimeMSForTest(0.0))
+      .then(() => Protocol.Runtime.evaluate({ expression: "console.time(\"a\");"}))
+      .then(() => setCurrentTimeMSForTest(0.001))
+      .then(() => Protocol.Runtime.evaluate({ expression: "console.timeEnd(\"a\");"}))
       .then(next);
   }
 ]);
-
-function dumpConsoleApiCalled(message) {
-  var firstArg = message.params.args[0];
-  if (firstArg.type === "string")
-    firstArg.value = firstArg.value.replace(/[0-9]+/g, "x");
-  InspectorTest.logMessage(message);
-}