Optimize iCAL parser

VERIFIED FIXED in B2G C1 (to 19nov)

Status

Firefox OS
Gaia::Calendar
P1
normal
VERIFIED FIXED
5 years ago
5 years ago

People

(Reporter: lightsofapollo, Assigned: lightsofapollo)

Tracking

(Blocks: 1 bug, {perf})

unspecified
B2G C1 (to 19nov)
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(blocking-basecamp:+)

Details

(Whiteboard: [MemShrink:P2])

Attachments

(3 attachments)

(Assignee)

Description

5 years ago
Created attachment 675017 [details]
Memory Report (use about:memory)

A staggering amount of memory is being used in the ical parser during sync.
Given the relatively small size of each caldav response something must be going really wrong here.
Huzzah!
In case it's not clear, when about:memory says something like

│  │  │  │  ├───0.94 MB (02.28%) ── string(length=3227, "ParserError@app:////calendar.gaia...") [120]

That means there are 120 occurrences of a length-3227 string which begins with "ParserError@app:////calendar.gaia...".
Blocks: 797189
Whiteboard: [MemShrink]
An interesting data-point would be to collect an about:memory dump as you did, and then to collect another one with --minimize.  That would tell us whether the problem is that we're leaking memory, or just not collecting it aggressively enough.
(Assignee)

Updated

