Squirrel.Windows icon indicating copy to clipboard operation
Squirrel.Windows copied to clipboard

UpdateManager. UpdateApp() stuck with AbandonedMutexException

Open safeermtp opened this issue 5 years ago • 14 comments

I have scheduled task to call the update app every 30 mins but some times some client app will stuck at update app and when i close the app will get the following exception at windows event log.

Framework Version: v4.0.30319 Description: The process was terminated due to an unhandled exception. Exception Info: System.Threading.AbandonedMutexException Stack: at Squirrel.SingleGlobalInstance.Finalize()

to identify the issue i have tried enabled the splat logging(refer attached log KioskSquirrelSetup_BGTNG.log )

As you can see form the log, it was running normal until 12:03:14. The next call to UpdateApp at 12:33 got stuck without any log and when i close the app i got the above exception.

Squirrel Version : 1.9.1 [had similar issues with 1.5.1 and recently updated to 1.9.1 expect it may fix it] OS: Windows 7 embedded standard Service Pack 1

Thanks

safeermtp avatar Mar 05 '19 06:03 safeermtp

Is it possible to see your implementation of the timed, repeated, check? I've had this happen to me before improperly using UpdateManager.

patrickklaeren avatar Apr 24 '19 20:04 patrickklaeren

My Application is using Akka.Net actor system and i have an actor for updating the app. The parent actor will send a scheduled UpdateAppMessage to the update actor to check for update.

here is the snippet of the actor's receive action,

public ApplicationUpdaterActor(IActorRef ilogger, string updateHost)
{
	_logger = ilogger;
	_updateHost = updateHost;
	ReceiveAsync<UpdateAppMessage>(async message =>
	{
		try
		{
			using (var logger = new SSKSetupLogLogger(false) { Level = LogLevel.Debug }) //Splat logger enabled to get Squirrel logs 
			{
				Locator.CurrentMutable.Register(() => logger, typeof(Splat.ILogger));
				_logger.Tell(new KioskInfoMessage() { Info = "App Updater - Check for updates" });

				using (var mgr = new UpdateManager(_updateHost))
				{
					await mgr.UpdateApp();


				}
				_logger.Tell(new KioskInfoMessage() { Info = "App Updater - Check for updates finished" });
				if (message.forceRestart)
				{
					UpdateManager.RestartApp();
				}
			}

		}
		catch (Exception e)
		{
			_logger.Tell(new KioskFailureMessage() { Reason = "App Updater - " + e.Message + " " + e.StackTrace });
		}
	});
	InitializeSquirrel();
}
private void InitializeSquirrel()
{
	_logger.Tell(new KioskInfoMessage() { Info = "App Updater - InitializeSquirrel" });
	using (var mgr = new UpdateManager(_updateHost))
	{
		SquirrelAwareApp.HandleEvents(
	  onInitialInstall: v => OnInitialInstall(mgr),
	  onAppUpdate: v => OnAppUpdate(mgr),
	  onAppUninstall: v => OnAppUninstall(mgr),
	  onFirstRun: () => ShowTheWelcomeWizard = true);
	}
}

We have over 120 unattended devices running the apps. daily will have atleast 3-5 devices stuck with the updater and they are not the same devices every day.

Thanks, Safeer

safeermtp avatar Apr 25 '19 01:04 safeermtp

And I assume you have verified you're not receiving the message multiple times?

patrickklaeren avatar Apr 25 '19 06:04 patrickklaeren

Yes.. i have verified that its not receiving the message multiple times. Also once the UpdateManager stuck(the issue happens) , the actor is is also stuck there and incoming messages will go to its message queue and wait for the stuck message to finish processing.

safeermtp avatar Apr 25 '19 07:04 safeermtp

i think the issue happens when there is network timeout when checking for updates. Yesterday our release server was down for few hours and today when i check most of the clients where stuck at updateapp call at around that time and never ended. when i restart the app i get the same exception logged.

safeermtp avatar Aug 09 '19 01:08 safeermtp

UPDATE:

My app have logged App Updater - Check for updates line

But in the Splat log file didn't have the IUpdateManager: Starting automatic update log and the update manage stuck there and never logged the App Updater - Check for updates finished line. When i close the app and it throws the AbandonedMutex Exception.

Based on the source it should be acquiring the lock after the log entry.. but here it didn't have the log but somehow it was still holding the lock.

Any assistance is much appreciated.

