Last Comment Bug 756846 - Prefetch files are sometimes in use on clear operation
: Prefetch files are sometimes in use on clear operation
Status: VERIFIED FIXED
[qa!]
:
Product: Core
Classification: Components
Component: Widget: Win32 (show other bugs)
: 15 Branch
: x86_64 Windows 7
: -- normal (vote)
: mozilla15
Assigned To: Brian R. Bondy [:bbondy]
:
:
Mentors:
Depends on:
Blocks: 692255
  Show dependency treegraph
 
Reported: 2012-05-20 00:01 PDT by Jason Smith [:jsmith]
Modified: 2012-08-27 13:22 PDT (History)
4 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Patch v1. (1.16 KB, patch)
2012-05-20 12:52 PDT, Brian R. Bondy [:bbondy]
robert.strong.bugs: review+
Details | Diff | Splinter Review

Description Jason Smith [:jsmith] 2012-05-20 00:01:01 PDT
Steps:

1. Download & Install the latest elm build containing the patch for bug 692255
2. Go to C:\Windows\Prefetch and remove all FIREFOX* pf files
3. Launch the elm build and wait more than a minute

Expected:

A Firefox PF file should be created and overwritten to 0 KB per the strategy to get rid of prefetch files.

Actual:

A Firefox PF file is created, but 0 KB write over never happens. The PF file still exists and has read/write access.

Additional Notes:

Found this in the maintenance log below. The third PF file (6AD33FF3) is the PF file that did not get overwritten to 0 KB when I ran the STR above.

Clearing prefetch files...
Error replacing prefetch path FIREFOX.EXE-18ACFCFF.pf. (5)
Error replacing prefetch path FIREFOX.EXE-24E4E637.pf. (5)
Error replacing prefetch path FIREFOX.EXE-6AD33FF3.pf. (5)
Done searching prefetch paths. (18)
Comment 1 Brian R. Bondy [:bbondy] 2012-05-20 12:22:06 PDT
Error code 5 is for: ERROR_ACCESS_DENIED

