1360205 - Getting a profile lock takes a long time after an update

Status: RESOLVED WORKSFORME

(Toolkit :: Startup and Profile System, defect)

Description

[Florian Quèze [:florian]]

See this profile https://perfht.ml/2ppvvru where we wait using PR_Sleep for 1200ms before actually starting. Apparently we are failing to get a profile lock; why is that? This was a profile of startup right after an update.

This profile is taken on a current nightly on the quantum reference hardware (low end windows10 laptop).

Comment 1

[Robert Strong (they/them - no direct email)]

I would suspect it is updating caches as that was the case years ago when I looked at something similar. That would be a toolkit -> startup bug.

Comment 2

[Robert Strong (they/them - no direct email)]

It is extremely doubtful that this is directly related to app update and it is more likely due to other components dealing with their caches after an update or after an install of a different version. You can check this by using a Firefox profile with one version and install a different version on top of it. Moving to startup which should be closer to the problem.

Comment 3

[(no longer active)]

Is this where these sleeps are coming from?

<https://searchfox.org/mozilla-central/rev/ae8c2e2354db652950fe0ec16983360c21857f2a/toolkit/xre/nsAppRunner.cpp#2577-2600>

If yes, this was done in bug 921046 in order to detect the case where we're restarting and the old instance of Firefox hasn't finished running.

Comment 4

[Andrew Overholt [:overholt]]

Benjamin, can you confirm comment 3? We're trying to determine a) if this should remain as a qf:p1 bug and b) who can work on it?

Comment 5

[Benjamin Smedberg]

I seem unable to load the profile. If this in fact caused by the sleep from comment 3, there is definitely a bug: the Firefox profile lock should be gone before we start updates.

What OS was this? This behavior is pretty OS-specific and I'd really only call this a quantum P1 if we see it on Windows.

Comment 6

[Andrew Overholt [:overholt]]

dmajor may know what's going on here. He's been amazingly helpful with other Windows-specific issues. Maybe he has time to see if it's still reproducible and/or how to fix it?

Comment 7

[Florian Quèze [:florian]]

(In reply to Benjamin Smedberg [:bsmedberg] from comment #5)

> What OS was this?

Windows 10, as comment 0 says.

Comment 8

[(Away)]

aklotz is more familiar with the profile lock code so I'd like to get his take if possible.

Bounce this back to me if you don't have time or ideas.

Comment 9

[(No longer employed by Mozilla) Aaron Klotz]

(In reply to David Major [:dmajor] from comment #8)
> Bounce this back to me if you don't have time or ideas.

I have neither, unfortunately.

Comment 10

[(Away)]

Florian, are you able to reproduce this or was it a one-off occurrence?

Comment 11

[Florian Quèze [:florian]]

I can't reproduce consistently, but I saw it at least 3 times (I've not been profiling the 'restart after update' case frequently, so I don't have a sense of how frequent it is, but my impression was that it's not rare).

Comment 12

[(Away)]

Ok, thanks. I'll do my best to look at this when possible but I don't think it will happen soon. :-(

Comment 13

[(Away)]

I've been unable to reproduce this.

It's unlikely that we can find the problem from Gecko Profiler data of the new (sleeping) process -- the ultimate cause is that the old process is taking too long to shut down. 

Florian, I think the only way forward is for you to take a recording with Windows Performance Analyzer just before you restart for the update, and hope that the delay reproduces. If successful then we'll be able to see both the old and new processes in the same trace.

Comment 14

[Andrew Overholt [:overholt]]

(In reply to David Major [:dmajor] from comment #13)
> Florian, I think the only way forward is for you to take a recording with
> Windows Performance Analyzer just before you restart for the update, and
> hope that the delay reproduces. If successful then we'll be able to see both
> the old and new processes in the same trace.

needinfo for the above.

Comment 15

[Florian Quèze [:florian]]

I haven't reproduced this in the last few weeks for the update case, so I'll close this bug. What I do see frequently is waiting a long time for the profile lock, but that's just shutdown being slow... We should look into it, but I think it's out of the scope for 57.