1358259 - 1,380,700 instances of "WARNING: file ipc/chromium/src/base/histogram.cc, line 637" emitted from none during windows7-32-vm debug testing

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect, P2)

Description

[Eric Rahm [:erahm]]

> 1380655 WARNING: file ipc/chromium/src/base/histogram.cc, line 637

This warning [1] shows up in the following test suites:

>  79040 - test-windows7-32-vm/debug-mochitest-browser-chrome-e10s-4 bc4
>  72464 - Mochitest e10s Browser Chrome bc4
>  59722 - test-windows7-32-vm/debug-mochitest-browser-chrome-1 bc1
>  42234 - Mochitest Browser Chrome bc1
>  41946 - Mochitest e10s 5
>  41844 - test-windows7-32-vm/debug-mochitest-browser-chrome-e10s-3 bc3
>  40012 - Mochitest e10s Browser Chrome bc6
>  38168 - test-windows7-32-vm/debug-mochitest-1 1
>  36144 - test-windows7-32-vm/debug-mochitest-browser-chrome-7 bc7
>  35575 - test-windows7-32-vm/debug-mochitest-devtools-chrome-8 dt8
>  35114 - Mochitest 1
>  34638 - test-windows7-32-vm/debug-mochitest-browser-chrome-e10s-6 bc6
>  33154 - test-windows7-32-vm/debug-mochitest-browser-chrome-e10s-1 bc1
>  33130 - Mochitest e10s 1
>  32600 - test-windows7-32-vm/debug-mochitest-e10s-1 1
>  28886 - Mochitest DevTools Browser Chrome dt4
>  28567 - test-windows7-32-vm/debug-mochitest-browser-chrome-6 bc6
>  28090 - Mochitest e10s Browser Chrome bc1
>  27988 - test-windows7-32-vm/debug-mochitest-devtools-chrome-4 dt4
>  26828 - test-windows7-32-vm/debug-mochitest-browser-chrome-5 bc5
>  26385 - test-windows7-32-vm/debug-mochitest-browser-chrome-e10s-5 bc5
>  25896 - Mochitest e10s Browser Chrome bc3
>  23494 - test-windows7-32-vm/debug-mochitest-media-e10s-1 mda1
>  23348 - Mochitest Browser Chrome bc7
>  22218 - test-windows7-32-vm/debug-mochitest-browser-chrome-2 bc2
>  22012 - Mochitest 5
>  21688 - Mochitest Browser Chrome bc3
>  21466 - Mochitest e10s Browser Chrome bc5
>  21209 - test-windows7-32-vm/debug-mochitest-browser-chrome-3 bc3
>  21198 - Mochitest Browser Chrome bc6
>  21131 - Mochitest e10s Browser Chrome bc2
>  20338 - Mochitest Browser Chrome bc2
>  17306 - Mochitest Browser Chrome bc5
>  16857 - test-windows7-32-vm/debug-mochitest-browser-chrome-e10s-2 bc2
>  15448 - test-windows7-32-vm/debug-mochitest-e10s-5 5
>  14282 - Mochitest e10s Browser Chrome bc7
>  13866 - Mochitest e10s 4
>  13754 - test-windows7-32-vm/debug-mochitest-5 5
>  13542 - test-windows7-32-vm/debug-mochitest-browser-chrome-4 bc4
>  12228 - Mochitest 2
>  11821 - test-windows7-32-vm/debug-mochitest-e10s-3 3
>  11745 - Mochitest e10s 3
>  11704 - Mochitest Browser Chrome bc4
>  11241 - Mochitest 3
>  10571 - test-windows7-32-vm/debug-mochitest-3 3
>  10436 - test-windows7-32-vm/debug-mochitest-4 4
>  10432 - test-windows7-32-vm/debug-mochitest-2 2
>  10168 - test-windows7-32-vm/debug-mochitest-media-e10s-2 mda2
>   9752 - test-windows7-32-vm/debug-mochitest-e10s-4 4
>   9648 - Mochitest DevTools Browser Chrome dt8
>   9494 - Mochitest e10s 2
>   9484 - Mochitest e10s DevTools Browser Chrome dt8
>   8932 - Mochitest 4
>   8228 - Mochitest e10s DevTools Browser Chrome dt5
>   7450 - test-windows7-32-vm/debug-mochitest-e10s-2 2
>   7171 - test-windows7-32-vm/debug-mochitest-browser-chrome-e10s-7 bc7
>   4756 - test-windows7-32-vm/debug-mochitest-devtools-chrome-2 dt2
>   4682 - Mochitest Media mda
>   4528 - Mochitest DevTools Browser Chrome dt2
>   2752 - Mochitest e10s WebGL gl2
>   2502 - test-windows7-32-vm/debug-mochitest-media-1 mda1
>   2454 - Mochitest e10s DevTools Browser Chrome dt7
>   2372 - test-windows7-32-vm/debug-mochitest-media-e10s-3 mda3
>   2232 - Mochitest WebGL gl1
>   2188 - test-windows7-32-vm/debug-mochitest-devtools-chrome-6 dt6
>   1732 - test-windows7-32-vm/debug-mochitest-media-2 mda2
>   1566 - Mochitest e10s DevTools Browser Chrome dt1
>   1502 - Mochitest DevTools Browser Chrome dt6
>   1214 - test-windows7-32-vm/debug-mochitest-media-3 mda3
>    858 - Mochitest DevTools Browser Chrome dt1
>    746 - Mochitest e10s DevTools Browser Chrome dt2
>    542 - test-windows7-32-vm/debug-mochitest-devtools-chrome-1 dt1
>    520 - Mochitest e10s DevTools Browser Chrome dt4
>    478 - Mochitest e10s WebGL gl3
>    264 - test-windows7-32-vm/debug-mochitest-a11y a11y
>    156 - Mochitest e10s GPU gpu
>    104 - Mochitest GPU gpu
>    102 - Mochitest a11y a11y
>     74 - Mochitest e10s WebGL gl1
>     60 - Mochitest WebGL gl3
>     34 - test-windows7-32-vm/debug-mochitest-devtools-chrome-5 dt5
>     34 - Mochitest DevTools Browser Chrome dt5
>     24 - Mochitest e10s DevTools Browser Chrome dt6
>     16 - test-windows7-32-vm/debug-mochitest-devtools-chrome-7 dt7
>     16 - Mochitest DevTools Browser Chrome dt7
>     12 - test-windows7-32-vm/debug-mochitest-devtools-chrome-3 dt3
>     12 - Mochitest e10s DevTools Browser Chrome dt3
>     12 - Mochitest DevTools Browser Chrome dt3
>      8 - test-windows7-32-vm/debug-mochitest-jetpack JP
>      8 - Mochitest WebGL gl2
>      8 - Mochitest Jetpack JP

