748397 - JSON from garbage-collector activity tracking API (bug 531396) is broken with comma as fraction separator

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Stefan Fleiter (:sfleiter)]

JSON from garbage-collector activity tracking API is broken with comma as fraction separator.

The API should not act Locale dependent and not produce broken JSON.

See https://github.com/mozilla/memchaser/issues/132

Example:
Timestamp: 24.04.2012 17:38:06
Error: {"timestamp": 1335281886926635, "total_time": 106,6, "compartments_collected": 300, "total_compartments": 300, "mmu_20ms": 0, "mmu_50ms": 0, "max_pause": 106,6, "nonincremental_reason": "GC mode", "allocated": 81, "added_chunks": 30, "removed_chunks": 0, "Slices": [{"slice": 0, "time": 106,6, "pause": 106,6, "reason": "POST_COMPARTMENT", "times": {"begin_callback": 0,1, "wait_background_thread": 0,0, "purge": 1,2, "mark": 49,9, "mark_roots": 7,5, "mark_delayed": 0,0, "mark_other": 3,5, "finalize_start_callback": 0,7, "sweep": 42,8, "sweep_compartments": 13,7, "sweep_object": 12,9, "sweep_string": 1,9, "sweep_script": 1,1, "sweep_shape": 6,8, "discard_code": 1,2, "discard_analysis": 3,2, "discard_ti": 0,2, "sweep_types": 0,4, "clear_script_analysis": 0,2, "finalize_end_callback": 4,7, "deallocate": 0,1, "end_callback": 12,2}}], "totals": {"begin_callback": 0,1, "wait_background_thread": 0,0, "purge": 1,2, "mark": 49,9, "mark_roots": 7,5, "mark_delayed": 0,0, "mark_other": 3,5, "finalize_start_callback": 0,7, "sweep": 42,8, "sweep_compartments": 13,7, "sweep_object": 12,9, "sweep_string": 1,9, "sweep_script": 1,1, "sweep_shape": 6,8, "discard_code": 1,2, "discard_analysis": 3,2, "discard_ti": 0,2, "sweep_types": 0,4, "clear_script_analysis": 0,2, "finalize_end_callback": 4,7, "deallocate": 0,1, "end_callback": 12,2}}
Source File: resource://memchaser-at-quality-dot-mozilla-dot-org/api-utils/lib/cuddlefish.js -> resource://memchaser-at-quality-dot-mozilla-dot-org/memchaser/lib/garbage-collector.js
Line: 91

Comment 1

[Boris Zbarsky [:bzbarsky]]

Stefan, what API are you using to get this json?

Comment 2

[Terrence Cole [:terrence]]

This is my bad.  I didn't think that spidermonkey's low-level snprintf implementation would have locale support.  Will try to whip something up today to hack around the problem.

Comment 3

[Terrence Cole [:terrence]]

Attachment: v0

This also removes locale encoding for the console messages.  This is a shame, but I don't think it is enough of one to complexify the code in such a low-level tool.

Comment 4

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Instead of this, could you add a new method to StatisticsSerializer like this:

  void appendDecimal(const char *name, const char *units, double n) {
    if (asJSON_)
      appendNumber(name, "%.1F", units, n);
    else
      appendNumber(name, "%.1f", units, n);
  }

and use this for all the existing %.1f stuff. That way the error console output will be localized.

Also, I don't think we need to change the GC(T+xxx) stuff. It never goes to JSON.

Comment 5

[Terrence Cole [:terrence]]

