#13 download / update hangs

[DethKnite]

I have noticed that some instances when a new version is detected, when the user clicks update the first time, it fails. It seems that the download size is DOUBLE the actual size.

I included the log file if it can help at all. I am going to see if I can find anything when I get a chance.

I noticed that if you run it immediately afterwards, the download size is correct (half of the 1st unsuccessful dwnld). And it works ok... but the first update program is still running and has to be killed from the task manager.

At first looks it appears that it is trying to download everything twice.

[DethKnite]

File Added: update-log-2nd_run_success.txt

[Doug Day]

Thanks for posting this. Hm... I'll check out both logs and see if I can find the reason this is happening. In the meantime, if you notice anything else let me know.

Thanks,
-Doug

[DethKnite]

I think I may have figured out what is going wrong. I posted the log from a failed update, and a log from a successful update. I noticed in the failed log file, the last line of debug code it processed was the "File downloads finished." line. It never fired off the "GetLocalDeploymentManifest()" code. I think this could possibly be due to the number of files that it needs to download not being reached? Maybe it isn't getting to the OnCompleted() of the Save Files. I am not sure as of yet. Just wanted to get an update on here to help you in looking as well.

DK
File Added: good-update-log.txt

[DethKnite]

Good Update Log

[DethKnite]

Bad Update Log

[DethKnite]

File Added: bad-update-log.txt

[DethKnite]

After testing out a few changes and looking closer... it appears what is happening, is sometimes, the download of files is not complete yet, but the code continues past as if it thinks it is complete. I attached a final log, that has a download happening after the "File downloads finished." line.

[DethKnite]

Final update attached

[DethKnite]

Ok, I added code to wait until each downloader in _FileDownloaders is either cancelled or completed and logged. It showed that each completed on a failed update, and died elsewhere...

2008-11-19 10:44:23,194 [1] DEBUG DDay.Update - No download required.
2008-11-19 10:44:23,194 [1] DEBUG DDay.Update - Attempting to save 'agilhost.ico'...
2008-11-19 10:44:23,194 [1] INFO DDay.Update - Using 'agilhost.ico' from previous version.
2008-11-19 10:44:23,194 [1] DEBUG DDay.Update - Determing if 'lhtasks.exe' requires downloading...
2008-11-19 10:44:23,194 [1] INFO DDay.Update - Downloading 'lhtasks.exe'...
2008-11-19 10:44:23,288 [8] INFO DDay.Update - Download of 'lhtasks.exe' completed.
2008-11-19 10:44:23,288 [1] INFO DDay.Update - DKFIX: Wait on ADAT.exe( False, True )
2008-11-19 10:44:23,288 [1] INFO DDay.Update - DKFIX: Wait on LHTaskScheduler.dll( False, True )
2008-11-19 10:44:23,288 [1] INFO DDay.Update - DKFIX: Wait on ADAT.exe.config( False, True )
2008-11-19 10:44:23,288 [1] INFO DDay.Update - DKFIX: Wait on agilhost.ico( False, True )
2008-11-19 10:44:23,288 [1] INFO DDay.Update - DKFIX: Wait on lhtasks.exe( False, True )
2008-11-19 10:44:23,288 [1] INFO DDay.Update - File downloads finished.
2008-11-19 10:44:23,304 [8] DEBUG DDay.Update - Attempting to save 'lhtasks.exe'...

[DethKnite]

I think I may have fixed it... I added a private _IsSaved bool on the FileDownloader, and a corresponding public method.
I then set the IsSaved = true; after the
{
lock
{
save file...
}
IsSaved = true;
}

Then in the Updater I added a wait while (!downloader.IsSaved).
I logged this and found that at times the last file was kinda quirky to the gun. But this is a harsh fix... though it works. I am not sure what is causing the finished to fire off prematurely.
You may want to use this as a workaround... or modify it if you can figure it out better.

DK

[DethKnite]

log.Debug("Downloading each file to be updated...");

// Download each file
foreach (FileDownloader downloader in _FileDownloaders)
{
if (!CancelledOrError)
{
// Download the new copy of the file
downloader.Download(UpdateNotifier);

// Wait for the item to be downloaded
_DownloadEvent.WaitOne();

}
else break; //<===== THIS MAY BE CAUSING THE PREMATURE EVENT FIREING
}