It shows up in 5348 tests. A few of the most prevalent:

>  21788 - [e10s] dom/cache/test/mochitest/test_cache_shrink.html
>  21740 -        dom/cache/test/mochitest/test_cache_shrink.html
>  15797 - [e10s] Shutdown
>  15558 -        Shutdown
>  15484 - [e10s] browser/base/content/test/general/browser_sanitizeDialog.js
>  11552 - [e10s] browser/base/content/test/general/browser_bookmark_popup.js
>   9592 - [e10s] browser/base/content/test/general/browser_sanitize-timespans.js
>   8884 -        browser/base/content/test/general/browser_sanitizeDialog.js
>   8308 -        browser/base/content/test/general/browser_sanitize-timespans.js
>   8308 -        browser/base/content/test/general/browser_bookmark_popup.js

[1] https://hg.mozilla.org/mozilla-central/annotate/27311156637f/none#l0

Comment 1

[Eric Rahm [:erahm]]

Regression narrowed down to: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=e9a5d4f62461ee0db07a41f59b73163ec106bc3e&tochange=20dff607fb88ee69135a280bbb7f32df75a86237

I think that has 3 merge commits in it, mozregression couldn't hang.

Comment 2

[Andrew McCreight [:mccr8]]

Line 637 is: DCHECK_GE(counts_[index], 0);

Bug 1344893 is the only one in that range that has data-review that I can see.

Comment 3

[Eric Rahm [:erahm]]

Manual bisection points to bug 1350765. Ehsan, can you take a look?

Comment 4

[(no longer active)]

Yes, I will look.  Sorry about this.

Comment 5

[(no longer active)]

I tried to reproduce this locally without any luck whatsoever.  I tried running some of the tests in comment 0, running the whole suite by passing --total-chunks and --this-chunk a few times and nothing seems to help.

Do I need to apply some magic environment variables and/or settings in order to activate telemetry during tests?  Any idea what I need to do in order to trigger these messages locally during the tests?  So far I have failed to trigger a single message from histogram.cc and I'm not sure what to do with this bug...  :/

Comment 6

[Eric Rahm [:erahm]]

I didn't see any interesting runtime flags, but here's an example linux64-dbg build config from treeherder:

