Output logging metadata from User Timing marks and measures

RESOLVED FIXED in Firefox 38, Firefox OS v2.2

Status

()

Core
DOM
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: Eli, Assigned: qdot)

Tracking

({dev-doc-needed})

Trunk
mozilla38
dev-doc-needed
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox36 wontfix, firefox37 wontfix, firefox38 fixed, b2g-v2.2 fixed, b2g-master fixed)

Details

(Whiteboard: [systemsfe])

Attachments

(2 attachments)

(Reporter)

Description

3 years ago
Decoupled performance testing on Firefox OS currently depends on reading marks and measures metadata from logging to rebuild timelines. Specifically, this is how logging currently takes place from within Gaia (in JS):

```
var message = 'Performance Entry: ' +
  entry.entryType + '|' +
  entry.name + '|' +
  entry.startTime + '|' +
  entry.duration + '|' +
  (entry.time || 0);

console.log(message);
```

When the Gecko implementation lands in bug 782751, we should have access to this same metadata in the logs, although I'm sure the format will change.

Also a note about `entry.time`: for each mark and measure created, we generate a Unix epoch via `Date.now()` in order to correlate markers between processes, e.g. between System, Homescreen, and individual apps. We would also need an epoch timestamp to be output to the logs with the rest of the standard entry metadata.

Feel free to ni? me with any questions.
Whiteboard: [systemsfe]
From discussion with Eli on IRC:

Plan is to make the throw a message out via PR_LOG or some other logging mechanism, and it will only do so when a certain pref is set.

Also, it should attach the origin of the window requesting the mark/measure.
(Reporter)

Updated

3 years ago
Blocks: 1129687
Created attachment 8559519 [details] [diff] [review]
Patch 1 (v1) - Add log output for User Timing API

Just adds a pref and a print statement that goes to either stderr or android log, depending on the platform.
Attachment #8559519 - Flags: review?(amarchesini)
Created attachment 8559529 [details] [review]
[PullReq] qdot:1115130-user-timing-logging to mozilla-b2g:master
(Reporter)

Comment 4

3 years ago
Comment on attachment 8559529 [details] [review]
[PullReq] qdot:1115130-user-timing-logging to mozilla-b2g:master

r+ with nit addressed.
Attachment #8559529 - Flags: review?(eperelman) → review+
Comment on attachment 8559519 [details] [diff] [review]
Patch 1 (v1) - Add log output for User Timing API

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

::: dom/base/nsPerformance.cpp
@@ +631,5 @@
>      NS_WARNING("Performance Entry buffer size maximum reached!");
>      return;
>    }
> +  if (aShouldPrint && nsContentUtils::IsUserTimingPrintingEnabled()) {
> +    nsCString uri;

nsAutoCString

@@ +632,5 @@
>      return;
>    }
> +  if (aShouldPrint && nsContentUtils::IsUserTimingPrintingEnabled()) {
> +    nsCString uri;
> +    mWindow->GetDocumentURI()->GetHost(uri);

nsresult rv = ... and check the error code.

@@ +633,5 @@
>    }
> +  if (aShouldPrint && nsContentUtils::IsUserTimingPrintingEnabled()) {
> +    nsCString uri;
> +    mWindow->GetDocumentURI()->GetHost(uri);
> +    LOG("Performance Entry: %s|%s|%s|%f|%f|%lld\n",

can you something else than LOG? I don't like the undef LOG ...

@@ +742,5 @@
>    }
>    nsRefPtr<PerformanceMeasure> performanceMeasure =
>      new PerformanceMeasure(this, aName, startTime, endTime);
> +  InsertPerformanceEntry(performanceMeasure, true);
> +  if (nsContentUtils::IsUserTimingPrintingEnabled()) {

... ?

::: dom/base/nsPerformance.h
@@ +353,4 @@
>    DOMTimeMilliSec GetPerformanceTimingFromString(const nsAString& aTimingName);
>    DOMHighResTimeStamp ConvertDOMMilliSecToHighRes(const DOMTimeMilliSec aTime);
>    void DispatchBufferFullEvent();
> +  void InsertPerformanceEntry(PerformanceEntry* aEntry, bool aShouldPrint);

this should be mozilla::dom::PerformanceEntry right?
Attachment #8559519 - Flags: review?(amarchesini) → review+
(In reply to Andrea Marchesini (:baku) from comment #5)
> this should be mozilla::dom::PerformanceEntry right?

It is. It gets typedef'd to PerformanceEntry in the class definition.
Oops. Thought I had Werror turned on locally too, guess that wasn't the case. Fixed printf formatting, running try at 

https://tbpl.mozilla.org/?tree=Try&rev=ad41f54afbab
https://hg.mozilla.org/mozilla-central/rev/8a97a4fd18a9
Status: NEW → RESOLVED
Last Resolved: 3 years ago
status-firefox38: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla38
Comment on attachment 8559519 [details] [diff] [review]
Patch 1 (v1) - Add log output for User Timing API

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: Raptor won't work with user timing API
Testing completed: Been in master for 6 weeks 
Risk to taking this patch (and alternatives if risky): None
String or UUID changes made by this patch: None
Attachment #8559519 - Flags: approval-mozilla-b2g37?
Comment on attachment 8559529 [details] [review]
[PullReq] qdot:1115130-user-timing-logging to mozilla-b2g:master

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: Raptor won't work with user timing API
Testing completed: Been in master for 6 weeks 
Risk to taking this patch (and alternatives if risky): None
String or UUID changes made by this patch: None
Attachment #8559529 - Flags: approval-mozilla-b2g37?

Updated

3 years ago
Attachment #8559519 - Flags: approval-mozilla-b2g37? → approval-mozilla-b2g37+

Updated

3 years ago
Attachment #8559529 - Flags: approval-mozilla-b2g37? → approval-mozilla-b2g37+
https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/92d315086242

v2.2: https://github.com/mozilla-b2g/gaia/commit/a50f961a839fe2f13de951eac674cb5509ccad64
status-b2g-v2.2: --- → fixed
status-b2g-master: --- → fixed
status-firefox36: --- → wontfix
status-firefox37: --- → wontfix
You need to log in before you can comment on or make changes to this bug.