763252 - Some addons seem to cause massive (and possibly malformed) addonsreconciler.json

Status: NEW

(Firefox :: Sync, defect, P3)

Description

[hc5023295]

User Agent: Mozilla/5.0 (Windows NT 6.2; rv:16.0) Gecko/16.0 Firefox/16.0a1
Build ID: 20120607025755

Steps to reproduce:

I use Firefox Sync synchronization extensions.I use Windows 8.



Actual results:

Memory is filled in soon time


Expected results:

Memory no major changes

Comment 1

[Andre Klapper]

So how did you find out?

Please enter the address "about:memory?verbose" (with a lower-case "v") in the address bar and attach (using the "Add an attachment" link above) the output here.

Comment 2

[hc5023295]

Attachment: Memory

I found out that if I disabled Firefox Sync, the problem will be solved. And then I disabled sync project one by one then I found it.

Comment 3

[Richard Newman [:rnewman]]

Sync is a resident part of Firefox, so I'd only use the word "leak" if you noticed memory use increasing over time.

The addon reconciler does seem to be hanging on to a lot of strings, though. Greg?

For reference, my machine with current Aurora is using:

│  ├──────333,592 B (00.04%) -- compartment([System Principal], resource://services-sync/util.js)
│  │      ├──151,552 B (00.02%) -- gc-heap
│  │      │  ├───54,544 B (00.01%) ── arena/unused
│  │      │  ├───49,616 B (00.01%) -- objects
│  │      │  │   ├──26,240 B (00.00%) ── function
│  │      │  │   └──23,376 B (00.00%) ── non-function
│  │      │  ├───28,080 B (00.00%) -- shapes
│  │      │  │   ├──19,040 B (00.00%) ── tree
│  │      │  │   └───9,040 B (00.00%) ── dict
│  │      │  └───19,312 B (00.00%) ── sundries
│  │      ├──131,072 B (00.02%) ── analysis-temporary
│  │      ├───17,304 B (00.00%) ── other-sundries
│  │      ├───14,336 B (00.00%) ── shapes-extra/compartment-tables
│  │      ├───11,136 B (00.00%) ── objects/slots
│  │      └────8,192 B (00.00%) ── cross-compartment-wrappers

│  ├──────105,080 B (00.01%) -- compartment([System Principal], resource://services-sync/addonsreconciler.js)
│  │      ├───77,824 B (00.01%) -- gc-heap
│  │      │   ├──43,440 B (00.01%) ── arena/unused
│  │      │   ├──24,304 B (00.00%) ── sundries
│  │      │   └──10,080 B (00.00%) ── objects/function
│  │      ├───18,624 B (00.00%) ── other-sundries
│  │      └────8,632 B (00.00%) ── script-data

with addon sync disabled.

Comment 4

[Gregory Szorc [:gps]]

350MB in services-common/utils.js and 100MB in services-sync/addonsreconciler.js (most in strings). Yeah, I'd say that quacks like a memory leak.

I can't reproduce it here either (OS X).

I'm trying to think how addonsreconciler could be burning through that much memory. I can think of no circumstance where it would be invoked enough times to even come close to allocating anything near that amount of memory. It shouldn't be allocating more than a few kilobytes of string data given what it does.

I almost wonder if there is some infinite loop or something it is caught in the middle of.

Original reporter: can you attach some Sync logs? See https://philikon.wordpress.com/2011/06/13/how-to-file-a-good-sync-bug/. In addition to the preferences described there, please also set:

  services.sync.log.logger.engine.addons -> Trace
  services.sync.log.logger.addonsreconciler -> Trace

You may need to create the addonsreconciler preference.

If Sync is getting in an infinite loop, a finished log may never be written. Please also set:

  services.sync.log.appender.console -> Trace

Then open the error console (Tools -> Web Developer -> Error Console) and let us know if you are seeing any messages related to add-on sync that are repeating over and over.

Comment 5

[hc5023295]

Attachment: sync log before I change the preferences.

sync log before I change the preferences.

Comment 6

[hc5023295]

Attachment: sync logs after I change the preferences

sync logs after I change the preferences

Comment 7

[hc5023295]

Attachment: error message

here're error messages

Comment 8

[hc5023295]

Attachment: from about:support

Then here're some messages form about:support

Comment 9

[Gregory Szorc [:gps]]

Yikes. There's a lot going on in these logs.

rnewman: you should definitely take a look!

One part that bothers me is the elapsed time in attachment 631884 [details]. We see the reconciler doing its thing:

1339322547984	Sync.Engine.Addons	DEBUG	Refreshing reconciler state
1339322547984	Sync.AddonsReconciler	INFO	Refreshing global state from AddonManager.
1339322576126	Sync.AddonsReconciler	INFO	Change recorded for http://userscripts.org/scripts/show/49911/è±ç£å©æ douban [e-mail]
1339322576127	Sync.Tracker.Addons	DEBUG	changeListener invoked: 2 http://userscripts.org/scripts/show/49911/è±ç£å©æ douban [e-mail]
1339322576127	Sync.Store.Addons	DEBUG	http://userscripts.org/scripts/show/49911/è±ç£å©æ douban [e-mail] not syncable: type not in whitelist: user-script
1339322576127	Sync.Tracker.Addons	DEBUG	Ignoring change because add-on isn't syncable: http://userscripts.org/scripts/show/49911/è±ç£å©æ douban [e-mail]
1339322576419	Sync.AddonsReconciler	INFO	Saving reconciler state to file: addonsreconciler

Then we get a repeating stream of:

1339322665345	Sync.SyncScheduler	DEBUG	Global Score threshold hit, triggering sync.
1339322665782	Sync.Service	DEBUG	User-Agent: Firefox/16.0a1 FxSync/1.18.0.20120607025755.
1339322665782	Sync.Service	INFO	Starting sync at 2012-06-10 18:04:25
1339322665782	Sync.Service	DEBUG	Exception: Could not acquire lock. Label: "service.js: sync". No traceback available
1339322665782	Sync.Service	INFO	Cannot start sync: already syncing?
1339322666720	Sync.SyncScheduler	DEBUG	Global Score threshold hit, triggering sync.
1339322666721	Sync.Service	DEBUG	User-Agent: Firefox/16.0a1 FxSync/1.18.0.20120607025755.
1339322666721	Sync.Service	INFO	Starting sync at 2012-06-10 18:04:26
1339322666721	Sync.Service	DEBUG	Exception: Could not acquire lock. Label: "service.js: sync". No traceback available
1339322666721	Sync.Service	INFO	Cannot start sync: already syncing?

About 105 minutes later, we get:

1339328984150	Sync.Status	DEBUG	Status for engine addons: error.engine.reason.unknown_fail
1339328984150	Sync.Status	DEBUG	Status.service: success.status_ok => error.sync.failed_partial
1339328984152	Sync.ErrorHandler	DEBUG	addons failed: App. Quitting Stack trace: resource://services-common/async.js:119 < waitForSyncCallback()@resource://services-common/async.js:94 < resource://services-common/async.js:137 < <file:unknown> < _refreshReconcilerState()@resource:///modules/services-sync/engines/addons.js:230 < _syncStartup()@resource:///modules/services-sync/engines/addons.js:200 < <file:unknown> < SyncEngine__sync()@resource://services-sync/engines.js:1282 < <file:unknown> < WrappedNotify()@resource://services-sync/util.js:142 < <file:unknown> < Engine_sync()@resource://services-sync/engines.js:481 < <file:unknown> < WeaveSvc__syncEngine()@resource:///modules/services-sync/service.js:1393 < resource:///modules/services-sync/service.js:1286 < <file:unknown> < WrappedNotify()@resource://services-sync/util.js:142 < WrappedLock()@resource://services-sync/util.js:97 < <file:unknown> < _lockedSync()@resource:///modules/services-sync/service.js:1186 < resource:///modules/services-sync/service.js:1177 < <file:unknown> < WrappedCatch()@resource://services-sync/util.js:71 < <file:unknown> < sync()@resource:///modules/services-sync/service.js:1165 < <file:unknown> < <file:unknown>
1339328984182	Sync.Service	INFO	Sync completed at 2012-06-10 19:49:44 after 6437.51 secs.
1339328984183	Sync.SyncScheduler	DEBUG	Next sync in 90000 ms.
1339328984183	Sync.ErrorHandler	DEBUG	Some engines did not sync correctly.

Cross-referencing the source, we're waiting on the callback from AddonsReconciler.refreshGlobalState. And, because the last log line before things start going wrong is "1339322576419	Sync.AddonsReconciler	INFO	Saving reconciler state to file: addonsreconciler", we must be getting lost in Utils.jsonSave().

The plot thickens. I'd really like to be able to reproduce this locally...

Comment 10

[Richard Newman [:rnewman]]

(In reply to Gregory Szorc [:gps] from comment #9)

> 1339322666721	Sync.Service	INFO	Cannot start sync: already syncing?
> 
> About 105 minutes later, we get:
> 
> 1339328984152	Sync.ErrorHandler	DEBUG	addons failed: App. Quitting Stack
> trace: resource://services-common/async.js:119 <

This is reminiscent of Bug 665872, and rings bells for Bug 666327.

If we're not getting an async callback, somehow, then we're just going to hang, and the sync will block later syncs.

It's conceivable that the huge string allocation is in log messages, or this is hanging trying to write out a huge blob of JSON…

Comment 11

[Nicholas Nethercote [inactive]]

Gregory, any idea how to make some progress on this?  100s of MBs for Sync sounds really bad...

Comment 12

[Richard Newman [:rnewman]]

(In reply to Nicholas Nethercote [:njn] from comment #11)
> Gregory, any idea how to make some progress on this?  100s of MBs for Sync
> sounds really bad...

Greg's traveling, so: the single biggest help would be seeing whether this is reproducible, which might require a machine with Windows 8 (which none of us have).

If not, then good and bad: less worrying, but harder to debug!

If it is reproducible, then cranking Sync logging to the max (and dumping it to the console) should give some hints about where those strings are coming from. If it's not Sync logging, then we're looking at JSON serialization or the addons reconciler.

Comment 13

[Gregory Szorc [:gps]]

Are you still seeing this issue in recent builds?

Comment 14

[hc5023295]

(In reply to Gregory Szorc [:gps] from comment #13)
> Are you still seeing this issue in recent builds?

Not yet. But if I don't Sync Adblock Plus setting, it will happen again. And if I delete weave/changes/adblockplus.json and adblockplus.private.json, this problem will be solve in a few days. Then it well happen again. Turn on sync it can solve this problem. And now,firefox crashes very often in Win8

Comment 15

[hc5023295]

And now,firefox crashes very often in Win8 if I sign in outlook.com

Comment 16

[Andrew McCreight [:mccr8]]

(In reply to hc5023295 from comment #15)
> And now,firefox crashes very often in Win8 if I sign in outlook.com

Are you using Nightly? There's a known crash there. I don't have the bug handy. I think it is being fixed soon.

Comment 17

[hc5023295]

(In reply to Andrew McCreight [:mccr8] from comment #16)
> (In reply to hc5023295 from comment #15)
> > And now,firefox crashes very often in Win8 if I sign in outlook.com
> 
> Are you using Nightly? There's a known crash there. I don't have the bug
> handy. I think it is being fixed soon.

In fact, it haven't be fixed yet...OK, I'll wait for the next update.

Comment 18

[hc5023295]

Here're crashes reports:
https://crash-stats.mozilla.com/report/index/bp-bc124863-6183-45af-bb69-093562120815
http://crash-stats.mozilla.com/report/index/bp-1c79095f-bd0a-45df-967b-dc2aa2120815
http://crash-stats.mozilla.com/report/index/bp-a8bddb8e-1f31-4465-9799-256562120815
http://crash-stats.mozilla.com/report/index/bp-15119575-5c49-47fb-890e-fde052120815
And so on.

Comment 19

[hc5023295]

Often css does not load, I had to refresh the page. Like bbs(http://bbs.duba.net/).

Comment 20

[Matthias Versen [:Matti]]

[e-mail]: This bug report is only about the memory leak and not about other issues. Please file new bugs for each different issue (after you checked for already existing bug reports). Thanks

Comment 21

[Andrew McCreight [:mccr8]]

(In reply to hc5023295 from comment #18)
> Here're crashes reports:
Ah, yes, that definitely looks like bug 781265. It will hopefully be fixed tomorrow or maybe the day after.  It has a reviewed patch already. If the crashes are really annoying, you could switch to Aurora for a bit and use the same profile.

Comment 22

[hc5023295]

This problem happens again on Windows XP.

Comment 23

[Nicholas Nethercote [inactive]]

Has any progress been made here?  This sounds bad, but it's also really unclear what the status is.

Comment 24

[Gregory Szorc [:gps]]

njn: we have no clue what is causing the memory leak. We have not been able to reproduce. There are references to crashes, but it isn't clear if they are related or if they have truly been resolved.

Original bug reporter: do you still see this memory issue on the latest Nightly (available from http://nightly.mozilla.org/)?

Comment 25

[hc5023295]

(In reply to Gregory Szorc [:gps] from comment #24)
> njn: we have no clue what is causing the memory leak. We have not been able
> to reproduce. There are references to crashes, but it isn't clear if they
> are related or if they have truly been resolved.
> 
> Original bug reporter: do you still see this memory issue on the latest
> Nightly (available from http://nightly.mozilla.org/)?

Yes. I see this issue yesterday. What should I do?

Comment 26

[Gregory Szorc [:gps]]

(In reply to hc5023295 from comment #25)
> Yes. I see this issue yesterday. What should I do?

Let's first try using the Gecko profiler and see if anything shows up. Follow the directions at https://developer.mozilla.org/en-US/docs/Performance/Profiling_with_the_Built-in_Profiler to install the Gecko profiler.

When you've noticed memory bloat, capture and upload the profiler output. That should hopefully give us some raw data to look at.

Comment 27

[hc5023295]

Attachment: profiler output

Comment 28

[Gregory Szorc [:gps]]

Thanks for the profile!

I'm actually not sure how to import a foreign profile for analyzing.

njn, et. al: can you provide assistance?

Comment 29

[hc5023295]

So, is there anyone can solve this?

I tried to creative a new clean profile, but it doesn't work.

Maybe it because of the connect?
Here's the tracert report.

C:\Users\浩成>tracert phx-sync134.services.mozilla.com

通过最多 30 个跃点跟踪
到 sync-rr.phx.services.mozilla.com [63.245.217.208] 的路由:

  1     2 ms     2 ms     5 ms  1.92.35.120.board.xm.fj.dynamic.163data.com.cn [
120.35.92.1]
  2     3 ms     2 ms     2 ms  1.92.35.120.board.xm.fj.dynamic.163data.com.cn [
120.35.92.1]
  3     2 ms     2 ms     2 ms  117.30.25.141
  4     3 ms     3 ms     2 ms  218.85.117.89
  5    18 ms    17 ms    18 ms  202.97.66.149
  6    18 ms    18 ms    18 ms  202.97.33.38
  7    19 ms    19 ms    18 ms  202.97.35.106
  8   194 ms   194 ms   194 ms  202.97.50.122
  9   247 ms   246 ms   250 ms  202.97.49.158
 10   168 ms   169 ms   168 ms  218.30.54.174
 11   259 ms   251 ms   256 ms  xe-2-3-0.cr1.lax112.us.above.net [64.125.31.190]

 12   262 ms   266 ms   270 ms  xe-1-1-0.mpr3.phx2.us.above.net [64.125.30.89]
 13   161 ms   162 ms   161 ms  64.124.201.178.mozilla.com [64.124.201.178]
 14   265 ms   271 ms   271 ms  xe-0-0-1.core1.phx1.mozilla.net [63.245.216.18]

 15     *        *        *     请求超时。
 16     *        *        *     请求超时。
 17     *        *        *     请求超时。
 18     *        *        *     请求超时。
 19     *        *        *     请求超时。
 20     *        *        *     请求超时。
 21     *        *        *     请求超时。
 22     *        *        *     请求超时。
 23     *        *        *     请求超时。
 24     *        *        *     请求超时。
 25     *        *        *     请求超时。
 26     *        *        *     请求超时。
 27     *        *        *     请求超时。
 28     *        *        *     请求超时。
 29     *        *        *     请求超时。
 30     *        *        *     请求超时。

跟踪完成。

Comment 30

[Richard Newman [:rnewman]]

(In reply to hc5023295 from comment #29)

> I tried to creative a new clean profile, but it doesn't work.
> 
> Maybe it because of the connect?

Pretty sure that won't be the issue.

What problem do you have with creating a new profile?

Comment 31

[hc5023295]

(In reply to Richard Newman [:rnewman] from comment #30)
> (In reply to hc5023295 from comment #29)
> 
> > I tried to creative a new clean profile, but it doesn't work.
> > 
> > Maybe it because of the connect?
> 
> Pretty sure that won't be the issue.
> 
> What problem do you have with creating a new profile?

memory leaks when i enable sync

Comment 32

[hc5023295]

Attachment: The compressed file of addonsreconciler.json

When memory leaks, Firefox Sync generate a large file named "addonsreconciler.json". After I delete this file, memory doesn't leak. But after a few days, this large file is generated again.

Comment 33

[Richard Newman [:rnewman]]

This looks like there's an addon entry whose ID is an enormous sequence of horror:

  "/Ã<U+0083>Â<U+0083>Ã<U+0082>Â<U+0083>Ã…

and includes fragments like this:

  ¦@greasespot.net"],[1353126234738,2,"http://userscripts.org/scripts/show/49911/
  ¢@greasespot.net"],[1353127535883,1,"DAR/
  ¦@greasespot.net"],[1353127535883,1,"http://userscripts.org/scripts/show/49911/
  ¤ Bean [e-mail]"],[1353129069278,2,"/

finally resolving to big chunks of nearly readable text (these identify addons that you have installed, but I figure you're OK with that, having just uploaded the file yourself):

¦@greasespot.net"],[1353135008162,2,"http://userscripts.org/scripts/show/49911/ÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂñÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂä Bean [e-mail]"],[1353135052073,2,"[e-mail]"],[1353135765098,4,"{32fce7ea-bc97-ac20-d883-25f4f55c7eca}"],[1353135771048,4,"{0447c180-ee6a-d33c-1a11-ed7a7f868537}"],[1353135775110,4,"{7200a3c6-c39e-97e7-cf7f-657c31cee8cc}"],[1353135786277,4,"{9b12657e-a060-a592-1dfb-5e57ebf3199b}"],[1353135787333,4,"{db20f3bd-1b16-b403-0450-f98276d89d22}"],[1353135788076,4,"{e35c2b1c-2f33-6a1d-5fce-68ae755832a2}"],[1353139577856,3,"{0447c180-ee6a-d33c-1a11-ed7a7f868537}"],[1353139577870,1,"/ÃÂÃÂÃÂçÃÂÃÂÃÂùÃÂÃÂÃÂÃÂÃÂÃÂÃÂçÃÂÃÂÃÂîÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂýÃÂÃÂÃÂìÃÂÃÂÃÂæÃÂÃÂÃÂÃÂÃÂÃÂÃÂâ@greasespot.net"],[1353139577871,1,"DAR/ÃÂÃÂÃÂèÃÂÃÂÃÂñÃÂÃÂÃÂÃÂÃÂÃÂÃÂæÃÂÃÂÃÂÃÂÃÂÃÂÃÂæ@greasespot.net"],[1353139577871,1,"http://userscripts.org/scripts/show/49911/ÃÂÃÂÃÂèÃÂÃÂÃÂñÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂÃÂÃÂÃÂÃÂä Bean [e-mail]"],[1353139577873,2,"/


and at the very end, we can see a possible culprit:

  [1353144431981,2,"http://userscripts.org/scripts/show/49911/ÃÂèÃÂñÃÂÃÂÃÂèÃÂÃÂÃÂä Bean [e-mail]"]

by comparison to a proper record:

  [1353156835089,4,"[e-mail]"]


I don't know if this is a problem with the record itself (malformed UTF-? sequence?), with its encoding in the Addons Manager, or during JSON serialization.

CCing Unfocused.

Blair, Greg: do either of you have a Windows machine on which to try installing <http://userscripts.org/scripts/show/49911/> ("Bean Vine for GreaseMonkey", which has Kanji "mame fuji" in the title and probably the descriptive URL) and see if you can reproduce?

Comment 34

[Richard Newman [:rnewman]]

This looks like there's an addon entry whose ID is an enormous sequence of horror:

  "/Ã<U+0083>Â<U+0083>Ã<U+0082>Â<U+0083>Ã…

and includes fragments like this:

  ¦@greasespot.net"],[1353126234738,2,"http://userscripts.org/scripts/show/49911/
  ¢@greasespot.net"],[1353127535883,1,"DAR/
  ¦@greasespot.net"],[1353127535883,1,"http://userscripts.org/scripts/show/49911/
  ¤ Bean [e-mail]"],[1353129069278,2,"/

finally resolving to big chunks of nearly readable text (these identify addons that you have installed, but I figure you're OK with that, having just uploaded the file yourself):

¦@greasespot.net"],[1353135008162,2,"http://userscripts.org/scripts/show/49911/ÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂñÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂÃÂä Bean [e-mail]"],[1353135052073,2,"[e-mail]"],[1353135765098,4,"{32fce7ea-bc97-ac20-d883-25f4f55c7eca}"],[1353135771048,4,"{0447c180-ee6a-d33c-1a11-ed7a7f868537}"],[1353135775110,4,"{7200a3c6-c39e-97e7-cf7f-657c31cee8cc}"],[1353135786277,4,"{9b12657e-a060-a592-1dfb-5e57ebf3199b}"],[1353135787333,4,"{db20f3bd-1b16-b403-0450-f98276d89d22}"],[1353135788076,4,"{e35c2b1c-2f33-6a1d-5fce-68ae755832a2}"],[1353139577856,3,"{0447c180-ee6a-d33c-1a11-ed7a7f868537}"],[1353139577870,1,"/ÃÂÃÂÃÂçÃÂÃÂÃÂùÃÂÃÂÃÂÃÂÃÂÃÂÃÂçÃÂÃÂÃÂîÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂýÃÂÃÂÃÂìÃÂÃÂÃÂæÃÂÃÂÃÂÃÂÃÂÃÂÃÂâ@greasespot.net"],[1353139577871,1,"DAR/ÃÂÃÂÃÂèÃÂÃÂÃÂñÃÂÃÂÃÂÃÂÃÂÃÂÃÂæÃÂÃÂÃÂÃÂÃÂÃÂÃÂæ@greasespot.net"],[1353139577871,1,"http://userscripts.org/scripts/show/49911/ÃÂÃÂÃÂèÃÂÃÂÃÂñÃÂÃÂÃÂÃÂÃÂÃÂÃÂèÃÂÃÂÃÂÃÂÃÂÃÂÃÂä Bean [e-mail]"],[1353139577873,2,"/


and at the very end, we can see a possible culprit:

  [1353144431981,2,"http://userscripts.org/scripts/show/49911/ÃÂèÃÂñÃÂÃÂÃÂèÃÂÃÂÃÂä Bean [e-mail]"]

by comparison to a proper record:

  [1353156835089,4,"[e-mail]"]


I don't know if this is a problem with the record itself (malformed UTF-? sequence?), with its encoding in the Addons Manager, or during JSON serialization.

CCing Unfocused.

Blair, Greg: do either of you have a Windows machine on which to try installing <http://userscripts.org/scripts/show/49911/> ("Bean Vine for GreaseMonkey", which has Kanji "mame fuji" in the title and probably the descriptive URL) and see if you can reproduce?

Comment 35

[Blair McBride [:Unfocused] (UNAVAILABLE)]

I don't know when I'll have time to look at this :\ But I'm not overly familiar with the addon sync code anyway, only how it interacts with Add-ons Manager APIs - which doesn't seem to be the problem here.

Comment 36

[Gregory Szorc [:gps]]

Perhaps if we had the extensions.sqlite file from the profile we could look at the source of truth and try to reproduce this.

If you go to about:support, there should be a button to open your profile directory. Click that, find the extensions.sqlite file and upload it to this bug.

Blair: Please confirm there isn't any super-private data (like passwords) that will be included in this file.

Comment 37

[Blair McBride [:Unfocused] (UNAVAILABLE)]

(In reply to Gregory Szorc [:gps] from comment #36)
> Blair: Please confirm there isn't any super-private data (like passwords)
> that will be included in this file.

Indeed, there is not.

But if that's just a normal Greasemonkey script, it won't be in extensions.sqlite (unless its been compiled into a normal addon).

Comment 38

[hc5023295]

Attachment: The compressed file of addonsreconciler.json

Hello, this problem still happens.

Comment 39

[hc5023295]

Lots of people have this problem:
http://g.mozest.com/viewthread.php?tid=41040
http://bbs.kafan.cn/thread-1473465-1-1.html
http://tieba.baidu.com/p/1568247523
http://bbs.kafan.cn/thread-1439708-1-1.html
http://www.firefox.net.cn/forum/viewtopic.php?p=322537

Comment 40

[hc5023295]

Maybe it's caused by a grasemonkey script with a long non-English name.
See http://www.firefox.net.cn/forum/viewtopic.php?f=4&t=47261 .

Comment 41

[Richard Newman [:rnewman]]

hc5023295: yes, it's the same Bean Vine script.

Comment 42

[Richard Newman [:rnewman]]

I can't reproduce this on Mac Nightly:

---
{"version":1,"addons":{"{e4a8a97b-f2ed-450b-b12d-ee082ba24781}":{"id":"{e4a8a97b-f2ed-450b-b12d-ee082ba24781}","guid":"j0yOt90HY140","enabled":true,"installed":true,"modified":1373476312407,"type":"extension","scope":1,"foreignInstall":false},"{972ce4c6-7e08-4474-a285-3208198ce6fd}":{"id":"{972ce4c6-7e08-4474-a285-3208198ce6fd}","guid":"KpnkOeYZVeeW","enabled":true,"installed":true,"modified":1373476430725,"type":"theme","scope":4,"foreignInstall":false},"{d95f2237-07c7-b389-7956-65e6f1ce8e0a}":{"id":"{d95f2237-07c7-b389-7956-65e6f1ce8e0a}","enabled":true,"installed":true,"modified":1373476430727,"type":"plugin","scope":8,"foreignInstall":true},"{bd5c7f2e-5ec5-9e68-0834-b7ead64237a1}":{"id":"{bd5c7f2e-5ec5-9e68-0834-b7ead64237a1}","enabled":true,"installed":true,"modified":1373476430728,"type":"plugin","scope":8,"foreignInstall":true},"{07b90314-1e79-c84a-4b47-fb7e1853be39}":{"id":"{07b90314-1e79-c84a-4b47-fb7e1853be39}","enabled":true,"installed":true,"modified":1373476430729,"type":"plugin","scope":8,"foreignInstall":true},"{16ae005c-9049-fc46-14bd-5ee5bbac9bbf}":{"id":"{16ae005c-9049-fc46-14bd-5ee5bbac9bbf}","enabled":true,"installed":true,"modified":1373476430730,"type":"plugin","scope":8,"foreignInstall":true},"{bd99908a-a333-fe50-6c71-605955a3cfb7}":{"id":"{bd99908a-a333-fe50-6c71-605955a3cfb7}","enabled":true,"installed":true,"modified":1373476430731,"type":"plugin","scope":8,"foreignInstall":true},"{b14169e2-11ed-f9d5-279a-9754401447dd}":{"id":"{b14169e2-11ed-f9d5-279a-9754401447dd}","enabled":true,"installed":true,"modified":1373476430732,"type":"plugin","scope":8,"foreignInstall":true},"{9b5e0cc5-8de7-6362-9e71-dd64d836c3a0}":{"id":"{9b5e0cc5-8de7-6362-9e71-dd64d836c3a0}","enabled":true,"installed":true,"modified":1373476430733,"type":"plugin","scope":8,"foreignInstall":true},"{a10379c7-cde4-255b-7f7b-89fb478ef17d}":{"id":"{a10379c7-cde4-255b-7f7b-89fb478ef17d}","enabled":false,"installed":true,"modified":1373476430733,"type":"plugin","scope":8,"foreignInstall":true},"{adb478a6-f33f-c661-f352-3fd5bfb60639}":{"id":"{adb478a6-f33f-c661-f352-3fd5bfb60639}","enabled":true,"installed":true,"modified":1373476430734,"type":"plugin","scope":8,"foreignInstall":true},"{815e30d5-4097-c260-7b7a-e872e2f1eab9}":{"id":"{815e30d5-4097-c260-7b7a-e872e2f1eab9}","enabled":false,"installed":true,"modified":1373476430734,"type":"plugin","scope":8,"foreignInstall":true},"{5ea60f7e-7eef-6fb6-03fc-6bb8b4b1aed4}":{"id":"{5ea60f7e-7eef-6fb6-03fc-6bb8b4b1aed4}","enabled":true,"installed":true,"modified":1373476430735,"type":"plugin","scope":8,"foreignInstall":true},"http://userscripts.org/scripts/show/49911/豆藤 Bean [e-mail]":{"id":"http://userscripts.org/scripts/show/49911/豆藤 Bean [e-mail]","enabled":true,"installed":true,"modified":1373476430735,"type":"greasemonkey-user-script","scope":1}},"changes":[[1373476312407,1,"{e4a8a97b-f2ed-450b-b12d-ee082ba24781}"],[1373476430725,1,"{972ce4c6-7e08-4474-a285-3208198ce6fd}"],[1373476430727,1,"{d95f2237-07c7-b389-7956-65e6f1ce8e0a}"],[1373476430728,1,"{bd5c7f2e-5ec5-9e68-0834-b7ead64237a1}"],[1373476430729,1,"{07b90314-1e79-c84a-4b47-fb7e1853be39}"],[1373476430730,1,"{16ae005c-9049-fc46-14bd-5ee5bbac9bbf}"],[1373476430731,1,"{bd99908a-a333-fe50-6c71-605955a3cfb7}"],[1373476430732,1,"{b14169e2-11ed-f9d5-279a-9754401447dd}"],[1373476430733,1,"{9b5e0cc5-8de7-6362-9e71-dd64d836c3a0}"],[1373476430733,1,"{a10379c7-cde4-255b-7f7b-89fb478ef17d}"],[1373476430734,1,"{adb478a6-f33f-c661-f352-3fd5bfb60639}"],[1373476430734,1,"{815e30d5-4097-c260-7b7a-e872e2f1eab9}"],[1373476430735,1,"{5ea60f7e-7eef-6fb6-03fc-6bb8b4b1aed4}"],[1373476430735,1,"http://userscripts.org/scripts/show/49911/豆藤 Bean [e-mail]"]]}
---

Memory corruption?

Comment 43

[hc5023295]

(In reply to Richard Newman [:rnewman] from comment #41)
> hc5023295: yes, it's the same Bean Vine script.

Of course, because I only installed one script with non-English name...
And my memory is intact.

Comment 44

[dgod.osa]

(In reply to Richard Newman [:rnewman] from comment #42)
> I can't reproduce this on Mac Nightly:

maybe the locale of macosx is utf-8 based, but windows in china is gbk based

Comment 45

[hc5023295]

This problem also happens on Windows 8 style Firefox, even through I don't sync addons.

Comment 46

[Richard Newman [:rnewman]]

(In reply to hc5023295 from comment #45)
> This problem also happens on Windows 8 style Firefox, even through I don't
> sync addons.

The Metro and Classic browsers communicate via Sync. If you have add-ons syncing in Classic, they will also be syncing in Metro, though the app itself doesn't support them.

Comment 47

[hc5023295]

(In reply to Richard Newman [:rnewman] from comment #46)
> (In reply to hc5023295 from comment #45)
> > This problem also happens on Windows 8 style Firefox, even through I don't
> > sync addons.
> 
> The Metro and Classic browsers communicate via Sync. If you have add-ons
> syncing in Classic, they will also be syncing in Metro, though the app
> itself doesn't support them.

But I don't have add-ons syncing in Classic.

Comment 48

[Richard Newman [:rnewman]]

(In reply to hc5023295 from comment #47)

> But I don't have add-ons syncing in Classic.

You mentioned in Comment 0 that you have add-on sync enabled, and we determined that turning it off avoids this issue, right?

(Note that you get one set of choices that apply to all of your profiles, so if you have add-ons syncing anywhere, you have them syncing everywhere.)

So could you clarify:

* Is "Add-ons" checked in Options > Sync in Windows?
* If not, could you explain how you determined "this problem also happens"?

Comment 49

[hc5023295]

(In reply to Richard Newman [:rnewman] from comment #48)
> (In reply to hc5023295 from comment #47)
> 
> > But I don't have add-ons syncing in Classic.
> 
> You mentioned in Comment 0 that you have add-on sync enabled, and we
> determined that turning it off avoids this issue, right?
> 
> (Note that you get one set of choices that apply to all of your profiles, so
> if you have add-ons syncing anywhere, you have them syncing everywhere.)
> 
> So could you clarify:
> 
> * Is "Add-ons" checked in Options > Sync in Windows?
> * If not, could you explain how you determined "this problem also happens"?

Yes, turning add-ons sync off avoids this issue, but actually it hasn't been solved.

I only have one computer logging in to Sync with this account. And I can clarify that I have disabled add-ons sync.

"This problem also happens" means that Firefox lead to memory leaks after I enable Sync in Firefox Metro.

Comment 50

[xunxun]

I don't know how to reproduce the issue.


I think addonsreconciler.json is created by https://mxr.mozilla.org/mozilla-central/source/services/sync/modules/addonsreconciler.js#266, will Utils.jsonSave function limit file's size? I don't think only state saving can cause a large addonsreconciler.json, is there any developer understand the information?

Comment 51

[hc5023295]

(In reply to xunxun from comment #50)
> I don't know how to reproduce the issue.
> 
> 
> I think addonsreconciler.json is created by
> https://mxr.mozilla.org/mozilla-central/source/services/sync/modules/
> addonsreconciler.js#266, will Utils.jsonSave function limit file's size? I
> don't think only state saving can cause a large addonsreconciler.json, is
> there any developer understand the information?

I install Greasemonkey, and installed a script with a Chinese name. When I start Sync, this problem will happen.

Comment 52

[Edwin Wong [:edwong]]

Triage: setting to P3 as priority is has time based implications

Comment 53

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

(In reply to Richard Newman [:rnewman] from comment #33)
> This looks like there's an addon entry whose ID is an enormous sequence of
> horror:
> 
>   "/Ã<U+0083>Â<U+0083>Ã<U+0082>Â<U+0083>Ã…

This is fascinating. The file is valid utf-8, and the strings in there are definitely the same string that's been utf-8 encoded multiple times. Interestingly, different copies of the string have been encoded multiple times - I wrote a script to repeatedly decode as utf-8 until we could go no further, and every single variation of the string ended up with the same value. I believe each time the file is written, 2 new versions of the string (ie, with one more utf-8 encode) is added to the list of installed addons. The attached file has copies of the string encoded from 1 to 22 times. The string in question is "\u8c46\u85e4" - repeatedly utf-8 encoding that 22 times yields a string with length 12.5MB.

A version of the greasemoney script can be found at http://userscripts-mirror.org/scripts/show/49911, and I can reproduce the problem on Firefox 30. I can *not* reproduce it in Firefox 35 (and sadly mozregression isn't making it easy to find exactly when it was fixed).

Sadly though, once that cruft is in the file it seems to stay there forever. ISTM the correct approach to take is:

* spend some time trying to find the specific patch that solved the underlying issue and verify the problem *really* doesn't exist any more. I suspect it will be something like bug 1235365 (although it doesn't seem to be that one specifically)
* bump the "version" when we load and save the file, forcing every Firefox install to regenerate the file.