From e7628476f75c71f0a556f29fe7beef64eea56088 Mon Sep 17 00:00:00 2001 From: Mark McDowall Date: Sat, 30 May 2020 16:40:41 -0700 Subject: [PATCH] Additional logging when trying to complete tracked downloads (cherry picked from commit 2df6b5370067635fdc9196451e09e4c2e6427eac) --- .../TrackedDownloadAlreadyImportedFixture.cs | 4 ++++ .../Download/CompletedDownloadService.cs | 9 ++++++++- .../TrackedDownloadAlreadyImported.cs | 16 ++++++++++++++++ .../AlreadyImportedSpecification.cs | 2 ++ 4 files changed, 30 insertions(+), 1 deletion(-) diff --git a/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs b/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs index 72563fba0..4d759127d 100644 --- a/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs +++ b/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs @@ -3,6 +3,7 @@ using FizzWare.NBuilder; using FluentAssertions; using NUnit.Framework; using NzbDrone.Core.Books; +using NzbDrone.Core.Download; using NzbDrone.Core.Download.TrackedDownloads; using NzbDrone.Core.History; using NzbDrone.Core.Parser.Model; @@ -26,8 +27,11 @@ namespace NzbDrone.Core.Test.Download.TrackedDownloads .With(r => r.Books = _books) .Build(); + var downloadItem = Builder.CreateNew().Build(); + _trackedDownload = Builder.CreateNew() .With(t => t.RemoteBook = remoteBook) + .With(t => t.DownloadItem = downloadItem) .Build(); _historyItems = new List(); diff --git a/src/NzbDrone.Core/Download/CompletedDownloadService.cs b/src/NzbDrone.Core/Download/CompletedDownloadService.cs index c0d0c92bb..e073aec6d 100644 --- a/src/NzbDrone.Core/Download/CompletedDownloadService.cs +++ b/src/NzbDrone.Core/Download/CompletedDownloadService.cs @@ -2,6 +2,7 @@ using System; using System.Collections.Generic; using System.IO; using System.Linq; +using NLog; using NzbDrone.Common.EnvironmentInfo; using NzbDrone.Common.Extensions; using NzbDrone.Core.Books; @@ -29,13 +30,15 @@ namespace NzbDrone.Core.Download private readonly IAuthorService _authorService; private readonly IProvideImportItemService _importItemService; private readonly ITrackedDownloadAlreadyImported _trackedDownloadAlreadyImported; + private readonly Logger _logger; public CompletedDownloadService(IEventAggregator eventAggregator, IHistoryService historyService, IProvideImportItemService importItemService, IDownloadedBooksImportService downloadedTracksImportService, IAuthorService authorService, - ITrackedDownloadAlreadyImported trackedDownloadAlreadyImported) + ITrackedDownloadAlreadyImported trackedDownloadAlreadyImported, + Logger logger) { _eventAggregator = eventAggregator; _historyService = historyService; @@ -43,6 +46,7 @@ namespace NzbDrone.Core.Download _downloadedTracksImportService = downloadedTracksImportService; _authorService = authorService; _trackedDownloadAlreadyImported = trackedDownloadAlreadyImported; + _logger = logger; } public void Check(TrackedDownload trackedDownload) @@ -129,6 +133,7 @@ namespace NzbDrone.Core.Download if (allItemsImported) { + _logger.Debug("All books were imported for {0}", trackedDownload.DownloadItem.Title); trackedDownload.State = TrackedDownloadState.Imported; var importedAuthorId = importResults.Where(x => x.Result == ImportResultType.Imported) @@ -156,6 +161,7 @@ namespace NzbDrone.Core.Download if (allEpisodesImportedInHistory) { + _logger.Debug("All books were imported in history for {0}", trackedDownload.DownloadItem.Title); trackedDownload.State = TrackedDownloadState.Imported; var importedAuthorId = historyItems.Where(x => x.EventType == EntityHistoryEventType.BookFileImported) @@ -166,6 +172,7 @@ namespace NzbDrone.Core.Download } } + _logger.Debug("Not all books have been imported for {0}", trackedDownload.DownloadItem.Title); return false; } } diff --git a/src/NzbDrone.Core/Download/TrackedDownloads/TrackedDownloadAlreadyImported.cs b/src/NzbDrone.Core/Download/TrackedDownloads/TrackedDownloadAlreadyImported.cs index 10108325b..c91042891 100644 --- a/src/NzbDrone.Core/Download/TrackedDownloads/TrackedDownloadAlreadyImported.cs +++ b/src/NzbDrone.Core/Download/TrackedDownloads/TrackedDownloadAlreadyImported.cs @@ -1,5 +1,6 @@ using System.Collections.Generic; using System.Linq; +using NLog; using NzbDrone.Common.Extensions; using NzbDrone.Core.History; @@ -12,10 +13,20 @@ namespace NzbDrone.Core.Download.TrackedDownloads public class TrackedDownloadAlreadyImported : ITrackedDownloadAlreadyImported { + private readonly Logger _logger; + + public TrackedDownloadAlreadyImported(Logger logger) + { + _logger = logger; + } + public bool IsImported(TrackedDownload trackedDownload, List historyItems) { + _logger.Trace("Checking if all books for '{0}' have been imported", trackedDownload.DownloadItem.Title); + if (historyItems.Empty()) { + _logger.Trace("No history for {0}", trackedDownload.DownloadItem.Title); return false; } @@ -30,12 +41,17 @@ namespace NzbDrone.Core.Download.TrackedDownloads if (lastHistoryItem == null) { + _logger.Trace($"No history for book: {book}"); return false; } + _logger.Trace($"Last event for book: {book} is: {lastHistoryItem.EventType}"); + return lastHistoryItem.EventType == EntityHistoryEventType.BookFileImported; }); + _logger.Trace("All books for '{0}' have been imported: {1}", trackedDownload.DownloadItem.Title, allBooksImportedInHistory); + return allBooksImportedInHistory; } } diff --git a/src/NzbDrone.Core/MediaFiles/BookImport/Specifications/AlreadyImportedSpecification.cs b/src/NzbDrone.Core/MediaFiles/BookImport/Specifications/AlreadyImportedSpecification.cs index 71a59a1fe..ab3050db6 100644 --- a/src/NzbDrone.Core/MediaFiles/BookImport/Specifications/AlreadyImportedSpecification.cs +++ b/src/NzbDrone.Core/MediaFiles/BookImport/Specifications/AlreadyImportedSpecification.cs @@ -44,11 +44,13 @@ namespace NzbDrone.Core.MediaFiles.BookImport.Specifications if (lastImported == null) { + _logger.Trace("Book file has not been imported"); return Decision.Accept(); } if (lastGrabbed != null && lastGrabbed.Date.After(lastImported.Date)) { + _logger.Trace("Book file was grabbed again after importing"); return Decision.Accept(); }