1156857 - Histograms seem to be gone in the child payload.

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect)

Description

[José Antonio Olivera Ortega [:jaoo]]

While working on bug 1115820 I've seen the histograms are gone in the child payload (no childPayloads[N].histograms).

Comment 1

[Georg Fritzsche [:gfritzsche]]

For testing we should be able to use e10s xpcshell tests:
https://dxr.mozilla.org/mozilla-central/search?q=run_test_in_child&case=true

Comment 2

[Georg Fritzsche [:gfritzsche]]

Apparently after bug 1100501 we are not initializing the StatisticsRecorder in child processes anymore.

Comment 3

[Jim Mathies [:jimm]]

I can take this if need be. Are you planning on working on this soon Georg?

Comment 4

[Georg Fritzsche [:gfritzsche]]

It's fine and an easy fix now that i know what caused it.
I'm just unsure where best to add the initializer. Is ScopedXREEmbed ok?

Comment 5

[Georg Fritzsche [:gfritzsche]]

Per IRC around here is better:
http://mxr.mozilla.org/mozilla-central/source/toolkit/xre/nsEmbedFunctions.cpp#142

Comment 6

[Georg Fritzsche [:gfritzsche]]

Attachment: Fix StatisticsRecorder not being initialized in content processes

Comment 7

[Jim Mathies [:jimm]]

Comment on attachment 8598679 [details] [diff] [review]
Fix StatisticsRecorder not being initialized in content processes

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

::: toolkit/xre/nsEmbedFunctions.cpp
@@ +146,5 @@
>  		   nsIFile *aAppDirectory,
>  		   nsIDirectoryServiceProvider *aAppDirProvider)
>  {
> +  // This is needed by Telemetry to initialize histogram collection.
> +  gStatisticsRecorder = MakeUnique<base::StatisticsRecorder>();

I think we want to move this below the sInitCounter check which returns early.

Comment 8

[Georg Fritzsche [:gfritzsche]]

Attachment: Make xpcshells run_test_in_child() and do_await_remote_message() return promises

Simple patch - this makes the xpchell head.js IPC helpers return promises. do_await_remote_message() message is trivial to change - only test_geolocation_reset_accuracy.js uses it and is fine with the change. run_test_in_child() has more tests already depending on the do_test_finished() call and the callback arg, so i'm leaving that for now.

Comment 9

[Georg Fritzsche [:gfritzsche]]

Attachment: Add test coverage for e10s child histogram collection

Roberto, can you review this?

Comment 10

[(not currently active) Ted Mielczarek]

Comment on attachment 8599256 [details] [diff] [review]
Make xpcshells run_test_in_child() and do_await_remote_message() return promises

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

In general I'm pro-Promise, but I think we should be using Promise directly and not any jsm wrappers.

::: testing/xpcshell/head.js
@@ +1246,2 @@
>  {
> +  var deferred = _PromiseUtils.defer();

PromiseUtils just seems to use ES6 Promises, so I think you should just use them directly:
https://dxr.mozilla.org/mozilla-central/source/toolkit/modules/PromiseUtils.jsm#27

That would look something like:
return new Promise((resolve, reject) => {
  do_load_child_test_harness();
  // ...
  sendCommand(//...,
              () => {
    resolve();
    //...
  }
}
});

You could instead make this function call itself recursively, like
if (typeof optionalCallback == 'undefined') {
  return new Promise((resolve, reject) => {
    run_test_in_child(testFile, () => { resolve(); do_test_finished(); });
  });
}
// Existing rest of function.

...and not return a Promise when a callback is passed.

Comment 11

[Georg Fritzsche [:gfritzsche]]

Attachment: Make xpcshells run_test_in_child() and do_await_remote_message() return promises

Ok - i usually much prefer the readability with defer(), but in this case it's definitely simple enough.

Comment 12

[Georg Fritzsche [:gfritzsche]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=798793f15041

Comment 13

[Pulsebot]

https://hg.mozilla.org/integration/fx-team/rev/41b2612eba71

Comment 14

[Roberto Agostino Vitillo (:rvitillo)]

Comment on attachment 8599262 [details] [diff] [review]
Add test coverage for e10s child histogram collection

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

::: toolkit/components/telemetry/tests/unit/head.js
@@ +189,5 @@
> +  Services.prefs.setCharPref("toolkit.telemetry.log.level", "Trace");
> +  // Telemetry archiving should be on.
> +  Services.prefs.setBoolPref("toolkit.telemetry.archive.enabled", true);
> +}
> +

As discussed on IRC, we should make sure that changing the logging level is reflected both in the parent and the children, no matter when it happens.

::: toolkit/components/telemetry/tests/unit/test_ChildHistograms.js
@@ +81,5 @@
> +  Assert.ok("keyedHistograms" in payload.childPayloads[0], "Child payload should have keyed histograms.");
> +  check_histogram_values(payload.childPayloads[0]);
> +
> +  do_test_finished();
> +});

Could you also test registerAddonHistogram and getAddonHistogram in the child?

Comment 15

[Georg Fritzsche [:gfritzsche]]

(In reply to Roberto Agostino Vitillo (:rvitillo) from comment #14)
> Comment on attachment 8599262 [details] [diff] [review]
> Add test coverage for e10s child histogram collection
> 
> Review of attachment 8599262 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: toolkit/components/telemetry/tests/unit/head.js
> @@ +189,5 @@
> > +  Services.prefs.setCharPref("toolkit.telemetry.log.level", "Trace");
> > +  // Telemetry archiving should be on.
> > +  Services.prefs.setBoolPref("toolkit.telemetry.archive.enabled", true);
> > +}
> > +
> 
> As discussed on IRC, we should make sure that changing the logging level is
> reflected both in the parent and the children, no matter when it happens.

