Last Comment Bug 354772 - Clicking later after succesfully downloading update causes update to fail
: Clicking later after succesfully downloading update causes update to fail
Status: RESOLVED FIXED
: fixed1.8.0.8
Product: Toolkit
Classification: Components
Component: Application Update (show other bugs)
: 1.8 Branch
: x86 Windows XP
: -- normal (vote)
: ---
Assigned To: Benjamin Smedberg [:bsmedberg]
:
: Robert Strong [:rstrong] (use needinfo to contact me)
Mentors:
Depends on:
Blocks: 312010
  Show dependency treegraph
 
Reported: 2006-09-28 19:20 PDT by 2newsixibh
Modified: 2008-07-31 04:30 PDT (History)
16 users (show)
mtschrep: blocking‑firefox2-
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Complete update log for similar failure (35.81 KB, text/plain)
2006-09-29 03:28 PDT, Nick Thomas [:nthomas]
no flags Details
patch (4.78 KB, patch)
2006-12-28 09:42 PST, Masatoshi Kimura [:emk]
no flags Details | Diff | Splinter Review
patch rv 0.2 (4.87 KB, patch)
2006-12-28 09:52 PST, Masatoshi Kimura [:emk]
no flags Details | Diff | Splinter Review

Description 2newsixibh 2006-09-28 19:20:51 PDT
User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1) Gecko/20060928 BonEcho/2.0
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1) Gecko/20060928 BonEcho/2.0

After getting partial update and choosing later, upon restart update does not install.

Reproducible: Always

Steps to Reproduce:
1.Check for updates
2.After downloading partial update, choose later.
3.Close then restart firefox.

Actual Results:  
Gets an update not verified screen.

Expected Results:  
Firefox should get updated.

