973881 - Cache I/O thread periodically writes to disk during idle

Status: RESOLVED INCOMPLETE

(Core :: Networking: Cache, defect, P5)

Description

[Roberto Agostino Vitillo (:rvitillo)]

Many of the disk writes on a complete idle system seems to be generated periodically from the Cache I/O thread (measured with iotop with 6 tabs open pointing to cnn.com). Those writes account for about 20% of the total writes performed by FF in an one hour period (~60MB). Are those writes necessary and could they be reduced?

Comment 1

[Honza Bambas (:mayhemer)]

(In reply to Roberto Agostino Vitillo (:rvitillo) from comment #0)
> Many of the disk writes on a complete idle system seems to be generated
> periodically from the Cache I/O thread (measured with iotop with 6 tabs open
> pointing to cnn.com). Those writes account for about 20% of the total writes
> performed by FF in an one hour period (~60MB). Are those writes necessary

Definitely.

> and could they be reduced?

Not sure why.  These are apparently cache writes of data that firefox downloads even during the idle period.  We do a lot of update checks in background, pages usually reload advertisement etc, so it's normal behavior.


Can you please test with "browser.cache.use_new_backend" preference set to 1?  That will turn the new http cache on, I would like to know the difference (The thread is then Cache2 I/O).  Thanks.

Comment 2

[Roberto Agostino Vitillo (:rvitillo)]

(In reply to Honza Bambas (:mayhemer) from comment #1)
> (In reply to Roberto Agostino Vitillo (:rvitillo) from comment #0)
> > Many of the disk writes on a complete idle system seems to be generated
> > periodically from the Cache I/O thread (measured with iotop with 6 tabs open
> > pointing to cnn.com). Those writes account for about 20% of the total writes
> > performed by FF in an one hour period (~60MB). Are those writes necessary
> 
> Definitely.
> 
> > and could they be reduced?
> 
> Not sure why.  These are apparently cache writes of data that firefox
> downloads even during the idle period.  We do a lot of update checks in
> background, pages usually reload advertisement etc, so it's normal behavior.
> 
> 
> Can you please test with "browser.cache.use_new_backend" preference set to
> 1?  That will turn the new http cache on, I would like to know the
> difference (The thread is then Cache2 I/O).  Thanks.

There is a reduction of about 30% in disk writes for Cache2 I/O but interestingly the Network Seer thread is behaving much better now (~65% reduction in disk writes). Not sure though if and how those two threads interact with each other.

Comment 3

[Roberto Agostino Vitillo (:rvitillo)]

See also Bug 973871.

Comment 4

[Honza Bambas (:mayhemer)]

(In reply to Roberto Agostino Vitillo (:rvitillo) from comment #2)
> (In reply to Honza Bambas (:mayhemer) from comment #1)

> There is a reduction of about 30% in disk writes for Cache2 I/O but
> interestingly the Network Seer thread is behaving much better now (~65%
> reduction in disk writes). 

Same conditions?

> Not sure though if and how those two threads
> interact with each other.

They don't interact at all!

(In reply to Roberto Agostino Vitillo (:rvitillo) from comment #3)
> See also Bug 973871.

I've seen it.  Looks like seer writes more then then the cache :D  Unbelievable!

Comment 5

[Roberto Agostino Vitillo (:rvitillo)]

(In reply to Honza Bambas (:mayhemer) from comment #4)
> Same conditions?

Exactly the same conditions. I tried to rerun again the test after restoring "browser.cache.use_new_backend" to 0 and the network seer was misbehaving again.

Comment 6

[Honza Bambas (:mayhemer)]

Adding nick, he might know more.

Comment 7

[u408661]

My best guess as to why changing the cache pref would affect the seer is that there is some non-nsHttpChannel consumer of the cache that also uses the seer. Either the old cache had a bug resulting in that consumer thinking some data was invalid, and needed loading from the network, or the new cache has a bug resulting in that consumer thinking some data is valid when it really needs refreshed. That consumer then fails to fire off a load, thus not hitting the seer, causing it to have less work.

This could be bad on two levels - (1) the new cache could have a serious bug with serving invalid data as valid, and (2) the seer could have a bug where it doesn't catch all resources for a page load, causing its statistics to be incorrect.

Honza, you probably have better knowledge of the consumers of the cache API than I do at this point. Do docshell, script loader, image loader, font loader, or style loader ever access the cache directly? (Those are the main consumers of the seer API). If so, that's probably our first point to check for the problem.

Comment 8

[Mark Finkle (:mfinkle) (use needinfo?)]

I think cnn.com will refresh itself every 1800seconds (30mins) which would give us a reason as to why the cache is updating. Nice that the new cache is reducing the effect.

Comment 9

[Honza Bambas (:mayhemer)]

Is this still actual?

Comment 10

[Roberto Agostino Vitillo (:rvitillo)]

Yes, with the current Nightly the Cache2 I/O thread remains the top offender (~ 30MB in an hour period).

Comment 11

[Honza Bambas (:mayhemer)]

Michal, do you have some theory here?

Comment 12

[Michal Novotny [:michal]]

(In reply to Roberto Agostino Vitillo (:rvitillo) from comment #10)
> Yes, with the current Nightly the Cache2 I/O thread remains the top offender
> (~ 30MB in an hour period).

I have no theory. I'll try to see what's happening from the logs. So what exactly should I do to reproduce it? Start firefox with cnn.com, then do nothing for an hour and watch iotop -a ?

Comment 13

[Roberto Agostino Vitillo (:rvitillo)]

(In reply to Michal Novotny (:michal) from comment #12)
> (In reply to Roberto Agostino Vitillo (:rvitillo) from comment #10)
> > Yes, with the current Nightly the Cache2 I/O thread remains the top offender
> > (~ 30MB in an hour period).
> 
> I have no theory. I'll try to see what's happening from the logs. So what
> exactly should I do to reproduce it? Start firefox with cnn.com, then do
> nothing for an hour and watch iotop -a ?

Open 6 or more cnn.com tabs and collect statistics with "iotop -a".

Comment 14

[Firefox Bug Husbandry Bot]

Bulk change to priority: https://bugzilla.mozilla.org/show_bug.cgi?id=1399258

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Florian, have you ever seen reported issue?

Comment 16

[Florian Quèze [:florian]]

(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #15)

Florian, have you ever seen reported issue?

I have never seen this when profiling Firefox being idle. But when I profile Firefox being idle, I ensure I have a single tab with about:blank. Maybe this only happens with some specific tabs? (eg. pages that do periodic network requests in the background)

Comment 17

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Thanks. Given that all the previous information is 8 to 9 years old, I assume a lot of the underlying code base has been changed and it might no longer be a problem. I would suggest that we close this bug and file a new one with clear reproduction steps.