Closed Bug 836284 Opened 12 years ago Closed 11 years ago

GC API produces unterminated fractional number values for entries


(Core :: JavaScript Engine, defect)

Not set





(Reporter: wsmwk, Assigned: terrence)




(2 files, 3 obsolete files)

firefox 21.0a1 (2013-01-16)
addons are up to date

Error: Failure parsing JSON data Error: Failure parsing JSON data: {"timestamp": 1359558330688000, "total_time": 5755.9, "compartments_collected": 970, "total_compartments": 970, "mmu_20ms": 0, "mmu_50ms": 0, "scc_sweep_total": 275.9, "scc_sweep_max_pause": 68.6, "max_pause": 158.8, "nonincremental_reason": "none", "allocated": 375, "added_chunks": 0, "removed_chunks": 0, "slices": [{"slice": 0, "pause": 102.8, "when": 0.0, "reason": "CC_WAITING", "page_faults": 73.0, "start_timestamp": 1359558315208597, "end_timestamp": 1359558315311440, "times": {"begin_callback": 0.1, "wait_background_thread": 0.0, "mark_discard_code": 28.7, "purge": 0.4, "mark": 58.9, "mark_roots": 58.5, "mark_types": 0.0, "mark_delayed": 0.0, "sweep": 0.0, "mark_during_sweeping": 0.0, "mark_types_during_sweeping": 0.0, "mark_delayed_during_sweeping": 0.0, "mark_incoming_black_pointers": 0.0, "mark_weak": 0.0, "mark_incoming_gray_pointers": 0.0, "mark_gray": 0.0, 
Source File: resource://gre/modules/XPIProvider.jsm -> jar:file:///C:/Users/Wayne/AppData/Roaming/Mozilla/Firefox/Profiles/3nviu178.Phoenix/extensions/!/bootstrap.js -> resource://memchaser-at-quality-dot-mozilla-dot-org/api-utils/lib/loader.js -> resource://memchaser-at-quality-dot-mozilla-dot-org/memchaser/lib/garbage-collector.js
Line: 75
the JSON data is about 430k.

This might also be a source of recent EMPTY crashes for me - bp-72c93f7f-3c23-47be-aebe-0df692130130
Also please provide a full example of the json blob.
Attached file json data (obsolete) —
issue filed
bug 507998 might help here
Depends on: 507998
This is causing my heartache on trunk.

from ...

I made a page with
 var jsObject = JSON.parse(json-data...);

and what I get from Firefox is
 SyntaxError: missing ) after argument list @ file:///C:/Users/Wayne/Documents/json.html:3

It's not because of unmatched { } - there are equal number in the data.

And it does not appear to be size related, because I did a much smaller blob 69k with a different set of mem data (I'll send you [Henrik] the data) and got back
Timestamp: 3/21/2013 3:41:30 PM
Error: SyntaxError: JSON.parse: unexpected character
Source File: file:///C:/Users/Wayne/Documents/jsontoday.html
Line: 3
Assignee: nobody → general
Severity: normal → major
Component: Extension Compatibility → JavaScript Engine
Product: Firefox → Core
Summary: memchaser json parse failure of GC data → memchaser json parse failure of GC data. malformed data from GC API?
Attached file parse error (obsolete) —
still seeing this, current trunk. what's next step?
Flags: needinfo?
Attached file Broken GC API JSON data (obsolete) —
Attachment #708218 - Attachment is obsolete: true
Attachment #811783 - Attachment is obsolete: true
Flags: needinfo?
Attached file GC API JSON
I incorrectly copied the bits of the last attachment and left the trailing file reference at the bottom. With the updated data I cannot see a problem by inspecting the data on All looks fine. As it looks like something is broken in JSON.parse()?
Attachment #811851 - Attachment is obsolete: true
Ok, so the problem here seems to be related to some non-parseable fractional numbers for one of the listed values. Seems like we are broken here on the JS side and are creating bad numbers:

"JSON.parse: unterminated fractional number"

The following two examples I took from the attached failure cases:

{"slice": 299,
 "pause": -11.-2,

"totals": {
 "finalize_end_callback": -19.-3,

Terrence, given that you have implemented most of it, do you have an idea?
Flags: needinfo?(terrence)
OS: Windows Vista → All
Hardware: x86 → All
Summary: memchaser json parse failure of GC data. malformed data from GC API? → GC API produces unterminated fractional number values for entries
Great find! Yes, I know what's going on: appendDecimal does not handle negative numbers correctly. We should definitely fix this specific bug, however, the larger question is how the negative times got in there in the first place. Slices are strictly ordered such that this should be impossible unless someone manually adjusts their clock backwards.

Is this Windows only? The optimizations we do for timekeeping on that platform may be implicated here.
Flags: needinfo?(terrence)
Good question. Lets ask Wayne on which platform he is on. Lately I haven't checked the browser console for such issues, so I cannot give a qualified answer. But I think I noticed something like that months ago on OS X.
Flags: needinfo?(vseerror)
Since negative times are meaningless here, but probably small, we should just
truncate to zero.
Assignee: general → terrence
Attachment #812114 - Flags: review?(wmccloskey)
Comment on attachment 812114 [details] [diff] [review]
v0: Handle negative slice times

Review of attachment 812114 [details] [diff] [review]:

That's weird.
Attachment #812114 - Flags: review?(wmccloskey) → review+
I experience this on vista laptop.  I never adjust the clock. But I run daily/trunk.  And the laptop goes through sleep/wake cycles as it gets transported.
Flags: needinfo?(vseerror)

In general, if ntp or the rtc tells the OS that it's clock is a few milliseconds fast, the OS should not just warp the clock backwards a few milliseconds. This would result in applications seeing time run backwards, resulting in problems like this. Instead the OS should be incrementally delaying future ticks so that the clock slowly drifts back into alignment. Either that is not happening on some machines or we have a bug in how slices record time.
Closed: 11 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla27
You need to log in before you can comment on or make changes to this bug.