//ADDED MY WAIT HERE*

[DethKnite]

Example of my modified versions output... notice how the last download is saved AFTER the local manifest is is loaded again... then it finishes saving... and then it continues to the "File downloads finished." then Starts the Application.

Using 'ADAT.exe.config' from previous version.
2008-11-19 11:20:24,332 [1] DEBUG DDay.Update - Determing if 'agilhost.ico' requires downloading...
2008-11-19 11:20:24,332 [1] DEBUG DDay.Update - No download required.
2008-11-19 11:20:24,332 [1] DEBUG DDay.Update - Attempting to save 'agilhost.ico'...
2008-11-19 11:20:24,332 [1] INFO DDay.Update - Using 'agilhost.ico' from previous version.
2008-11-19 11:20:24,332 [1] DEBUG DDay.Update - Determing if 'lhtasks.exe' requires downloading...
2008-11-19 11:20:24,332 [1] INFO DDay.Update - Downloading 'lhtasks.exe'...
2008-11-19 11:20:24,425 [9] INFO DDay.Update - Download of 'lhtasks.exe' completed.
2008-11-19 11:20:24,425 [9] DEBUG DDay.Update - Attempting to save 'lhtasks.exe'...
2008-11-19 11:20:24,441 [1] DEBUG DDay.Update - DKFIX: Wait on ADAT.exe( Saved=True, Cancelled=False, Completed=True )
2008-11-19 11:20:24,441 [1] DEBUG DDay.Update - DKFIX: Wait on LHTaskScheduler.dll( Saved=True, Cancelled=False, Completed=True )
2008-11-19 11:20:24,441 [1] DEBUG DDay.Update - DKFIX: Wait on ADAT.exe.config( Saved=True, Cancelled=False, Completed=True )
2008-11-19 11:20:24,441 [1] DEBUG DDay.Update - DKFIX: Wait on agilhost.ico( Saved=True, Cancelled=False, Completed=True )
2008-11-19 11:20:24,441 [1] DEBUG DDay.Update - DKFIX: Wait on lhtasks.exe( Saved=False, Cancelled=False, Completed=True )
2008-11-19 11:20:24,488 [1] DEBUG DDay.Update - DKFIX: Wait on lhtasks.exe( Saved=False, Cancelled=False, Completed=True )
2008-11-19 11:20:24,488 [9] DEBUG DDay.Update - Loading local deployment manifest...
2008-11-19 11:20:24,488 [9] DEBUG DDay.Update - Checking for deployment manifest at 'C:\DMSi\Agility Database Administration Tool\deployment.manifest'...
2008-11-19 11:20:24,488 [9] DEBUG DDay.Update - Local deployment manifest found.
2008-11-19 11:20:24,488 [9] DEBUG DDay.Update - Loading deployment manifest...
2008-11-19 11:20:24,535 [1] DEBUG DDay.Update - DKFIX: Wait on lhtasks.exe( Saved=False, Cancelled=False, Completed=True )
2008-11-19 11:20:24,582 [1] DEBUG DDay.Update - DKFIX: Wait on lhtasks.exe( Saved=False, Cancelled=False, Completed=True )
2008-11-19 11:20:24,644 [1] DEBUG DDay.Update - DKFIX: Wait on lhtasks.exe( Saved=False, Cancelled=False, Completed=True )
2008-11-19 11:20:24,691 [1] DEBUG DDay.Update - DKFIX: Wait on lhtasks.exe( Saved=False, Cancelled=False, Completed=True )
2008-11-19 11:20:24,738 [1] DEBUG DDay.Update - DKFIX: Wait on lhtasks.exe( Saved=True, Cancelled=False, Completed=True )
2008-11-19 11:20:24,738 [1] INFO DDay.Update - File downloads finished.
2008-11-19 11:20:24,753 [1] INFO DDay.Update - Starting application...
2008-11-19 11:20:24,753 [1] DEBUG DDay.Update - Loading application manifest from deployment manifest...
2008-11-19 11:20:24,769 [1] DEBUG DDay.Update - Loaded.
2008-11-19 11:20:24,769 [1] DEBUG DDay.Update - Executing entry point...
2008-11-19 11:20:25,050 [1] DEBUG DDay.Update - Done.
2008-11-19 11:20:25,050 [1] DEBUG DDay.Update - Exiting bootstrap application...