658368 - Expand console object with time and timeEnd methods that add a simple timer implementation

Status: RESOLVED FIXED

(DevTools :: General, defect)

Description

[Panos Astithas (he/him) [:past] (please ni?)]

As described in bug 644596, we have to implement the rest of the de-facto standard methods in the console object, like time() and timeEnd(). This bug will track the work for these two.

Comment 1

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: First draft

This is just the implementation bits. Looking for feedback before I add the required tests.

Comment 2

[Mihai Sucan [:msucan]]

Comment on attachment 533765 [details] [diff] [review]
First draft

Review of attachment 533765 [details] [diff] [review]:
-----------------------------------------------------------------

The patch is in the right direction, but please display the timer name in the Web Console output and the timer unit.

console.time("foobar");
let result = console.timeEnd("foobar");

Web Console output should be: "foobar: NNN ms." The result variable needs to hold the time elapsed.

Comment 3

[Mihai Sucan [:msucan]]

Also you need to have the call location in the Web Console output, so the user can see where the timeEnd() call originated from (the script and line number). Just like you did for all the other console.* methods.

Comment 4

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Updated patch

Addressed all comments and added API and UI tests. There are a couple of things I should note:

1) Firebug logs timeEnd results as INFO with the appropriate icon, while Chrome, Safari and Opera do not show anything distinctive at all. I've used log/debug level in the patch since I think we should reserve INFO for things the user deems adequate for that level.

2) Firebug has added the ability to return a numeric value from timeEnd in bug 42 (http://code.google.com/p/fbug/issues/detail?id=42). This has not been adopted by either Chrome, Safari or Opera. Following their example, I haven't implemented this in the patch, for a variety reasons. For starters, we don't have support in the current code to return values from console.foo calls. I believe there has to be some refactoring work there, in order to do this. Furthermore, the console API is basically an I/O, side-effects only kind of thing. Firebug has broken this consistency in the API, by having this call both compute a value and produce a side-effect. Moreover they display a different output than the one that is returned (a human-readable vs. a numeric value). I think there is already marginal value in console.time/timeEnd, compared to the traditional way of storing a timestamp and comparing it to the current time at the end, and that value is in the simplicity of displaying the result for quick prototyping. The use cases that require the use of the calculated duration, can already be serviced by the manual timekeeping method.

Comment 5

[Mihai Sucan [:msucan]]

Comment on attachment 534458 [details] [diff] [review]
Updated patch

Review of attachment 534458 [details] [diff] [review]:
-----------------------------------------------------------------

Great improvements. Thanks!

General comments:

- The HUDService test browser_webconsole_console_extras.js fails. Needs updates.
- The dom/tests/mochitest/general/test_consoleAPI.html test also fails. Needs updates.

Please also check the comments below. Thank you!

::: dom/base/ConsoleAPI.js
@@ +87,5 @@
> +      time: function CA_time() {
> +        self.notifyObservers(id, "time", self.startTimer(arguments[0]));
> +      },
> +      timeEnd: function CA_timeEnd() {
> +        self.notifyObservers(id, "timeEnd", self.stopTimer(arguments[0]));

Firebug returns the elapsed time to the caller. Please do this.

I want from the page to be able to do:
let elapsedTime = console.timeEnd("foo");

You do not need to do any refactoring. Just return in this function the time elapsed. It's trivial.

timeEnd: function CA_timeEnd() {
  let result = self.stopTimer(arguments[0]);
  self.notifyObservers(id, "timeEnd", result);
  return result.duration;
}

I also tested Chrome, and it's true, it doesn't return the time elapsed, but if we easily can do this, why not? We aim Firebug compatibility. Perhaps the Chrome implementation has technical hurdles that prevented them from easily returning the time elapsed.

Opera does not implement console.time()/timeEnd(). I see no effect when calling these methods.

@@ +191,5 @@
> +    }
> +    let key = KEY_PREFIX + aName.toString();
> +    if (!this.timerRegistry[key]) {
> +        this.timerRegistry[key] = Date.now();
> +    }

I think you could return an object with the timer name and the recorded Date.now().

In the Web Console we shall ignore this, but the notification alone is useful for other purposes, we may think of different uses later. Currently your patch outputs undefined in the Web Console when you call console.time(). That's not really nice - Chrome doesn't do this, nor Firebug.

::: dom/tests/browser/browser_ConsoleAPITests.js
@@ +224,5 @@
> +    }
> +  };
> +  gLevel = "timeEnd";
> +  gArgs = [
> +    {filename: TEST_URI, lineNumber: 27, functionName: "foobar658368b", arguments: [{ name: "foo", duration: "10"}]},

I think you can remove duration from here.

::: toolkit/components/console/hudservice/HUDService.jsm
@@ +2061,5 @@
> +      case "time":
> +        clipboardText = body = args;
> +        sourceURL = aMessage.filename;
> +        sourceLine = aMessage.lineNumber;
> +        break;

I think we don't need to display the calls to console.time(), at least not as "undefined". :)

Either remove this, or change the output to something like:

"fooTimerKey: timer started"

This would actually be an improvement over the Chrome and Firebug implementations.

Comment 6

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #5)
> Comment on attachment 534458 [details] [diff] [review] [review]
> Updated patch
> 
> Review of attachment 534458 [details] [diff] [review] [review]:
> -----------------------------------------------------------------
> 
> Great improvements. Thanks!
> 
> General comments:
> 
> - The HUDService test browser_webconsole_console_extras.js fails. Needs
> updates.
> - The dom/tests/mochitest/general/test_consoleAPI.html test also fails.
> Needs updates.

Sorry about that, I was sure I ran all the tests after the last patch iteration. Thanks for catching it!

> Please also check the comments below. Thank you!
> 
> ::: dom/base/ConsoleAPI.js
> @@ +87,5 @@
> > +      time: function CA_time() {
> > +        self.notifyObservers(id, "time", self.startTimer(arguments[0]));
> > +      },
> > +      timeEnd: function CA_timeEnd() {
> > +        self.notifyObservers(id, "timeEnd", self.stopTimer(arguments[0]));
> 
> Firebug returns the elapsed time to the caller. Please do this.
> 
> I want from the page to be able to do:
> let elapsedTime = console.timeEnd("foo");
> 
> You do not need to do any refactoring. Just return in this function the time
> elapsed. It's trivial.
> 
> timeEnd: function CA_timeEnd() {
>   let result = self.stopTimer(arguments[0]);
>   self.notifyObservers(id, "timeEnd", result);
>   return result.duration;
> }
> 
> I also tested Chrome, and it's true, it doesn't return the time elapsed, but
> if we easily can do this, why not? We aim Firebug compatibility. Perhaps the
> Chrome implementation has technical hurdles that prevented them from easily
> returning the time elapsed.

You're right about the ease of implementation, I was utterly confused, obviously. Still, I think this is a mistake for the reasons explained above, a mistake that was probably made by jjb in Firebug on the same grounds, namely ease of implementation. Nevertheless, perhaps API compatibility should trump good API design, so I've added this as you requested.

> Opera does not implement console.time()/timeEnd(). I see no effect when
> calling these methods.

It works here on Opera 11.11, although not always. They seem to have some bugs there.

> @@ +191,5 @@
> > +    }
> > +    let key = KEY_PREFIX + aName.toString();
> > +    if (!this.timerRegistry[key]) {
> > +        this.timerRegistry[key] = Date.now();
> > +    }
> 
> I think you could return an object with the timer name and the recorded
> Date.now().
> 
> In the Web Console we shall ignore this, but the notification alone is
> useful for other purposes, we may think of different uses later. Currently
> your patch outputs undefined in the Web Console when you call
> console.time(). That's not really nice - Chrome doesn't do this, nor Firebug.

Chrome does display undefined actually and so does Safari. Firebug doesn't display anything and I'm assuming they have extra checks to silence output that has no meaningful info. But I agree it would be more useful to display something. After all these two methods are designed for logging, otherwise they wouldn't belong in the console object. Opera shows "Started: timerName", FWIW.

> ::: dom/tests/browser/browser_ConsoleAPITests.js
> @@ +224,5 @@
> > +    }
> > +  };
> > +  gLevel = "timeEnd";
> > +  gArgs = [
> > +    {filename: TEST_URI, lineNumber: 27, functionName: "foobar658368b", arguments: [{ name: "foo", duration: "10"}]},
> 
> I think you can remove duration from here.

Done.

> ::: toolkit/components/console/hudservice/HUDService.jsm
> @@ +2061,5 @@
> > +      case "time":
> > +        clipboardText = body = args;
> > +        sourceURL = aMessage.filename;
> > +        sourceLine = aMessage.lineNumber;
> > +        break;
> 
> I think we don't need to display the calls to console.time(), at least not
> as "undefined". :)
> 
> Either remove this, or change the output to something like:
> 
> "fooTimerKey: timer started"
> 
> This would actually be an improvement over the Chrome and Firebug
> implementations.

