1433698 - Improve logging for synced bookmark trees

Status: RESOLVED FIXED

(Firefox :: Sync, enhancement)

Description

[Lina Butler [:lina]]

Today, I tried out the buffered engine with my bookmarks. With trace logging enabled, one error log ballooned to 1.28 *giga*bytes (!), to the point where `JSON.stringify` locked up the browser for several minutes. (My tree is fairly flat, but large; with 3487 bookmarks). Moreover, the default `toJSON()` output is noisy, and doesn't show the tree structure at all: it's hard to see what went wrong looking at a JSON dump of flat bookmark nodes.

We can dump an ASCII art representation of the trees instead, and cut down on the logging we do for nodes overall. With this patch, I get a more reasonable 3.8 MB/trace log. The output looks something like this:

> 1517088512958 Sync.Engine.Bookmarks.Mirror  TRACE Built remote tree from mirror
> + root________ [folder; 0.000s]
> | + menu________ [folder; 0.000s]
> | | - mozBmk______ [bookmark; 0.000s; unmerged]
> | + toolbar_____ [folder; 0.000s; unmerged]
> | | - fxBmk_______ [bookmark; 0.000s; unmerged]
> | | + tFolder_____ [folder; 0.000s; unmerged]
> | | | - tbBmk_______ [bookmark; 0.000s; unmerged]
> | + unfiled_____ [folder; 0.000s]
> | + mobile______ [folder; 0.000s]
> 1517088512961 Sync.Engine.Bookmarks.Mirror  TRACE Built local tree from Places
> + root________ [folder; 0.000s]
> | + menu________ [folder; 0.105s]
> | | - mozBmk______ [bookmark; 0.105s]
> | + toolbar_____ [folder; 0.038s; unmerged]
> | | - bzBmk_______ [bookmark; 0.038s; unmerged]
> | + unfiled_____ [folder; 0.184s]
> | + mobile______ [folder; 0.183s]
> ~ deletedAAAAA
> ~ deletedBBBBB

Comment 1

[Lina Butler [:lina]]

Attachment: Bug 1433698 - Make trace logging for synced bookmark trees less noisy.

Review commit: https://reviewboard.mozilla.org/r/216112/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/216112/

Comment 2

[Lina Butler [:lina]]

Comment on attachment 8946090 [details]
Bug 1433698 - Make trace logging for synced bookmark trees less noisy.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/216112/diff/1-2/

Comment 3

[Lina Butler [:lina]]

Tightening up the format a bit:

> 1517163777413 Sync.Engine.Bookmarks.Mirror  TRACE Built remote tree from mirror
> + root________ (F; 0.000s)
> | + menu________ (F; 0.000s)
> | | + folderAAAAAA (F; 0.000s)
> | | | + folderBBBBBB (F; 0.000s)
> | | | | - bookmarkCCCC (B; 0.000s; !)
> | | | | - bookmarkDDDD (B; 0.000s)
> | + toolbar_____ (F; 0.000s)
> | + unfiled_____ (F; 0.000s)
> | + mobile______ (F; 0.000s)
> 1517163777414 Sync.Engine.Bookmarks.Mirror  DEBUG Building local tree from Places
> 1517163777417 Sync.Engine.Bookmarks.Mirror  TRACE Built local tree from Places
> + root________ (F; 0.000s)
> | + menu________ (F; 0.031s; !)
> | + toolbar_____ (F; 0.013s; !)
> | + unfiled_____ (F; 0.100s)
> | + mobile______ (F; 0.100s)
> ~bookmarkCCCC, ~bookmarkDDDD, ~folderAAAAAA, ~folderBBBBBB
> 1517163777420 Sync.Engine.Bookmarks.Mirror  TRACE Item root________ exists locally as "root________ (F; 0.000s)" and remotely as "root________ (F; 0.000s)"; merging
> 1517163777420 Sync.Engine.Bookmarks.Mirror  TRACE Merge state for root________ is "(V: L; S: L)"
> 1517163777420 Sync.Engine.Bookmarks.Mirror  TRACE Merging folders "root________ (F; 0.000s)" and "root________ (F; 0.000s)"
> 1517163777424 Sync.Engine.Bookmarks.Mirror  TRACE Built new merged tree
> + root________ (V: L; S: L)
> | + menu________ (V: L; S: +)
> | | - bookmarkCCCC (V: R; S: +)
> | - toolbar_____ (V: L; S: L)
> | - unfiled_____ (V: L; S: L)
> | - mobile______ (V: L; S: L)
> R: ~folderAAAAAA, ~folderBBBBBB, ~bookmarkDDDD

Comment 4

[Mark Hammond [:markh] [:mhammond]]

Comment on attachment 8946090 [details]
Bug 1433698 - Make trace logging for synced bookmark trees less noisy.

https://reviewboard.mozilla.org/r/216112/#review221926

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/2f9d19afde26
Make trace logging for synced bookmark trees less noisy. r=markh

Comment 6

[Stefan Hindli [:stefan_hindli]]

https://hg.mozilla.org/mozilla-central/rev/2f9d19afde26