safeermtp avatar Sep 05 '19 04:09 safeermtp

@safeermtp Would it make sense to wait for mgr.UpdateApp(); with a timeout? At least to fail more gracefully in the problematic cases? If UpdateApp() is still running, the AbandonnedMutex is bound to happen considering https://github.com/Squirrel/Squirrel.Windows/issues/1235#issuecomment-358187746

Thieum avatar Sep 05 '19 13:09 Thieum

@Thieum i have checked the code on referenced comment, but even if i send cancel token to the wrapped task, it wont stop until the stuck await mgr.UpdateApp(); call finishes.

My problem is the call to await mgr.UpdateApp(); stuck forever holding the mutex until i close the app and it will throw the exception.

safeermtp avatar Sep 06 '19 07:09 safeermtp

@safeermtp I was more thinking (at least as a test) about something like this:

await mgr.UpdateApp();

would become

mgr.UpdateApp().Wait(/*A possible reasonable timeout value ???*/);

I know it would be blocking the thread with this change, but at least you would have a way to control directly the time you allow the task to proceed?

The only issue I could see is what happens if the timeout pops when we are still updating...

Thieum avatar Sep 06 '19 17:09 Thieum

@Thieum to test your suggestion, i have tried the following.

changed the await to mgr.UpdateApp().Wait(TimeSpan.FromMinutes(2)); And to simulate a hang in updater i have added an infinite loop at the UpdateApp extension method in squirrel.

But the wait didn't timeout after 2 mins.

So i changed my infinite loop to something like a loop which exit after 4 mins. and then the Wait code returned after 4mins

safeermtp avatar Sep 12 '19 04:09 safeermtp

@safeermtp does your loop/exit solution would solve your issue on the devices that get stuck ?

Thieum avatar Sep 12 '19 19:09 Thieum

@Thieum , this is my testing at local, its very hard to get the actual issue happen in local. I will try to push it to live and see if its solve the problem or not.

safeermtp avatar Sep 13 '19 02:09 safeermtp

After a lot of troubleshooting, i have found the problem. its with FileDownloader using WebClient.DownloadDataTaskAsync which will never timeout if there is any glitches while downloading the release file. So my check for update will be stuck forever and when i close the app it will throw mutex exception. I found in the IIS server log, request for releases file has return 200 status but win32-status code 1236 : ERROR_CONNECTION_ABORTED which leads to the problem situation. This issue happen at IIS server randomly.

to simulate the issue, Just run the following node web server which will never respond to a request. Set the update url to this service. like http://localhost:3000/



const app = express();

app.use((req, res, next) => {
  
});

app.listen(3000, () => {
  
  console.log('  Press CTRL-C to stop\n');
});


module.exports = app;

Solution: I have implemented custom IFileDownloader similar to original squirrel code but with some additional logic for timeout and to cancel webClient asyc operations.

return await this.WarnIfThrows(() => {


                        var request = wc.DownloadDataTaskAsync(failedUrl ?? url);
                        var timeout = Task.Delay(TimeSpan.FromMinutes(5));
                        var completed = Task.WhenAny(request, timeout).Result;
                        if (completed == timeout)
                        {
                            wc.CancelAsync();
                            throw new TimeoutException("Download file timeout!");
                        }
                        else
                        {
                            return request;
                        }

                    },
                        "Failed to download url: " + (failedUrl ?? url));

Thanks All

safeermtp avatar Oct 01 '19 07:10 safeermtp

When the IIS site, hosting app, is down, the Squirrel update stuck forever. @safeermtp, can you add the full class code of your custom FileDownloader? I try without success.

For the moment, I use this update implementation where the WebClient is injected to ensure that is disposed :

public static void Update()
{
    bool restart = false;
    // Inject the WebClient to ensure that is disposed
    using (var webClient = Utility.CreateWebClient())
    using (var mgr = new UpdateManager(ConfigurationManager.AppSettings["UpdateUrl"], null, null, new FileDownloader(webClient)))
    {
        var task = mgr.UpdateApp();
        if(task.Wait(TimeSpan.FromSeconds(10)))
        {
            restart = task.Result != null;
        }
        else
        {
            LogError("Update Timeout : 10 secondes");
        }
    }
    // It is necessary to restart after disposed the UpdateManager
    if (restart)
    {
        UpdateManager.RestartApp();
    }
}

vernou avatar Mar 05 '21 09:03 vernou