Open iskarian opened 7 years ago
The title parser has trouble with titles that are formatted oddly. The brackets in beginning of the title throw it off. If the parser can't figure out the title for the movie it can't add it to the library.
I'll fix the mtime call in a commit soon.
On Sun, Aug 20, 2017 at 4:13 AM, iskarian notifications@github.com wrote:
If a postprocessing scan fails (encounters an exception), Watcher does not log the cause, although at least part of it may show up as a notification in the web interface. Additionally, Watcher seems to never consider the scan finished and so does not start any subsequent scheduled scans.
This is easy to test, as in the current build it seems any postprocessing scan with the 'new files only' option on will fail. The cause: https://github.com/nosmokingbandit/Watcher3/blob/ c75c8af9215feab1b17dcdd3aaa02b2a893e90ee/core/scheduler.py#L78 It looks like os.path.join(d, i).getmtime() should be os.path.getmtime(os.path.join(d, i)).
I also encountered a silent failure when it parsed the title as empty (''), although I'm not sure if it would have impacted other postprocessing occurring on the same scan:
INFO 2017-08-20 00:44:45,408 core.cp_plugins.taskscheduler._task: == Executing Scheduled Task: PostProcessing Scan == INFO 2017-08-20 00:44:45,409 core.scheduler.scan_directory: Scanning /storage/downloads/auto-import-movies for movies to process. INFO 2017-08-20 00:44:45,409 core.scheduler.scan_directory: Scanning for new files only (last scan: /storage/downloads/auto-import-movies). INFO 2017-08-20 00:44:45,409 core.scheduler.scan_directory: Processing /storage/downloads/auto-import-movies/[Nii-sama] Koe no Katachi [1080p].mkv. DEBUG 2017-08-20 00:44:45,409 core.sqldb.get_single_search_result: Retrieving search result details for [Nii-sama] Koe no Katachi [1080p].mkv. DEBUG 2017-08-20 00:44:45,409 core.sqldb.execute: Executing SQL command: ['SELECT FROM SEARCHRESULTS WHERE title="[Nii-sama] Koe no Katachi [1080p].mkv" ORDER BY score DESC, size DESC'] INFO 2017-08-20 00:44:45,410 core.scheduler.scan_directory: Unable to find match in database for [Nii-sama] Koe no Katachi [1080p].mkv, release cannot be marked as Finished. INFO 2017-08-20 00:44:45,410 core.postprocessing.POST: ################################# INFO 2017-08-20 00:44:45,410 core.postprocessing.POST: Post-processing request received. INFO 2017-08-20 00:44:45,410 core.postprocessing.POST: ################################# DEBUG 2017-08-20 00:44:45,410 core.postprocessing.POST: {'downloadid': '', 'mode': 'complete', 'apikey': 'fdf2e6c8e5810dca3544b6a0b717807a', 'guid': 'POSTPROCESSING5B4E69692D73616D', 'path': '/storage/downloads/auto-import-movies/[Nii-sama] Koe no Katachi [1080p].mkv'} INFO 2017-08-20 00:44:45,410 core.postprocessing.get_movie_file: Finding movie file. INFO 2017-08-20 00:44:45,410 core.postprocessing.get_movie_file: Post-processing file /storage/downloads/auto-import-movies/[Nii-sama] Koe no Katachi [1080p].mkv. INFO 2017-08-20 00:44:45,410 core.postprocessing.POST: Gathering release information. INFO 2017-08-20 00:44:45,410 core.postprocessing.get_movie_info: Searching local database for guid. DEBUG 2017-08-20 00:44:45,410 core.sqldb.get_single_search_result: Retrieving search result details for POSTPROCESSING5B4E69692D73616D. DEBUG 2017-08-20 00:44:45,410 core.sqldb.execute: Executing SQL command: ['SELECT FROM SEARCHRESULTS WHERE guid="POSTPROCESSING5B4E69692D73616D" ORDER BY score DESC, size DESC'] INFO 2017-08-20 00:44:45,411 core.postprocessing.get_movie_info: Unable to find local release info by guid. INFO 2017-08-20 00:44:45,411 core.postprocessing.get_movie_info: Guid not found. INFO 2017-08-20 00:44:45,411 core.postprocessing.get_movie_info: Searching local database for release name [Nii-sama] Koe no Katachi [1080p].mkv DEBUG 2017-08-20 00:44:45,411 core.sqldb.get_single_search_result: Retrieving search result details for [Nii-sama] Koe no Katachi [1080p].mkv. DEBUG 2017-08-20 00:44:45,411 core.sqldb.execute: Executing SQL command: ['SELECT * FROM SEARCHRESULTS WHERE title="[Nii-sama] Koe no Katachi [1080p].mkv" ORDER BY score DESC, size DESC'] INFO 2017-08-20 00:44:45,411 core.postprocessing.get_movie_info: Unable to find local release info by release name. INFO 2017-08-20 00:44:45,412 core.postprocessing.get_movie_info: Unable to find local data for release. Using only data found from file. INFO 2017-08-20 00:44:45,412 core.library.from_file: Gathering metadata for /storage/downloads/auto-import-movies/[Nii-sama] Koe no Katachi [1080p].mkv. INFO 2017-08-20 00:44:45,412 core.library.parse_filename: Parsing filename for movie information: /storage/downloads/auto-import-movies/[Nii-sama] Koe no Katachi [1080p].mkv. INFO 2017-08-20 00:44:45,416 core.library.parse_filename: Found {'resolution': '1080p', 'container': 'mkv', 'title': '', 'release_name': '[Nii-sama] Koe no Katachi [1080p].mkv'} in filename. INFO 2017-08-20 00:44:45,416 core.library.parse_media: Parsing codec data from file /storage/downloads/auto-import-movies/[Nii-sama] Koe no Katachi [1080p].mkv. INFO 2017-08-20 00:44:45,474 core.postprocessing.POST: Post-processing as Complete. INFO 2017-08-20 00:44:45,474 core.postprocessing.complete: Marking guid as Finished. INFO 2017-08-20 00:44:45,474 core.postprocessing.complete: Imdbid not supplied or found, unable to update Movie status. INFO 2017-08-20 00:44:45,474 core.library.convert_to_db: Converting movie metadata to database structure for .
The movie did not appear to be moved or the library affected in any way after this.
— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/nosmokingbandit/Watcher3/issues/119, or mute the thread https://github.com/notifications/unsubscribe-auth/AKX1SQ8lLMXlI2mfbsk_4tP6h19ejX0vks5sZ-q3gaJpZM4O8jNe .
Watcher now seems to be logging the errors correctly. However, in a postprocessing scan, if there are multiple files to process and it fails on the first one, the crash causes it to not attempt processing the rest.
INFO 2017-08-29 20:27:26,752 CPTaskScheduler._task: == Executing Scheduled Task: PostProcessing Scan ==
INFO 2017-08-29 20:27:26,752 core.scheduler.scan_directory: Scanning /storage/downloads/auto-import-movies for movies to process.
INFO 2017-08-29 20:27:26,752 core.scheduler.scan_directory: Scanning for new files only (last scan: /storage/downloads/auto-import-movies).
INFO 2017-08-29 20:27:26,752 core.scheduler.scan_directory: Processing /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson.
DEBUG 2017-08-29 20:27:26,752 core.sqldb.get_single_search_result: Retrieving search result details for Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson.
DEBUG 2017-08-29 20:27:26,752 core.sqldb.execute: Executing SQL command: ['SELECT * FROM SEARCHRESULTS WHERE title="Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson" ORDER BY score DESC, size DESC']
INFO 2017-08-29 20:27:26,753 core.scheduler.scan_directory: Unable to find match in database for Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson, release cannot be marked as Finished.
INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: #################################
INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: Post-processing request received.
INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: #################################
DEBUG 2017-08-29 20:27:26,753 core.postprocessing.POST: {'downloadid': '', 'mode': 'complete', 'apikey': 'fdf2e6c8e5810dca3544b6a0b717807a', 'path': '/storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson', 'guid': 'POSTPROCESSING48617272792E506F'}
INFO 2017-08-29 20:27:26,753 core.postprocessing.get_movie_file: Finding movie file.
INFO 2017-08-29 20:27:26,753 core.postprocessing.get_movie_file: Post-processing file /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv.
INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: Gathering release information.
INFO 2017-08-29 20:27:26,753 core.postprocessing.get_movie_info: Searching local database for guid.
DEBUG 2017-08-29 20:27:26,754 core.sqldb.get_single_search_result: Retrieving search result details for POSTPROCESSING48617272792E506F.
DEBUG 2017-08-29 20:27:26,754 core.sqldb.execute: Executing SQL command: ['SELECT * FROM SEARCHRESULTS WHERE guid="POSTPROCESSING48617272792E506F" ORDER BY score DESC, size DESC']
INFO 2017-08-29 20:27:26,754 core.postprocessing.get_movie_info: Unable to find local release info by guid.
INFO 2017-08-29 20:27:26,754 core.postprocessing.get_movie_info: Guid not found.
INFO 2017-08-29 20:27:26,754 core.postprocessing.get_movie_info: Searching local database for release name Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson
DEBUG 2017-08-29 20:27:26,754 core.sqldb.get_single_search_result: Retrieving search result details for Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson.
DEBUG 2017-08-29 20:27:26,754 core.sqldb.execute: Executing SQL command: ['SELECT * FROM SEARCHRESULTS WHERE title="Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson" ORDER BY score DESC, size DESC']
INFO 2017-08-29 20:27:26,755 core.postprocessing.get_movie_info: Unable to find local release info by release name.
INFO 2017-08-29 20:27:26,755 core.postprocessing.get_movie_info: Unable to find local data for release. Using only data found from file.
INFO 2017-08-29 20:27:26,755 core.library.from_file: Gathering metadata for /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv.
INFO 2017-08-29 20:27:26,755 core.library.parse_filename: Parsing filename for movie information: /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv.
INFO 2017-08-29 20:27:26,755 core.library.parse_filename: Found {'release_name': 'japhson-hp7-720p.mkv', 'resolution': '720p', 'container': 'mkv', 'title': 'japhson-hp7', 'group': '720p.mkv'} in filename.
INFO 2017-08-29 20:27:26,755 core.library.parse_media: Parsing codec data from file /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv.
INFO 2017-08-29 20:27:26,774 core.movieinfo.search: Searching TheMovieDB for japhson-hp7
INFO 2017-08-29 20:27:26,775 core.movieinfo._search_title: Searching TheMovieDB for title: japhson-hp7.
INFO 2017-08-29 20:27:26,775 core.movieinfo._search_title: Searching TMDB https://api.themoviedb.org/3/search/movie?page=1&include_adult=false&query=japhson hp7
INFO 2017-08-29 20:27:27,149 core.movieinfo.search: Nothing found on TheMovieDatabase for japhson-hp7
WARNING 2017-08-29 20:27:27,149 core.library.from_file: Unable to get data from TheMovieDB for None
INFO 2017-08-29 20:27:27,150 core.postprocessing.POST: Post-processing as Complete.
INFO 2017-08-29 20:27:27,150 core.postprocessing.complete: Marking guid as Finished.
INFO 2017-08-29 20:27:27,150 core.postprocessing.complete: Imdbid not supplied or found, unable to update Movie status.
INFO 2017-08-29 20:27:27,150 core.library.convert_to_db: Converting movie metadata to database structure for japhson-hp7.
WARNING 2017-08-29 20:27:27,150 CPTaskScheduler._task: Scheduled Task PostProcessing Scan Failed:
Traceback (most recent call last):
File "/var/lib/watcher/core/cp_plugins/taskscheduler.py", line 209, in _task
self.task()
File "/var/lib/watcher/core/scheduler.py", line 107, in scan_directory
pp.POST(**d)
File "/var/lib/watcher/core/postprocessing.py", line 84, in POST
response = self.complete(data)
File "/var/lib/watcher/core/postprocessing.py", line 417, in complete
data.update(self.metadata.convert_to_db(data))
File "/var/lib/watcher/core/library.py", line 601, in convert_to_db
movie['score'] = movie['vote_average'] if not movie.get('score') else movie.get('score')
KeyError: 'vote_average'
INFO 2017-08-29 20:27:27,150 CPTaskScheduler._task: == Finished Scheduled Task: PostProcessing Scan ==
a228bd50b1f254b7c3730277b0d94dac1e9c2262 will fix the exception, but that movie isn't going to import correctly without being renamed.
INFO 2017-08-29 20:27:26,755 core.library.parse_filename: Found
{'release_name': 'japhson-hp7-720p.mkv', 'resolution': '720p',
'container': 'mkv', 'title': 'japhson-hp7', 'group': '720p.mkv'} in
filename.
On Tue, Aug 29, 2017 at 11:31 PM, iskarian notifications@github.com wrote:
Watcher now seems to be logging the errors correctly. However, in a postprocessing scan, if there are multiple files to process and it fails on the first one, the crash causes it to not attempt processing the rest.
INFO 2017-08-29 20:27:26,752 CPTaskScheduler._task: == Executing Scheduled Task: PostProcessing Scan == INFO 2017-08-29 20:27:26,752 core.scheduler.scan_directory: Scanning /storage/downloads/auto-import-movies for movies to process. INFO 2017-08-29 20:27:26,752 core.scheduler.scan_directory: Scanning for new files only (last scan: /storage/downloads/auto-import-movies). INFO 2017-08-29 20:27:26,752 core.scheduler.scan_directory: Processing /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson. DEBUG 2017-08-29 20:27:26,752 core.sqldb.get_single_search_result: Retrieving search result details for Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson. DEBUG 2017-08-29 20:27:26,752 core.sqldb.execute: Executing SQL command: ['SELECT FROM SEARCHRESULTS WHERE title="Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson" ORDER BY score DESC, size DESC'] INFO 2017-08-29 20:27:26,753 core.scheduler.scan_directory: Unable to find match in database for Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson, release cannot be marked as Finished. INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: ################################# INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: Post-processing request received. INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: ################################# DEBUG 2017-08-29 20:27:26,753 core.postprocessing.POST: {'downloadid': '', 'mode': 'complete', 'apikey': 'fdf2e6c8e5810dca3544b6a0b717807a', 'path': '/storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson', 'guid': 'POSTPROCESSING48617272792E506F'} INFO 2017-08-29 20:27:26,753 core.postprocessing.get_movie_file: Finding movie file. INFO 2017-08-29 20:27:26,753 core.postprocessing.get_movie_file: Post-processing file /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv. INFO 2017-08-29 20:27:26,753 core.postprocessing.POST: Gathering release information. INFO 2017-08-29 20:27:26,753 core.postprocessing.get_movie_info: Searching local database for guid. DEBUG 2017-08-29 20:27:26,754 core.sqldb.get_single_search_result: Retrieving search result details for POSTPROCESSING48617272792E506F. DEBUG 2017-08-29 20:27:26,754 core.sqldb.execute: Executing SQL command: ['SELECT FROM SEARCHRESULTS WHERE guid="POSTPROCESSING48617272792E506F" ORDER BY score DESC, size DESC'] INFO 2017-08-29 20:27:26,754 core.postprocessing.get_movie_info: Unable to find local release info by guid. INFO 2017-08-29 20:27:26,754 core.postprocessing.get_movie_info: Guid not found. INFO 2017-08-29 20:27:26,754 core.postprocessing.get_movie_info: Searching local database for release name Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson DEBUG 2017-08-29 20:27:26,754 core.sqldb.get_single_search_result: Retrieving search result details for Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson. DEBUG 2017-08-29 20:27:26,754 core.sqldb.execute: Executing SQL command: ['SELECT * FROM SEARCHRESULTS WHERE title="Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson" ORDER BY score DESC, size DESC'] INFO 2017-08-29 20:27:26,755 core.postprocessing.get_movie_info: Unable to find local release info by release name. INFO 2017-08-29 20:27:26,755 core.postprocessing.get_movie_info: Unable to find local data for release. Using only data found from file. INFO 2017-08-29 20:27:26,755 core.library.from_file: Gathering metadata for /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv. INFO 2017-08-29 20:27:26,755 core.library.parse_filename: Parsing filename for movie information: /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv. INFO 2017-08-29 20:27:26,755 core.library.parse_filename: Found {'release_name': 'japhson-hp7-720p.mkv', 'resolution': '720p', 'container': 'mkv', 'title': 'japhson-hp7', 'group': '720p.mkv'} in filename. INFO 2017-08-29 20:27:26,755 core.library.parse_media: Parsing codec data from file /storage/downloads/auto-import-movies/Harry.Potter.And.The.Deathly.Hallows.Part.1.2010.PROPER.720p.BluRay.x264-Japhson/japhson-hp7-720p.mkv. INFO 2017-08-29 20:27:26,774 core.movieinfo.search: Searching TheMovieDB for japhson-hp7 INFO 2017-08-29 20:27:26,775 core.movieinfo._search_title: Searching TheMovieDB for title: japhson-hp7. INFO 2017-08-29 20:27:26,775 core.movieinfo._search_title: Searching TMDB https://api.themoviedb.org/3/search/movie?page=1&include_adult=false&query=japhson hp7 INFO 2017-08-29 20:27:27,149 core.movieinfo.search: Nothing found on TheMovieDatabase for japhson-hp7 WARNING 2017-08-29 20:27:27,149 core.library.from_file: Unable to get data from TheMovieDB for None INFO 2017-08-29 20:27:27,150 core.postprocessing.POST: Post-processing as Complete. INFO 2017-08-29 20:27:27,150 core.postprocessing.complete: Marking guid as Finished. INFO 2017-08-29 20:27:27,150 core.postprocessing.complete: Imdbid not supplied or found, unable to update Movie status. INFO 2017-08-29 20:27:27,150 core.library.convert_to_db: Converting movie metadata to database structure for japhson-hp7. WARNING 2017-08-29 20:27:27,150 CPTaskScheduler._task: Scheduled Task PostProcessing Scan Failed: Traceback (most recent call last): File "/var/lib/watcher/core/cp_plugins/taskscheduler.py", line 209, in _task self.task() File "/var/lib/watcher/core/scheduler.py", line 107, in scan_directory pp.POST(**d) File "/var/lib/watcher/core/postprocessing.py", line 84, in POST response = self.complete(data) File "/var/lib/watcher/core/postprocessing.py", line 417, in complete data.update(self.metadata.convert_to_db(data)) File "/var/lib/watcher/core/library.py", line 601, in convert_to_db movie['score'] = movie['vote_average'] if not movie.get('score') else movie.get('score') KeyError: 'vote_average' INFO 2017-08-29 20:27:27,150 CPTaskScheduler._task: == Finished Scheduled Task: PostProcessing Scan ==
— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/nosmokingbandit/Watcher3/issues/119#issuecomment-325869717, or mute the thread https://github.com/notifications/unsubscribe-auth/AKX1ST5DowcvF94Iu4Lrs96cg1Wk40eXks5sdNeJgaJpZM4O8jNe .
Yeah, it worked on renaming them. But it is rather annoying to have to figure out which ones didn't import because there was an issue with them and which didn't import because something else had an issue. Perhaps wrapping each processing attempt in the directory scan in a try/except would help if any other issues crop up later?
If a postprocessing scan fails (encounters an exception), Watcher does not log the cause, although at least part of it may show up as a notification in the web interface. Additionally, Watcher seems to never consider the scan finished and so does not start any subsequent scheduled scans.
This is easy to test, as in the current build it seems any postprocessing scan with the 'new files only' option on will fail. The cause: https://github.com/nosmokingbandit/Watcher3/blob/c75c8af9215feab1b17dcdd3aaa02b2a893e90ee/core/scheduler.py#L78 It looks like
os.path.join(d, i).getmtime()
should beos.path.getmtime(os.path.join(d, i))
.I also encountered a silent failure when it parsed the title as empty (
''
), although I'm not sure if it would have impacted other postprocessing occurring on the same scan:The movie did not appear to be moved or the library affected in any way after this.