Is the read only flag set on the third prefetch file?
Comment 2 Jason Smith [:jsmith] 2012-05-20 12:33:29 PDT
(In reply to Brian R. Bondy [:bbondy] from comment #1)
> Error code 5 is for: ERROR_ACCESS_DENIED
> 
> Is the read only flag set on the third prefetch file?

Nope. The read only flag is not set.
Comment 3 Brian R. Bondy [:bbondy] 2012-05-20 12:34:29 PDT
Could you try resetting the clear prefetch one time pref, then rerunning the clear prefetch operation, and then see if you get the same error?
Comment 4 Jason Smith [:jsmith] 2012-05-20 12:43:31 PDT
(In reply to Brian R. Bondy [:bbondy] from comment #3)
> Could you try resetting the clear prefetch one time pref, then rerunning the
> clear prefetch operation, and then see if you get the same error?

Resetting app.update.service.prefetchCleared to false and restarted firefox. The pref is now set to true and FIREFOX.EXE-6AD33FF3.pf has 0 KB and is read only. 

Clearing prefetch files...
Prefetch file cleared and set to read-only successfully: C:\Windows\prefetch\FIREFOX.EXE-6AD33FF3.pf
Done searching prefetch paths. (18)
Comment 5 Brian R. Bondy [:bbondy] 2012-05-20 12:45:21 PDT
So I'm thinking there is a chance that we try to clear it while Windows is writing it, maybe just increasing the 1 minute to 3 minutes wait to clear or something like that would help.
Comment 6 Brian R. Bondy [:bbondy] 2012-05-20 12:52:09 PDT
Created attachment 625510 [details] [diff] [review]
Patch v1.

So what sometimes happens is that Windows is already using the prefetch file and so we can't clear it.  I think increasing the timeout to 3 minutes would help this problem.  I don't think we need to 100% solve this problem though, because it will be cleared on the next software update if it wasn't cleared on this one.
Comment 7 Robert Strong [:rstrong] (use needinfo to contact me) 2012-05-21 14:11:19 PDT
Can you run some tests to see how long the files are typically in use? Perhaps it might be better to have the service retry instead?
Comment 8 Jason Smith [:jsmith] 2012-05-21 14:27:20 PDT
(In reply to Robert Strong [:rstrong] (do not email) from comment #7)
> Can you run some tests to see how long the files are typically in use?
> Perhaps it might be better to have the service retry instead?

I'll look into this. Flagging qawanted.
Comment 9 Brian R. Bondy [:bbondy] 2012-05-21 15:23:20 PDT
Thanks jsmith. 
I think we can treat this as a non blocker for landing the prefetch stuff.
Comment 10 Jason Smith [:jsmith] 2012-05-22 15:18:08 PDT
(In reply to Robert Strong [:rstrong] (do not email) from comment #7)
> Can you run some tests to see how long the files are typically in use?
> Perhaps it might be better to have the service retry instead?

On Windows XP, did the following 3 times:

1. Deleted the prefetch FIREFOX.PF files
2. Started up nightly and started a timer
3. Ended a timer when the PF file appeared

Looks like the prefetch files generate within seconds (< 5 seconds) upon startup. With this notion, I don't think the patch here will solve the problem in this bug (increasing the timer won't work).
Comment 11 Brian R. Bondy [:bbondy] 2012-05-22 16:38:25 PDT
Have you seen the access denied error again at all in your testing?
Comment 12 Jason Smith [:jsmith] 2012-05-22 16:59:55 PDT
(In reply to Brian R. Bondy [:bbondy] from comment #11)
> Have you seen the access denied error again at all in your testing?

Ah the error is not right in first comment. There's nothing appearing in the logs at all actually now (Win XP). Probably has to do with the fact that this is a one time operation - We write PF file to 0 KB and set it read only, flip a pref. If I keep the pref on and clear the prefetched files manually, the prefetched files will re-generate without having the 0 KB read only process done to it.

A user likely wouldn't delete prefetch files intentionally from their machine, but some other application with the right privileges might try to do so (whether malicious or not). I wonder due to this issue - Is a one-time operation safe to go with? Or would an option to watch for FIREFOX PF files in the prefetch directory that are >0KB not read only and clear them as needed?
Comment 13 Brian R. Bondy [:bbondy] 2012-05-22 17:26:45 PDT
Ya you'll have to reset the pref if you want to re-run the prefetch operation. 

The prefetch files will be cleared one time with that pref, but it will also be cleared on each software update.
Comment 14 Brian R. Bondy [:bbondy] 2012-05-22 17:28:01 PDT
For testing in Bug 692255 Comment 70 #2 you should also be checking that
Comment 15 Jason Smith [:jsmith] 2012-05-22 17:30:00 PDT
(In reply to Brian R. Bondy [:bbondy] from comment #14)
> For testing in Bug 692255 Comment 70 #2 you should also be checking that

Okay. I'll go check that. So the use case a user would experience if the FIREFOX.PF so happened to disappear and was recreated is that they would not have the prefetch clear happen until the next update of firefox, right? If that works, then we can resolve this bug as invalid.
Comment 16 Brian R. Bondy [:bbondy] 2012-05-22 17:32:41 PDT
That is the case yup, but we should keep this bug open for now in case we can improve the situation. That's why in Comment 9 I mentioned that this should be a non blocker for landing the prefetch stuff.
Comment 17 Jason Smith [:jsmith] 2012-05-22 17:46:41 PDT
Nope, the update user flow does not work. Filing a bug now. If you are curious, the log indicated that it could not find the clear-prefetch service command.
Comment 18 Brian R. Bondy [:bbondy] 2012-05-22 17:49:14 PDT
> Nope, the update user flow does not work. Filing a bug now. If you are curious,
> the log indicated that it could not find the clear-prefetch service command.

So I think you updated while having an old service installed and not the one from elm. It would be best to uninstall the maintenance service that you have installed, then install a recent elm build (but not the most recent), and have it update to the most recent.
Comment 19 Jason Smith [:jsmith] 2012-05-22 18:16:58 PDT
(In reply to Brian R. Bondy [:bbondy] from comment #18)
> > Nope, the update user flow does not work. Filing a bug now. If you are curious,
> > the log indicated that it could not find the clear-prefetch service command.
> 
> So I think you updated while having an old service installed and not the one
> from elm. It would be best to uninstall the maintenance service that you
> have installed, then install a recent elm build (but not the most recent),
> and have it update to the most recent.

See bug 757685 for more information on this discussion.
Comment 20 Robert Strong [:rstrong] (use needinfo to contact me) 2012-05-23 18:21:37 PDT
Comment on attachment 625510 [details] [diff] [review]
Patch v1.

r=me though I am tempted to just ask that the service handle this instead in its prefetch clearing code. I suspect that even though this isn't ideal it is sufficient but what do you think?
Comment 21 Brian R. Bondy [:bbondy] 2012-05-23 18:39:52 PDT
> I suspect that even though this isn't ideal it is sufficient but what do you think?

I'm just worried that on some machine(s) there will be some prefetch file that can't be deleted and we'd have a timer + thread on startup extra for every startup.  We haven't seen that yet but not sure what is best here. 

The service command should be fast and then finish in case something tries to use it for an update.

I do think prefetch files are only read/written during startup though so I think increasing the timer makes sense.  I agree it's not ideal too, I just don't know what is.  Maybe something like max 3 tries before setting the pref? It would also have to be changed to a reg entry since the service doesn't have access to prefs.  

I think we should re-file if this becomes a problem.

jsmith: Please let me know if you see this again with a build after 05-23 and if so how often you see it.
Comment 22 Robert Strong [:rstrong] (use needinfo to contact me) 2012-05-23 18:42:19 PDT
I was thinking more along the lines of setting the pref before clearing the prefetch and having the service retry several times over a period of a few to 10 minutes.
Comment 23 Brian R. Bondy [:bbondy] 2012-05-23 18:43:43 PDT
I'm concerned with keeping the service running for 10 minutes in case an update happens from another install that uses the single service.  Or even from the same install after the command is issued.
Comment 24 Brian R. Bondy [:bbondy] 2012-05-23 18:45:00 PDT
we could execute another app to do it, from some temporary secure location, but that's probably more resources towards this than we have avail at the moment.
Comment 25 Robert Strong [:rstrong] (use needinfo to contact me) 2012-05-23 18:48:55 PDT
Agreed and I think a better goal would be to figure out another way to accomplish (e.g. figuring out the prefetch file names, launching firefox.exe silently from the installer to pre-generate the prefetch files, or something else) and thereby be able to remove this code.
Comment 26 Brian R. Bondy [:bbondy] 2012-05-23 18:55:59 PDT
> e.g. figuring out the prefetch file names

I tried this but didn't have good success.  There are a couple sites that claim that they had the algorithm for this but it didn't work when I implemented the hashing they suggested. I'm pretty sure it changes with each windows version and possibly it's a different seed for each Windows install.

I really dislike the whole task by the way because it seems so wrong to do but if it's a win on startup I guess it's worth it.

One idea is to just only do this with updates and take the hit that brand new installs wont' have as fast of startup.  In those cases we know the prefetch files won't be in use and that for sure they will already be generated.  We  could then move it to the post update and not have any service changes at all.
Comment 27 Brian R. Bondy [:bbondy] 2012-05-23 18:56:34 PDT
If the no prefetch cleared on new install thing is acceptable by the way I'd rather implement that now rather than revisit this task later.
Comment 28 Robert Strong [:rstrong] (use needinfo to contact me) 2012-05-23 18:59:33 PDT
It seems to me that it wouldn't be acceptable but it doesn't mean we couldn't come up with a different way at some point such as generating them by launching firefox.exe silently via the installer. We could also have the installer only do this for brand new installs (there are a lot of pave over installs per metrics).
Comment 29 Brian R. Bondy [:bbondy] 2012-05-23 19:01:23 PDT
So another point is that Windows doesn't always generate the prefetch files, and it sometimes get in a broken state where prefetch files are not generated until a reboot.  Before I worked on this task my computer was in that state and I had to reboot to fix it.
Comment 30 Robert Strong [:rstrong] (use needinfo to contact me) 2012-05-23 19:06:19 PDT
Good to know. As it stands I am by no means trying to stop this from landing as is... I just want us to come up with a better way if at all possible.
Comment 31 Brian R. Bondy [:bbondy] 2012-05-23 19:09:37 PDT
Further support for broken prefetch:
bug 627591 Comment 163

> Good to know. As it stands I am by no means trying to stop this from landing as
> is... I just want us to come up with a better way if at all possible.

OK cool, ya I hope there's a better way too but it's such an ugly task to begin with that each way has some down sides. 
Taras mentioned that he wanted some telemetry added before this lands by the way. I'll be posting for that soon.
Comment 32 Brian R. Bondy [:bbondy] 2012-05-27 19:49:16 PDT
http://hg.mozilla.org/mozilla-central/rev/b3ca05098ddc
Comment 33 Jason Smith [:jsmith] 2012-06-07 17:34:50 PDT
Verified. The timer is definitely longer here from testing this on Nightly.

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