diff --git a/FASTER/Models/Logger.cs b/FASTER/Models/Logger.cs new file mode 100644 index 0000000..93d24ad --- /dev/null +++ b/FASTER/Models/Logger.cs @@ -0,0 +1,27 @@ +using System; +using System.IO; + +namespace FASTER.Models +{ + public static class Logger + { + private static readonly string LogPath = Path.Combine( + Environment.GetFolderPath(Environment.SpecialFolder.ApplicationData), + "FASTER", "faster.log"); + + public static bool IsEnabled => Properties.Settings.Default.enableDebugLog; + + public static string LogFilePath => LogPath; + + public static void Log(string message) + { + if (!IsEnabled) return; + try + { + Directory.CreateDirectory(Path.GetDirectoryName(LogPath)!); + File.AppendAllText(LogPath, $"[{DateTime.Now:yyyy-MM-dd HH:mm:ss}] {message}{Environment.NewLine}"); + } + catch { } + } + } +} diff --git a/FASTER/Properties/Settings.Designer.cs b/FASTER/Properties/Settings.Designer.cs index 2d01c64..bdf6f6f 100644 --- a/FASTER/Properties/Settings.Designer.cs +++ b/FASTER/Properties/Settings.Designer.cs @@ -199,6 +199,18 @@ public bool excludeServerFolder { } } + [global::System.Configuration.UserScopedSettingAttribute()] + [global::System.Diagnostics.DebuggerNonUserCodeAttribute()] + [global::System.Configuration.DefaultSettingValueAttribute("False")] + public bool enableDebugLog { + get { + return ((bool)(this["enableDebugLog"])); + } + set { + this["enableDebugLog"] = value; + } + } + [global::System.Configuration.UserScopedSettingAttribute()] [global::System.Diagnostics.DebuggerNonUserCodeAttribute()] [global::System.Configuration.DefaultSettingValueAttribute("True")] diff --git a/FASTER/Properties/Settings.settings b/FASTER/Properties/Settings.settings index cf92712..c041c40 100644 --- a/FASTER/Properties/Settings.settings +++ b/FASTER/Properties/Settings.settings @@ -95,5 +95,8 @@ False + + False + diff --git a/FASTER/ViewModel/SteamUpdaterViewModel.cs b/FASTER/ViewModel/SteamUpdaterViewModel.cs index a4a97c0..5d2a285 100644 --- a/FASTER/ViewModel/SteamUpdaterViewModel.cs +++ b/FASTER/ViewModel/SteamUpdaterViewModel.cs @@ -445,9 +445,86 @@ public async Task RunModsUpdater(ObservableCollection mods) Logger.Log($"RunModsUpdater: waiting semaphore for mod {mod.WorkshopId} ({mod.Name})"); await maxThread.WaitAsync(); - _ = Task.Factory.StartNew( - () => ProcessModDownloadAsync(mod), - TaskCreationOptions.LongRunning).Unwrap().ContinueWith((t) => + _ = Task.Factory.StartNew(async () => + { + Logger.Log($" Task started: {mod.WorkshopId} ({mod.Name}), path={mod.Path}"); + try + { + if (!Directory.Exists(mod.Path)) + { + Logger.Log($" Creating dir: {mod.Path}"); + Directory.CreateDirectory(mod.Path); + } + + if (tokenSource.Token.IsCancellationRequested) + { + Logger.Log($" Cancellation requested before {mod.WorkshopId}, skipping."); + return; + } + Parameters.Output += $"\n Starting {mod.WorkshopId}"; + + Stopwatch sw = Stopwatch.StartNew(); + try + { + ManifestId manifestId = default; + + if(mod.LocalLastUpdated > mod.SteamLastUpdated && mod.Size > 0) + { + mod.Status = ArmaModStatus.UpToDate; + Parameters.Output += $"\n Mod{mod.WorkshopId} already up to date. Ignoring..."; + Logger.Log($" {mod.WorkshopId} already up to date, skipping."); + return; + } + + if (!SteamClient.Credentials.IsAnonymous) + { + Logger.Log($" Getting manifest for {mod.WorkshopId}"); + Parameters.Output += $"\n Getting manifest for {mod.WorkshopId}"; + manifestId = (await SteamContentClient.GetPublishedFileDetailsAsync(mod.WorkshopId)).hcontent_file; + Manifest manifest = await SteamContentClient.GetManifestAsync(107410, 107410, manifestId); + Parameters.Output += $"\n Manifest retrieved {mod.WorkshopId}"; + Logger.Log($" Manifest retrieved for {mod.WorkshopId}, syncing deleted files..."); + SyncDeleteRemovedFiles(mod.Path, manifest); + } + + Logger.Log($" Requesting download handler for {mod.WorkshopId}"); + Parameters.Output += $"\n Attempting to start download of item {mod.WorkshopId}... "; + + var downloadHandler = await SteamContentClient.GetPublishedFileDataAsync(mod.WorkshopId, manifestId, tokenSource.Token); + Logger.Log($" Download handler obtained for {mod.WorkshopId}, starting download..."); + await DownloadForMultiple(downloadHandler, mod.Path); + Logger.Log($" Download complete for {mod.WorkshopId}"); + + mod.Status = ArmaModStatus.UpToDate; + var nx = DateTime.UnixEpoch; + var ts = DateTime.UtcNow - nx; + mod.LocalLastUpdated = (ulong)ts.TotalSeconds; + } + catch (TaskCanceledException) + { + Logger.Log($" {mod.WorkshopId} task cancelled."); + sw.Stop(); + mod.Status = ArmaModStatus.NotComplete; + } + catch (Exception ex) + { + Logger.Log($" ERROR downloading {mod.WorkshopId}: {ex.GetType().Name}: {ex.Message}{(ex.InnerException != null ? $" | Inner: {ex.InnerException.Message}" : "")}\n StackTrace: {ex.StackTrace}"); + sw.Stop(); + mod.Status = ArmaModStatus.NotComplete; + Parameters.Output += $"\nError: {ex.Message}{(ex.InnerException != null ? $" Inner Exception: {ex.InnerException.Message}" : "")}"; + } + sw.Stop(); + + mod.CheckModSize(); + Parameters.Output += $"\n Download {mod.WorkshopId} completed, it took {sw.Elapsed.Minutes + sw.Elapsed.Hours*60}m {sw.Elapsed.Seconds}s {sw.Elapsed.Milliseconds}ms"; + } + + if (!SteamClient.Credentials.IsAnonymous) + { + Logger.Log($" UNHANDLED ERROR in task for {mod.WorkshopId}: {ex.GetType().Name}: {ex.Message}\n StackTrace: {ex.StackTrace}"); + } + + }, TaskCreationOptions.LongRunning).Unwrap().ContinueWith((t) => { if (t.IsFaulted) Logger.Log($" ContinueWith: task for {mod.WorkshopId} faulted: {t.Exception}"); @@ -475,82 +552,6 @@ public async Task RunModsUpdater(ObservableCollection mods) return UpdateState.Success; } - private async Task ProcessModDownloadAsync(ArmaMod mod) - { - Logger.Log($" Task started: {mod.WorkshopId} ({mod.Name}), path={mod.Path}"); - try - { - if (!Directory.Exists(mod.Path)) - { - Logger.Log($" Creating dir: {mod.Path}"); - Directory.CreateDirectory(mod.Path); - } - - if (tokenSource.Token.IsCancellationRequested) - { - Logger.Log($" Cancellation requested before {mod.WorkshopId}, skipping."); - return; - } - Parameters.Output += $"\n Starting {mod.WorkshopId}"; - - Stopwatch sw = Stopwatch.StartNew(); - try - { - ManifestId manifestId = default; - - if (mod.LocalLastUpdated > mod.SteamLastUpdated && mod.Size > 0) - { - mod.Status = ArmaModStatus.UpToDate; - Parameters.Output += $"\n Mod{mod.WorkshopId} already up to date. Ignoring..."; - Logger.Log($" {mod.WorkshopId} already up to date, skipping."); - return; - } - - if (!SteamClient.Credentials.IsAnonymous) - { - Logger.Log($" Getting manifest for {mod.WorkshopId}"); - Parameters.Output += $"\n Getting manifest for {mod.WorkshopId}"; - manifestId = (await SteamContentClient.GetPublishedFileDetailsAsync(mod.WorkshopId)).hcontent_file; - Manifest manifest = await SteamContentClient.GetManifestAsync(107410, 107410, manifestId); - Parameters.Output += $"\n Manifest retrieved {mod.WorkshopId}"; - Logger.Log($" Manifest retrieved for {mod.WorkshopId}, syncing deleted files..."); - SyncDeleteRemovedFiles(mod.Path, manifest); - } - - Logger.Log($" Requesting download handler for {mod.WorkshopId}"); - Parameters.Output += $"\n Attempting to start download of item {mod.WorkshopId}... "; - - var downloadHandler = await SteamContentClient.GetPublishedFileDataAsync(mod.WorkshopId, manifestId, tokenSource.Token); - Logger.Log($" Download handler obtained for {mod.WorkshopId}, starting download..."); - await DownloadForMultiple(downloadHandler, mod.Path); - Logger.Log($" Download complete for {mod.WorkshopId}"); - - mod.Status = ArmaModStatus.UpToDate; - mod.LocalLastUpdated = (ulong)(DateTime.UtcNow - DateTime.UnixEpoch).TotalSeconds; - } - catch (TaskCanceledException) - { - Logger.Log($" {mod.WorkshopId} task cancelled."); - sw.Stop(); - mod.Status = ArmaModStatus.NotComplete; - } - catch (Exception ex) - { - Logger.Log($" ERROR downloading {mod.WorkshopId}: {ex.GetType().Name}: {ex.Message}{(ex.InnerException != null ? $" | Inner: {ex.InnerException.Message}" : "")}\n StackTrace: {ex.StackTrace}"); - sw.Stop(); - mod.Status = ArmaModStatus.NotComplete; - Parameters.Output += $"\nError: {ex.Message}{(ex.InnerException != null ? $" Inner Exception: {ex.InnerException.Message}" : "")}"; - } - sw.Stop(); - mod.CheckModSize(); - Parameters.Output += $"\n Download {mod.WorkshopId} completed in {sw.Elapsed.Hours * 60 + sw.Elapsed.Minutes}m {sw.Elapsed.Seconds}s {sw.Elapsed.Milliseconds}ms"; - } - catch (Exception ex) - { - Logger.Log($" UNHANDLED ERROR in task for {mod.WorkshopId}: {ex.GetType().Name}: {ex.Message}\n StackTrace: {ex.StackTrace}"); - } - } - internal async Task SteamLogin() { Logger.Log("SteamLogin: start"); diff --git a/FASTER/Views/Settings.xaml b/FASTER/Views/Settings.xaml index 0b4fdd3..4e79e4b 100644 --- a/FASTER/Views/Settings.xaml +++ b/FASTER/Views/Settings.xaml @@ -39,6 +39,7 @@ + @@ -50,7 +51,17 @@ - + + + + + + + +