Closed Bug 782751 Opened 12 years ago Closed 9 years ago

Implement the User Timing spec

Categories

(Core :: DOM: Core & HTML, defect)

Product:
Core
Component:
DOM: Core & HTML
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla38
Tracking Flags:
Tracking Status
firefox36 --- wontfix
firefox37 --- wontfix
firefox38 --- fixed
b2g-v2.2 --- fixed
b2g-master --- fixed

People

(Reporter: WeirdAl, Assigned: qdot)

References

(Depends on 1 open bug,
URL
)

Details

(Keywords: dev-doc-needed, Whiteboard: [systemsfe])

Attachments

(7 files, 9 obsolete files)

Patch 1 (v5) - User Timing API Implementation
25.84 KB, patch
baku
: review+
Details | Diff | Splinter Review
Patch 2 (v3) - User Timing API Mochitests (r=baku, carrying forward from v1)
17.30 KB, patch
baku
: feedback+
Details | Diff | Splinter Review
Patch 3 (v1) - User Timing API Web Platform Test Metadata update; a=TEST-ONLY
9.82 KB, patch
Details | Diff | Splinter Review
Patch 3 (b2g 2.2 uplift) - User Timing API Web Platform Test Metadata update; a=TEST-ONLY
8.27 KB, patch
bajaj
: approval-mozilla-b2g37+
Details | Diff | Splinter Review
Patch 2 (b2g 2.2 uplift, fixed) - User Timing API Mochitests; r=baku
17.98 KB, patch
bajaj
: approval-mozilla-b2g37+
Details | Diff | Splinter Review
Patch 1 (b2g 2.2 uplift, win build fixed, b2g-2.2 approved) - User Timing API Implementation; r=baku
25.26 KB, patch
Details | Diff | Splinter Review
Patch 4 (b2g 2.2 uplift) - User Timing API Web Platform Test Metadata fixes; a=TEST-ONLY
790 bytes, patch
Details | Diff | Splinter Review 
The User Timing spec is a prerequisite to the Performance Timeline spec, at least, as far as the hyperlinks in the latter indicate.
I got the dependencies backwards:  it's actually the other way around.
No longer blocks: 765933
Depends on: 765933
Any progress? This spec actual has Recommendation state:
http://www.w3.org/TR/2013/REC-user-timing-20131212/

Chrome and IE11 support it now, but Firefox still not.
The Performance Timeline spec *became* User Timing spec.
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → DUPLICATE
No longer depends on: 765933
Ignore comment 3, was mistaken about the page I was looking at. :/
Status: RESOLVED → REOPENED
Depends on: 765933
Resolution: DUPLICATE → ---
Assignee: nobody → kyle
Blocks: 1115130
Whiteboard: [systemsfe]
Just a quick update, development is progressing and I'm hoping to have this in for review by the end of the week. Development is happening at 

https://github.com/qdot/gecko-dev/tree/782751-user-timing

Basically, all functionality is in, I've finished most of the mochitests, it's down to making sure we have full spec coverage. Most of the difficulty there comes from the weirdness of having to translate mark names into navigationTiming properties, and making sure we convert times correctly.
Comment on attachment 8549696 [details] [diff] [review]
Patch 1 (v1) - User Timing API Implementation

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

Ok, r?'ing bz by advice of #content (blame ms2ger).

Pretty sure everything is solid, but things to watch for:

- Wonder if there's a better way of doing GetPerformanceTimingFromString, but not quite sure since these values need to be fetched at time of call since some of them may not be filled in yet (i.e. we might be trying to make user timing calls before LoadEnd). The spec requires us to convert mark names to navigationTiming properties for checking though, so maybe it's just gross since this is C++.