(In reply to Bill McCloskey (:billm) from comment #4)
> Also, I don't think we need to change the GC(T+xxx) stuff. It never goes to
> JSON.

True.  That was just to make the output consistent.

Comment 6

[Terrence Cole [:terrence]]

Attachment: v1: Not as bad as I thought it would be.

Not as bad as I thought it would be.  I was worried about appendIfNonZero, but that can just be a second branch.

Comment 7

[Terrence Cole [:terrence]]

Attachment: v2: Even better.

Bill pointed out that since we're hard-coding the format string we shouldn't be taking varargs anymore.  This allows us to just use appendDecimal directly from appendIfNonZeroMS, simplifying things greatly.

Comment 8

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Comment on attachment 617957 [details] [diff] [review]
v2: Even better.

Thanks. Can you move the double argument of appendDecimal last so the order is more like appendNumber?

Comment 9

[Terrence Cole [:terrence]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ec2a64a2f5d9

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This breaks all tools which depend on the API in Firefox 14 and 15. Asking for tracking both branches.

Comment 11

[(no longer active)]

https://hg.mozilla.org/mozilla-central/rev/ec2a64a2f5d9

Comment 12

[Olli Pettay [:smaug][[e-mail]]]

Is memchaser still broken. I don't get any gc values, cc is ok.
I'm using an up-to-date m-c build.

Comment 13

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Olli Pettay [:smaug] from comment #12)
> Is memchaser still broken. I don't get any gc values, cc is ok.
> I'm using an up-to-date m-c build.

You could add a dump statement in Memchaser to test the data as coming from the API. See lib/garbage_collector.js line 91.

Comment 14

[Stefan Fleiter (:sfleiter)]

Sorry, but this is not fixed
(Mozilla/5.0 (X11; Linux x86_64; rv:15.0) Gecko/20120426 Firefox/15.0a1)

The JSON structure looks like this now:

{"timestamp": 1335439002064508, "total_time": %F, "compartments_collected": 342, "total_compartments": 342, "mmu_20ms": 0, "mmu_50ms": 0, "max_pause": %F, "nonincremental_reason": "GC mode", "allocated": 98, "added_chunks": 2, "removed_chunks": 2, "Slices": [{"slice": 0, "time": %F, "pause": %F, "reason": "CC_WAITING", "times": {"begin_callback": %F, "wait_background_thread": %F, "purge": %F, "mark": %F, "mark_roots": %F, "mark_delayed": %F, "mark_other": %F, "finalize_start_callback": %F, "sweep": %F, "sweep_compartments": %F, "sweep_object": %F, "sweep_string": %F, "sweep_script": %F, "sweep_shape": %F, "discard_code": %F, "discard_analysis": %F, "discard_ti": %F, "sweep_types": %F, "clear_script_analysis": %F, "finalize_end_callback": %F, "deallocate": %F, "end_callback": %F}}], "totals": {"begin_callback": %F, "wait_background_thread": %F, "purge": %F, "mark": %F, "mark_roots": %F, "mark_delayed": %F, "mark_other": %F, "finalize_start_callback": %F, "sweep": %F, "sweep_compartments": %F, "sweep_object": %F, "sweep_string": %F, "sweep_script": %F, "sweep_shape": %F, "discard_code": %F, "discard_analysis": %F, "discard_ti": %F, "sweep_types": %F, "clear_script_analysis": %F, "finalize_end_callback": %F, "deallocate": %F, "end_callback": %F}}

I would assume that %F should be replaced by a float value with dot as the fraction separator.

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Can we get some kind of unit tests here or for the whole API?

Comment 16

[Terrence Cole [:terrence]]

Attachment: v0: Use only standard format flags.

It turns out the %F format flag is not in SuSv2.  This patch re-does the printing in a hackier, but portable, way.

Comment 17

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

(In reply to Terrence Cole [:terrence] from comment #16)
> Created attachment 618806 [details] [diff] [review]
> v0: Use only standard format flags.
> 
> It turns out the %F format flag is not in SuSv2.  This patch re-does the
> printing in a hackier, but portable, way.

I don't think this will work on 32-bit machines, where a long is 32 bits. I would suggest just using %d and casting to an int in both cases. These numbers are never going to be very big.

Comment 18

[Terrence Cole [:terrence]]

Attachment: v1: Using int.

Verified in a 32bit browser build.

Comment 19

[Terrence Cole [:terrence]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/58a6a61544c9

Comment 20

[:Ms2ger (he/him; ⌚ UTC+1/+2)]

https://hg.mozilla.org/mozilla-central/rev/58a6a61544c9

Comment 21

[Terrence Cole [:terrence]]

Stephan, sorry for the continued bustage.  Since we don't yet have tests, can you confirm that this works?  This went into central early this morning, so it should be in tonight's nightly build.  Thanks!

Comment 22

[Stefan Fleiter (:sfleiter)]

This finally works for me (again).
Thanks a lot for your work!

Comment 23

[Lukas Blakk [:lsblakk] use ?needinfo]

Please nominate for Aurora approval so we can uplift.

Comment 24

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Lukas Blakk [:lsblakk] from comment #23)
> Please nominate for Aurora approval so we can uplift.

Doesn't 'tracking-firefox14:+' mean we can directly check-in the patch? Sorry if I miss something.

Comment 25

[Olli Pettay [:smaug][[e-mail]]]

tracking-X+ doesn't mean that the patch can land.

Comment 26

[Terrence Cole [:terrence]]

This had fallen off of my radar.  What action is needed to get this bug fixed in firefox14?

Comment 27

[Andrew McCreight [:mccr8]]

Go to details for the patch you want to land on Aurora, select ? under approval-mozilla-aurora, fill out the form, wait for approval.

Comment 28

[Terrence Cole [:terrence]]

Attachment: Combined and backported patches to aurora.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 
The extension "MemChaser" will fail to work depending on what the user's LC_NUMERIC environment variable is set to.

User impact if declined: 
Memchaser will stop working when users upgrade from Firefox13 to Firefox14.

Testing completed (on m-c, etc.): 
This patch has been in Nightlys since April, fixing the bug and causing no other regressions.

Risk to taking this patch (and alternatives if risky): 
Low risk. The code is only used by one extension and is now well tested.

String or UUID changes made by this patch: 
None.

Comment 29

[Lukas Blakk [:lsblakk] use ?needinfo]

Comment on attachment 628006 [details] [diff] [review]
Combined and backported patches to aurora.

low risk, fixes tools, approved.

Comment 30

[Terrence Cole [:terrence]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/91eca10ae9a5