Adding configure options from /home/worker/workspace/build/src/.mozconfig
  --enable-debug
  --enable-dmd
  --enable-verify-mar
  --enable-crashreporter
  --enable-release
  --enable-js-shell
  --enable-elf-hack
  --enable-stdcxx-compat
  --enable-default-toolkit=cairo-gtk3
  --with-branding=browser/branding/nightly
  --with-ccache
  PKG_CONFIG_SYSROOT_DIR=/home/worker/workspace/build/src/gtk3
  PKG_CONFIG_LIBDIR=/usr/lib64/pkgconfig:/usr/share/pkgconfig
  MOZ_TELEMETRY_REPORTING=1
  SOCORRO_SYMBOL_UPLOAD_TOKEN_FILE=/builds/crash-stats-api.token
  MOZ_PACKAGE_JSSHELL=1
  MOZ_AUTOMATION_MOZCONFIG=1
  MOZILLA_OFFICIAL=1
  PKG_CONFIG_PATH=/home/worker/workspace/build/src/gtk3/usr/local/lib/pkgconfig
  PATH=/home/worker/workspace/build/src/gtk3/usr/local/bin:/home/worker/workspace/build/src/gcc/bin:/tools/buildbot/bin:/usr/local/bin:/usr/lib64/ccache:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/sbin:/tools/git/bin:/tools/python27/bin:/tools/python27-mercurial/bin:/home/cltbld/bin
  LD_LIBRARY_PATH=/tools/gcc-4.3.3/installed/lib64:obj-firefox/dist/bin:/home/worker/workspace/build/src/clang/lib:/home/worker/workspace/build/src/gtk3/usr/local/lib:/home/worker/workspace/build/src/clang/lib:/home/worker/workspace/build/src/gtk3/usr/local/lib
  CARGO=/home/worker/workspace/build/src/rustc/bin/cargo
  MOZ_ADDON_SIGNING=1
  MOZ_REQUIRE_SIGNING=0
  CC=/home/worker/workspace/build/src/gcc/bin/gcc
  LDFLAGS=-L/home/worker/workspace/build/src/gtk3/usr/local/lib
  TOOLTOOL_DIR=/home/worker/workspace/build/src
  CXX=/home/worker/workspace/build/src/gcc/bin/g++
  PKG_CONFIG=/home/worker/workspace/build/src/gtk3/usr/local/bin/pkg-config
  RUSTC=/home/worker/workspace/build/src/rustc/bin/rustc

Comment 7

[Georg Fritzsche [:gfritzsche]]

Until we understand this, i'm worried about this having impact on Telemetry collection on Nightly.
Can we back out bug 1350765 until this is cleared up?

Comment 8

[Georg Fritzsche [:gfritzsche]]

(In reply to Eric Rahm [:erahm] from comment #6)
> I didn't see any interesting runtime flags, but here's an example
> linux64-dbg build config from treeherder:
> 
> Adding configure options from /home/worker/workspace/build/src/.mozconfig
>   --enable-debug
...
>   MOZ_TELEMETRY_REPORTING=1
...
>   MOZILLA_OFFICIAL=1

These seem most relevant.
The histogram.cc debug logging is active when `DEBUG` is defined. (Is that set from --enable-debug?)

1: https://dxr.mozilla.org/mozilla-central/rev/abdcc8dfc28397b95338245390e12c56658ad182/ipc/chromium/src/base/histogram.cc#637
2: https://dxr.mozilla.org/mozilla-central/rev/abdcc8dfc28397b95338245390e12c56658ad182/ipc/chromium/src/base/logging.h#104

Comment 9

[Georg Fritzsche [:gfritzsche]]

(In reply to Georg Fritzsche [:gfritzsche] from comment #7)
> Until we understand this, i'm worried about this having impact on Telemetry
> collection on Nightly.
> Can we back out bug 1350765 until this is cleared up?

Also i assume you are probably busy enough Ehsan - if it's not urgent to land bug 1350765, we can take this.

Comment 10

[(no longer active)]

(In reply to Georg Fritzsche [:gfritzsche] from comment #9)
> (In reply to Georg Fritzsche [:gfritzsche] from comment #7)
> > Until we understand this, i'm worried about this having impact on Telemetry
> > collection on Nightly.
> > Can we back out bug 1350765 until this is cleared up?
> 
> Also i assume you are probably busy enough Ehsan - if it's not urgent to
> land bug 1350765, we can take this.

Sigh, sure.  I'm never going to touch telemetry code ever again.  I'm going to back out bug 1350765 and unassign myself from it.  :-(

Comment 11

[(no longer active)]

Bug 1350765 is backed out now, this should be fixed when that hits your favorite branch.