Merge pull request 'mcdf-background-creation' (#112) from mcdf-background-creation into 2.0.2

Reviewed-on: #112

LightlessSync/Services/CharaData/CharaDataFileHandler.cs

@@ -1,13 +1,16 @@
-using Dalamud.Game.ClientState.Objects.SubKinds;
+using Dalamud.Game.ClientState.Objects.SubKinds;
 using K4os.Compression.LZ4.Legacy;
 using LightlessSync.API.Data;
 using LightlessSync.API.Data.Enum;
 using LightlessSync.API.Dto.CharaData;
 using LightlessSync.FileCache;
+using LightlessSync.LightlessConfiguration.Models;
 using LightlessSync.PlayerData.Factories;
 using LightlessSync.PlayerData.Handlers;
 using LightlessSync.Services.CharaData;
 using LightlessSync.Services.CharaData.Models;
+using LightlessSync.Services.Mediator;
+using LightlessSync.UI.Models;
 using LightlessSync.Utils;
 using LightlessSync.WebAPI.Files;
 using Microsoft.Extensions.Logging;
@@ -24,10 +27,11 @@ public sealed class CharaDataFileHandler : IDisposable
     private readonly ILogger<CharaDataFileHandler> _logger;
     private readonly LightlessCharaFileDataFactory _lightlessCharaFileDataFactory;
     private readonly PlayerDataFactory _playerDataFactory;
+    private readonly NotificationService _notificationService;
     private int _globalFileCounter = 0;
 
     public CharaDataFileHandler(ILogger<CharaDataFileHandler> logger, FileDownloadManagerFactory fileDownloadManagerFactory, FileUploadManager fileUploadManager, FileCacheManager fileCacheManager,
-            DalamudUtilService dalamudUtilService, GameObjectHandlerFactory gameObjectHandlerFactory, PlayerDataFactory playerDataFactory)
+            DalamudUtilService dalamudUtilService, GameObjectHandlerFactory gameObjectHandlerFactory, PlayerDataFactory playerDataFactory, NotificationService notificationService)
     {
         _fileDownloadManager = fileDownloadManagerFactory.Create();
         _logger = logger;
@@ -36,6 +40,7 @@ public sealed class CharaDataFileHandler : IDisposable
         _dalamudUtilService = dalamudUtilService;
         _gameObjectHandlerFactory = gameObjectHandlerFactory;
         _playerDataFactory = playerDataFactory;
+        _notificationService = notificationService;
         _lightlessCharaFileDataFactory = new(fileCacheManager);
     }
 
@@ -248,54 +253,161 @@ public sealed class CharaDataFileHandler : IDisposable
     }
 
     internal async Task SaveCharaFileAsync(string description, string filePath)
