1368887 - Crash in mozilla::net::CacheFile::IsKilled

Status: VERIFIED FIXED

(Core :: Networking: Cache, defect)

Description

[Ekanan Ketunuti]

This bug was filed from the Socorro interface and is 
report bp-810dd8bc-cf1e-4107-8d0f-398d00170531.
=============================================================

It crashes randomly if dom.script_loader.bytecode_cache.enabled=true.

Comment 1

[Nicolas B. Pierron [:nbp]]

Ekanan, Thanks for testing this flag and reporting this issue.  This is really helpful :)
Did you enabled dom.script_loader.bytecode_cache.eager as well?

I will note that as of today (before Bug 1368675 landing), enabling dom.script_loader.bytecode_cache.enabled is doing nothing else than requesting the bytecode alternate data type.  We should not even attempt to save any alternate data content, which makes me wonder about this crash on a WriteEvent, when the CacheFile got freed.

I look if I can find a way to reproduce this issue locally.

Valentin, maybe you have more ideas on what might be going wrong?

Comment 2

[Ekanan Ketunuti]

(In reply to Nicolas B. Pierron [:nbp] from comment #1)
> Ekanan, Thanks for testing this flag and reporting this issue.  This is
> really helpful :)
> Did you enabled dom.script_loader.bytecode_cache.eager as well?

I didn't.

I got this crash before bug 1364118 landed on nightly bp-9212bd2e-39c0-4abe-8c30-0bf170170511 so I think it doesn't matter.

Comment 3

[Valentin Gosu [:valentin] (he/him)]

I don't know the code terribly well, but it looks to me that WriteEvent has a CacheFileChunk as listener on which it calls IsKilled.
The IsKilled implementation returns mFile->IsKilled, but mFile may be nulled out in [1]
We probably only need a null check. Michal, is my logic correct?

[1] http://searchfox.org/mozilla-central/rev/b318c7dca7392bd16c0b11929f55b1be133f0b31/netwerk/cache2/CacheFile.cpp#1724

Comment 4

[Nicolas B. Pierron [:nbp]]