Indeed, and I like your message better than Opera's, since it is more consistent with the output from timeEnd().

Thanks for the detailed review!

Comment 7

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v3

Comment 8

[Mihai Sucan [:msucan]]

(In reply to comment #6)
> (In reply to comment #5)
> > Comment on attachment 534458 [details] [diff] [review] [review] [review]
> > Updated patch
> > 
> > Review of attachment 534458 [details] [diff] [review] [review] [review]:
> > -----------------------------------------------------------------
> > 
> > Great improvements. Thanks!
> > 
> > General comments:
> > 
> > - The HUDService test browser_webconsole_console_extras.js fails. Needs
> > updates.
> > - The dom/tests/mochitest/general/test_consoleAPI.html test also fails.
> > Needs updates.
> 
> Sorry about that, I was sure I ran all the tests after the last patch
> iteration. Thanks for catching it!

No problem. :)


> > Please also check the comments below. Thank you!
> > 
> > ::: dom/base/ConsoleAPI.js
> > @@ +87,5 @@
> > > +      time: function CA_time() {
> > > +        self.notifyObservers(id, "time", self.startTimer(arguments[0]));
> > > +      },
> > > +      timeEnd: function CA_timeEnd() {
> > > +        self.notifyObservers(id, "timeEnd", self.stopTimer(arguments[0]));
> > 
> > Firebug returns the elapsed time to the caller. Please do this.
> > 
> > I want from the page to be able to do:
> > let elapsedTime = console.timeEnd("foo");
> > 
> > You do not need to do any refactoring. Just return in this function the time
> > elapsed. It's trivial.
> > 
> > timeEnd: function CA_timeEnd() {
> >   let result = self.stopTimer(arguments[0]);
> >   self.notifyObservers(id, "timeEnd", result);
> >   return result.duration;
> > }
> > 
> > I also tested Chrome, and it's true, it doesn't return the time elapsed, but
> > if we easily can do this, why not? We aim Firebug compatibility. Perhaps the
> > Chrome implementation has technical hurdles that prevented them from easily
> > returning the time elapsed.
> 
> You're right about the ease of implementation, I was utterly confused,
> obviously. Still, I think this is a mistake for the reasons explained above,
> a mistake that was probably made by jjb in Firebug on the same grounds,
> namely ease of implementation. Nevertheless, perhaps API compatibility
> should trump good API design, so I've added this as you requested.

I don't see anything "bad" in the choice of returning the elapsed time, but I can see your point about console.* methods having no return values.


> > Opera does not implement console.time()/timeEnd(). I see no effect when
> > calling these methods.
> 
> It works here on Opera 11.11, although not always. They seem to have some
> bugs there.

I use Opera 11.11 as well and I saw no output. Uh oh. Buggy. :)


> > @@ +191,5 @@
> > > +    }
> > > +    let key = KEY_PREFIX + aName.toString();
> > > +    if (!this.timerRegistry[key]) {
> > > +        this.timerRegistry[key] = Date.now();
> > > +    }
> > 
> > I think you could return an object with the timer name and the recorded
> > Date.now().
> > 
> > In the Web Console we shall ignore this, but the notification alone is
> > useful for other purposes, we may think of different uses later. Currently
> > your patch outputs undefined in the Web Console when you call
> > console.time(). That's not really nice - Chrome doesn't do this, nor Firebug.
> 
> Chrome does display undefined actually and so does Safari. Firebug doesn't
> display anything and I'm assuming they have extra checks to silence output
> that has no meaningful info. But I agree it would be more useful to display
> something. After all these two methods are designed for logging, otherwise
> they wouldn't belong in the console object. Opera shows "Started:
> timerName", FWIW.