+    {
+        var createPlayerDataStopwatch = System.Diagnostics.Stopwatch.StartNew();
+        var data = await CreatePlayerData().ConfigureAwait(false);
+        createPlayerDataStopwatch.Stop();
+        _logger.LogInformation("CreatePlayerData took {elapsed}ms", createPlayerDataStopwatch.ElapsedMilliseconds);
+
+        if (data == null) return;
+
+        await Task.Run(async () => await SaveCharaFileAsyncInternal(description, filePath, data).ConfigureAwait(false)).ConfigureAwait(false);
+    }
+
+    private async Task SaveCharaFileAsyncInternal(string description, string filePath, CharacterData data)
     {
         var tempFilePath = filePath + ".tmp";
+        var overallStopwatch = System.Diagnostics.Stopwatch.StartNew();
 
         try
         {
-            var data = await CreatePlayerData().ConfigureAwait(false);
-            if (data == null) return;
-
             var lightlessCharaFileData = _lightlessCharaFileDataFactory.Create(description, data);
             LightlessCharaFileHeader output = new(LightlessCharaFileHeader.CurrentVersion, lightlessCharaFileData);
 
-            using var fs = new FileStream(tempFilePath, FileMode.Create, FileAccess.ReadWrite, FileShare.None);
+            using var fs = new FileStream(tempFilePath, FileMode.Create, FileAccess.ReadWrite, FileShare.None, bufferSize: 65536, useAsync: false);
             using var lz4 = new LZ4Stream(fs, LZ4StreamMode.Compress, LZ4StreamFlags.HighCompression);
             using var writer = new BinaryWriter(lz4);
             output.WriteToStream(writer);
 
+            int fileIndex = 0;
+            long totalBytesWritten = 0;
+            long totalBytesToWrite = output.CharaFileData.Files.Sum(f => f.Length);
+            var fileWriteStopwatch = System.Diagnostics.Stopwatch.StartNew();
+            const long updateIntervalMs = 1000;
+
             foreach (var item in output.CharaFileData.Files)
             {
+                fileIndex++;
+                var fileStopwatch = System.Diagnostics.Stopwatch.StartNew();
+
                 var file = _fileCacheManager.GetFileCacheByHash(item.Hash)!;
-                _logger.LogDebug("Saving to MCDF: {hash}:{file}", item.Hash, file.ResolvedFilepath);
+                _logger.LogDebug("Saving to MCDF [{fileNum}/{totalFiles}]: {hash}:{file}", fileIndex, output.CharaFileData.Files.Count, item.Hash, file.ResolvedFilepath);
                 _logger.LogDebug("\tAssociated GamePaths:");
                 foreach (var path in item.GamePaths)
                 {
                     _logger.LogDebug("\t{path}", path);
                 }
 
-                var fsRead = File.OpenRead(file.ResolvedFilepath);
+                using var fsRead = File.OpenRead(file.ResolvedFilepath);
-                await using (fsRead.ConfigureAwait(false))
+                using var br = new BinaryReader(fsRead);
+                byte[] buffer = new byte[item.Length];
+                int bytesRead = br.Read(buffer, 0, item.Length);
+
+                if (bytesRead != item.Length)
                 {
-                    using var br = new BinaryReader(fsRead);
+                    _logger.LogWarning("Expected to read {expected} bytes but got {actual} bytes from {file}", item.Length, bytesRead, file.ResolvedFilepath);
-                    byte[] buffer = new byte[item.Length];
+                }
-                    br.Read(buffer, 0, item.Length);
+
-                    writer.Write(buffer);
+                writer.Write(buffer);
+                totalBytesWritten += bytesRead;
+
+                fileStopwatch.Stop();
+                _logger.LogDebug("Wrote file [{fileNum}/{totalFiles}] in {elapsed}ms ({sizeKb}kb)", fileIndex, output.CharaFileData.Files.Count, fileStopwatch.ElapsedMilliseconds, item.Length / 1024);
+
+                if (fileWriteStopwatch.ElapsedMilliseconds >= updateIntervalMs && totalBytesToWrite > 0)
+                {
+                    float progress = (float)totalBytesWritten / totalBytesToWrite;
+                    var elapsed = overallStopwatch.Elapsed;
+                    var eta = CalculateEta(elapsed, progress);
+
+                    var notification = new LightlessNotification
+                    {
+                        Id = "chara_file_save_progress",
+                        Title = "Character Data",
+                        Message = $"Compressing and saving character file... {(progress * 100):F0}%\nETA: {FormatTimespan(eta)}",
+                        Type = NotificationType.Info,
+                        Duration = TimeSpan.FromMinutes(5),
+                        ShowProgress = true,
+                        Progress = progress
+                    };
+
+                    _notificationService.Mediator.Publish(new LightlessNotificationMessage(notification));
+
+                    fileWriteStopwatch.Restart();
                 }
             }
+
+            var flushStopwatch = System.Diagnostics.Stopwatch.StartNew();
             writer.Flush();
-            await lz4.FlushAsync().ConfigureAwait(false);
+            lz4.Flush();
-            await fs.FlushAsync().ConfigureAwait(false);
+            fs.Flush();
             fs.Close();
+            flushStopwatch.Stop();
+            _logger.LogInformation("Flush operations took {elapsed}ms", flushStopwatch.ElapsedMilliseconds);
+
+            var moveStopwatch = System.Diagnostics.Stopwatch.StartNew();
             File.Move(tempFilePath, filePath, true);
+            moveStopwatch.Stop();
+            _logger.LogInformation("File move took {elapsed}ms", moveStopwatch.ElapsedMilliseconds);
+
+            overallStopwatch.Stop();
+            _logger.LogInformation("SaveCharaFileAsync completed successfully in {elapsed}ms. Total bytes written: {totalBytes}mb", overallStopwatch.ElapsedMilliseconds, totalBytesWritten / (1024 * 1024));
+
+            _notificationService.ShowNotification(
+                "Character Data",
+                "Character file saved successfully!",
+                NotificationType.Info,
+                duration: TimeSpan.FromSeconds(5));
+
+            _notificationService.Mediator.Publish(new LightlessNotificationDismissMessage("chara_file_save_progress"));
         }
         catch (Exception ex)
         {
-            _logger.LogError(ex, "Failure Saving Lightless Chara File, deleting output");
+            overallStopwatch.Stop();
-            File.Delete(tempFilePath);
+            _logger.LogError(ex, "Failure Saving Lightless Chara File after {elapsed}ms, deleting output", overallStopwatch.ElapsedMilliseconds);
+            try
+            {
+                File.Delete(tempFilePath);
+            }
+            catch (Exception deleteEx)
+            {
+                _logger.LogError(deleteEx, "Failed to delete temporary file {file}", tempFilePath);
+            }
+
+            _notificationService.ShowErrorNotification(
+                "Character Data Save Failed",
+                "Failed to save character file",
+                ex);
+
+            _notificationService.Mediator.Publish(new LightlessNotificationDismissMessage("chara_file_save_progress"));
         }
     }
 
+    private static TimeSpan CalculateEta(TimeSpan elapsed, float progress)
+    {
+        if (progress <= 0 || elapsed.TotalSeconds < 0.1)
+            return TimeSpan.Zero;
+
+        double totalSeconds = elapsed.TotalSeconds / progress;
+        double remainingSeconds = totalSeconds - elapsed.TotalSeconds;
+
+        return TimeSpan.FromSeconds(Math.Max(0, remainingSeconds));
+    }
+
+    private static string FormatTimespan(TimeSpan ts)
+    {
+        if (ts.TotalSeconds < 1)
+            return "< 1s";
+
+        if (ts.TotalSeconds < 60)
+            return $"{ts.TotalSeconds:F0}s";
+
+        if (ts.TotalMinutes < 60)
+            return $"{ts.TotalMinutes:F1}m";
+
+        return $"{ts.TotalHours:F1}h";
+    }
+
     internal async Task<List<string>> UploadFiles(List<string> fileList, ValueProgress<string> uploadProgress, CancellationToken token)
     {
         return await _fileUploadManager.UploadFiles(fileList, uploadProgress, token).ConfigureAwait(false);