Doing a quick check here: we do the setup in TelemetryController configureLogging().
This is called in both content and chrome process and adds an observer for the logging prefs, so this is fine.

Comment 16

[Roberto Agostino Vitillo (:rvitillo)]

(In reply to Georg Fritzsche [:gfritzsche] from comment #15)
> (In reply to Roberto Agostino Vitillo (:rvitillo) from comment #14)
> > Comment on attachment 8599262 [details] [diff] [review]
> > Add test coverage for e10s child histogram collection
> > 
> > Review of attachment 8599262 [details] [diff] [review]:
> > -----------------------------------------------------------------
> > 
> > ::: toolkit/components/telemetry/tests/unit/head.js
> > @@ +189,5 @@
> > > +  Services.prefs.setCharPref("toolkit.telemetry.log.level", "Trace");
> > > +  // Telemetry archiving should be on.
> > > +  Services.prefs.setBoolPref("toolkit.telemetry.archive.enabled", true);
> > > +}
> > > +
> > 
> > As discussed on IRC, we should make sure that changing the logging level is
> > reflected both in the parent and the children, no matter when it happens.
> 
> Doing a quick check here: we do the setup in TelemetryController
> configureLogging().
> This is called in both content and chrome process and adds an observer for
> the logging prefs, so this is fine.

OK, so for this test it's fine but what about the more general case? Do we have a listener somewhere in case the preference is changed afterwards?

Comment 17

[Georg Fritzsche [:gfritzsche]]

(In reply to Roberto Agostino Vitillo (:rvitillo) from comment #16)
> > > As discussed on IRC, we should make sure that changing the logging level is
> > > reflected both in the parent and the children, no matter when it happens.
> > 
> > Doing a quick check here: we do the setup in TelemetryController
> > configureLogging().
> > This is called in both content and chrome process and adds an observer for
> > the logging prefs, so this is fine.
> 
> OK, so for this test it's fine but what about the more general case? Do we
> have a listener somewhere in case the preference is changed afterwards?

Yes, that's not specific to this test. This is part of the standard Telemetry module setup - TelemetryController being the central module and setting up the logging & observer on "profile-after-change" (chrome) and "app-startup" (content)

Comment 18

[Georg Fritzsche [:gfritzsche]]

That is here: https://dxr.mozilla.org/mozilla-central/source/toolkit/components/telemetry/TelemetryController.jsm?from=TelemetryController.jsm&case=true#1003

Comment 19

[Ryan VanderMeulen [:RyanVM]]

This brought back bug 1100501 :(. Backed out.
https://hg.mozilla.org/integration/fx-team/rev/8319693198eb

https://treeherder.mozilla.org/logviewer.html#?job_id=2882673&repo=fx-team
https://treeherder.mozilla.org/logviewer.html#?job_id=2882675&repo=fx-team

Comment 20

[Jim Mathies [:jimm]]

Attachment: wip

I think all we need to care about here is XRE_InitChildProcess.

Comment 21

[Jim Mathies [:jimm]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=60427fb7c8e1

Comment 22

[Jim Mathies [:jimm]]

(In reply to Jim Mathies [:jimm] from comment #21)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=60427fb7c8e1

I think we're ok here, by adding this to XRE_InitChildProcess it gets initialized earlier and shuts regardless of which process object we create.

Comment 23

[Jim Mathies [:jimm]]

Comment on attachment 8600873 [details] [diff] [review]
wip

This avoid late freeing of this statistics memory which our memory alloocator doesn't like. We've already patched the main process and xpcshell in bug 1100501. This patch covers all content and plugin processes.

Comment 24

[Jim Mathies [:jimm]]

review ping.. bsmedberg, any issues here?

Comment 25

[José Antonio Olivera Ortega [:jaoo]]

This bug is blocking bug 1115820 to land. I don't want to put pressure on anyone but I'd like to know if there is any ETA here. Thanks guys!

Comment 26

[Benjamin Smedberg]

Comment on attachment 8600873 [details] [diff] [review]
wip

Why is this a global? It doesn't look like we need to use this as a global and could just make it a scoped variable.

Comment 27

[Andrew McCreight [:mccr8]]

Any updates here? This is pretty bad.

Comment 28

[Noemí Freire (:noemi)]

Per comment 25 and comment 27 setting ni to Jim, your feedback here would be much appreciated. Thanks.

Comment 29

[Jim Mathies [:jimm]]

(In reply to Benjamin Smedberg  [:bsmedberg] from comment #26)
> Comment on attachment 8600873 [details] [diff] [review]
> wip
> 
> Why is this a global? It doesn't look like we need to use this as a global
> and could just make it a scoped variable.

I don't think it makes any difference. We can try using as local. Seems fine either way though, not sure you're r- just for that.

Comment 30

[Jim Mathies [:jimm]]

Attachment: patch v.2

Comment 31

[Jim Mathies [:jimm]]

Comment on attachment 8611301 [details] [diff] [review]
patch v.2

updated to use a local variable.

Comment 32

[Jim Mathies [:jimm]]

Attachment: patch v.2

Comment 33

[Pulsebot]

https://hg.mozilla.org/integration/fx-team/rev/158cc43ff74c

Comment 34

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/integration/fx-team/rev/158cc43ff74c

Comment 35

[Georg Fritzsche [:gfritzsche]]

Re the patch obsoletion - i still intend to pick up the tests here now that it's fixed (currently we have no coverage of child payloads at all), but i can move that to a separate bug.

Comment 36

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/158cc43ff74c