I use Chromium 12 beta on Ubuntu. Who knows what goes wrong ... why I don't see undefined.

How do you call console.time()? From a web page or from the JS command line? I call it from a web page.


> Thanks for the detailed review!

You're welcome!

Comment 9

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #8)
> (In reply to comment #6)
> > Chrome does display undefined actually and so does Safari. Firebug doesn't
> > display anything and I'm assuming they have extra checks to silence output
> > that has no meaningful info. But I agree it would be more useful to display
> > something. After all these two methods are designed for logging, otherwise
> > they wouldn't belong in the console object. Opera shows "Started:
> > timerName", FWIW.
> 
> I use Chromium 12 beta on Ubuntu. Who knows what goes wrong ... why I don't
> see undefined.

I'm using Chrome 11, so they may have changed it in the new version.

> How do you call console.time()? From a web page or from the JS command line?
> I call it from a web page.

Ah, that explains it. I'm doing it from the console.

Comment 10

[Mihai Sucan [:msucan]]

Comment on attachment 535010 [details] [diff] [review]
Patch v3

Review of attachment 535010 [details] [diff] [review]:
-----------------------------------------------------------------

Goodness! R+!

Please address the comments below. :)

::: toolkit/components/console/hudservice/HUDService.jsm
@@ +2059,5 @@
>          break;
>  
> +      case "time":
> +        if (args) {
> +          clipboardText = body = args[0].name + ": timer started";

You need to localize the string.

@@ +2062,5 @@
> +        if (args) {
> +          clipboardText = body = args[0].name + ": timer started";
> +        }
> +        else {
> +          clipboardText = body = args;

I think we do not want to show undefined when the author calls console.time() without any argument. Firebug, Web Inspector and Dragonfly do not show anything. I suggest you skip such cases.

If you think it's useful for debugging purposes, maybe you can show an error. Like ... "No timer name given".

@@ +2073,5 @@
> +        if (args) {
> +          clipboardText = body = args[0].name + ": " + args[0].duration + "ms";
> +        }
> +        else {
> +          clipboardText = body = args;

When console.timeEnd() or timeEnd("undefined-timer") are called you do not need to show undefined. The other devtools in the other browsers do not show it.

If you think it's useful for debugging purposes, maybe you can show an error. Like ... "Undefined timer" (when timeEnd is received).

Comment 11

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v4

Addressed all of Mihai's comments in comment 10.

Comment 12

[:Gavin Sharp [email: [e-mail]]]

The startTimer/endTimer stuff looks like it belongs in the front-end code, rather than ConsoleAPI.js.

Comment 13

[Shawn Wilsher :sdwilsh]

This is going to need sr.

Comment 14

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #12)
> The startTimer/endTimer stuff looks like it belongs in the front-end code,
> rather than ConsoleAPI.js.

My main motivation for putting it in ConsoleAPI is Fennec. Mark Finkle suggested in a similar bug to put the basic functionality in ConsoleAPI instead of HUDService, since the latter cannot be used in Fennec:

https://bugzilla.mozilla.org/show_bug.cgi?id=614586#c2

If this is not interesting for Fennec, I'll move it to HUDService.

Comment 15

[Mark Finkle (:mfinkle) (use needinfo?)]

(In reply to comment #14)
> (In reply to comment #12)
> > The startTimer/endTimer stuff looks like it belongs in the front-end code,
> > rather than ConsoleAPI.js.
> 
> My main motivation for putting it in ConsoleAPI is Fennec. Mark Finkle
> suggested in a similar bug to put the basic functionality in ConsoleAPI
> instead of HUDService, since the latter cannot be used in Fennec:
> 
> https://bugzilla.mozilla.org/show_bug.cgi?id=614586#c2
> 
> If this is not interesting for Fennec, I'll move it to HUDService.

This is wanted by Fennec. Fennec cannot currently use HUDService - it too many desktop Firefox dependencies.

Looks like Fennec will need a small patch to use these new features (as well as the new console.trace method).

Comment 16

[Shawn Wilsher :sdwilsh]

(In reply to comment #15)
> This is wanted by Fennec. Fennec cannot currently use HUDService - it too
> many desktop Firefox dependencies.
Ugh.  Is there a bug on file for that?  That needs to start getting fixed, or HUDService needs to move out of toolkit/

Comment 17

[:Gavin Sharp [email: [e-mail]]]

Fennec probably wouldn't want to use HUDService even if it was app-agnostic. It's probably reasonable to share code for this in ConsoleAPI.js, on second thought, given how tied it is to the methods names.

(It's a little bit unfortunate that all we're using as a basis for which methods to add is "Firebug's de-facto standard".)

Comment 18

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #16)
> (In reply to comment #15)
> > This is wanted by Fennec. Fennec cannot currently use HUDService - it too
> > many desktop Firefox dependencies.
> Ugh.  Is there a bug on file for that?  That needs to start getting fixed,
> or HUDService needs to move out of toolkit/

There is actually a bug for the latter, namely bug 579909.

(In reply to comment #17)
> Fennec probably wouldn't want to use HUDService even if it was app-agnostic.
> It's probably reasonable to share code for this in ConsoleAPI.js, on second
> thought, given how tied it is to the methods names.
> 
> (It's a little bit unfortunate that all we're using as a basis for which
> methods to add is "Firebug's de-facto standard".)

Note that these two ones are also implemented in Chrome, Safari and Opera. I am not sure about IE.

Comment 19

[Shawn Wilsher :sdwilsh]

Sorry, but I'm going to disagree with Mihai here.  Returning the time is something we should not do at this time.  We could add it in the future and not break consumers, but if we had to remove it in the future, or change what it returned, we'd break people.

For example, say we wanted to start using some newer high-resolution timer.  We could use the new timer value in the UI, but then we'd be bound to returning only milliseconds in the API, which would not be nearly as useful.  I'd much rather be at API parity with other browser vendors instead of parity with Firebug.  Firebug doesn't have to worry about breaking the web nearly as much as browsers do.

Another data point: node.js's console.timeEnd does not return anything either: http://nodejs.org/docs/v0.4.8/api/stdio.html#console.timeEnd

Comment 20

[Shawn Wilsher :sdwilsh]

Comment on attachment 535075 [details] [diff] [review]
Patch v4

I'll review a new patch that addresses comment 19.

Comment 21

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v5

timeEnd() no longer returns a value.

Comment 22

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #19)
> Another data point: node.js's console.timeEnd does not return anything
> either: http://nodejs.org/docs/v0.4.8/api/stdio.html#console.timeEnd

One thing that is unique about the node.js implementation, is that they don't clear the timer after timeEnd(). This permits repeated calls to mark milestones or something like that, but the timer registry memory is never reclaimed. This is probably a bug, not a feature.

Comment 23

[Rob Campbell [:rc] (:robcee)]

That's neat, but should probably be an explicit invocation. Adding something like timeMark() to the API could achieve the same.

Comment 24

[Shawn Wilsher :sdwilsh]

Comment on attachment 536538 [details] [diff] [review]
Patch v5

Review of attachment 536538 [details] [diff] [review]:
-----------------------------------------------------------------

I've got too many questions for this to be r+ with comments addressed, but this is close.  Sorry.

::: dom/base/ConsoleAPI.js
@@ +179,5 @@
> +  /**
> +   * Create a new timer by recording the current time under the specified name.
> +   *
> +   * @param string aName
> +   *        The name of the timer.

Given other comments in this file, it looks like this may not actually be a string, but could also be an object (which is why you call toString on it)?  Why don't we enforce that it is a string?

@@ +184,5 @@
> +   **/
> +  startTimer: function CA_startTimer(aName) {
> +    if (!aName) {
> +        return;
> +    }

Is silently failing the right thing to do here?  What do other browsers do?

(My gut tells me it's be better to throw and let the consumer know they need to supply a name instead of silently doing nothing and wondering why it doesn't work).

@@ +187,5 @@
> +        return;
> +    }
> +    if (!this.timerRegistry) {
> +        this.timerRegistry = {};
> +    }

You should just initialize timeRegistry on the object so you don't have to do that here.  It's silly to have to have this check every time you want to start a timer.

@@ +220,5 @@
>  
>  let NSGetFactory = XPCOMUtils.generateNSGetFactory([ConsoleAPI]);
> +// Avoids NaN duration for timers with Object prototype method names. See:
> +// http://code.google.com/p/fbug/issues/detail?id=1267
> +let KEY_PREFIX = "timer-";

This constant should be at the top of the file with the rest of the constants.

::: dom/tests/browser/test-console-api.html
@@ +18,5 @@
>        function foobar646025(omg) {
>          console.log(omg, "o", "d");
>        }
>  
> +      function foobar658368(timer) {

ugh.  useful test names would be nice here.

@@ +19,5 @@
>          console.log(omg, "o", "d");
>        }
>  
> +      function foobar658368(timer) {
> +        console.time(timer);

You aren't testing not providing a name here, which should have a test since we have code that checks for it.

@@ +23,5 @@
> +        console.time(timer);
> +      }
> +
> +      function foobar658368b(timer) {
> +        console.timeEnd(timer);

Likewise here.

::: toolkit/components/console/hudservice/HUDService.jsm
@@ +2059,5 @@
>          break;
>  
> +      case "time":
> +        if (!args)
> +          return;

nit: brace all ifs (also, comment regarding possibly throwing here applies as well).

@@ +2067,5 @@
> +        break;
> +
> +      case "timeEnd":
> +        if (!args)
> +          return;

nit: brace all ifs (also, comment regarding possibly throwing here applies as well).

::: toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_658368_time_methods.js
@@ +10,5 @@
> +                 "hudservice/tests/browser/test-bug-658368-time-methods.html";
> +
> +function test() {
> +  addTab("data:text/html,Web Console test for bug 658368: Expand console " +
> +         "object with time and timeEnd methods");

Why are you loading this, and then loading the test page?  That doesn't seem useful.  Additionally, what benefit is test-bug-658368-time-methods.html with test-console-api.html?

Comment 25

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to comment #24)
> Comment on attachment 536538 [details] [diff] [review] [review]
> Patch v5
> 
> Review of attachment 536538 [details] [diff] [review] [review]:
> -----------------------------------------------------------------
> 
> I've got too many questions for this to be r+ with comments addressed, but
> this is close.  Sorry.

No worries, these are some good suggestions!

> ::: dom/base/ConsoleAPI.js
> @@ +179,5 @@
> > +  /**
> > +   * Create a new timer by recording the current time under the specified name.
> > +   *
> > +   * @param string aName
> > +   *        The name of the timer.
> 
> Given other comments in this file, it looks like this may not actually be a
> string, but could also be an object (which is why you call toString on it)? 
> Why don't we enforce that it is a string?

That's what everybody else is doing, so I think it makes sense from a compatibility point of view. We will be the only ones who throw, breaking working (albeit somewhat ugly) programs.

> @@ +184,5 @@
> > +   **/
> > +  startTimer: function CA_startTimer(aName) {
> > +    if (!aName) {
> > +        return;
> > +    }
> 
> Is silently failing the right thing to do here?  What do other browsers do?
> 
> (My gut tells me it's be better to throw and let the consumer know they need
> to supply a name instead of silently doing nothing and wondering why it
> doesn't work).

Same as above, everybody fails silently. Although, if I were creating the API from scratch, I might have opted for an anonymous timer in such cases, giving a dead-simple API for the (probably) majority use case.

> @@ +187,5 @@
> > +        return;
> > +    }
> > +    if (!this.timerRegistry) {
> > +        this.timerRegistry = {};
> > +    }
> 
> You should just initialize timeRegistry on the object so you don't have to
> do that here.  It's silly to have to have this check every time you want to
> start a timer.

I opted for the memory savings of the registry object, assuming time/timeEnd are not that commonly used. I'm trusting your judgement though. Fixed.

> @@ +220,5 @@
> >  
> >  let NSGetFactory = XPCOMUtils.generateNSGetFactory([ConsoleAPI]);
> > +// Avoids NaN duration for timers with Object prototype method names. See:
> > +// http://code.google.com/p/fbug/issues/detail?id=1267
> > +let KEY_PREFIX = "timer-";
> 
> This constant should be at the top of the file with the rest of the
> constants.

Done.

> ::: dom/tests/browser/test-console-api.html
> @@ +18,5 @@
> >        function foobar646025(omg) {
> >          console.log(omg, "o", "d");
> >        }
> >  
> > +      function foobar658368(timer) {
> 
> ugh.  useful test names would be nice here.

Sorry, got carried away by the existing functions. Fixed.

> @@ +19,5 @@
> >          console.log(omg, "o", "d");
> >        }
> >  
> > +      function foobar658368(timer) {
> > +        console.time(timer);
> 
> You aren't testing not providing a name here, which should have a test since
> we have code that checks for it.

I'm not sure I follow: I provide the timer name in the onclick handler. Did you mean something else?

> @@ +23,5 @@
> > +        console.time(timer);
> > +      }
> > +
> > +      function foobar658368b(timer) {
> > +        console.timeEnd(timer);
> 
> Likewise here.

Same as above.

> ::: toolkit/components/console/hudservice/HUDService.jsm
> @@ +2059,5 @@
> >          break;
> >  
> > +      case "time":
> > +        if (!args)
> > +          return;
> 
> nit: brace all ifs (also, comment regarding possibly throwing here applies
> as well).

Bracing: fixed. Throwing: see my previous comment on compatibility with the competition.

> @@ +2067,5 @@
> > +        break;
> > +
> > +      case "timeEnd":
> > +        if (!args)
> > +          return;
> 
> nit: brace all ifs (also, comment regarding possibly throwing here applies
> as well).

Ditto.

> :::
> toolkit/components/console/hudservice/tests/browser/
> browser_webconsole_bug_658368_time_methods.js
> @@ +10,5 @@
> > +                 "hudservice/tests/browser/test-bug-658368-time-methods.html";
> > +
> > +function test() {
> > +  addTab("data:text/html,Web Console test for bug 658368: Expand console " +
> > +         "object with time and timeEnd methods");
> 
> Why are you loading this, and then loading the test page?  That doesn't seem

Fixed.

> useful.  Additionally, what benefit is test-bug-658368-time-methods.html
> with test-console-api.html?

The latter helps test the narrower API limits, whereas the former helps test the console output as well. Perhaps you are suggesting that I reuse the latter in the browser_webconsole_bug_658368_time_methods.js test? Is mixing tests from different directories allowed? Any coupling/fragility concerns?

Comment 26

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v6

Updated patch. If you are not swayed by my compatibility argument against throwing, let me know and I'll fix that, too.

Comment 27

[Shawn Wilsher :sdwilsh]

(In reply to comment #25)
> That's what everybody else is doing, so I think it makes sense from a
> compatibility point of view. We will be the only ones who throw, breaking
> working (albeit somewhat ugly) programs.
You should consult your SR here on what the right thing to do is.

> Same as above, everybody fails silently. Although, if I were creating the API
> from scratch, I might have opted for an anonymous timer in such cases, giving a
> dead-simple API for the (probably) majority use case.
Same here.

> I'm not sure I follow: I provide the timer name in the onclick handler. Did you
> mean something else?
I meant the case of "console.time();"

> The latter helps test the narrower API limits, whereas the former helps test
> the console output as well. Perhaps you are suggesting that I reuse the latter
> in the browser_webconsole_bug_658368_time_methods.js test? Is mixing tests from
> different directories allowed? Any coupling/fragility concerns?
No, I hadn't realized that the later was testing output in the console.  My bad.

Comment 28

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v7

(In reply to comment #27)
> (In reply to comment #25)
> > That's what everybody else is doing, so I think it makes sense from a
> > compatibility point of view. We will be the only ones who throw, breaking
> > working (albeit somewhat ugly) programs.
> You should consult your SR here on what the right thing to do is.

OK, will do.

> > Same as above, everybody fails silently. Although, if I were creating the API
> > from scratch, I might have opted for an anonymous timer in such cases, giving a
> > dead-simple API for the (probably) majority use case.
> Same here.

Will do.

> > I'm not sure I follow: I provide the timer name in the onclick handler. Did you
> > mean something else?
> I meant the case of "console.time();"

OK, I understand now. I added a test for that case as well.

> > The latter helps test the narrower API limits, whereas the former helps test
> > the console output as well. Perhaps you are suggesting that I reuse the latter
> > in the browser_webconsole_bug_658368_time_methods.js test? Is mixing tests from
> > different directories allowed? Any coupling/fragility concerns?
> No, I hadn't realized that the later was testing output in the console.  My
> bad.

Thanks for the comments! I don't mean to impose on your free time, so let me know if you don't have any more availability for reviewing this.

Comment 29

[Shawn Wilsher :sdwilsh]

I should be able to review this tomorrow.  Sorry for the delay!

Comment 30

[Shawn Wilsher :sdwilsh]

Comment on attachment 538922 [details] [diff] [review]
Patch v7

Review of attachment 538922 [details] [diff] [review]:
-----------------------------------------------------------------

r=sdwilsh with comments addressed.  Please be sure to make sure your sr takes a look at the issues we previously talked about.

::: dom/base/ConsoleAPI.js
@@ +185,5 @@
> +  /**
> +   * Create a new timer by recording the current time under the specified name.
> +   *
> +   * @param string aName
> +   *        The name of the timer.

nit: missing @return

@@ +204,5 @@
> +   *
> +   * @param string aName
> +   *        The name of the timer.
> +   * @return number
> +   *        The number of milliseconds since the timer started.

This isn't accurate.

@@ +216,5 @@
> +        return;
> +    }
> +    let duration = Date.now() - this.timerRegistry[key];
> +    delete this.timerRegistry[key];
> +    return [{ name: aName, duration: duration }];

It's a bit confusing why this method and startTimer return an array with one object in it.  Can you add comments explaining that to both please.

::: dom/tests/browser/test-console-api.html
@@ +26,5 @@
> +      function stopTimer(timer) {
> +        console.timeEnd(timer);
> +      }
> +
> +      function emptyTimer() {

It's nameless, not empty, right?

::: toolkit/components/console/hudservice/HUDService.jsm
@@ +2061,5 @@
> +      case "time":
> +        if (!args) {
> +          return;
> +        }
> +        clipboardText = body = args[0].name + this.getStr("timerStarted");

I missed this before, but this isn't really l10n friendly.  You should use a string replacement here I think.

@@ +2070,5 @@
> +      case "timeEnd":
> +        if (!args) {
> +          return;
> +        }
> +        clipboardText = body = args[0].name + ": " + args[0].duration + "ms";

Same here.  Not l10n friendly at all.

Comment 31

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v8

(In reply to comment #30)
> Comment on attachment 538922 [details] [diff] [review] [review]
> Patch v7
> 
> Review of attachment 538922 [details] [diff] [review] [review]:
> -----------------------------------------------------------------
> 
> r=sdwilsh with comments addressed.  Please be sure to make sure your sr
> takes a look at the issues we previously talked about.
> 
> ::: dom/base/ConsoleAPI.js
> @@ +185,5 @@
> > +  /**
> > +   * Create a new timer by recording the current time under the specified name.
> > +   *
> > +   * @param string aName
> > +   *        The name of the timer.
> 
> nit: missing @return

Fixed.

> @@ +204,5 @@
> > +   *
> > +   * @param string aName
> > +   *        The name of the timer.
> > +   * @return number
> > +   *        The number of milliseconds since the timer started.
> 
> This isn't accurate.

Refactoring leftover. Fixed.

> @@ +216,5 @@
> > +        return;
> > +    }
> > +    let duration = Date.now() - this.timerRegistry[key];
> > +    delete this.timerRegistry[key];
> > +    return [{ name: aName, duration: duration }];
> 
> It's a bit confusing why this method and startTimer return an array with one
> object in it.  Can you add comments explaining that to both please.

I originally thought that it would be best to have the same data type in the arguments parameter among all console.* calls. Now that I'm revisiting it, I don't find it such a worthy goal any more, since there is only a single call site that is affected and the unified data type probably obscures things more than it simplifies them. So I just return the object instead.

> ::: dom/tests/browser/test-console-api.html
> @@ +26,5 @@
> > +      function stopTimer(timer) {
> > +        console.timeEnd(timer);
> > +      }
> > +
> > +      function emptyTimer() {
> 
> It's nameless, not empty, right?

Correct, fixed.

> ::: toolkit/components/console/hudservice/HUDService.jsm
> @@ +2061,5 @@
> > +      case "time":
> > +        if (!args) {
> > +          return;
> > +        }
> > +        clipboardText = body = args[0].name + this.getStr("timerStarted");
> 
> I missed this before, but this isn't really l10n friendly.  You should use a
> string replacement here I think.
> 
> @@ +2070,5 @@
> > +      case "timeEnd":
> > +        if (!args) {
> > +          return;
> > +        }
> > +        clipboardText = body = args[0].name + ": " + args[0].duration + "ms";
> 
> Same here.  Not l10n friendly at all.

Fixed both l10n issues.

Thanks for the thorough review. It was worth the wait!

Comment 32

[Panos Astithas (he/him) [:past] (please ni?)]

Comment on attachment 541356 [details] [diff] [review]
Patch v8

Gavin, see comments 24-27 for some issues that require your attention.

Comment 33

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v9

Rebased against latest fx-team repo.

Comment 34

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v10

Rebased due to the creation of the new devtools module.

Comment 35

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 548758 [details] [diff] [review]
Patch v10

This seems to have a similar issue as the patch in bug 664131 - multiple tabs/sites can interfere with each other's timers by re-using the same timer name. I think you can solve that fairly easily by including the inner window ID in the timerRegistry key?

Comment 36

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v11

(In reply to comment #35)
> Comment on attachment 548758 [details] [diff] [review] [diff] [details] [review]
> Patch v10
> 
> This seems to have a similar issue as the patch in bug 664131 - multiple
> tabs/sites can interfere with each other's timers by re-using the same timer
> name. I think you can solve that fairly easily by including the inner window
> ID in the timerRegistry key?

Yes, it suffers from the same problem. In one of the first versions of the patch I had actually tested against this case, but I seem to have dropped the ball at some point.

In this version I'm following your suggestion, but using the outer window ID, since it is already available. I hope it is the same, since it seems to work fine.

Comment 37

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Diff between v10 and v11

I rebased the patch as well, so for your convenience I'm providing a diff between the previous version (after rebasing), and the latest version with the fix. It should be clearer what the actual changes were.

Comment 38

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 550730 [details] [diff] [review]
Patch v11

I thought of some other issues:
- outer ID is not suitable for this, since different pages loaded in the same tab will have the same outer window ID. The patch for bug 612658 adds some innerID code to this, so you could just use that once it lands.
- there's no mechanism in place to remove timers added by pages that are unloaded without calling timeEnd. It might be best to cap the number of timers that a page can create, and also hook into the inner-window-destroyed notifications to clear out these timer references when the relevant inner window is destroyed - again, the patch in bug 612658 has some relevant code for that.

Comment 39

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v12

(In reply to Gavin Sharp from comment #38)
> Comment on attachment 550730 [details] [diff] [review]
> Patch v11
> 
> I thought of some other issues:
> - outer ID is not suitable for this, since different pages loaded in the
> same tab will have the same outer window ID. The patch for bug 612658 adds
> some innerID code to this, so you could just use that once it lands.

Done. I also added tests for making sure that timers with the same name have different values in different pages in the same tab, or in separate tabs.

> - there's no mechanism in place to remove timers added by pages that are
> unloaded without calling timeEnd. It might be best to cap the number of
> timers that a page can create, and also hook into the inner-window-destroyed
> notifications to clear out these timer references when the relevant inner
> window is destroyed - again, the patch in bug 612658 has some relevant code
> for that.

Done. I've set the maximum allowed number of timers in a page to 10000. It seems large enough to cover crazy use cases, and low enough to avoid memory issues.

Comment 40

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Diff between v11 and v12

A diff between the last two version of the patch to highlight the recent changes.

Comment 41

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v12 take 2

Oops! Apparently hg export doesn't respect the setting for 8 lines of context (among other things). This should be easier to discern.

Comment 42

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 556547 [details] [diff] [review]
Patch v12 take 2

Two things I noticed from a quick look:
- the l10n notes need a bit more detail (what gets inserted into the string variables?), and you should use positional arguments (e.g. %1$S, %2$S, etc.) so that locales that need to can control the order (even though that might be unlikely to be necessary in this case)
- does console.timeEnd("undefined") end a timer started using console.time()? this might need special-casing.

Comment 43

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v13

(In reply to Gavin Sharp from comment #42)
> Comment on attachment 556547 [details] [diff] [review]
> Patch v12 take 2
> 
> Two things I noticed from a quick look:
> - the l10n notes need a bit more detail (what gets inserted into the string
> variables?), and you should use positional arguments (e.g. %1$S, %2$S, etc.)
> so that locales that need to can control the order (even though that might
> be unlikely to be necessary in this case)

Fixed.

> - does console.timeEnd("undefined") end a timer started using
> console.time()? this might need special-casing.

Nope, calling time/timeEnd with no arguments does nothing, as in other browsers. console.timeEnd("undefined") does end a timer started with console.time("undefined") though.

Comment 44

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Diff between v12 and v13

The latest localization changes, for easier verification.

Comment 45

[:Gavin Sharp [email: [e-mail]]]

(In reply to Panos Astithas [:past] from comment #43)
> Nope, calling time/timeEnd with no arguments does nothing

Ah, indeed - I missed the !aName checks.

Comment 46

[Kevin Dangoor]

I believe this is just waiting on sr+. The last comment was from gavin, but as far as I can see the ball is in his court to say whether there are any sr-level concerns here.

This is the last bug in our efforts to have a console object implementation with all of the commonly used methods.

Comment 47

[Mark Finkle (:mfinkle) (use needinfo?)]

What can we do to get the ConsoleAPI changes on Firefox Mobile too? We have rudimentary support for window.console, but trying to follow desktop changes isn't easy.

File a new bug?

Comment 48

[Panos Astithas (he/him) [:past] (please ni?)]

(In reply to Mark Finkle (:mfinkle) from comment #47)
> What can we do to get the ConsoleAPI changes on Firefox Mobile too? We have
> rudimentary support for window.console, but trying to follow desktop changes
> isn't easy.

I've been meaning to look into the console support in Firefox Mobile for some time. In every one of these console improvements I made a conscious effort to keep as much stuff as possible in ConsoleAPI.js, which I believe is shared among desktop and mobile. Therefore it's only the HUDService changes that have to be implemented in the right place for mobile. Can you point me in the right direction here? And also, how do I find and play with the console in Firefox Mobile on my tablet?

> File a new bug?

That's a good idea. CC me too, please.

Comment 49

[Mark Finkle (:mfinkle) (use needinfo?)]

(In reply to Panos Astithas [:past] from comment #48)
> (In reply to Mark Finkle (:mfinkle) from comment #47)
> > What can we do to get the ConsoleAPI changes on Firefox Mobile too? We have
> > rudimentary support for window.console, but trying to follow desktop changes
> > isn't easy.
> 
> I've been meaning to look into the console support in Firefox Mobile for
> some time. In every one of these console improvements I made a conscious
> effort to keep as much stuff as possible in ConsoleAPI.js, which I believe
> is shared among desktop and mobile. Therefore it's only the HUDService
> changes that have to be implemented in the right place for mobile. Can you
> point me in the right direction here? And also, how do I find and play with
> the console in Firefox Mobile on my tablet?

Here is the console observer in Firefox Mobile. It just pushes text into the nsIConsoleService.

To see the Error Console in Firefox Mobile, just enable the pref in about:config (devtools.errorconsole.enabled) and go to the Settings pages (Prefs, Downloads, Add-ons) and you should see a new page there.

> > File a new bug?
> 
> That's a good idea. CC me too, please.

Bug 692535

Comment 50

[Kevin Dangoor]

Ping? Still waiting on sr, and it's been 2 months since Gavin's last comment (which was neither a + or -)

Comment 51

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 556793 [details] [diff] [review]
Patch v13

Sorry for the unreasonable delay. A few minor comments:

>diff --git a/browser/devtools/webconsole/test/browser/browser_webconsole_bug_658368_time_methods.js b/browser/devtools/webconsole/test/browser/browser_webconsole_bug_658368_time_methods.js

>+// This must be the same as MAX_PAGE_TIMERS in ConsoleAPI.js.
>+const MAX_PAGE_TIMERS = 10000;

This doesn't appear to be used in the test. Did you mean to add a test of the timer cap?

>diff --git a/dom/tests/browser/browser_ConsoleAPITests.js b/dom/tests/browser/browser_ConsoleAPITests.js

>+  EventUtils.synthesizeMouse(button, 2, 2, {}, gWindow);

Should favor synthesizeMouseAtCenter now (applies to multiple cases in this test).

>diff --git a/toolkit/locales/en-US/chrome/global/headsUpDisplay.properties b/toolkit/locales/en-US/chrome/global/headsUpDisplay.properties

>+# LOCALIZATION NOTE (timerStarted):
>+# These strings are used to display the results of console.time() and
>+# console.timeEnd() calls. The argument before the colon is the name of the
>+# timer, and the argument after the colon (in the case of timeEnd) is the
>+# duration of the timer in milliseconds.
>+timerStarted=%S: timer started
>+timeEnd=%1$S: %2$Sms

It would be clearer if you split the localization note in two (one for each string) and explicitly listed each argument's value (%S=name of timer, %1$S=name of timer, %2$S=number of milliseconds).

Comment 52

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Patch v14

(In reply to Gavin Sharp (use [e-mail] for email) from comment #51)
> Comment on attachment 556793 [details] [diff] [review] [diff] [details] [review]
> Patch v13
> 
> Sorry for the unreasonable delay. A few minor comments:
> 
> >diff --git a/browser/devtools/webconsole/test/browser/browser_webconsole_bug_658368_time_methods.js b/browser/devtools/webconsole/test/browser/browser_webconsole_bug_658368_time_methods.js
> 
> >+// This must be the same as MAX_PAGE_TIMERS in ConsoleAPI.js.
> >+const MAX_PAGE_TIMERS = 10000;
> 
> This doesn't appear to be used in the test. Did you mean to add a test of
> the timer cap?

Indeed, I had written such a test, but I left it out because it took a ridiculous amount of time to check a simple loop condition. I removed this const as well.

> >diff --git a/dom/tests/browser/browser_ConsoleAPITests.js b/dom/tests/browser/browser_ConsoleAPITests.js
> 
> >+  EventUtils.synthesizeMouse(button, 2, 2, {}, gWindow);
> 
> Should favor synthesizeMouseAtCenter now (applies to multiple cases in this
> test).

Done.

> >diff --git a/toolkit/locales/en-US/chrome/global/headsUpDisplay.properties b/toolkit/locales/en-US/chrome/global/headsUpDisplay.properties
> 
> >+# LOCALIZATION NOTE (timerStarted):
> >+# These strings are used to display the results of console.time() and
> >+# console.timeEnd() calls. The argument before the colon is the name of the
> >+# timer, and the argument after the colon (in the case of timeEnd) is the
> >+# duration of the timer in milliseconds.
> >+timerStarted=%S: timer started
> >+timeEnd=%1$S: %2$Sms
> 
> It would be clearer if you split the localization note in two (one for each
> string) and explicitly listed each argument's value (%S=name of timer,
> %1$S=name of timer, %2$S=number of milliseconds).

Done.

Thanks for the review!

Try build at: https://tbpl.mozilla.org/?tree=Try&rev=0d29ab93f64e

Comment 53

[Mozilla RelEng Bot]

Try run for 0d29ab93f64e is complete.
Detailed breakdown of the results available here:
    https://tbpl.mozilla.org/?tree=Try&rev=0d29ab93f64e
Results (out of 155 total builds):
    success: 150
    warnings: 5
Builds available at http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-0d29ab93f64e

Comment 54

[Rob Campbell [:rc] (:robcee)]

https://hg.mozilla.org/integration/fx-team/rev/3dae8be98e38

Comment 55

[Rob Campbell [:rc] (:robcee)]

https://hg.mozilla.org/mozilla-central/rev/3dae8be98e38

Comment 56

[Jean-Yves Perrier [:teoli]]

I've updated the documentation:
https://developer.mozilla.org/en/Using_the_Web_Console
and
https://developer.mozilla.org/en/Firefox_10_for_developers