Folder Watching Polish + Epub Fix (#1550)

* Fixed entrypoint writing bad json (from develop)

* Fixed a bug where log file could write out a crap ton of information (serializing Series object) when a db error occurs.

* Fixed an issue with scan loop where concurrency issues could occur on new series being added.

* Tweaked the logger to suppress some noisy logs when using Debug log level.

* Fixed a regression with epub parsing from v3.2 of Vers-One's release

* Fixed up folder watching to work more reliable. Validated in production.

* Code cleanup

API.Benchmark/CleanTitleBenchmark.cs

@@ -8,15 +8,15 @@ using BenchmarkDotNet.Order;
 namespace API.Benchmark;
 
 [MemoryDiagnoser]
-public class CleanTitleBenchmarks
+public static class CleanTitleBenchmarks
 {
     private static IList<string> _names;
 
     [GlobalSetup]
-    public void LoadData() => _names = File.ReadAllLines("Data/Comics.txt");
+    public static void LoadData() => _names = File.ReadAllLines("Data/Comics.txt");
 
     [Benchmark]
-    public void TestCleanTitle()
+    public static void TestCleanTitle()
     {
         foreach (var name in _names)
         {

API.Tests/Parser/MangaParserTests.cs

@@ -189,6 +189,7 @@ public class MangaParserTests
     [InlineData("Манга Глава 2", "Манга")]
     [InlineData("Манга Глава 2-2", "Манга")]
     [InlineData("Манга Том 1 3-4 Глава", "Манга")]
+    [InlineData("Esquire 6권 2021년 10월호", "Esquire")]
     public void ParseSeriesTest(string filename, string expected)
     {
         Assert.Equal(expected, API.Services.Tasks.Scanner.Parser.Parser.ParseSeries(filename));

API/API.csproj

@@ -72,9 +72,11 @@
     <PackageReference Include="Microsoft.IO.RecyclableMemoryStream" Version="2.2.1" />
     <PackageReference Include="NetVips" Version="2.2.0" />
     <PackageReference Include="NetVips.Native" Version="8.13.1" />
+    <PackageReference Include="Ng.UserAgentService" Version="1.1.0" />
     <PackageReference Include="NReco.Logging.File" Version="1.1.5" />
     <PackageReference Include="Serilog" Version="2.12.0" />
     <PackageReference Include="Serilog.AspNetCore" Version="6.0.1" />
+    <PackageReference Include="Serilog.Enrichers.Thread" Version="3.2.0-dev-00752" />
     <PackageReference Include="Serilog.Extensions.Hosting" Version="5.0.1" />
     <PackageReference Include="Serilog.Settings.Configuration" Version="3.4.0" />
     <PackageReference Include="Serilog.Sinks.AspNetCore.SignalR" Version="0.4.0" />
@@ -83,15 +85,15 @@
     <PackageReference Include="Serilog.Sinks.SignalR.Core" Version="0.1.2" />
     <PackageReference Include="SharpCompress" Version="0.32.2" />
     <PackageReference Include="SixLabors.ImageSharp" Version="2.1.3" />
-    <PackageReference Include="SonarAnalyzer.CSharp" Version="8.44.0.52574">
+    <PackageReference Include="SonarAnalyzer.CSharp" Version="8.45.0.54064">
       <PrivateAssets>all</PrivateAssets>
       <IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
     </PackageReference>
     <PackageReference Include="Swashbuckle.AspNetCore" Version="6.4.0" />
     <PackageReference Include="System.Drawing.Common" Version="6.0.0" />
     <PackageReference Include="System.IdentityModel.Tokens.Jwt" Version="6.23.1" />
-    <PackageReference Include="System.IO.Abstractions" Version="17.2.1" />
+    <PackageReference Include="System.IO.Abstractions" Version="17.2.3" />
-    <PackageReference Include="VersOne.Epub" Version="3.2.0" />
+    <PackageReference Include="VersOne.Epub" Version="3.3.0-alpha1" />
   </ItemGroup>
 
   <ItemGroup>

API/DTOs/Filtering/FilterDto.cs

@@ -99,8 +99,10 @@ public class FilterDto
     /// An optional name string to filter by. Empty string will ignore.
     /// </summary>
     public string SeriesNameQuery { get; init; } = string.Empty;
+    #nullable enable
     /// <summary>
     /// An optional release year to filter by. Null will ignore. You can pass 0 for an individual field to ignore it.
     /// </summary>
     public Range<int>? ReleaseYearRange { get; init; } = null;
+    #nullable disable
 }

API/Data/Repositories/SeriesRepository.cs

@@ -56,6 +56,7 @@ internal class RecentlyAddedSeries
 
 public interface ISeriesRepository
 {
+    void Add(Series series);
     void Attach(Series series);
     void Update(Series series);
     void Remove(Series series);
@@ -136,6 +137,11 @@ public class SeriesRepository : ISeriesRepository
         _mapper = mapper;
     }
 
+    public void Add(Series series)
+    {
+        _context.Series.Add(series);
+    }
+
     public void Attach(Series series)
     {
         _context.Series.Attach(series);

API/Extensions/ApplicationServiceExtensions.cs

@@ -59,12 +59,11 @@ public static class ApplicationServiceExtensions
         services.AddScoped<IPresenceTracker, PresenceTracker>();
         services.AddScoped<IEventHub, EventHub>();
 
-        services.AddSqLite(config, env);
+        services.AddSqLite(env);
         services.AddSignalR(opt => opt.EnableDetailedErrors = true);
     }
 
-    private static void AddSqLite(this IServiceCollection services, IConfiguration config,
+    private static void AddSqLite(this IServiceCollection services, IHostEnvironment env)
-        IHostEnvironment env)
     {
         services.AddDbContext<DataContext>(options =>
         {

API/Logging/LogLevelOptions.cs

@@ -46,12 +46,16 @@ public static class LogLevelOptions
             .MinimumLevel.Override("Microsoft.Hosting.Lifetime", MicrosoftHostingLifetimeLogLevelSwitch)
             .MinimumLevel.Override("Hangfire", HangfireLogLevelSwitch)
             .MinimumLevel.Override("Microsoft.AspNetCore.Hosting.Internal.WebHost", AspNetCoreLogLevelSwitch)
+            // Suppress noisy loggers that add no value
+            .MinimumLevel.Override("Microsoft.AspNetCore.ResponseCaching.ResponseCachingMiddleware", LogEventLevel.Error)
+            .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Error)
             .Enrich.FromLogContext()
+            .Enrich.WithThreadId()
             .WriteTo.Console()
             .WriteTo.File(LogFile,
                 shared: true,
                 rollingInterval: RollingInterval.Day,
-                outputTemplate: "[{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} {CorrelationId}] [{Level}] {Message:lj}{NewLine}{Exception}");
+                outputTemplate: "[{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} {CorrelationId} {ThreadId}] [{Level}] {SourceContext} {Message:lj}{NewLine}{Exception}");
     }
 
     public static void SwitchLogLevel(string level)
@@ -60,9 +64,9 @@ public static class LogLevelOptions
         {
             case "Debug":
                 LogLevelSwitch.MinimumLevel = LogEventLevel.Debug;
-                MicrosoftLogLevelSwitch.MinimumLevel = LogEventLevel.Information;
+                MicrosoftLogLevelSwitch.MinimumLevel = LogEventLevel.Warning; // This is DB output information, Inf shows the SQL
-                MicrosoftHostingLifetimeLogLevelSwitch.MinimumLevel = LogEventLevel.Debug;
+                MicrosoftHostingLifetimeLogLevelSwitch.MinimumLevel = LogEventLevel.Information;
-                AspNetCoreLogLevelSwitch.MinimumLevel = LogEventLevel.Debug;
+                AspNetCoreLogLevelSwitch.MinimumLevel = LogEventLevel.Warning;
                 break;
             case "Information":
                 LogLevelSwitch.MinimumLevel = LogEventLevel.Error;
@@ -74,7 +78,7 @@ public static class LogLevelOptions
                 LogLevelSwitch.MinimumLevel = LogEventLevel.Verbose;
                 MicrosoftLogLevelSwitch.MinimumLevel = LogEventLevel.Information;
                 MicrosoftHostingLifetimeLogLevelSwitch.MinimumLevel = LogEventLevel.Debug;
-                AspNetCoreLogLevelSwitch.MinimumLevel = LogEventLevel.Debug;
+                AspNetCoreLogLevelSwitch.MinimumLevel = LogEventLevel.Information;
                 break;
             case "Warning":
                 LogLevelSwitch.MinimumLevel = LogEventLevel.Warning;

API/Services/Tasks/Scanner/LibraryWatcher.cs

@@ -40,12 +40,11 @@ public class LibraryWatcher : ILibraryWatcher
     private readonly ILogger<LibraryWatcher> _logger;
     private readonly IScannerService _scannerService;
 
-    private readonly Dictionary<string, IList<FileSystemWatcher>> _watcherDictionary = new ();
+    private static readonly Dictionary<string, IList<FileSystemWatcher>> WatcherDictionary = new ();
     /// <summary>
     /// This is just here to prevent GC from Disposing our watchers
     /// </summary>
-    private readonly IList<FileSystemWatcher> _fileWatchers = new List<FileSystemWatcher>();
+    private static readonly IList<FileSystemWatcher> FileWatchers = new List<FileSystemWatcher>();
-    private IList<string> _libraryFolders = new List<string>();
     /// <summary>
     /// The amount of time until the Schedule ScanFolder task should be executed
     /// </summary>
@@ -68,13 +67,14 @@ public class LibraryWatcher : ILibraryWatcher
     {
         _logger.LogInformation("[LibraryWatcher] Starting file watchers");
 
-        _libraryFolders = (await _unitOfWork.LibraryRepository.GetLibraryDtosAsync())
+        var libraryFolders = (await _unitOfWork.LibraryRepository.GetLibraryDtosAsync())
             .SelectMany(l => l.Folders)
             .Distinct()
             .Select(Parser.Parser.NormalizePath)
             .Where(_directoryService.Exists)
             .ToList();
-        foreach (var libraryFolder in _libraryFolders)
+
+        foreach (var libraryFolder in libraryFolders)
         {
             _logger.LogDebug("[LibraryWatcher] Watching {FolderPath}", libraryFolder);
             var watcher = new FileSystemWatcher(libraryFolder);
@@ -87,21 +87,21 @@ public class LibraryWatcher : ILibraryWatcher
             watcher.Filter = "*.*";
             watcher.IncludeSubdirectories = true;
             watcher.EnableRaisingEvents = true;
-            _fileWatchers.Add(watcher);
+            FileWatchers.Add(watcher);
-            if (!_watcherDictionary.ContainsKey(libraryFolder))
+            if (!WatcherDictionary.ContainsKey(libraryFolder))
             {
-                _watcherDictionary.Add(libraryFolder, new List<FileSystemWatcher>());
+                WatcherDictionary.Add(libraryFolder, new List<FileSystemWatcher>());
             }
 
-            _watcherDictionary[libraryFolder].Add(watcher);
+            WatcherDictionary[libraryFolder].Add(watcher);
         }
-        _logger.LogInformation("[LibraryWatcher] Watching {Count} folders", _fileWatchers.Count);
+        _logger.LogInformation("[LibraryWatcher] Watching {Count} folders", FileWatchers.Count);
     }
 
     public void StopWatching()
     {
         _logger.LogInformation("[LibraryWatcher] Stopping watching folders");
-        foreach (var fileSystemWatcher in _watcherDictionary.Values.SelectMany(watcher => watcher))
+        foreach (var fileSystemWatcher in WatcherDictionary.Values.SelectMany(watcher => watcher))
         {
             fileSystemWatcher.EnableRaisingEvents = false;
             fileSystemWatcher.Changed -= OnChanged;
@@ -110,12 +110,13 @@ public class LibraryWatcher : ILibraryWatcher
             fileSystemWatcher.Error -= OnError;
             fileSystemWatcher.Dispose();
         }
-        _fileWatchers.Clear();
+        FileWatchers.Clear();
-        _watcherDictionary.Clear();
+        WatcherDictionary.Clear();
     }
 
     public async Task RestartWatching()
     {
+        _logger.LogDebug("[LibraryWatcher] Restarting watcher");
         StopWatching();
         await StartWatching();
     }
@@ -160,7 +161,7 @@ public class LibraryWatcher : ILibraryWatcher
     /// <remarks>This is public only because Hangfire will invoke it. Do not call external to this class.</remarks>
     /// <param name="filePath">File or folder that changed</param>
     /// <param name="isDirectoryChange">If the change is on a directory and not a file</param>
-    public void ProcessChange(string filePath, bool isDirectoryChange = false)
+    public async Task ProcessChange(string filePath, bool isDirectoryChange = false)
     {
         var sw = Stopwatch.StartNew();
         _logger.LogDebug("[LibraryWatcher] Processing change of {FilePath}", filePath);
@@ -174,26 +175,33 @@ public class LibraryWatcher : ILibraryWatcher
                 return;
             }
 
-            var fullPath = GetFolder(filePath, _libraryFolders);
+            var libraryFolders = (await _unitOfWork.LibraryRepository.GetLibraryDtosAsync())
+                .SelectMany(l => l.Folders)
+                .Distinct()
+                .Select(Parser.Parser.NormalizePath)
+                .Where(_directoryService.Exists)
+                .ToList();
+
+            var fullPath = GetFolder(filePath, libraryFolders);
+            _logger.LogDebug("Folder path: {FolderPath}", fullPath);
             if (string.IsNullOrEmpty(fullPath))
             {
                 _logger.LogDebug("[LibraryWatcher] Change from {FilePath} could not find root level folder, ignoring change", filePath);
                 return;
             }
 
-            // Check if this task has already enqueued or is being processed, before enquing
+            // Check if this task has already enqueued or is being processed, before enqueing
 
             var alreadyScheduled =
                 TaskScheduler.HasAlreadyEnqueuedTask(ScannerService.Name, "ScanFolder", new object[] {fullPath});
-            _logger.LogDebug("[LibraryWatcher] {FullPath} already enqueued: {Value}", fullPath, alreadyScheduled);
             if (!alreadyScheduled)
             {
-                _logger.LogDebug("[LibraryWatcher] Scheduling ScanFolder for {Folder}", fullPath);
+                _logger.LogInformation("[LibraryWatcher] Scheduling ScanFolder for {Folder}", fullPath);
                 BackgroundJob.Schedule(() => _scannerService.ScanFolder(fullPath), _queueWaitTime);
             }
             else
             {
-                _logger.LogDebug("[LibraryWatcher] Skipped scheduling ScanFolder for {Folder} as a job already queued",
+                _logger.LogInformation("[LibraryWatcher] Skipped scheduling ScanFolder for {Folder} as a job already queued",
                     fullPath);
             }
         }
@@ -207,18 +215,17 @@ public class LibraryWatcher : ILibraryWatcher
     private string GetFolder(string filePath, IList<string> libraryFolders)
     {
         var parentDirectory = _directoryService.GetParentDirectoryName(filePath);
-        if (string.IsNullOrEmpty(parentDirectory))
+        _logger.LogDebug("[LibraryWatcher] Parent Directory: {ParentDirectory}", parentDirectory);
-        {
-            return string.Empty;
-        }
         if (string.IsNullOrEmpty(parentDirectory)) return string.Empty;
 
         // We need to find the library this creation belongs to
         // Multiple libraries can point to the same base folder. In this case, we need use FirstOrDefault
         var libraryFolder = libraryFolders.FirstOrDefault(f => parentDirectory.Contains(f));
+        _logger.LogDebug("[LibraryWatcher] Library Folder: {LibraryFolder}", libraryFolder);
         if (string.IsNullOrEmpty(libraryFolder)) return string.Empty;
 
         var rootFolder = _directoryService.GetFoldersTillRoot(libraryFolder, filePath).ToList();
+        _logger.LogDebug("[LibraryWatcher] Root Folders: {RootFolders}", rootFolder);
         if (!rootFolder.Any()) return string.Empty;
 
         // Select the first folder and join with library folder, this should give us the folder to scan.

API/Services/Tasks/Scanner/ProcessSeries.cs

@@ -44,9 +44,9 @@ public class ProcessSeries : IProcessSeries
     private readonly IMetadataService _metadataService;
     private readonly IWordCountAnalyzerService _wordCountAnalyzerService;
 
-    private IList<Genre> _genres;
+    private volatile IList<Genre> _genres;
-    private IList<Person> _people;
+    private volatile IList<Person> _people;
-    private IList<Tag> _tags;
+    private volatile IList<Tag> _tags;
 
 
 
@@ -108,6 +108,7 @@ public class ProcessSeries : IProcessSeries
         {
             seriesAdded = true;
             series = DbFactory.Series(firstInfo.Series, firstInfo.LocalizedSeries);
+            _unitOfWork.SeriesRepository.Add(series);
         }
 
         if (series.LibraryId == 0) series.LibraryId = library.Id;
@@ -156,7 +157,6 @@ public class ProcessSeries : IProcessSeries
             await UpdateSeriesFolderPath(parsedInfos, library, series);
 
             series.LastFolderScanned = DateTime.Now;
-            _unitOfWork.SeriesRepository.Attach(series);
 
             if (_unitOfWork.HasChanges())
             {
@@ -167,7 +167,7 @@ public class ProcessSeries : IProcessSeries
                 catch (Exception ex)
                 {
                     await _unitOfWork.RollbackAsync();
-                    _logger.LogCritical(ex, "[ScannerService] There was an issue writing to the for series {@SeriesName}", series);
+                    _logger.LogCritical(ex, "[ScannerService] There was an issue writing to the database for series {@SeriesName}", series.Name);
 
                     await _eventHub.SendMessageAsync(MessageFactory.Error,
                         MessageFactory.ErrorEvent($"There was an issue writing to the DB for Series {series}",

API/Startup.cs

@@ -268,7 +268,10 @@ public class Startup
         });
 
         app.UseSerilogRequestLogging(opts
-            => opts.EnrichDiagnosticContext = LogEnricher.EnrichFromRequest);
+            =>
+        {
+            opts.EnrichDiagnosticContext = LogEnricher.EnrichFromRequest;
+        });
 
         app.Use(async (context, next) =>
         {

entrypoint.sh

@@ -4,7 +4,6 @@ if [ ! -f "/kavita/config/appsettings.json" ]; then
     echo "Kavita configuration file does not exist, creating..."
     echo '{
   "TokenKey": "super secret unguessable key",
-  },
   "Port": 5000
 }' >> /kavita/config/appsettings.json
 fi