LightlessSync/Services/CharaData/CharaDataFileHandler.cs

@@ -1,4 +1,4 @@
-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;
@@ -185,7 +185,7 @@ public sealed class CharaDataFileHandler : IDisposable
     {
         if (charaFileHeader == null) return [];
 
-        using var lz4Stream = new LZ4Stream(File.OpenRead(charaFileHeader.FilePath), LZ4StreamMode.Decompress, LZ4StreamFlags.HighCompression);
+        using var lz4Stream = new LZ4Stream(File.OpenRead(charaFileHeader.FilePath), LZ4StreamMode.Decompress, LZ4StreamFlags.Default);
         using var reader = new BinaryReader(lz4Stream);
         LightlessCharaFileHeader.AdvanceReaderToData(reader);
 
@@ -248,51 +248,93 @@ 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;
+
             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);
             }
+
+            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));
         }
         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);
+            }
         }
     }