5 years ago
Blocks: 796789
James, can you answer the question from comment 3?
Flags: needinfo?(jlal)
Whiteboard: [MemShrink] → [MemShrink:P2]
Can someone paste in the highlights from this memory report, so we don't get the false impression from comment 2 that we're talking about 1mb of memory here?  (I'm on a 3G connection right now.)
Okay, connected to the real Internet again.  Here we go:

41.16 MB (100.0%) -- explicit
├──26.86 MB (65.27%) -- workers/workers(gaiamobile.org)/worker(/caldav_worker.js?time=1351153005062, 436c4400)
│  ├──18.06 MB (43.87%) -- compartment(web-worker)
│  │  ├──13.10 MB (31.82%) -- string-chars
│  │  │  ├──11.09 MB (26.95%) -- huge
│  │  │  │  ├───4.49 MB (10.91%) ++ (43 tiny)
│  │  │  │  ├───0.94 MB (02.28%) ── string(length=3227, "ParserError@app:////calendar.gaia...") [120]
│  │  │  │  ├───0.94 MB (02.28%) ── string(length=3147, "expectRE@app:////calendar.gaiamob...") [120]
│  │  │  │  ├───0.87 MB (02.11%) ── string(length=2818, "expectRE@app:////calendar.gaiamob...") [111]
│  │  │  │  ├───0.87 MB (02.11%) ── string(length=2898, "ParserError@app:////calendar.gaia...") [111]
│  │  │  │  ├───0.78 MB (01.90%) ── string(length=3224, "ParserError@app:////calendar.gaia...") [100]
│  │  │  │  ├───0.78 MB (01.90%) ── string(length=3144, "expectRE@app:////calendar.gaiamob...") [100]
│  │  │  │  ├───0.72 MB (01.75%) ── string(length=2815, "expectRE@app:////calendar.gaiamob...") [92]
│  │  │  │  └───0.71 MB (01.73%) ── string(length=2895, "ParserError@app:////calendar.gaia...") [91]
│  │  │  └───2.00 MB (04.87%) ── non-huge

I guess one way to approach this would be to figure out what these strings are.
(Assignee)

Comment 7

5 years ago
Created attachment 676851 [details]
With --minimize
Flags: needinfo?(jlal)
Minimizing gets rid of all the string chars, and the space taken by the worker drops from 27 MiB to 11 MiB:

├──11.17 MB (27.02%) -- workers/workers(gaiamobile.org)/worker(/caldav_worker.js?time=1342627067940, 446d4800)
│  ├───4.87 MB (11.78%) -- gc-heap
│  │   ├──4.78 MB (11.56%) ── decommitted-arenas [2]
│  │   └──0.09 MB (00.23%) ++ (3 tiny)
│  ├───3.25 MB (07.85%) -- compartment(web-worker)
│  │   ├──1.34 MB (03.24%) ── analysis-temporary [2]
│  │   ├──0.86 MB (02.07%) ++ gc-heap
│  │   ├──0.62 MB (01.50%) -- (6 tiny)
│  │   │  ├──0.24 MB (00.59%) ++ type-inference
│  │   │  ├──0.18 MB (00.43%) ── jaeger-data [2]
│  │   │  ├──0.07 MB (00.16%) ── other-sundries [4]
│  │   │  ├──0.06 MB (00.15%) ── objects/slots [2]
│  │   │  ├──0.06 MB (00.14%) ++ shapes-extra
│  │   │  └──0.01 MB (00.03%) ── string-chars/non-huge
│  │   └──0.43 MB (01.04%) ── script-data [2]
│  ├───2.68 MB (06.49%) -- runtime
│  │   ├──1.18 MB (02.86%) ── script-sources [2]
│  │   ├──0.79 MB (01.90%) ── jaeger-code [2]
│  │   └──0.72 MB (01.73%) ++ (12 tiny)

So it's a collection issue, though you could also argue that it'd be nice not to generate all these strings in the first place.
(Assignee)

Comment 9

5 years ago
re 3:

--minimize gives me odd results, I see something like 8/4 then eventually it times out with: expected 4 but see only 8 files.  Giving up...

I can successfully run it but only during periods of inactivity.

re 6:

I know that those strings are the .ics documents that are currently being parsed.
Eventually (as in the new memory report I added) these strings are no longer present (though consumption is still bad).

I am puzzled by this in particular (─9.03 MB (21.84%) ── heap-unclassified).
What should I be looking for here?

(highlight with -m):

├──11.17 MB (27.02%) -- workers/workers(gaiamobile.org)/worker(/caldav_worker.js?time=1342627067940, 446d4800)
│  ├───4.87 MB (11.78%) -- gc-heap
│  │   ├──4.78 MB (11.56%) ── decommitted-arenas [2]
│  │   └──0.09 MB (00.23%) -- (3 tiny)
│  │      ├──0.09 MB (00.23%) ── chunk-admin [2]
│  │      ├──0.00 MB (00.00%) ── unused-arenas
│  │      └──0.00 MB (00.00%) ── unused-chunks
│  ├───3.25 MB (07.85%) -- compartment(web-worker)
│  │   ├──1.34 MB (03.24%) ── analysis-temporary [2]
│  │   ├──0.86 MB (02.07%) -- gc-heap
│  │   │  ├──0.24 MB (00.57%) ++ objects
│  │   │  ├──0.20 MB (00.48%) ── unused-gc-things [4]
│  │   │  ├──0.15 MB (00.36%) ── scripts [2]
│  │   │  ├──0.14 MB (00.34%) ++ shapes
│  │   │  ├──0.07 MB (00.18%) ── strings [2]
│  │   │  ├──0.05 MB (00.11%) ── type-objects [2]
│  │   │  └──0.01 MB (00.03%) ── sundries [4]
│  │   ├──0.62 MB (01.50%) -- (6 tiny)
│  │   │  ├──0.24 MB (00.59%) ++ type-inference
│  │   │  ├──0.18 MB (00.43%) ── jaeger-data [2]
│  │   │  ├──0.07 MB (00.16%) ── other-sundries [4]
│  │   │  ├──0.06 MB (00.15%) ── objects/slots [2]
│  │   │  ├──0.06 MB (00.14%) ++ shapes-extra
│  │   │  └──0.01 MB (00.03%) ── string-chars/non-huge
│  │   └──0.43 MB (01.04%) ── script-data [2]
│  ├───2.68 MB (06.49%) -- runtime
│  │   ├──1.18 MB (02.86%) ── script-sources [2]
│  │   ├──0.79 MB (01.90%) ── jaeger-code [2]
│  │   └──0.72 MB (01.73%) ++ (12 tiny)
│  └───0.37 MB (00.89%) ++ compartment(web-worker-atoms)
├───9.03 MB (21.84%) ── heap-unclassified
├───6.22 MB (15.05%) -- window-objects/top(app://calendar.gaiamobile.org/settings/, id=1)/active/window(app://calendar.gaiamobile.org/settings/)
│   ├──4.13 MB (09.99%) -- js/compartment(app://calendar.gaiamobile.org/index.html)
│   │  ├──2.34 MB (05.65%) -- gc-heap
│   │  │  ├──0.98 MB (02.36%) ── unused-gc-things [2]
│   │  │  ├──0.53 MB (01.28%) ++ shapes
│   │  │  ├──0.49 MB (01.18%) ++ objects
│   │  │  └──0.34 MB (00.83%) ++ (4 tiny)
│   │  ├──0.89 MB (02.16%) ++ (5 tiny)
│   │  ├──0.47 MB (01.13%) ── analysis-temporary [2]
│   │  └──0.43 MB (01.05%) ── script-data [2]
│   ├──1.32 MB (03.20%) -- layout
│   │  ├──0.78 MB (01.89%) ++ (7 tiny)
│   │  └──0.54 MB (01.31%) ── pres-shell [2]
│   └──0.77 MB (01.86%) ++ (3 tiny)
> --minimize gives me odd results, I see something like 8/4 then eventually it times out 
> with: expected 4 but see only 8 files.  Giving up...

bug 806239, sorry.
> I am puzzled by this in particular (─9.03 MB (21.84%) ── heap-unclassified).
> What should I be looking for here?

That's heap memory that we don't have a specific reporter for, so we don't know who is allocating it.  Bug 798484 is open for reducing it.
> I am puzzled by this in particular (─9.03 MB (21.84%) ── heap-unclassified).
> What should I be looking for here?

Hover over any line in about:memory to get a description.  heap-unclassified means "we don't know."  9mb/20% isn't particularly high for B2G; it's probably not anomalous.
If these strings go away on GC then maybe we can just let bug 771195 fix this.
(Assignee)

Comment 14

5 years ago
I am working on some major changes to the ical lib (which lives outside of gaia).

The parser layer (which is shown above to have memory issues) has been completely rewritten with good results. I need to make major changes to the layer between the parsed object and what gaia consumes before I can take another memory screenshot but the raw numbers look a lot better:

(numbers taken with benchmark.js)

#parse v2 x 9,284 ops/sec ±2.19% (81 runs sampled)
#parse x 161 ops/sec ±5.04% (76 runs sampled)

--

I am renaming the bug to reflect the work that is actually being done though I believe we will see a substantial reduction in memory usage and a major decrease in the amount of time it takes to parse / process.
Summary: Optimize Memory Usage in ICAL parser → Optimize iCAL parser

Updated

5 years ago
blocking-basecamp: --- → ?
blocking-basecamp: ? → +
Priority: -- → P1
Target Milestone: --- → B2G C1 (to 19nov)
Assignee: nobody → jlal
(Assignee)

Comment 15

5 years ago
jsmith: The final pieces are in testing now, I need to add the piece that makes auto-upgrade smoother (not break current dog-fooding). Other then that it is fairly complete and I have been able to sync calendars without issue. Using the patch in its current state will probably break any existing calendars.

https://github.com/lightsofapollo/gaia/tree/calendar-parser-rewrite
(Assignee)

Comment 16

5 years ago
Created attachment 681851 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/6417

Pointer to Github pull-request
(Assignee)

Updated

5 years ago
Attachment #681851 - Flags: review+
(Assignee)

Comment 17

5 years ago
Reviewed on GH.

This is not a cure-all for memory or performance problems but brings some major memory and performance improvements (will post some details of memory/parser time later)  to the iCAL parser.
Status: NEW → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → FIXED

Updated

5 years ago
Keywords: verifyme
QA Contact: jsmith

Updated

5 years ago
Keywords: verifyme
Whiteboard: [MemShrink:P2] → [MemShrink:P2][qa-]

Updated

5 years ago
Flags: in-testsuite+

Updated

5 years ago
Whiteboard: [MemShrink:P2][qa-] → [MemShrink:P2]

Updated

5 years ago
Keywords: verifyme
Verified. Performance of importing large calendars seems far better now - tested with a few large yahoo and google calendars.
Status: RESOLVED → VERIFIED
Keywords: verifyme
You need to log in before you can comment on or make changes to this bug.