GC API produces unterminated fractional number values for entries

RESOLVED FIXED in mozilla27

Status

()

Core
JavaScript Engine
--
major
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: wsmwk, Assigned: terrence)

Tracking

Trunk
mozilla27
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(2 attachments, 3 obsolete attachments)

(Reporter)

Description

5 years ago
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/memchaser@quality.mozilla.org.xpi!/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
(Reporter)

Comment 1

5 years ago
the JSON data is about 430k.

This might also be a source of recent EMPTY crashes for me - bp-72c93f7f-3c23-47be-aebe-0df692130130
Can you please file an issue here:
https://github.com/mozilla/memchaser
Also please provide a full example of the json blob.
(Reporter)

Comment 5

5 years ago
bug 507998 might help here
Depends on: 507998
(Reporter)

Comment 6

5 years ago
This is causing my heartache on trunk.

from  https://github.com/mozilla/memchaser/issues/161 ...

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?
(Reporter)

Comment 7

5 years ago
Created attachment 811783 [details]
parse error

still seeing this, current trunk. what's next step?
Flags: needinfo?
Created attachment 811851 [details]
Broken GC API JSON data
Attachment #708218 - Attachment is obsolete: true
Attachment #811783 - Attachment is obsolete: true
Flags: needinfo?
Created attachment 811852 [details]
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 http://jsonviewer.stack.hu/. 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
(Assignee)

Comment 11

5 years ago
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)
(Assignee)

Comment 13

5 years ago
Created attachment 812114 [details] [diff] [review]
v0: Handle negative slice times

Since negative times are meaningless here, but probably small, we should just
truncate to zero.
(Assignee)

Updated

5 years ago
Assignee: general → terrence
Status: NEW → ASSIGNED
(Assignee)

Updated

5 years ago
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+
(Reporter)

Comment 15

5 years ago
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)
(Assignee)

Comment 16

5 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/fd872b99606c

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.
https://hg.mozilla.org/mozilla-central/rev/fd872b99606c
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla27
You need to log in before you can comment on or make changes to this bug.