The partial works if i use restart firefox instead of later.
Comment 1 Marcia Knous [:marcia - use ni] 2006-09-28 19:26:23 PDT
Reporter: Can you please specify which build you were updating from so we can try to reproduce?  Thanks.
Comment 2 2newsixibh 2006-09-28 20:46:46 PDT
(In reply to comment #1)
> Reporter: Can you please specify which build you were updating from so we can
> try to reproduce?  Thanks.
> 
I noticed this first from 926 to 927. Same also with 927 to 928.
Comment 3 Nick Thomas [:nthomas] 2006-09-29 02:36:28 PDT
I confirm this using the 0927 -> 0928 update for Windows Bon Echo nightly, with a clean zip extract and new profile. The errors message is "The partial Update could not be applied. Bon Echo will try again by downloading a complete Update."

The end of <firefox_dir>\updates\last-update.log is:
...
PREPARE PATCH plc4.dll
PREPARE PATCH xpcom_core.dll
PREPARE PATCH xpcom.dll
PREPARE PATCH ssl3.dll
PREPARE PATCH firefox.exe
failed: 6
calling QuitProgressUI

The log is much shorter than normal, as the updater is failing to read firefox.exe very early in the process. Reporter, do you see the same in your log file ? Note that the complete update that follows the partial will overwrite this file.

firefox.exe seems to exit cleanly (it disappears from the Process List of the Windows Task Manager). Applying the update manually is successful (http://wiki.mozilla.org/Software_Update:Manually_Installing_a_MAR_file).
Comment 4 Nick Thomas [:nthomas] 2006-09-29 03:25:35 PDT
Confirming that using Later causes problems on partials for 0925 -> 0926 & 0926 -> 0927. Painful to test though because you have to construct a custom update.xml that points to the right file and with the correct hash and filesize.

Comment 5 Nick Thomas [:nthomas] 2006-09-29 03:28:26 PDT
Created attachment 240594 [details]
Complete update log for similar failure

I tried using complete updates from the AUS supplied info, in particular the 2006092511 win32 build. Using the Later button, the update fails and the original version is present when you startup. There is no dialog reporting this but check the useragent to confirm (or use Nightly tester tools to put it on the titlebar of the window). 

The relevant snippet from the attached log is:
...
EXECUTE ADD extensions/talkback@mozilla.org/install.rdf
EXECUTE ADD extensions/{972ce4c6-7e08-4474-a285-3208198ce6fd}/install.rdf
EXECUTE ADD firefox.exe
copy_file: failed to open or stat: -1,firefox.exe,13
### execution failed
...

So problems accessing firefox.exe again. 

Hopefully this will make finding the regression easier. For anyone trying this, beware the weirdness for windows builds on the 1.8branch between 0922 and 0925.
Comment 7 2newsixibh 2006-09-29 08:18:18 PDT
(In reply to comment #3)
> The end of <firefox_dir>\updates\last-update.log is:
> ...
> PREPARE PATCH plc4.dll
> PREPARE PATCH xpcom_core.dll
> PREPARE PATCH xpcom.dll
> PREPARE PATCH ssl3.dll
> PREPARE PATCH firefox.exe
> failed: 6
> calling QuitProgressUI
> 
> The log is much shorter than normal, as the updater is failing to read
> firefox.exe very early in the process. Reporter, do you see the same in your
> log file ? Note that the complete update that follows the partial will
> overwrite this file.
Yes I see this too.
Comment 8 Nick Thomas [:nthomas] 2006-09-29 08:29:05 PDT
2newsixibh, thank you.

Further testing 
 - Can't reproduce in Linux by spot checking recent branch builds
 - 1.5.0.6 windows is fine updating to 1.5.0.7
 - 1.5.0.7 windows moved onto the nightly channel has the problem

So that points to bug 312010.
Comment 9 Benjamin Smedberg [:bsmedberg] 2006-09-29 08:57:41 PDT
Darin, help! I'm totally confused as to why I would be getting an EACCESS error opening firefox.exe (for reading) in the one case but not the other. We pass the same path to updater.exe in both cases, no?
Comment 10 Darin Fisher 2006-09-29 12:28:07 PDT
Are you sure that the first instance of firefox.exe is completely shutdown?  What happens if you wait a minute before re-launching firefox.exe?
Comment 11 Mike Beltzner [:beltzner, not reading bugmail] 2006-09-29 18:49:46 PDT
What's the impact here? I'm hoping someone can answer the following:

 - what's the use case for this failure? all updates when user clicks "Later"?
 - does the full update then install successfully?
Comment 12 Nick Thomas [:nthomas] 2006-09-30 05:00:36 PDT
(In reply to comment #10)
> Are you sure that the first instance of firefox.exe is completely shutdown? 
> What happens if you wait a minute before re-launching firefox.exe?

Waiting for 10 minutes doesn't make a difference. Something is different between the "cold start" and the restarting cases. 

Also, I'm not convinced that 312010 is still working properly. If I apply a complete update then try to launch Firefox, I will sometimes get errors - dialogs with "One more files could not be updated ..." and the Firefox is already running message. Closing those dialogs allows the complete to run again and it applies ok, but partials would failover to a complete. 


(In reply to comment #11)
> What's the impact here? I'm hoping someone can answer the following:
> 
>  - what's the use case for this failure? all updates when user clicks "Later"?

From my testing, an update will fail when you use the Later button. You can go: partial update download, click Later, close and restart, the update fails, complete update downloads, click Later, close & restart, it fails, repeat from the top. The app is unmodified at the end of this sequence (except for updates.xml, active-updates.xml and last-update.log).

>  - does the full update then install successfully?

Only if you let the app apply it immediately.

If it's not clear why bug 312010 is causing this then perhaps it should be backed out for Fx2 (see also bug 312010 comment #18). Unfortunately it's already in the wild as a part of Firefox & Thunderbird 1.5.0.7.

If time is short, then I think this boils down to a choice between "the Later button working" and "not being able to start Firefox while it's being updated". My guess is that the former is a more common situation. The consequences are an un-updated but working install vs a broken browser.
Comment 13 Mike Schroepfer 2006-09-30 10:16:58 PDT
Can we confirm that bug 312010 causes the issue?
Comment 14 Doug Turner (:dougt) 2006-09-30 20:15:36 PDT
I could not reproduce this bug with build 2006-09-29-03-mozilla1.8.  WFM
Comment 15 Benjamin Smedberg [:bsmedberg] 2006-09-30 20:47:07 PDT
For those who see this bug, can you replace updater.exe with the one from 1.5.0.5? Since I'm pretty sure I tested this scenario before landing bug 312010, I'm wondering if something about some systems is different from others.

The code sequence that is probably failing is:

CreateFile("path/to/firefox.exe", DELETE | GENERIC_WRITE, 0 /* no sharing */)
...
open("path/to/firefox.exe", O_RDONLY | _O_BINARY);

This is supposed to work (since it's the same process opening the file); perhaps there's a longname/shortname issue?
Comment 16 dex_sf 2006-10-01 00:16:58 PDT
With Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1)
Gecko/20060929 BonEcho/2.0 I have got the same problem. After replacing the updater.exe with the one from 1.5.0.5 the problem is still existing, the partial update still can't be applied.
Comment 17 Nick Thomas [:nthomas] 2006-10-01 05:22:40 PDT
(In reply to comment #16)
> With Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1)
> Gecko/20060929 BonEcho/2.0 I have got the same problem. After replacing the
> updater.exe with the one from 1.5.0.5 the problem is still existing, the
> partial update still can't be applied.

I wouldn't expect a partial update using the 1.5.0.5 updater to apply. This is because updater.exe is included in the update every day - for some reason the compiler produces very slightly different output for all the executables, even without code changes. 

When the updater.exe from the 1.5.0.5 doesn't have the expected CRC the partial for that file can't be applied.
Comment 18 Nick Thomas [:nthomas] 2006-10-01 05:26:36 PDT
(In reply to comment #15)

I can go one better than this. I tested the complete update from the 2006092710 nightly build to the freshly minted 20061001:

1, original updater.exe - FAILS as in comment #5

2, homebuilt updater.exe with current CVS code - FAILS as in comment #5

3, homebuilt updater.exe with bug 312010 backed out - SUCCESS
Comment 19 Steve England [:stevee] 2006-10-01 05:44:58 PDT
Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.8.1) Gecko/20061001 BonEcho/2.0 ID:2006100103

I am definitely still seeing this.

1. Running 20060930, Help > Check for updates.
2. Update (20061001) found (PARTIAL), choose to install
3. After download installed, click 'Later'
4. Close firefox (I use the [x] in the top right of the browser window)
5. Check Task Manager to ensure no firefox.exe process is left in the process list
6. Start firefox up, the update bar briefly appears (as it tends to do with partials)
7. Firefox starts, error "Partial update could not be applied. Bon Echo will try again by downloading a complete update"
last-update.log finishes with:
PREPARE PATCH ssl3.dll
PREPARE PATCH firefox.exe
failed: 6
calling QuitProgressUI
8. Since the partial didn't apply, Bon Echo downloads the FULL update.
9. When the full update is finished, click 'Later'.
10. Close firefox (I use the [x] in the top right of the browser window)
11. Check Task Manager to ensure no firefox.exe process is left in the process list.
12. Relaunch firefox
13. Update progress bar displayed, and shows some progress until ~50%
13. Update progress bar disappears, browser window is shown. But check the User Agent String and it is still 20060930 (expected: 20061001). *NO* error message has been displayed to indicate the full update failed.
First error in last-update.log is:
EXECUTE ADD extensions/talkback@mozilla.org/install.rdf
EXECUTE ADD extensions/{972ce4c6-7e08-4474-a285-3208198ce6fd}/install.rdf
EXECUTE ADD firefox.exe
copy_file: failed to open or stat: -1,firefox.exe,13
### execution failed

So I concur that clicking 'Later' after updates have been downloaded results in the updates not being applied.
Comment 20 Nick Thomas [:nthomas] 2006-10-01 06:23:08 PDT
The problem here seems to be launching firefox with additional arguments. If don't use any then updates apply after using the Later button, but if "-P <profile>" and/or "-no-remote" are added it will fail. Steve England reports similar results (via IRC) when using "-profilemanager".

Doug, does that explain your WFM too ? If so, the impact of this bug is limited to those users using multiple profiles, or other command line switches.
Comment 21 Benjamin Smedberg [:bsmedberg] 2006-10-01 07:18:24 PDT
cf, thanks for the QA. I'm going to back out bug 312010 from the 1.8 branch because it seems that the double-launch bug is less important than this one.

cf, do you have the ability to debug your updater.exe? I'd be very interested to see what the value of argv[4] is at this point: http://lxr.mozilla.org/mozilla/source/toolkit/mozapps/update/src/updater/updater.cpp#1102 when we launch firefox with a commandline flag (and without, for that matter).
Comment 22 Nick Thomas [:nthomas] 2006-10-01 10:05:18 PDT
Benjamin, without extra args I get:

argc    5
argv[1] C:\Documents and Settings\N&N\Desktop\firefox\updates\0
argv[2] 5944
argv[3] C:\Documents and Settings\N&N\Desktop\firefox
argv[4] C:\Documents and Settings\N&N\Desktop\firefox\firefox.exe
argv[5] (null)

And with an extra arg ("-P uptest"):
argc    7
argv[1] C:\Documents and Settings\N&N\Desktop\firefox\updates\0
argv[2] 4872
argv[3] C:\Documents and Settings\N&N\Desktop\firefox
argv[4] C:\Documents and Settings\N&N\Desktop\firefox\firefox.exe
argv[5] -P
argv[6] uptest
argv[7] (null)

The bug also occurs if I use a simple path like C:\temp\firefox, giving equivalent output to above. (I used LogPrintf just before line 1101 of updater.cpp, and moved the LogInit call before #ifdef WIN_XP).
Comment 23 Mike Schroepfer 2006-10-01 14:51:39 PDT
Clearing the blockingff2 flag and noming for 1.8.1.1 so this can follow bug 312010 if that goes into the 2.0.0.1
Comment 24 Daniel Veditz [:dveditz] 2006-10-02 11:18:40 PDT
Assigning to bsmedberg because bug 312010 is getting the blame for now.
Comment 25 Steve England [:stevee] 2006-10-03 05:59:53 PDT
Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.8.1) Gecko/20061003 BonEcho/2.0 ID:2006100303

After the backout of bug 312010, the partial update 20061002 to 20061003 now works for me when using the 'Later' button on the update dialog.
Comment 26 Daniel Veditz [:dveditz] 2006-10-05 10:58:28 PDT
backed out the patch for bug 312010 on the 1.8.0 branch
Comment 27 Daniel Veditz [:dveditz] 2006-11-03 13:31:40 PST
Marking blocking for the branches because bug 312010 has been marked that way. We don't need this one if that one doesn't land, though.
Comment 28 James Ross 2006-11-22 07:05:11 PST
(In reply to comment #15)
> CreateFile("path/to/firefox.exe", DELETE | GENERIC_WRITE, 0 /* no sharing */)
> ...
> open("path/to/firefox.exe", O_RDONLY | _O_BINARY);
> 
> This is supposed to work (since it's the same process opening the file);

Just for the record, this is very definitely not supposed to work. "An open file that is not shared cannot be opened again, either by the application that opened it or by another application, until its handle has been closed."
Comment 29 Masatoshi Kimura [:emk] 2006-12-25 08:50:03 PST
(In reply to comment #28)
> Just for the record, this is very definitely not supposed to work.
You are right. It's unlikely that we can replace the locked file.
(In reply to comment #22)
> Benjamin, without extra args I get:
> argc    5
See the following code from updater.cpp:
>  if (argc > 5) <=== should be |argc >= 5|!
>    exefile = CreateFile(argv[4], DELETE | GENERIC_WRITE,
>                         0, // no sharing!
>                         NULL, OPEN_EXISTING, 0, NULL);
We will succeed if you launch Firefox without any args because we DON'T lock the executable.
Comment 30 Masatoshi Kimura [:emk] 2006-12-28 09:42:31 PST
Created attachment 249870 [details] [diff] [review]
patch

I confirmed this patch worked perfectly with or without extra args on Win98 (VMware) and WinVista.
This also contains a fix for bug 312010.
Benjamin, may I take this bug or did you already make a patch?
Comment 31 Masatoshi Kimura [:emk] 2006-12-28 09:52:29 PST
Created attachment 249871 [details] [diff] [review]
patch rv 0.2

Oops, I've forgotten to add an error check.
Comment 32 Benjamin Smedberg [:bsmedberg] 2007-02-02 07:20:48 PST
Marking this FIXED by the backout. Bug 312010 will need a different technique.

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