Make sure every scheduled job logs start and a stop

headphones/__init__.py

@@ -267,7 +267,8 @@ def initialize_scheduler():
         torrentfinished
 
     with SCHED_LOCK:
-        # Remove all jobs
+        # Remove all jobs first, because this method is also invoked when the
+        # settings are saved.
         count = len(SCHED.get_jobs())
 
         if count > 0:
@@ -301,7 +302,7 @@ def initialize_scheduler():
                               minutes=CONFIG.TORRENT_REMOVAL_INTERVAL))
 
         # Start scheduler
-        logger.info("(Re-)Scheduling background tasks")
+        logger.info("(Re-)Scheduled %d background tasks", len(SCHED.get_jobs()))
         SCHED.start()
 
 

headphones/librarysync.py

@@ -20,10 +20,10 @@ from beets.mediafile import MediaFile, FileTypeError, UnreadableFileError
 
 from headphones import db, logger, helpers, importer, lastfm
 
-# You can scan a single directory and append it to the current library by specifying append=True, ArtistID & ArtistName
-
-
-def libraryScan(dir=None, append=False, ArtistID=None, ArtistName=None, cron=False):
+# You can scan a single directory and append it to the current library by
+# specifying append=True, ArtistID and ArtistName.
+def libraryScan(dir=None, append=False, ArtistID=None, ArtistName=None,
+    cron=False):
 
     if cron and not headphones.CONFIG.LIBRARYSCAN:
         return
@@ -357,6 +357,7 @@ def libraryScan(dir=None, append=False, ArtistID=None, ArtistName=None, cron=Fal
     if not append:
         update_album_status()
         lastfm.getSimilar()
+
     logger.info('Library scan complete')
 
 #ADDED THIS SECTION TO MARK ALBUMS AS DOWNLOADED IF ARTISTS ARE ADDED EN MASSE BEFORE LIBRARY IS SCANNED

headphones/postprocessor.py

@@ -33,16 +33,14 @@ postprocessor_lock = threading.Lock()
 
 
 def checkFolder():
+    logger.info("Checking download folder for completed downloads")
 
     with postprocessor_lock:
-
         myDB = db.DBConnection()
         snatched = myDB.select('SELECT * from snatched WHERE Status="Snatched"')
 
         for album in snatched:
-
             if album['FolderName']:
-
                 if album['Kind'] == 'nzb':
                     download_dir = headphones.CONFIG.DOWNLOAD_DIR
                 else:
@@ -50,13 +48,14 @@ def checkFolder():
 
                 album_path = os.path.join(download_dir, album['FolderName']).encode(headphones.SYS_ENCODING, 'replace')
                 logger.info("Checking if %s exists" % album_path)
+
                 if os.path.exists(album_path):
                     logger.info('Found "' + album['FolderName'] + '" in ' + album['Kind'] + ' download folder. Verifying....')
                     verify(album['AlbumID'], album_path, album['Kind'])
-
             else:
                 logger.info("No folder name found for " + album['Title'])
 
+    logger.info("Checking download folder finished")
 
 def verify(albumid, albumpath, Kind=None, forced=False):
 

headphones/searcher.py

@@ -176,7 +176,10 @@ def get_seed_ratio(provider):
     return seed_ratio
 
 
-def searchforalbum(albumid=None, new=False, losslessOnly=False, choose_specific_download=False):
+def searchforalbum(albumid=None, new=False, losslessOnly=False,
+    choose_specific_download=False):
+
+    logger.info('Searching for wanted albums')
     myDB = db.DBConnection()
 
     if not albumid:
@@ -185,7 +188,7 @@ def searchforalbum(albumid=None, new=False, losslessOnly=False, choose_specific_
         for album in results:
 
             if not album['AlbumTitle'] or not album['ArtistName']:
-                logger.warn('Skipping release %s. No title available' % album['AlbumID'])
+                logger.warn('Skipping release %s. No title available', album['AlbumID'])
                 continue
 
             new = True
@@ -197,7 +200,6 @@ def searchforalbum(albumid=None, new=False, losslessOnly=False, choose_specific_
             do_sorted_search(album, new, losslessOnly)
 
     elif albumid and choose_specific_download:
-
         album = myDB.action('SELECT * from albums WHERE AlbumID=?', [albumid]).fetchone()
         logger.info('Searching for "%s - %s"' % (album['ArtistName'], album['AlbumTitle']))
         results = do_sorted_search(album, new, losslessOnly, choose_specific_download=True)
@@ -208,7 +210,7 @@ def searchforalbum(albumid=None, new=False, losslessOnly=False, choose_specific_
         logger.info('Searching for "%s - %s" since it was marked as wanted' % (album['ArtistName'], album['AlbumTitle']))
         do_sorted_search(album, new, losslessOnly)
 
-    logger.info('Search for Wanted albums complete')
+    logger.info('Search for wanted albums complete')
 
 
 def do_sorted_search(album, new, losslessOnly, choose_specific_download=False):

headphones/torrentfinished.py

@@ -13,21 +13,21 @@
 #  You should have received a copy of the GNU General Public License
 #  along with Headphones.  If not, see <http://www.gnu.org/licenses/>.
 
+from headphones import db, utorrent, transmission, logger
+
 import threading
 import headphones
-from headphones import db, utorrent, transmission, logger
 
 postprocessor_lock = threading.Lock()
 
-# Remove Torrent + data if Post Processed and finished Seeding
-
-
 def checkTorrentFinished():
+    """
+    Remove Torrent + data if Post Processed and finished Seeding
+    """
 
     logger.info("Checking if any torrents have finished seeding and can be removed")
 
     with postprocessor_lock:
-
         myDB = db.DBConnection()
         results = myDB.select('SELECT * from snatched WHERE Status="Seed_Processed"')
 
@@ -42,3 +42,5 @@ def checkTorrentFinished():
 
             if torrent_removed:
                 myDB.action('DELETE from snatched WHERE status = "Seed_Processed" and AlbumID=?', [albumid])
+
+    logger.info("Checking finished torrents completed")

headphones/updater.py

@@ -20,11 +20,10 @@ def dbUpdate(forcefull=False):
 
     myDB = db.DBConnection()
 
-    activeartists = myDB.select('SELECT ArtistID, ArtistName from artists WHERE Status="Active" or Status="Loading" order by LastUpdated ASC')
-    logger.info('Starting update for %i active artists' % len(activeartists))
-
-    for artist in activeartists:
+    active_artists = myDB.select('SELECT ArtistID, ArtistName from artists WHERE Status="Active" or Status="Loading" order by LastUpdated ASC')
+    logger.info('Starting update for %i active artists', len(active_artists))
 
+    for artist in active_artists:
         artistid = artist[0]
         importer.addArtisttoDB(artistid=artistid, extrasonly=False, forcefull=forcefull)