Negative "heap-unclassified" in about:memory, perhaps due to the non-atomicity of memory reporters

RESOLVED WORKSFORME

Status

()

defect
RESOLVED WORKSFORME
8 years ago
6 years ago

People

(Reporter: aceman, Assigned: njn)

Tracking

12 Branch
x86
Windows XP
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [MemShrink:P3])

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.
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?
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.  :-/
Summary: negative numbers in tiny collectors → negative heap-unclassified, cause unknown
Any extensions, aceman?
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}
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...
Summary: negative heap-unclassified, cause unknown → negative heap-unclassified, perhaps due to overlarge storage/other, perhaps caused by an extension
Whiteboard: [MemShrink]
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.
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"...
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.
(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.
Summary: negative heap-unclassified, perhaps due to overlarge storage/other, perhaps caused by an extension → Negative "heap-unclassified" in about:memory, perhaps due to the non-atomicity of memory reporters
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.
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.
Assignee: nobody → n.nethercote
Whiteboard: [MemShrink] → [MemShrink:P2]
Whiteboard: [MemShrink:P2] → [MemShrink:P3]
Duplicate of this bug: 756527
Nicholas, you have done a lot of work since this report. Did the work at comment 11 happen?
> 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! :)
Depends on: 913260
> 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.
> 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.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.