- I think I have the conversion from DOMTimeMillisec to DOMHighResTimeStamp correct, but would like extra eyes on that.
Attachment #8549696 - Flags: review?(bzbarsky)
Attachment #8549697 - Flags: review?(bzbarsky)
I'm not sure when I'll be able to get to this review.  Before the end of next week is pretty unlikely.
Ok. I'll shop it around a bit too then, thanks for the heads up.
ni?'ers: Looking for someone that could review this sooner, if you've got any ideas or could yourself.
Flags: needinfo?(overholt)
Flags: needinfo?(jst)
Flags: needinfo?(amarchesini)
I'm going to guess baku is your best bet here.
Flags: needinfo?(overholt)
(In reply to Andrew Overholt [:overholt] from comment #12)
> I'm going to guess baku is your best bet here.

Sure! Put your patches in my review queue. You will have them reviewed for this week.
Flags: needinfo?(amarchesini)
Attachment #8549696 - Flags: review?(bzbarsky) → review?(amarchesini)
Attachment #8549697 - Flags: review?(bzbarsky) → review?(amarchesini)
Comment on attachment 8549696 [details] [diff] [review]
Patch 1 (v1) - User Timing API Implementation

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

It looks good but there are small details here and there. I would like to see it again.
Plus, there are no mochitests but I haveen't checked if the second patch contains some tests yet.
Thanks!

::: dom/base/PerformanceEntry.h
@@ +20,5 @@
>    virtual ~PerformanceEntry();
>  
>  public:
> +  explicit PerformanceEntry(nsPerformance* aPerformance,
> +                            const nsAString& aName,

No 'explicit' if the number of args is != 1

::: dom/base/PerformanceMark.h
@@ +5,5 @@
> +
> +#ifndef mozilla_dom_performancemark_h___
> +#define mozilla_dom_performancemark_h___
> +
> +#include "PerformanceEntry.h"

mozilla/dom/PerformanceEntry.h

::: dom/base/PerformanceMeasure.cpp
@@ +15,5 @@
> +: PerformanceEntry(aPerformance, aName, NS_LITERAL_STRING("measure")),
> +  mStartTime(aStartTime),
> +  mDuration(aEndTime - aStartTime)
> +{
> +  MOZ_ASSERT(aPerformance, "Parent performance object should be provided");

MOZ_ASSERT(aEndTime >= aStartTime);

::: dom/base/nsContentUtils.h
@@ +1873,5 @@
>  
> +  /*
> +   * Returns true if the user timing APIs are enabled.
> +   */
> +  static bool IsUserTimingEnabled()

I guess we can get rid of this.

::: dom/base/nsPerformance.cpp
@@ +14,5 @@
>  #include "nsIURI.h"
>  #include "PerformanceEntry.h"
>  #include "PerformanceResourceTiming.h"
> +#include "PerformanceMark.h"
> +#include "PerformanceMeasure.h"

Alphabetic order.

@@ +26,2 @@
>  
>  using namespace mozilla;

using namespace mozilla::dom; and remove all the mozilla::dom:: and dom:: in this file.

@@ +505,5 @@
>  void
> +nsPerformance::ClearEntries(const mozilla::dom::Optional< nsAString >& aEntryName,
> +                            const nsAString& aEntryType) {
> +  uint32_t count = mEntries.Length();
> +  if (!count) return;

if (!count) {
  return;
}

@@ +510,5 @@
> +  do {
> +    count -= 1;
> +    if ((!aEntryName.WasPassed() ||
> +         (mEntries[count]->GetName().Equals(aEntryName.Value()))) &&
> +        (!aEntryType.IsEmpty() &&

This seems wrong. It seems that what you want is:

   if ((!aEntryName.WasPassed() ||
       mEntries[count]->GetName().Equals(aEntryName.Value())) &&
      (aEntryType.IsEmpty() ||
       mEntries[count]->GetEntryType().Equals(aEntryType))) {

@@ +514,5 @@
> +        (!aEntryType.IsEmpty() &&
> +         mEntries[count]->GetEntryType().Equals(aEntryType))) {
> +      mEntries.RemoveElementAt(count);
> +    }
> +  } while (count > 0);

This looks correct, but what about this:

for (uint32_t i = 0; i < mEntries.Length();) {
  if ((!aEntryName.WasPassed() ||
       mEntries[i]->GetName().Equals(aEntryName.Value())) &&
      (aEntryType.IsEmpty() ||
       mEntries[i]->GetEntryType().Equals(aEntryType))) {
    mEntries.RemoveElementAt(i);
  } else {
    ++i;
  }
}

@@ +523,5 @@
>  {
>    MOZ_ASSERT(NS_IsMainThread());
> +  ClearEntries(mozilla::dom::Optional< nsAString >(),
> +               NS_LITERAL_STRING("resource"));
> +  //mEntries.Clear();

Why this comment?

@@ +617,5 @@
>    return aElem1->StartTime() < aElem2->StartTime();
>  }
> +
> +void
> +nsPerformance::InsertPerformanceEntry(nsRefPtr<dom::PerformanceEntry> aEntry)

Actually, you don't use this method, right?
Plus, use PerformanceEntry* aEntry as argument.

@@ +620,5 @@
> +void
> +nsPerformance::InsertPerformanceEntry(nsRefPtr<dom::PerformanceEntry> aEntry)
> +{
> +  mEntries.InsertElementSorted(aEntry,
> +                               PerformanceEntryComparator());

Same line?

@@ +621,5 @@
> +nsPerformance::InsertPerformanceEntry(nsRefPtr<dom::PerformanceEntry> aEntry)
> +{
> +  mEntries.InsertElementSorted(aEntry,
> +                               PerformanceEntryComparator());
> +  if (mEntries.Length() >= mPrimaryBufferSize) {

This means that we still insert elements and we dispatch events... is this what the spec says?
Probably we want to do something like:

if (mEntries.Length() == mPrimaryBufferSize) {
  // some kind of warning...
  return;
}

mEntries.InsertElementSorted(...);
if (mEntries.Length() == mPrimaryBufferSize) {
  DispatchBufferFullEvent();
}

@@ +632,5 @@
> +nsPerformance::Mark(const nsAString& aName, ErrorResult& aRv)
> +{
> +  MOZ_ASSERT(NS_IsMainThread());
> +  // Check if user timing is prefed off.
> +  if (!nsContentUtils::IsUserTimingEnabled()) {

You don't need this check because WebIDL does it for you. But just in case, write a mochitest...

@@ +637,5 @@
> +    return;
> +  }
> +  // Don't add the entry if the buffer is full
> +  if (mEntries.Length() >= mPrimaryBufferSize) {
> +    return;

No error in this case?

@@ +645,5 @@
> +    aRv.Throw(NS_ERROR_DOM_SYNTAX_ERR);
> +    return;
> +  }
> +  nsRefPtr<dom::PerformanceMark> performanceMark =
> +    new dom::PerformanceMark(this, aName);

What about InsertPerformanceEntry() ?

@@ +659,5 @@
> +nsPerformance::ClearMarks(const mozilla::dom::Optional< nsAString >& aName)
> +{
> +  MOZ_ASSERT(NS_IsMainThread());
> +  // Check if user timing is prefed off.
> +  if (!nsContentUtils::IsUserTimingEnabled()) {

Remove this.

@@ +662,5 @@
> +  // Check if user timing is prefed off.
> +  if (!nsContentUtils::IsUserTimingEnabled()) {
> +    return;
> +  }
> +  nsString name;

nsAutoString

@@ +665,5 @@
> +  }
> +  nsString name;
> +  if (aName.WasPassed()) {
> +    name = aName.Value();
> +  }

Where do you use this 'name'?

@@ +667,5 @@
> +  if (aName.WasPassed()) {
> +    name = aName.Value();
> +  }
> +  ClearEntries(aName,
> +               NS_LITERAL_STRING("mark"));

This can stay in the same line.

@@ +678,5 @@
> +                       ErrorResult& aRv)
> +{
> +  MOZ_ASSERT(NS_IsMainThread());
> +  // Check if user timing is prefed off.
> +  if (!nsContentUtils::IsUserTimingEnabled()) {

Remove.

@@ +682,5 @@
> +  if (!nsContentUtils::IsUserTimingEnabled()) {
> +    return;
> +  }
> +  // Don't add the entry if the buffer is full
> +  if (mEntries.Length() >= mPrimaryBufferSize) {

Error?

@@ +695,5 @@
> +    return;
> +  }
> +
> +  mozilla::dom::Optional< nsAString > typeParam;
> +  nsString str = NS_LITERAL_STRING("mark");

nsAutoString

@@ +698,5 @@
> +  mozilla::dom::Optional< nsAString > typeParam;
> +  nsString str = NS_LITERAL_STRING("mark");
> +  typeParam = &str;
> +  if (aStartMark.WasPassed()) {
> +    nsTArray<nsRefPtr<PerformanceEntry>> arr;

nsAutoTArray

@@ +700,5 @@
> +  typeParam = &str;
> +  if (aStartMark.WasPassed()) {
> +    nsTArray<nsRefPtr<PerformanceEntry>> arr;
> +    GetEntriesByName(aStartMark.Value(), typeParam, arr);
> +    if (arr.Length() > 0) {

if (!arr.IsEmpty())

@@ +702,5 @@
> +    nsTArray<nsRefPtr<PerformanceEntry>> arr;
> +    GetEntriesByName(aStartMark.Value(), typeParam, arr);
> +    if (arr.Length() > 0) {
> +      startTime = arr[0]->StartTime();
> +    } else if (GetPerformanceTimingFromString(aStartMark.Value(), ts)) {

} else {
  if (!GetPerformanceTimingFromString(...)) {
    aRv.Throw(...SYNTAX_ERR);
    return;
  }

  if (!ts) {
    aRv.Throw(...INVALID_ACCESS_ERR);
    return;
  }

  startTime = ts;
}

@@ +713,5 @@
> +      return;
> +    }
> +  } else {
> +    startTime = mDOMTiming->GetNavigationStartHighRes();
> +  }

Just to be sure I would do:

MOZ_ASSERT(startTime);

because at this point we cannot have starTime == 0, right?

@@ +715,5 @@
> +  } else {
> +    startTime = mDOMTiming->GetNavigationStartHighRes();
> +  }
> +  if (aEndMark.WasPassed()) {
> +    nsTArray<nsRefPtr<PerformanceEntry>> arr;

nsAutoTArray

@@ +717,5 @@
> +  }
> +  if (aEndMark.WasPassed()) {
> +    nsTArray<nsRefPtr<PerformanceEntry>> arr;
> +    GetEntriesByName(aEndMark.Value(), typeParam, arr);
> +    if (arr.Length() > 0) {

if (!arr.IsEmpty()) {

@@ +719,5 @@
> +    nsTArray<nsRefPtr<PerformanceEntry>> arr;
> +    GetEntriesByName(aEndMark.Value(), typeParam, arr);
> +    if (arr.Length() > 0) {
> +      endTime = arr[0]->StartTime();
> +    } else if (GetPerformanceTimingFromString(aEndMark.Value(), ts)) {

Same logic as before. The basic idea is, keep the error throwing near the methods.

@@ +730,5 @@
> +      return;
> +    }
> +  } else {
> +    endTime = Now();
> +  }

MOZ_ASSERT(endTime); Makes sense?

@@ +733,5 @@
> +    endTime = Now();
> +  }
> +  nsRefPtr<dom::PerformanceMeasure> performanceMeasure =
> +    new dom::PerformanceMeasure(this, aName, startTime, endTime);
> +  mEntries.InsertElementSorted(performanceMeasure,

The famous method...

@@ +746,5 @@
> +nsPerformance::ClearMeasures(const mozilla::dom::Optional< nsAString >& aName)
> +{
> +  MOZ_ASSERT(NS_IsMainThread());
> +  // Check if user timing is prefed off.
> +  if (!nsContentUtils::IsUserTimingEnabled()) {

Remove.

@@ +749,5 @@
> +  // Check if user timing is prefed off.
> +  if (!nsContentUtils::IsUserTimingEnabled()) {
> +    return;
> +  }
> +  nsString name;

nsAutoString... but again, name is unused.

@@ +753,5 @@
> +  nsString name;
> +  if (aName.WasPassed()) {
> +    name = aName.Value();
> +  }
> +  ClearEntries(aName,

same line.

@@ +761,5 @@
> +DOMHighResTimeStamp
> +nsPerformance::ConvertDOMMilliSecToHighRes(DOMTimeMilliSec aTime) {
> +  // If the time we're trying to convert is equal to zero, it hasn't been set
> +  // yet so just return 0.
> +  if (aTime == 0) { return 0; }

if (!aTime) {
  return 0;
}

@@ +771,5 @@
> +                                              DOMHighResTimeStamp& aTimestamp)
> +{
> +  if (aProperty == NS_LITERAL_STRING("navigationStart")) {
> +    aTimestamp = GetDOMTiming()->GetNavigationStartHighRes();
> +    return true;

no } else { if after a 'return'. Just do:

if (foo) {
  bar;
  return true;
}

...

::: dom/base/nsPerformance.h
@@ +336,5 @@
>                  nsITimedChannel* timedChannel);
>    void ClearResourceTimings();
>    void SetResourceTimingBufferSize(uint64_t maxSize);
> +  void Mark(const nsAString& aName, mozilla::ErrorResult& aRv);
> +  void ClearMarks(const mozilla::dom::Optional< nsAString >& aName);

no extra spaces before and after <>, everywhere in this patch.

@@ +353,2 @@
>    void DispatchBufferFullEvent();
> +  void InsertPerformanceEntry(nsRefPtr<PerformanceEntry> aEntry);

PerformanceEntry*

::: dom/webidl/PerformanceMark.webidl
@@ +8,5 @@
> + */
> +
> +interface PerformanceMark : PerformanceEntry
> +{
> +  jsonifier;

same here.

::: dom/webidl/PerformanceMeasure.webidl
@@ +8,5 @@
> + */
> +
> +interface PerformanceMeasure : PerformanceEntry
> +{
> +  jsonifier;

In the spec URL I don't see this jsonifier.
Attachment #8549696 - Flags: review?(amarchesini) → review-
Comment on attachment 8549697 [details] [diff] [review]
Patch 2 (v1) - User Timing API Mochitests

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

Good, but we need more tests!

::: dom/base/test/test_performance_user_timing.html
@@ +19,5 @@
> +                 // Test mark addition
> +                 function () {
> +                     ok(true, "Running mark addition test");
> +                     performance.mark("test");
> +                     var marks = performance.getEntriesByType("mark");

Just do:
is(marks.length, 1, "Wrong number of marks!");

@@ +26,5 @@
> +                         return;
> +                     }
> +                     var mark = marks[0];
> +                     if (mark.name != "test") {
> +                         ok(false, "mark name not correct!");

here and everywhere else as well:

is(mark.name, 'test', 'mark name is not correct!');

@@ +63,5 @@
> +                 },
> +                 // Test single mark removal
> +                 function () {
> +                     ok(true, "Running single mark removal test");
> +                     performance.mark("test");

I would like to see:

1a. 0 'test' marks with other marks
2b. 0 'test' marks with no other marks
2a. 1 'test' mark with other marks
2b. 1 'test' mark with no other marks
3a. 2 or more 'test' marks with other marks
3b. 2 or more 'test' marks with no other marks.

just to test clearMarks fully.

@@ +84,5 @@
> +                     ok(true, "Running mark name collision test");
> +                     try {
> +                         performance.mark("navigationStart");
> +                         ok(false, "Mark name collision test failed, shouldn't make it here!");
> +                     } catch (e) {

check also the kind of exception.

@@ +119,5 @@
> +                 },
> +                 function () {
> +                     ok(true, "Running measure addition with only start time test");
> +                     performance.mark("test1");
> +                     performance.measure("test", "test1", undefined);

remove this 'undefined'.

@@ +137,5 @@
> +                 },
> +                 function () {
> +                     ok(true, "Running measure addition with only end time test");
> +                     performance.mark("test1");
> +                     performance.measure("test", undefined, "test1");

This acutally is not supported by the spec. We should file a bug for the spec and ask to change how the 'endTime' is managed. I read this:

    If neither the startMark nor the endMark argument is specified, measure() will store the duration as a DOMHighResTimeStamp from navigationStart to the current time.
    If the startMark argument is specified, but the endMark argument is not specified, measure() will store the duration as a DOMHighResTimeStamp from the most recent occurrence of the start mark to the current time.
    If both the startMark and endMark arguments are specified, measure() will store the duration as a DOMHighResTimeStamp from the most recent occurrence of the start mark to the most recent occurrence of the end mark.

@@ +227,5 @@
> +                     } catch(ex) {
> +                         ok(false, "Caught exception", ex);
> +                     }
> +                 }
> +             }

All the tests look good but I would like to have each test self-contained. I mean: testB should not depend on marks created by testA. What about if you clean all the marks after each test?

For instance I'm not 100% sure we do a test like:

performance.mark('a');
// some async operation.. maybe XHR:
var xhr = new XMLHttpRequest();
xhr.open(something);
xhr.onreadystatechange = function() {
  if (xhr.readystate == 4) {
       .. do some measure. It has to be > 0.
  }
}

plus, multiple marks with the same name. I wonder if the 'chosen' one for the measure is the last one all the time. Can you double check it with a mochitest?

Last test I would like to see if the mark and measure tests are shown in performance.entries()
Attachment #8549697 - Flags: review?(amarchesini) → review+
Flags: needinfo?(jst)
(In reply to Andrea Marchesini (:baku) from comment #14)
> ::: dom/base/PerformanceMeasure.cpp
> @@ +15,5 @@
> > +: PerformanceEntry(aPerformance, aName, NS_LITERAL_STRING("measure")),
> > +  mStartTime(aStartTime),
> > +  mDuration(aEndTime - aStartTime)
> > +{
> > +  MOZ_ASSERT(aPerformance, "Parent performance object should be provided");
> 
> MOZ_ASSERT(aEndTime >= aStartTime);

There's nothing in the Performance Timeline spec (http://www.w3.org/TR/2013/REC-performance-timeline-20131212/) saying we can't have a negative duration, and DOMHighResTimeStamp being a double supports negative times. Granted, I don't know why you'd /want/ that, but it could happen?

> ::: dom/base/nsContentUtils.h
> @@ +1873,5 @@
> >  
> > +  /*
> > +   * Returns true if the user timing APIs are enabled.
> > +   */
> > +  static bool IsUserTimingEnabled()
> 
> I guess we can get rid of this. 

Should I clean these up for Performance/Resource timing while we're at it? Never quite sure how much to clean when I encounter this stuff. :)


> This looks correct, but what about this:
> 
> for (uint32_t i = 0; i < mEntries.Length();) {
>   if ((!aEntryName.WasPassed() ||
>        mEntries[i]->GetName().Equals(aEntryName.Value())) &&
>       (aEntryType.IsEmpty() ||
>        mEntries[i]->GetEntryType().Equals(aEntryType))) {
>     mEntries.RemoveElementAt(i);
>   } else {
>     ++i;
>   }
> }

Hah, was wondering about this. I only saw one other do/while loop in the whole of m-c. :)

> @@ +637,5 @@
> > +    return;
> > +  }
> > +  // Don't add the entry if the buffer is full
> > +  if (mEntries.Length() >= mPrimaryBufferSize) {
> > +    return;
> 
> No error in this case?

I can do an NS_ERROR, but this case is weird, I'm not sure I could throw on it since the spec doesn't cover that?
From the official spec at http://www.w3.org/TR/user-timing/#monotonic-clock :

The time values stored within the interface must monotonically increase to ensure they are not affected by adjustments to the system clock. The difference between any two chronologically recorded time values must never be negative. The user agent must record the system clock at the beginning of the navigation and define subsequent time values in terms of a monotonic clock measuring time elapsed from the beginning of the navigation.
(In reply to :Eli Perelman from comment #17)
> From the official spec at http://www.w3.org/TR/user-timing/#monotonic-clock :
> 
> The time values stored within the interface must monotonically increase to
> ensure they are not affected by adjustments to the system clock. The
> difference between any two chronologically recorded time values must never
> be negative. The user agent must record the system clock at the beginning of
> the navigation and define subsequent time values in terms of a monotonic
> clock measuring time elapsed from the beginning of the navigation.

Hmm. That seems a little tenuous for the scope of the issue, since we're talking about a duration of two marks specified by the user, not by polling the system clock, but sure, I'll go with it and add the assert.
Ah I see, we're talking about `.measure`. Yeah, from what I see in the spec there's nothing preventing this:

```js
performance.mark('A');
performance.mark('B');
performance.measure('delta', 'B', 'A');

performance.getEntriesByType('measure')[0]; // negative PerformanceMeasure#duration
```

Testing this out in Chrome, it also allows this, delivering a negative duration.
Annnnd out the assert goes then! Should probably also file this as a spec clarification.
(In reply to Andrea Marchesini (:baku) from comment #15)

> @@ +137,5 @@
> > +                 },
> > +                 function () {
> > +                     ok(true, "Running measure addition with only end time test");
> > +                     performance.mark("test1");
> > +                     performance.measure("test", undefined, "test1");
> 
> This acutally is not supported by the spec. We should file a bug for the
> spec and ask to change how the 'endTime' is managed. I read this:

After talking to :Eli, This is supported by the spec, it's just not laid out in the description of the method. If you look at the description of the startMark parameter:

in startMark type of DOMString
[optional] The name of the start mark.
If specified, the most recent DOMHighResTimeStamp time value of the start mark is used.
If not specified, navigationStart is used.

So that handles this case for us.
(In reply to Andrea Marchesini (:baku) from comment #15)

> plus, multiple marks with the same name. I wonder if the 'chosen' one for
> the measure is the last one all the time. Can you double check it with a
> mochitest?

So the spec says we can "reuse" mark/measure names, which is kind of hard to translate. Does that mean we still only have one mark named any certain thing, and if we call performance.mark with that name again, we erase the previous mark of that name? Or do we keep all marks around until some sort of clearing function is called or the page is navigated away from?
Note to self, Eli pointed out that the spec repo has compliance tests too: https://github.com/w3c/web-platform-tests/tree/master/user-timing
New patch with review comments addressed.
Attachment #8549696 - Attachment is obsolete: true
Attachment #8552188 - Flags: review?(amarchesini)
Depends on: 1124165
Comment on attachment 8552188 [details] [diff] [review]
Patch 1 (v2) - User Timing API Implementation

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

It's almost great! Can I see it 1 more time with this list of strings instead GetPerofrmanceTimingFromString?
maybe you want a better name than HasPerformanceTimingAttribute. I'm really bad with names.

::: dom/base/nsContentUtils.h
@@ +2330,4 @@
>    static uint32_t sHandlingInputTimeout;
>    static bool sIsPerformanceTimingEnabled;
>    static bool sIsResourceTimingEnabled;
> +  static bool sIsUserTimingEnabled;

Remove this.

::: dom/base/nsPerformance.cpp
@@ +503,4 @@
>  }
>  
>  void
> +nsPerformance::ClearEntries(const Optional< nsAString >& aEntryName,

remove extra spaces before and after <> here and in the rest of the patch.

@@ +522,4 @@
>  nsPerformance::ClearResourceTimings()
>  {
>    MOZ_ASSERT(NS_IsMainThread());
> +  ClearEntries(Optional< nsAString >(),

ditto.

@@ +613,5 @@
>  }
> +
> +void
> +nsPerformance::InsertPerformanceEntry(PerformanceEntry* aEntry)
> +{

MOZ_ASSERT(aEntry);

Plus, let's do the check about the size in any other methods and here add:

MOZ_ASSERT(mEntries.Length() < mPrimaryBufferSize);

@@ +636,5 @@
> +    NS_ERROR("Performance Entry buffer size maximum reached!");
> +    return;
> +  }
> +  DOMHighResTimeStamp ts;
> +  if (GetPerformanceTimingFromString(aName, ts)) {

I don't like the fact that you are actually calculating the performance timing because you don't need it.
What about if you do:

bool
nsPerformance::HasPerformanceTimingAttribute(const nsAString& aName)
{
  static const char* attributes[] = { "navigationStart", "foobar", nullptr };

  for (uint32_t i = 0; attributes[i]; ++i) {
    if (!aName.EqualsASCII(attributes[i])) {
      return false;
    }
  }
  return true;
}

This code will be removed when bug 1124165 is fixed. Add a comment.

@@ +654,5 @@
> +}
> +
> +void
> +nsPerformance::Measure(const nsAString& aName,
> +                       const Optional< nsAString >& aStartMark,

ditto

@@ +673,5 @@
> +    aRv.Throw(NS_ERROR_DOM_SYNTAX_ERR);
> +    return;
> +  }
> +
> +  Optional< nsAString > typeParam;

ditto

@@ +674,5 @@
> +    return;
> +  }
> +
> +  Optional< nsAString > typeParam;
> +  nsString str = NS_LITERAL_STRING("mark");

nsAutoString

@@ +676,5 @@
> +
> +  Optional< nsAString > typeParam;
> +  nsString str = NS_LITERAL_STRING("mark");
> +  typeParam = &str;
> +  if (aStartMark.WasPassed()) {

Just because what you do with aStartMark and aEndMark is similar, what about if you create an helper method and then do:

DOMHighRestTimeStamp startTime = YourHelperMethod(aStartTime, aRv);
if (NS_WARN_IF(aRv.Failed())) {
  return;
}

DOMHighRestTimeStamp endTime = YourHelperMethod(aEndTime, aRv);
if (NS_WARN_IF(aRv.Failed())) {
  return;
}

@@ +722,5 @@
> +  InsertPerformanceEntry(performanceMeasure);
> +}
> +
> +void
> +nsPerformance::ClearMeasures(const Optional< nsAString >& aName)

ditto
Attachment #8552188 - Flags: review?(amarchesini) → review-
Plus, add a test to check that all the non-valid mark names actually throw exceptions.
Made all recommended review changes.
Attachment #8552188 - Attachment is obsolete: true
Attachment #8553956 - Flags: review?(amarchesini)
Hmm, ok, interesting problem found when updating the mochitests. We have jsonifier on PerformanceTiming, meaning the name toJSON shows up when trying to iterate through property names. This is due to bug 1047878, where we decided to go against spec and add jsonifier. So should we add toJSON to the list of unallowable mark names?
Er, sorry, that's bug 1047848
Comment on attachment 8553956 [details] [diff] [review]
Patch 1 (v3) - User Timing API Implementation

Ok, this patch doesn't take into account that multiple marks/measures of the same name can exist (as indirectly per the spec, where "most recent occurrence" is referred to multiple times). Still need to fix that and add tests.
Attachment #8553956 - Flags: review?(amarchesini)
Updated patch to make new mochitests pass. Still needs multiple mark/measure fix.
Attachment #8553956 - Attachment is obsolete: true
Cleaned up mochitests, now more robust. Still need multiple mark/measure tests.
Attachment #8549697 - Attachment is obsolete: true
> So should we add toJSON to the list of unallowable mark names?

What does IE do?  It has a toJSON as well, right?

In general, though, I don't think we should.  The idea of disallowing existing names from being used as custom mark names is that those names can appear in timing records, right?  The fact that they happen to be members of this interface is just a coincidence (and it would be nice if the spec were not depending on this coincidence).
Flags: needinfo?(kyle)
Yeah, I agree I think I was probably reading rules into the spec that aren't actually there. Will leave toJSON available.
Flags: needinfo?(kyle)
> I think I was probably reading rules into the spec that aren't actually there

No, you were reading exactly what the spec says. But the spec doesn't say what it means.  Please raise a spec issue about this exact problem or let me know and I can do it, I guess (I've been trying to not be involved with this working group anymore, but if it's really needed...).
Flags: needinfo?(kyle)
Measure function now uses latest version of mark for measure calculation
Attachment #8554073 - Attachment is obsolete: true
Attachment #8554822 - Flags: review?(amarchesini)
Added more tests, including multiple marks, and making sure measure uses the correct mark when multiple are available. Already r+'d, but putting in for fb because it also addresses comments made in the r+ review.
Attachment #8554074 - Attachment is obsolete: true
Attachment #8554827 - Flags: feedback?(amarchesini)
Comment on attachment 8554822 [details] [diff] [review]
Patch 1 (v5) - User Timing API Implementation

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

::: dom/base/nsPerformance.cpp
@@ +22,4 @@
>  #include "mozilla/TimeStamp.h"
>  #include "nsThreadUtils.h"
>  #include "nsILoadInfo.h"
> +#include "mozilla/ErrorResult.h"

alphabetic order. Move it up.

@@ +26,2 @@
>  
> +using namespace mozilla::dom;

using namespace mozilla;
using namespace mozilla:dom;

@@ +634,5 @@
> +{
> +  MOZ_ASSERT(NS_IsMainThread());
> +  // Don't add the entry if the buffer is full
> +  if (mEntries.Length() >= mPrimaryBufferSize) {
> +    NS_ERROR("Performance Entry buffer size maximum reached!");

NS_WARNING is ok, here and everywhere.

@@ +661,5 @@
> +  nsAutoTArray<nsRefPtr<PerformanceEntry>, 1> arr;
> +  DOMHighResTimeStamp ts;
> +  Optional<nsAString> typeParam;
> +  nsAutoString str;
> +  str = NS_LITERAL_STRING("mark");

nsAutoString str;
str.AssignLiteral("mark"); or AssignASCII

@@ +751,5 @@
> +     "redirectEnd", "fetchStart", "domainLookupStart", "domainLookupEnd",
> +     "connectStart", "connectEnd", "requestStart", "responseStart",
> +     "responseEnd", "domLoading", "domInteractive", "domContentLoadedEventStart",
> +     "domContentLoadedEventEnd", "domComplete", "loadEventStart",
> +     "loadEventEnd"};

nullptr at the end.

@@ +763,5 @@
> +}
> +
> +DOMHighResTimeStamp
> +nsPerformance::GetPerformanceTimingFromString(const nsAString& aProperty)
> +{

Just to be 100% sure this method and IsPerformanceTimingAttriubte are in sync, do:

if (!IsPerformanceTimingAttribute(aProperty)) {
  return 0;
}

and ath the end of this list of 'if()' statement do:

MOZ_CRASH("IsPerformanceTimingAttribute and GetPerformanceTimingFromString are out of sync");
Attachment #8554822 - Flags: review?(amarchesini) → review+
Comment on attachment 8554827 [details] [diff] [review]
Patch 2 (v3) - User Timing API Mochitests (r=baku, carrying forward from v1)

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

lgtm. Maybe add something async.
Attachment #8554827 - Flags: feedback?(amarchesini) → feedback+
Kyle, did you address what I asked you for in comment 35?
Flags: needinfo?(kyle)
Agh, sorry, got involved in reviews and missed that. Will raise now while also trying to get this ready to land, since that try was awfully colorful.
Flags: needinfo?(kyle)
And so the "oops..." iteration begins. So far (todo list for myself to fix tomorrow):

- Had to fix missing header for nsDOMAttributeMap, introduced in bug 1075702, flared up here because I changed the unified build order
- According to last try, looks like there's also an issue in nsFrameMessageManager on windows, possibly due to unified build order
- Forgot to update test_interfaces in mochitest for new public exposure of PerformanceMark/Measure/etc interfaces
- Times on Android API11 are equal between two timestamps taken one right after the other, not increasing. Not sure what to do about this case.
Oh and:

- W3C Web Platform tests completely failing
A quick update to Comment 28, the bug for adding toJSON to PerformanceTiming is bug 760851.
Eli is helping take care of the spec issue mentioned by bz in Comment 35

http://lists.w3.org/Archives/Public/public-web-perf/2015Jan/0070.html
Updating our metadata for the User Timing web platform tests, since these will no longer fail. Leaving in a couple of the expected fails on object creation, as the tests do not yet reflect some updates to the WebIDL spec.
New try run, now with fixes for:

- Had to fix missing header for nsDOMAttributeMap, introduced in bug 1075702, flared up here because I changed the unified build order
- Forgot to update test_interfaces in mochitest for new public exposure of PerformanceMark/Measure/etc interfaces
- W3C Web Platform tests completely failing

New issues found and fixed:
- Accessing mTiming member of nsPerformance before it was initialized, which the web platform tests caught via crashing
- Changed when we convert from DOMTimeMilliSec to DOMHighResTimeStamp, so we stay in line with the spec (this was causing failures in web platform tests)

Things that I'm not sure whether I've fixed:

- nsFrameMessageManager on windows having compilation issues
- Times on Android API11 are equal between two timestamps taken one right after the other, not increasing

https://treeherder.mozilla.org/#/jobs?repo=try&revision=9d9b283b0c8b
https://tbpl.mozilla.org/?tree=Try&rev=9d9b283b0c8b
New try run:

- nsFrameMessageManager issue from earlier seems to have fixed itself? There was hg errors in that log anyways.
- Fixed error in monotonicity tests that was causing Android to fail (needed >= 0, not > 0)

https://treeherder.mozilla.org/#/jobs?repo=try&revision=846808eaf20b
https://tbpl.mozilla.org/?tree=Try&rev=846808eaf20b

Now down to fixing issues on Windows XP with mark timing tests, which I'm going to disable because they work on Windows 7 and 8, and the measure tests that do basically the same thing also work on XP? They're just falling slightly outside of the timing range. May also put in pull request to w3c repo up the timing boundaries on the tests.
Backed out in https://hg.mozilla.org/integration/mozilla-inbound/rev/70bb61e6791b because no plan ever survives contact with the enemy.
Looks like the web platform timing tests fail intermittently on more windows platforms than just XP, so will expand that and update bug 1127392.

The android test that failed is the same problem that I was having earlier, where two mark times can equal each other because of how the android clock updates. Need to change that to >= 0. Will run trys again tomorrow to sort this out and hopefully land.
Due to bug 1127468 landing right before I landed this, the idl tests in web platform now work, causing web-platform-4's to orange. This is fixed in bug 1127948, which I just landed.
Unfortunately, the |TEST-UNEXPECTED-ERROR | test_clock_set_alarm.py TestClockSetAlarm.test_clock_set_alarm | TimeoutException: TimeoutException: Timed out after 10.1 seconds| failures from your Try push weren't resolved before pushing. Backed out.
https://hg.mozilla.org/integration/mozilla-inbound/rev/fd1c6005059b
Oooook. Well, come to find out, the clock app in gaia is using user timing polyfill, and now something isn't failing gracefully when the real API comes in, hence the gaia error. Debugging now.

Not sure why windows is continuing to fail web platform tests, other than the threshold issues continuing.
Depends on: 1128180
Blocks: 1129041
Ok. Gaia patches are in, and I disabled measure tests on windows too (they're coming in like 10ms higher than the threshold, which isn't enough to signify complete breakage).

Try at:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=f45ba225ff9b
https://tbpl.mozilla.org/?tree=Try&rev=f45ba225ff9b

Once the windows retriggers are done, I'll try landing to m-i. Yet again. :)
https://hg.mozilla.org/mozilla-central/rev/9b0c94f564f3
https://hg.mozilla.org/mozilla-central/rev/3183962fbeb0
https://hg.mozilla.org/mozilla-central/rev/0fff984a8556
Status: REOPENED → RESOLVED
Closed: 10 years ago → 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla38
NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): bug 782751
User impact if declined: No user timing API
Testing completed: Mochitests/Web Platform tests in bug, try run
Risk to taking this patch (and alternatives if risky): Little if any
String or UUID changes made by this patch: None
Attachment #8577318 - Flags: approval-mozilla-b2g37?
NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): bug 782751
User impact if declined: No user timing API
Testing completed: Mochitests/Web Platform tests in bug, try run
Risk to taking this patch (and alternatives if risky): Little if any
String or UUID changes made by this patch: None
Attachment #8577320 - Flags: approval-mozilla-b2g37?
NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): bug 782751
User impact if declined: No user timing API
Testing completed: Mochitests/Web Platform tests in bug, try run
Risk to taking this patch (and alternatives if risky): Little if any
String or UUID changes made by this patch: None
Attachment #8577321 - Flags: approval-mozilla-b2g37?
Ok well I have no idea what's up with try, it keeps failing during configure on some sort of sandbox issue? The build is working for me locally though.
:fabrice mentioned he'll check with kyle on the try errors so holding off approval here till we get that sorted out.
Missed checking in some files when making new patches, didn't see the error messages when reading logs on try, hence the confusion. Fixed, new try:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=41c6abe46c37
Fixing earlier patch for v2.2 uplift
Attachment #8577318 - Attachment is obsolete: true
Attachment #8577318 - Flags: approval-mozilla-b2g37?
Attachment #8577527 - Flags: approval-mozilla-b2g37?

        Attachment #8577320 -
        Attachment is obsolete: true

        Attachment #8577320 -
        Flags: approval-mozilla-b2g37?

        Attachment #8577528 -
        Flags: approval-mozilla-b2g37?

    
    

    
  
Ok, this is broken on 2.2 with the same FrameMessageManager issue I reported earlier, which magically fixed itself on master. How badly do we want this in 2.2? This landed 2 days after the branch and no one seemed to care, so deciding we need it 6 /weeks/ later seems silly.

    
    

    
  
(In reply to Kyle Machulis [:kmachulis] [:qdot] (USE NEEDINFO?) from comment #72)
> Ok, this is broken on 2.2 with the same FrameMessageManager issue I reported
> earlier, which magically fixed itself on master. How badly do we want this
> in 2.2? This landed 2 days after the branch and no one seemed to care, so
> deciding we need it 6 /weeks/ later seems silly.

I am not sure of why the timing slipped but Eli can comment here. The point here is we need raptor for fxos 2.2 and eli mentioned your patches implement the user timing api which it uses uses to build deltas between performance marker, so we did nto have much choice. Between not having raptor for a release like that 2.2 that is long supported this year vs uplifting this, I think doing the uplift here benefits us all.

Thanks for the test fixes, I'll a+ this to land now.

        Attachment #8577321 -
        Flags: approval-mozilla-b2g37? → approval-mozilla-b2g37+

        Attachment #8577527 -
        Flags: approval-mozilla-b2g37? → approval-mozilla-b2g37+

        Attachment #8577528 -
        Flags: approval-mozilla-b2g37? → approval-mozilla-b2g37+

    
    

    
  
Ok, as I suspected, did a local non-unified windows build and things built fine. Not real sure how to fix this. I'll see if I can figure out where the symbol is coming from, if not, I'll just disable this on windows in the uplift patches.

    
    

    
  
Ok, just removed nsFrameMessageManager from unified sources (as happened in bug 917322 patch 11 on master), things now build fine locally. New try at:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=4eff08de4107

Also updating patch in bug, pretty sure it'll be ready for uplift now.

    
    

    
  
Ok, to land this cleanly to v2.2, we'll need to land the following bugs at once:

- Bug 782751
- Bug 1129041 (fixes gaia clock issues, currently awaiting 2.2 approval)
- Bug 1129497 (fixes w-p-t issues, TEST_ONLY)

We'll also need to make sure that 2.2 gecko points to the gaia with Bug 1129041 applied, otherwise we'll continue failing gaia.

I'll update this once Bug 1129041 gets approval and we can try again.
Flags: needinfo?(kyle)

    
    

    
  
Now that bug 1128180 has landed, we are free to start landing the Gecko User Timing patches. Once those are done, we are free to land a Gaia v2.2 patch which will comprise the changes made to master in bug 1129041.

    
    

    
  
https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/2e85ba4545b0
https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/be320a9c6aae
https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/7fc5ffbc2490

I landed this without bug 1129497 for now because it didn't apply cleanly. However, I'm going to let w-p-t burn for now as known failures (since it's an issue with the tests rather than the code itself). I've needinfo'd jgraham over in that bug for assistance on getting the harness updated to properly solve the failures.

          status-b2g-v2.2:
          affected → fixed

    
    

    
  
Ok, Patch 4 should hopefully fix the w-p-t issues we're seeing.
Flags: needinfo?(ryanvm)

    
  
Depends on: 1192787
Component: DOM → DOM: Core & HTML

          You need to log in
          before you can comment on or make changes to this bug.
        






  

    
  







  

    

      
Attachment

      

      
      
      
      
    

    

      

        

          

            
General

            

              Creator: 



            

            
Created: 

            
Updated: 

            
Size: