System.TimoutException (transaction timeout) for large downloads on a slower connection

[buttercookie42]

Thanks for wanting to bring an issue to our attention!

Before you open a ticket, please do a quick search of the existing issues to see if it's already been brought up.

CKAN Version:
1.20.1-0-gd41fe54 (beta)

Operating System:
Windows 7

The issue you are experiencing:
After downloading has finished, instead of the mods installing I just get the unhandled exception window showing that a transaction timeout exception (System.TimoutException) has occured. Luckily the mods do get downloaded into the cache, so the next installation attempt succeeds.

How to recreate this issue:
Download any largeish mod (e.g. Stock Visual Enhancements) on a none too fast internet connection (2 Mbps in my case). It seems like the transaction timeouts currently configured in CKAN might not take account of the fact that in those cases downloads can legitimately take more than a few minutes.

[ayan4m1]

We set the timeout here to be the maximum time limit proscribed by the transaction library itself. The issue is documented (see, MS told us to do it that way 🙉) elsewhere I agree with the idea that a single CKAN transaction could take over 10 minutes and still complete successfully. Ultimately, we can either hammer a huge number in there or we can make it configurable somewhere. Paging @politas to weigh in on this.

[politas]

Spacedock has been having some issues recently, so I would suspect the problem is there. Have you had any issues with mods on Curse or GitHub?

[buttercookie42]

@politas
Isn't Stock Visual Enhancements already downloaded from Github? At least all the relevant links are pointing to it being hosted on Github now.

What I'm wondering is why the download is part of the transaction as well (and therefore counts against the time limit), since as I said downloading can legitimately take quite a while and it seems that despite the transaction timeout, the download itself does make it into the cache and (luckily) isn't rolled back. Also, the timeout (again, luckily) doesn't force an abort of the currently running download, but at least in my case only kicks in after downloading has terminated normally. So if the intention is to roll back genuinely failed downloads, this must (or should ?) be handled somehow differently? Or was there any other reason why this approach was chosen?

Actually, looking at the ModuleInstaller, it looks like in theory we do kick off the downloads outside of the transaction - could the issue be that the downloads are done asynchronously, so we start all the downloads, enter the transaction and then timeout while waiting for all the downloads to complete?

[ayan4m1]

Please provide KSP file or console log output or the stack trace from your TimeoutException.

[buttercookie42]

Which log file are you referring to?
Unfortunately I cannot reproduce this error when installing a mod through the command line - I've (re)downloaded some large mods (the HermesInterplanetarySpacecraft, Real Solar System Textures - 4096 x 2048 and SVE-Terrain) and every time installing via the command line worked without a problem.

Using the GUI I haven't seen any obvious way to get the logs and the unhandled exception dialogue doesn't show any stack trace in this case - just the exception name and description as well as the big list of loaded modules.

However when running a local build under Visual Studio I end up with a TransactionAbortedException and the following stack trace:

   bei System.Transactions.TransactionStateAborted.CreateAbortingClone(InternalTransaction tx)
   bei System.Transactions.DependentTransaction..ctor(IsolationLevel isoLevel, InternalTransaction internalTransaction, Boolean blocking)
   bei System.Transactions.Transaction.DependentClone(DependentCloneOption cloneOption)
   bei System.Transactions.TransactionScope.SetCurrent(Transaction newCurrent)
   bei System.Transactions.TransactionScope.PushScope()
   bei System.Transactions.TransactionScope..ctor(TransactionScopeOption scopeOption, TransactionOptions transactionOptions, TransactionScopeAsyncFlowOption asyncFlowOption)
   bei System.Transactions.TransactionScope..ctor(TransactionScopeOption scopeOption, TransactionOptions transactionOptions)
   bei CKAN.CkanTransaction.CreateTransactionScope() in D:\Users\Jan\Documents\Kerbal Space Program\CKAN source\Core\CkanTransaction.cs:Zeile 18.
   bei CKAN.ModuleInstaller.InstallList(ICollection`1 modules, RelationshipResolverOptions options, IDownloader downloader) in D:\Users\Jan\Documents\Kerbal Space Program\CKAN source\Core\ModuleInstaller.cs:Zeile 218.
   bei CKAN.ModuleInstaller.InstallList(List`1 modules, RelationshipResolverOptions options, IDownloader downloader) in D:\Users\Jan\Documents\Kerbal Space Program\CKAN source\Core\ModuleInstaller.cs:Zeile 157.
   bei CKAN.Main.<>c__DisplayClass259_0.<InstallList>b__0() in D:\Users\Jan\Documents\Kerbal Space Program\CKAN source\GUI\MainInstall.cs:Zeile 306.
   bei CKAN.Main.WasSuccessful(Action action) in D:\Users\Jan\Documents\Kerbal Space Program\CKAN source\GUI\MainInstall.cs:Zeile 219.
   bei CKAN.Main.InstallList(HashSet`1 toInstall, RelationshipResolverOptions options, IDownloader downloader) in D:\Users\Jan\Documents\Kerbal Space Program\CKAN source\GUI\MainInstall.cs:Zeile 305.
   bei CKAN.Main.InstallMods(Object sender, DoWorkEventArgs e) in D:\Users\Jan\Documents\Kerbal Space Program\CKAN source\GUI\MainInstall.cs:Zeile 129.
   bei System.ComponentModel.BackgroundWorker.OnDoWork(DoWorkEventArgs e)
   bei System.ComponentModel.BackgroundWorker.WorkerThreadStart(Object argument)

with the actual TimeoutException being shown as an inner exception without any further details (which probably explains why the standard .NET exception handler didn't show any stack trace).

[ayan4m1]

The command line difference will prove useful, thanks for that trace. When a transaction - specifically not the one related to your requested install - times out, it will not throw any TimeoutException immediately as the timeout is passed. When there is still a timed out exception on the stack that TransactionScope maintaines, it tries to wrap the new transaction (i.e. the one related to your requested install) using DependentClone which calls DependentTransaction..ctor which refuses to wrap the current transaction around the previous one because the previous one is complete because it has timed out. Because the transaction being passed in is aborted, we get this exception.

There is a lot going on here and as you have seen the ModuleInstaller code is complex and tightly coupled. Ultimately the issue written up is about a TimeoutException inside a TransactionAbortedException that only seems to affect the GUI. Will follow up when I have more time to look into it.

[archer884]

@politas I believe this issue can now be closed.

[politas]

@archer884, might wait until I push out a new release.

[vfauth]

Sorry to revive this issue, but for people with a slow connection, it is simply impossible to download big mods (200MB is the maximum for me).

[HebaruSan]

This should have been addressed by #3512's disabling of the mis-feature of transaction timeout limits.