Last Comment Bug 725248 - Negative "heap-unclassified" in about:memory, perhaps due to the non-atomicity of memory reporters
: Negative "heap-unclassified" in about:memory, perhaps due to the non-atomicit...
Status: RESOLVED WORKSFORME
[MemShrink:P3]
:
Product: Toolkit
Classification: Components
Component: about:memory (show other bugs)
: 12 Branch
: x86 Windows XP
: -- normal (vote)
: ---
Assigned To: Nicholas Nethercote [:njn]
:
Mentors:
: 756527 (view as bug list)
Depends on: 913260
Blocks:
  Show dependency treegraph
 
Reported: 2012-02-08 02:42 PST by :aceman
Modified: 2013-11-20 23:00 PST (History)
6 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments

Description :aceman 2012-02-08 02:42:15 PST
WARNING: the following values are negative or unreasonably large.
 explicit/(4 tiny)
 explicit/(4 tiny)/heap-unclassified
This indicates a defect in one or more memory reporters.  The invalid values are highlighted, but you may need to expand one or more sub-trees to see them.

Explicit Allocations
66.69 MB (100.0%) -- explicit
├──42.61 MB (63.89%) -- storage
│  ├──41.16 MB (61.72%) -- sqlite
│  │  ├──20.08 MB (30.11%) -- urlclassifier3.sqlite
│  │  │  ├──19.98 MB (29.96%) ── cache-used
│  │  │  └───0.11 MB (00.16%) ++ (2 tiny)
│  │  ├──19.62 MB (29.42%) ── other
│  │  └───1.45 MB (02.18%) ++ (7 tiny)
│  └───1.45 MB (02.17%) -- prefixset
│      └──1.45 MB (02.17%) ── all
├──24.97 MB (37.44%) -- js
│  ├──13.40 MB (20.09%) -- compartment([System Principal], 0x3675000)
│  │  ├───7.03 MB (10.54%) -- gc-heap
│  │  │   ├──1.89 MB (02.84%) -- arena
│  │  │   │  ├──1.84 MB (02.76%) ── unused
│  │  │   │  └──0.05 MB (00.08%) ++ (2 tiny)
│  │  │   ├──1.88 MB (02.81%) -- shapes
│  │  │   │  ├──1.22 MB (01.83%) ── tree
│  │  │   │  └──0.65 MB (00.98%) ++ (2 tiny)
│  │  │   ├──1.85 MB (02.78%) -- objects
│  │  │   │  ├──1.26 MB (01.88%) ── function
│  │  │   │  └──0.60 MB (00.90%) ── non-function
│  │  │   ├──1.28 MB (01.92%) ── scripts
│  │  │   └──0.12 MB (00.19%) ++ (3 tiny)
│  │  ├───2.48 MB (03.72%) ── script-data
│  │  ├───1.29 MB (01.93%) ++ shapes-extra
│  │  ├───1.13 MB (01.69%) ── analysis-temporary
│  │  ├───0.76 MB (01.14%) ++ (5 tiny)
│  │  └───0.71 MB (01.07%) ── object-slots
│  ├───4.07 MB (06.11%) ── gc-heap-chunk-dirty-unused
│  ├───2.00 MB (03.00%) ── gc-heap-chunk-clean-unused
│  ├───1.77 MB (02.66%) -- compartment(atoms)
│  │   ├──1.05 MB (01.58%) ── string-chars
│  │   └──0.72 MB (01.08%) -- gc-heap
│  │      ├──0.71 MB (01.07%) ── strings
│  │      └──0.01 MB (00.02%) ++ arena
│  ├───1.58 MB (02.37%) ++ (8 tiny)
│  ├───1.34 MB (02.01%) ++ runtime
│  └───0.80 MB (01.20%) ++ compartment(https://bugzilla.mozilla.org/describecomponents.cgi?product=Core)
├──11.29 MB (16.93%) -- images
│  ├──11.09 MB (16.63%) -- content
│  │  ├──11.09 MB (16.63%) -- used
│  │  │  ├──10.89 MB (16.32%) ── uncompressed-nonheap
│  │  │  └───0.21 MB (00.31%) ++ (2 tiny)
│  │  └───0.00 MB (00.00%) ++ unused
│  └───0.20 MB (00.30%) ++ chrome
├───5.64 MB (08.46%) -- startup-cache
│   ├──5.64 MB (08.46%) ── data
│   └──0.00 MB (00.00%) ── mapping
├───1.99 MB (02.98%) -- layout
│   ├──1.30 MB (01.95%) ++ (5 tiny)
│   └──0.69 MB (01.04%) ++ shell(about:blank)
├───0.99 MB (01.49%) -- dom
│   └──0.99 MB (01.49%) -- window-objects
│      └──0.99 MB (01.49%) ++ active
├───0.91 MB (01.36%) ── xpti-working-set
└──-21.71 MB (-32.56%) -- (4 tiny) [?!]
   ├────0.33 MB (00.49%) ── atom-table
   ├────0.05 MB (00.07%) ── cycle-collector
   ├────0.02 MB (00.02%) ── history-links-hashtable
   └──-22.11 MB (-33.14%) ── heap-unclassified [?!]

I have noticed this on today's Aurora 12.
Comment 1 :aceman 2012-02-08 02:44:18 PST
This was after browsing bugzilla for some minutes. I do not know why storage is so unusually large. Maybe it is just updating the urlclassifier3?
Comment 2 Justin Lebar (not reading bugmail) 2012-02-08 07:55:09 PST
When we see negative heap-unclassified, that usually indicates that someone is over-reporting.  It *could* be storage, although that doesn't look ridiculously high.  :-/
Comment 3 Justin Lebar (not reading bugmail) 2012-02-08 07:55:38 PST
Any extensions, aceman?
Comment 4 :aceman 2012-02-08 08:05:53 PST
For me the storage size is unusual, I have newer saw such a big one.

Extensions:
BlockSite 0.7.1.1 true {dd3d7613-0246-469d-bc65-2a3cc1668adc}
DOM Inspector 2.0.10trueinspector@mozilla.org
IE Tab +2.04.20110724truecoralietab@mozdev.org
Internote 3.0.1true{e3631030-7c02-11da-a72b-0800200c9a66}
MinimizeToTray revived (MinTrayR) 1.0 truemintrayr@tn123.ath.cx
Mozilla Archive Format 2.0.4true{7f57cf46-4467-4c2d-adfa-0cba7c507e54}
NoScript 2.2.9true{73a6fe31-595d-460b-a920-fcc0f8843232}
Nuke Anything Enhanced 1.0.2true{1ced4832-f06e-413f-aa14-9eb63ad40ace}
pdfit 1.17trueservice@touchpdf.com
PrefBar 6.0.1true{8A6C82A1-F6C9-481a-AAE7-C96444C9A754}
printpdf 0.76trueprintpdf@pavlov.net
Slovníky slovenského pravopisu 2.03.2truesk@dictionaries.addons.mozilla.org
Web Developer 1.1.9true{c45c406e-ab73-11d8-be73-000a95be3b12}
Comment 5 Justin Lebar (not reading bugmail) 2012-02-08 08:20:45 PST
I guess the problem is likely storage/other; my storage/other is about 3mb.

Although an extension could be triggering this, it looks like our bug; storage/other is managed by us...
Comment 6 :aceman 2012-02-08 08:25:08 PST
After I refreshed the page the problem vanished and I haven't seen it since. But I could try nuking the safebrowsing database or something like that.
Comment 7 Nicholas Nethercote [:njn] 2012-02-08 14:45:30 PST
I've seen similar negative heap-unclassified when starting up -- I have about:memory in my session.  I think the problem is that lots of stuff is happening at once, and the memory measurements aren't atomic, and we measure "heap-allocated" very early (when fewer things have been allocated) and more stuff gets allocated in parallel while the remaining memory reporters are running.

The big urlclassifier3.sqlite numbers indicate that the safebrowsing database is probably being updated at the same time.

I suspect we'll get a bunch of reports like this.  The proper fix is to put a big lock around the memory reporters, but I doubt that's possible.  Instead we'll probably have to change the warning message when heap-unclassified goes negative, because it's a derived value.  Something like "heap-unclassified is negative, this sometimes happens when you load/refresh about:memory while the browser is busy doing stuff in other tabs, try refreshing when the browser is less busy and it'll probably turn positive again"...
Comment 8 :aceman 2012-02-08 14:48:08 PST
I have it in my session too. I just don't remember if this report was at the initial load or I already refreshed it after some browsing. I'll watch that.
Comment 9 Nicholas Nethercote [:njn] 2012-02-08 15:02:07 PST
(In reply to :aceman from comment #8)
> I have it in my session too. I just don't remember if this report was at the
> initial load or I already refreshed it after some browsing. I'll watch that.

If my hypothesis is correct it could happen any time about:memory loads while lots of other stuff is happening.  Session start-up is one such case, but there could be others.
Comment 10 :aceman 2012-02-08 23:40:20 PST
Confirming it happened again after starting the session containing about:memory, i.e. first render of the page after start. Further refreshes caused the problem to go away.
Comment 11 Nicholas Nethercote [:njn] 2012-02-14 14:44:09 PST
If we measure "heap-allocated" right at the end of all the measurements this'll probably go away.  That's probably the easiest way to deal with this.
Comment 12 Nicholas Nethercote [:njn] 2012-05-18 21:01:58 PDT
*** Bug 756527 has been marked as a duplicate of this bug. ***
Comment 13 Guilherme Lima 2013-09-15 15:31:38 PDT
Nicholas, you have done a lot of work since this report. Did the work at comment 11 happen?
Comment 14 Nicholas Nethercote [:njn] 2013-09-15 20:01:36 PDT
> Nicholas, you have done a lot of work since this report. Did the work at
> comment 11 happen?

No, but I'm working on bug 913260 which will allow me to do it! :)
Comment 15 Nicholas Nethercote [:njn] 2013-09-25 15:25:21 PDT
> No, but I'm working on bug 913260 which will allow me to do it! :)

I was wrong about that -- bug 913260 ended up not helping.

But this problem shouldn't happen as much any more.  The main case I was aware of was when about:memory was a saved tab and it auto-loaded at start-up.  But now that you have to press the "measure" button, the auto-measurement-at-startup won't happen.
Comment 16 Nicholas Nethercote [:njn] 2013-11-20 23:00:54 PST
> But this problem shouldn't happen as much any more.  The main case I was
> aware of was when about:memory was a saved tab and it auto-loaded at
> start-up.  But now that you have to press the "measure" button, the
> auto-measurement-at-startup won't happen.

I haven't seen this problem occur for a long time thanks to this change.  Good enough, I reckon.

Note You need to log in before you can comment on or make changes to this bug.