More logging updates.

ycdl/objects.py

@@ -39,7 +39,7 @@ class Channel(Base):
         return videos
 
     def delete(self, commit=True):
-        self.ycdldb.log.debug('Deleting %s.', self)
+        self.ycdldb.log.info('Deleting %s.', self)
 
         self.ycdldb.sql_delete(table='videos', pairs={'author_id': self.id})
         self.ycdldb.sql_delete(table='channels', pairs={'id': self.id})
@@ -61,7 +61,7 @@ class Channel(Base):
         return self.ycdldb.sql_select_one(query, bindings) is not None
 
     def refresh(self, *, force=False, rss_assisted=True, commit=True):
-        self.ycdldb.log.debug('Refreshing %s.', self.id)
+        self.ycdldb.log.info('Refreshing %s.', self.id)
 
         if not self.uploads_playlist:
             self.uploads_playlist = self.ycdldb.youtube.get_user_uploads_playlist_id(self.id)
@@ -90,6 +90,11 @@ class Channel(Base):
             # Of course, it's possible they were deleted.
             known_ids = {v.id for v in self.ycdldb.get_videos(channel_id=self.id)}
             refresh_ids = list(known_ids.difference(seen_ids))
+            if refresh_ids:
+                self.ycdldb.log.debug(
+                    '%d ids did not come back from the generator, fetching them separately.',
+                    len(refresh_ids),
+                )
             for video in self.ycdldb.youtube.get_videos(refresh_ids):
                 self.ycdldb.insert_video(video, commit=False)
 
@@ -169,7 +174,7 @@ class Video(Base):
             return None
 
     def delete(self, commit=True):
-        self.ycdldb.log.debug('Deleting %s.', self)
+        self.ycdldb.log.info('Deleting %s.', self)
 
         self.ycdldb.sql_delete(table='videos', pairs={'id': self.id})
 
@@ -183,7 +188,7 @@ class Video(Base):
         if state not in constants.VIDEO_STATES:
             raise exceptions.InvalidVideoState(state)
 
-        self.ycdldb.log.debug('Marking %s as %s.', self, state)
+        self.ycdldb.log.info('Marking %s as %s.', self, state)
 
         pairs = {
             'id': self.id,

ycdl/ycdldb.py

@@ -205,6 +205,8 @@ class YCDLDBChannelMixin:
         return excs
 
     def refresh_all_channels(self, *, force=False, rss_assisted=True, skip_failures=False, commit=True):
+        self.log.info('Refreshing all channels.')
+
         if rss_assisted and not force:
             return self._rss_assisted_refresh(skip_failures=skip_failures, commit=commit)
 
@@ -365,7 +367,7 @@ class YCDLDBVideoMixin:
 
         query = 'SELECT * FROM videos' + wheres + orderbys
 
-        self.log.debug(f'{query} {bindings}')
+        self.log.debug('%s %s', query, bindings)
         explain = self.sql_execute('EXPLAIN QUERY PLAN ' + query, bindings)
         self.log.debug('\n'.join(str(x) for x in explain.fetchall()))
 
@@ -438,8 +440,10 @@ class YCDLDBVideoMixin:
         }
 
         if existing:
+            self.log.loud('Updating Video %s.', video.id)
             self.sql_update(table='videos', pairs=data, where_key='id')
         else:
+            self.log.loud('Inserting Video %s.', video.id)
             self.sql_insert(table='videos', data=data)
 
         video = self.get_cached_instance('video', data)
@@ -478,6 +482,7 @@ class YCDLDB(
         # LOGGING
         self.log = vlogging.getLogger('ycdl:%s' % self.data_directory.absolute_path)
         self.log.setLevel(log_level)
+        self.youtube.log.setLevel(log_level)
 
         # DATABASE
         self.database_filepath = self.data_directory.with_child(constants.DEFAULT_DBNAME)
@@ -519,7 +524,7 @@ class YCDLDB(
             )
 
     def _first_time_setup(self):
-        self.log.debug('Running first-time database setup.')
+        self.log.info('Running first-time database setup.')
         self.sql.executescript(constants.DB_INIT)
         self.commit()
 

ycdl/ytapi.py

@@ -1,6 +1,7 @@
 import apiclient.discovery
 import isodate
-import logging
+
+from voussoirkit import vlogging
 
 from . import helpers
 
@@ -53,7 +54,7 @@ class Youtube:
             serviceName='youtube',
             version='v3',
         )
-        self.log = logging.getLogger(__name__)
+        self.log = vlogging.getLogger(__name__)
 
     def get_playlist_videos(self, playlist_id):
         page_token = None
@@ -70,8 +71,6 @@ class Youtube:
             videos = self.get_videos(video_ids)
             videos.sort(key=lambda x: x.published, reverse=True)
 
-            self.log.debug('Got %d more videos.', len(videos))
-
             for video in videos:
                 yield video
 
@@ -127,12 +126,14 @@ class Youtube:
         chunks = helpers.chunk_sequence(video_ids, 50)
         for chunk in chunks:
             self.log.debug('Requesting batch of %d video ids.', len(chunk))
+            self.log.loud(chunk)
             chunk = ','.join(chunk)
             data = self.youtube.videos().list(
                 part='id,contentDetails,snippet,statistics',
                 id=chunk,
             ).execute()
             items = data['items']
+            self.log.debug('Got %d snippets.', len(items))
             snippets.extend(items)
 
         videos = []