From 1849ce4190723e28ff06310e4e25f6dd48be2b63 Mon Sep 17 00:00:00 2001 From: Qstick Date: Tue, 9 Jun 2020 00:06:31 -0400 Subject: [PATCH] Additional logging when trying to complete tracked downloads Co-Authored-By: Mark McDowall --- .../TrackedDownloadAlreadyImportedFixture.cs | 5 +++++ .../Download/CompletedDownloadService.cs | 9 ++++++++- .../TrackedDownloadAlreadyImported.cs | 14 ++++++++++++++ .../Specifications/AlreadyImportedSpecification.cs | 2 ++ 4 files changed, 29 insertions(+), 1 deletion(-) diff --git a/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs b/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs index ce9768219..cd97fe8ed 100644 --- a/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs +++ b/src/NzbDrone.Core.Test/Download/TrackedDownloads/TrackedDownloadAlreadyImportedFixture.cs @@ -2,6 +2,7 @@ using FizzWare.NBuilder; using FluentAssertions; using NUnit.Framework; +using NzbDrone.Core.Download; using NzbDrone.Core.Download.TrackedDownloads; using NzbDrone.Core.History; using NzbDrone.Core.Movies; @@ -26,8 +27,12 @@ public void Setup() .With(r => r.Movie = _movie) .Build(); + var downloadItem = Builder.CreateNew() + .Build(); + _trackedDownload = Builder.CreateNew() .With(t => t.RemoteMovie = remoteMovie) + .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 c549d21d4..98f9f5ff3 100644 --- a/src/NzbDrone.Core/Download/CompletedDownloadService.cs +++ b/src/NzbDrone.Core/Download/CompletedDownloadService.cs @@ -1,6 +1,7 @@ using System.Collections.Generic; using System.IO; using System.Linq; +using NLog; using NzbDrone.Common.EnvironmentInfo; using NzbDrone.Common.Extensions; using NzbDrone.Core.Download.TrackedDownloads; @@ -28,13 +29,15 @@ public class CompletedDownloadService : ICompletedDownloadService private readonly IParsingService _parsingService; private readonly IMovieService _movieService; private readonly ITrackedDownloadAlreadyImported _trackedDownloadAlreadyImported; + private readonly Logger _logger; public CompletedDownloadService(IEventAggregator eventAggregator, IHistoryService historyService, IDownloadedMovieImportService downloadedMovieImportService, IParsingService parsingService, IMovieService movieService, - ITrackedDownloadAlreadyImported trackedDownloadAlreadyImported) + ITrackedDownloadAlreadyImported trackedDownloadAlreadyImported, + Logger logger) { _eventAggregator = eventAggregator; _historyService = historyService; @@ -42,6 +45,7 @@ public CompletedDownloadService(IEventAggregator eventAggregator, _parsingService = parsingService; _movieService = movieService; _trackedDownloadAlreadyImported = trackedDownloadAlreadyImported; + _logger = logger; } public void Check(TrackedDownload trackedDownload) @@ -137,6 +141,7 @@ public bool VerifyImport(TrackedDownload trackedDownload, List imp if (allMoviesImported) { + _logger.Debug("All movies were imported for {0}", trackedDownload.DownloadItem.Title); trackedDownload.State = TrackedDownloadState.Imported; _eventAggregator.PublishEvent(new DownloadCompletedEvent(trackedDownload, trackedDownload.RemoteMovie.Movie.Id)); return true; @@ -155,12 +160,14 @@ public bool VerifyImport(TrackedDownload trackedDownload, List imp if (allMoviesImportedInHistory) { + _logger.Debug("All movies were imported in history for {0}", trackedDownload.DownloadItem.Title); trackedDownload.State = TrackedDownloadState.Imported; _eventAggregator.PublishEvent(new DownloadCompletedEvent(trackedDownload, trackedDownload.RemoteMovie.Movie.Id)); return true; } } + _logger.Debug("Not all movies 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 55e577b10..13eb50ec7 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 @@ public interface ITrackedDownloadAlreadyImported 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 movies for '{0}' have been imported", trackedDownload.DownloadItem.Title); + if (historyItems.Empty()) { + _logger.Trace("No history for {0}", trackedDownload.DownloadItem.Title); return false; } @@ -25,11 +36,14 @@ public bool IsImported(TrackedDownload trackedDownload, List histo if (lastHistoryItem == null) { + _logger.Trace("No history for movie: {0}", movie.ToString()); return false; } var allMoviesImportedInHistory = lastHistoryItem.EventType == MovieHistoryEventType.DownloadFolderImported; + _logger.Trace("Last event for movie: {0} is: {1}", movie, lastHistoryItem.EventType); + _logger.Trace("All movies for '{0}' have been imported: {1}", trackedDownload.DownloadItem.Title, allMoviesImportedInHistory); return allMoviesImportedInHistory; } } diff --git a/src/NzbDrone.Core/MediaFiles/MovieImport/Specifications/AlreadyImportedSpecification.cs b/src/NzbDrone.Core/MediaFiles/MovieImport/Specifications/AlreadyImportedSpecification.cs index 778f226e3..3472e41c2 100644 --- a/src/NzbDrone.Core/MediaFiles/MovieImport/Specifications/AlreadyImportedSpecification.cs +++ b/src/NzbDrone.Core/MediaFiles/MovieImport/Specifications/AlreadyImportedSpecification.cs @@ -44,12 +44,14 @@ public Decision IsSatisfiedBy(LocalMovie localMovie, DownloadClientItem download if (lastImported == null) { + _logger.Trace("Movie file has not been imported"); return Decision.Accept(); } // If the release was grabbed again after importing don't reject it if (lastGrabbed != null && lastGrabbed.Date.After(lastImported.Date)) { + _logger.Trace("Movie file was grabbed again after importing"); return Decision.Accept(); }