(In reply to Ekanan Ketunuti from comment #2)
> I got this crash before bug 1364118 landed on nightly
> bp-9212bd2e-39c0-4abe-8c30-0bf170170511 so I think it doesn't matter.

Before bug 1364118, when enabled, the cache was eagerly generating and saving bytecode only for large scripts (≳ 100kB).

Comment 5

[Michal Novotny [:michal]]

(In reply to Valentin Gosu [:valentin] from comment #3)
> The IsKilled implementation returns mFile->IsKilled, but mFile may be nulled
> out in [1]
> We probably only need a null check. Michal, is my logic correct?

This shouldn't happen, because the chunk is referenced by mDiscardedChunks and the write event, so CacheFile::DeactivateChunk wouldn't be called for this chunk.

Ekanan, if you can reproduce it easily, could you please provide a log? Use following log modules: timestamp,sync,rotate:500,cache2:5

Comment 6

[Ekanan Ketunuti]

Attachment: bug-1368887.log.tar.xz

(In reply to Michal Novotny (:michal) from comment #5)
> Ekanan, if you can reproduce it easily, could you please provide a log? Use
> following log modules: timestamp,sync,rotate:500,cache2:5

Hard to reproduce. Yesterday I tried to play with this all day long but ain't got any luck. Today it did crash for me after short browsing.

Here comes the result for
 - dom.script_loader.bytecode_cache.eager;true
 - dom.script_loader.bytecode_cache.enabled;true
 - log modules: timestamp,sync,rotate:500,cache2:5

Comment 7

[Ekanan Ketunuti]

bp-b7fd8974-1676-4847-b406-13c7a0170602

Comment 8

[Patrick Albrecht]

I ran into this crash today multiple times. (I have dom.script_loader.bytecode_cache.enabled=true)
I could reproduce it once on this page https://www.golem.de/news/xbox-one-supersampling-im-zeichen-des-x-1706-128318-2.html when I scroll down a little bit, but unfortunately not again.

My crashes:
https://crash-stats.mozilla.com/report/index/0078457d-980e-4a7a-89ae-5ed0b0170612
https://crash-stats.mozilla.com/report/index/6cd79d36-a520-4161-81fd-88c6a0170612
https://crash-stats.mozilla.com/report/index/669ea98d-80a8-41bb-a300-af8850170612

Comment 9

[Michal Novotny [:michal]]

The problem is that CacheFile::OnChunkWritten called for discarded chunk proceeds normally and removes the newly created chunk with the new data.

Comment 10

[Michal Novotny [:michal]]

Attachment: patch v1

changes in this patch:

- fixed an edge case when we could discard a chunk that is references by an input stream
- failing listeners before discarding chunk
- CacheFile::OnChunkRead and CacheFile::OnChunkWritten handle discarded chunks correctly
- fixed CacheFileInputStream::CanRead to respect end of the normal data
- added few assertions to make sure we truncate at the alt-data offset and that no input stream is beyond this point

Comment 11

[Valentin Gosu [:valentin] (he/him)]

Comment on attachment 8879256 [details] [diff] [review]
patch v1

Review of attachment 8879256 [details] [diff] [review]:
-----------------------------------------------------------------

It looks good to me, but I'm not comfortable enough with the code to be the only reviewer. Hopefully Honza can help with a quick review.

Comment 12

[Honza Bambas (:mayhemer)]

Comment on attachment 8879256 [details] [diff] [review]
patch v1

Review of attachment 8879256 [details] [diff] [review]:
-----------------------------------------------------------------

has this patch been through try?  I don't see any link to try in the bug.

OK, I could star into this for hours and not getting it much anyway.  If this has been tested (I presume an automated crash test would be too complicated?) then let's land it.

::: netwerk/cache2/CacheFile.cpp
@@ +1927,5 @@
>  
>    MOZ_ASSERT(aOffset <= mDataSize);
> +  // If we ever need to truncate on non alt-data boundary, we need to handle
> +  // existing input streams.
> +  MOZ_ASSERT(aOffset == mAltDataOffset, "Truncating normal data not implemented");

so, this patch removes the ability to truncate normal data?  or it never was implemented (or used?)

do we still need the MOZ_ASSERT(aOffset <= mDataSize); assertion?

@@ +1971,5 @@
> +    if (maxInputChunk < inputChunk) {
> +      maxInputChunk = inputChunk;
> +    }
> +
> +    MOZ_RELEASE_ASSERT(mInputs[i]->GetPosition() <= aOffset);

how can this ever be ensured?

Comment 13

[Michal Novotny [:michal]]

(In reply to Honza Bambas (:mayhemer) from comment #12)
> has this patch been through try?  I don't see any link to try in the bug.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=16656d502af724a9c1ab9934b33885f0901a4b39

> OK, I could star into this for hours and not getting it much anyway.  If
> this has been tested (I presume an automated crash test would be too
> complicated?) then let's land it.

It's almost impossible to make an automated test. We would need to expose some debugging API that would synchronize all the involved components.

> ::: netwerk/cache2/CacheFile.cpp
> @@ +1927,5 @@
> >  
> >    MOZ_ASSERT(aOffset <= mDataSize);
> > +  // If we ever need to truncate on non alt-data boundary, we need to handle
> > +  // existing input streams.
> > +  MOZ_ASSERT(aOffset == mAltDataOffset, "Truncating normal data not implemented");
> 
> so, this patch removes the ability to truncate normal data?  or it never was
> implemented (or used?)

This was never needed, so it wasn't implemented.

> do we still need the MOZ_ASSERT(aOffset <= mDataSize); assertion?

It is probably redundant.

> @@ +1971,5 @@
> > +    if (maxInputChunk < inputChunk) {
> > +      maxInputChunk = inputChunk;
> > +    }
> > +
> > +    MOZ_RELEASE_ASSERT(mInputs[i]->GetPosition() <= aOffset);
> 
> how can this ever be ensured?

Truncate() is called from 2 places and both check that there is no input stream for alt-data. So all existing input stream are reading normal data and the position cannot go beyond mAltDataOffset.

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/acd2949f5415
Crash in mozilla::net::CacheFile::IsKilled, r=valentin, r=honzab

Comment 15

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/acd2949f5415