"Clamped larged numeric value." error is logged in the browser console every one minute

RESOLVED FIXED in Firefox 60

Status

()

defect
P1
normal
RESOLVED FIXED
Last year
Last year

People

(Reporter: magicp.jp, Assigned: chutten)

Tracking

(Blocks 1 bug)

Trunk
mozilla60
All
Windows
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox58 unaffected, firefox59 ?, firefox60 fixed)

Details

Attachments

(1 attachment)

Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0 ID:20180223100113

Steps to reproduce:
1. Launch Nightly on Windows
2. Open the Browser Console (Ctrl+Shift+J)
3. Waiting a few minutes

Actual results:
The following error is logged in the browser console every one minute. I can reproduce on Windows 7 and 10.

Clamped larged numeric value. (unknown)


Expected results:
No error


Regression range:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=4560309df57b52d4946e309d12c150ddef61ef66&tochange=ba1d6f897a923b561bd9458f77bd3f7f63b99573
Has Regression Range: --- → yes
Has STR: --- → yes
User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0

Hello,

I have tested this issue on latest Nightly build 60.0a1 (2017-02-28)and managed to reproduce it. 
Moreover, I obtained the same pushlog result.

I did not manage to reproduce this issue on Mac 10.13.3 and Ubuntu 14.04 x64.

Gijs, can you please take a look at this issue?
Blocks: 1438180
Component: Untriaged → Preferences
Flags: needinfo?(gijskruitbosch+bugs)
This is a change from telemetry, which is bug 1438335. The pushlog must be wrong. Maybe mozregression isn't picking the right branch to look at or whatever.

The number of errors we get in the wild from this makes me pretty apprehensive about uplifting this change to beta. What's the benefit of logging something to the console here?
Blocks: 1438335
No longer blocks: 1438180
Component: Preferences → Untriaged
Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(chutten)
Generally speaking, we introduced this error logging to ensure devs adding new Telemetry measures are aware that they are doing something wrong by accumulating too-large-values to their histograms. That way it can be fixed before analysis is performed on clamped data.

ni?gfritzsche for any comments he wishes to add.
Flags: needinfo?(chutten) → needinfo?(gfritzsche)
The telemetry dist viewer shows half a million hits (!) for HTTP_CACHE_IO_QUEUE_2_EVICT over the course of less than 1 week. There's some other ones as well.
Component: Untriaged → Telemetry
Product: Firefox → Toolkit
Oh, and these _particular_ logs are from virtual memory size measurements. The plan for them is under discussion in bug 1436914
(In reply to :Gijs from comment #4)
> The telemetry dist viewer shows half a million hits (!) for
> HTTP_CACHE_IO_QUEUE_2_EVICT over the course of less than 1 week. There's
> some other ones as well.

The plan for analysing these hits and notifying users is bug 1438885
(In reply to Chris H-C :chutten from comment #3)
> Generally speaking, we introduced this error logging to ensure devs adding
> new Telemetry measures are aware that they are doing something wrong by
> accumulating too-large-values to their histograms. That way it can be fixed
> before analysis is performed on clamped data.
> 
> ni?gfritzsche for any comments he wishes to add.

Can we do this just on automation and local builds? That would avoid this kind of stuff affecting release users. Logging messages to the console the way it happens here is not really cheap, and once we ship this in a nightly / beta / release build there's nothing users can do about it.
FWIW, these messages are currently the #4-most-common error message as reported through the nightly error reporter, with all the ones above it being related to add-ons.
I'm amenable to wrapping it in `#ifdef DEBUG` so long as there isn't a case Georg can come up with against it. I think given our recording of counts of affected probes in the scalar telemetry.accumulate_clamped_values we should be able to do that.
Comment on attachment 8954856 [details]
bug 1440832 - Only log when clamping on debug builds

https://reviewboard.mozilla.org/r/224006/#review230046

I'm wondering how developers should discover when they introduce measurements in the futures.
Turning this on specifically in testing or ignoring the existing problematic probes might improve this.

For now this is causing disruption though.
So yes, let's limit the impact and think about a better solution.
Attachment #8954856 - Flags: review?(gfritzsche) → review+
Given that bug 1438335 was uplifted, does this need to be uplifted too?
Pushed by chutten@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/f262f531263f
Only log when clamping on debug builds r=gfritzsche
(In reply to :Gijs from comment #12)
> Given that bug 1438335 was uplifted, does this need to be uplifted too?

After it is verified on Nightly, yup.
https://hg.mozilla.org/mozilla-central/rev/f262f531263f
Status: NEW → RESOLVED
Closed: Last year
Resolution: --- → FIXED
Target Milestone: --- → mozilla60
Flags: needinfo?(gfritzsche)
Assignee: nobody → chutten
Priority: -- → P1
"Clamped large numeric value" log still occurs in Firefox 60.0a1 (2018-03-02) (64-bit)
Oh darn, so it is. This is likely to be a bad rebase interaction with bug 1428893.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Pushed by chutten@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/d4e9a7bee582
Only log on debug builds when clamping. r=gfritzsche
https://hg.mozilla.org/mozilla-central/rev/d4e9a7bee582
Status: REOPENED → RESOLVED
Closed: Last yearLast year
Resolution: --- → FIXED
Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0 ID:20180302190033
"Clamped large numeric value" occurs in Firefox Developer Edition 60.0b1 (20180302190033)
(In reply to magicp from comment #20)
> Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101
> Firefox/60.0 ID:20180302190033
> "Clamped large numeric value" occurs in Firefox Developer Edition 60.0b1
> (20180302190033)

That has a buildid for March 2, and the merge comment to central at comment #19 is March 3, so for sure this wasn't in beta a day earlier. Can you check b2, which off-hand I'd expect to have the code changes from here ?
Flags: needinfo?(magicp.jp)
(In reply to :Gijs from comment #21)
> (In reply to magicp from comment #20)
> > Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101
> > Firefox/60.0 ID:20180302190033
> > "Clamped large numeric value" occurs in Firefox Developer Edition 60.0b1
> > (20180302190033)
> 
> That has a buildid for March 2, and the merge comment to central at comment
> #19 is March 3, so for sure this wasn't in beta a day earlier. Can you check
> b2, which off-hand I'd expect to have the code changes from here ?

Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0 ID:20180307142707
Ah! It works fine in 60.0b2 (20180307142707). Thanks!
Flags: needinfo?(magicp.jp)
You need to log in before you can comment on or make changes to this bug.