Agregando logs a medium

fetcher/medium.py

@@ -14,10 +14,10 @@ import fetcher.musicbrainz as mb
 from fetcher import jobs
 from utils import get_redis_connection
 
-
 _log = logging.getLogger('fetcher_medium')
 _log.addHandler(logging.NullHandler())
 
+
 ###
 # Utility code
 ###
@@ -168,15 +168,20 @@ def map_coverart(mb_cover):
 
 def get_artist(mbid):
     """Obtiene un artista desde musicbrainz incluyendo sus tags"""
+    _log.info('Obteniendo artista con id %s', mbid)
 
     with get_redis_connection() as redis:
+        _log.debug('Intentando obtener artista %s desde redis', mbid)
         mb_artist = redis.get(f'artist:{mbid}')
         if mb_artist is None:
+            _log.debug('El artista %s no estaba en redis, obteniendo desde musicbrainz', mbid)
             mb_artist = mb.get_artist_by_mbid(mbid, includes=['tags'])
         else:
+            _log.debug('El artista %s fue encontrado en redis', mbid)
             mb_artist = json.loads(mb_artist)
 
         if 'error' in mb_artist:
+            _log.debug('Error en artista %s', mbid)
             return mb_artist
 
         jobs.load_artist_on_cache.delay(mbid)
@@ -186,15 +191,20 @@ def get_artist(mbid):
 
 def get_disc(mbid):
     """Obtiene un disco desde musicbrainz"""
+    _log.info('Obteniendo disco con id %s', mbid)
 
     with get_redis_connection() as redis:
+        _log.debug('Intentando obtener disco %s desde redis', mbid)
         mb_disc = redis.get(f'release_group:{mbid}')
         if mb_disc is None:
+            _log.debug('El disco %s no estaba en redis, obteniendo desde musicbrainz', mbid)
             mb_disc = mb.get_release_group_by_mbid(mbid, ['artists'])
         else:
+            _log.debug('El disco %s fue encontrado en redis', mbid)
             mb_disc = json.loads(mb_disc)
 
         if 'error' in mb_disc:
+            _log.debug('El disco tiene un error %s', mb_disc)
             return mb_disc
 
         jobs.load_entities_of_release_group.delay(mbid)
@@ -203,6 +213,8 @@ def get_disc(mbid):
 
 def get_discs_of_artist(mbid, limit, page):
     """Obtiene los discos de un artista desde musicbrainz incluyendo"""
+    _log.debug("Obteniendo los discos del artista %s en la pagina %s con limite %s",
+               mbid, limit, page)
 
     offset = limit * (page - 1)
 
@@ -232,7 +244,7 @@ def get_discs_of_artist(mbid, limit, page):
             _log.debug('%s no se encontraba en redis, saltando código', key_releases)
 
     if len(mb_discs) == 0:
-        _log.debug('Cargar desde musicbrainz las releases de %s', mbid)
+        _log.debug('Cargar desde musicbrainz las release groups de %s', mbid)
 
         # Si es que no había ningún disco, enviar a cargar al artista, quizás nunca se a guardado
         # en cache antes
@@ -242,7 +254,7 @@ def get_discs_of_artist(mbid, limit, page):
                                                    includes=['artist-credits'],
                                                    limit=limit, offset=offset)
         if 'error' in mb_discs_browse:
-            _log.error('Error al hacer browse %s', mb_discs_browse)
+            _log.error('Error al hacer browse de %s', mb_discs_browse)
             return mb_discs_browse
 
         mb_discs = mb_discs_browse.get('release_groups')
@@ -256,24 +268,28 @@ def get_discs_of_artist(mbid, limit, page):
 
 def get_artist_of_disc(mbid):
     """Obtiene el artista de un disco"""
-
+    _log.info('Obteniendo artista del disco %s', mbid)
     mb_artist = None
 
     with get_redis_connection() as redis:
-        key_id = f'release_group:{mbid}:artist'
+        _log.debug('Intentando obtener el artista del disco %s desde redis', mbid)
-        if key_id in redis:
+        if f'release_group:{mbid}:artist' in redis:
-            mb_artist = get_artist(redis.get(key_id))
+            _log.debug('Se encontró el artista del disco %s en redis', mbid)
+            mb_artist = get_artist(redis.get(f'release_group:{mbid}:artist'))
+        else:
+            _log.debug('El artista del disco %s no estaba en redis', mbid)
 
     if mb_artist is None:
+        _log.debug('Obteniendo el artista del disco %s desde musicbrainz', mbid)
         mb_artist_browse = mb.browse_artists(params={'release-group': mbid},
                                              includes=['tags'],
                                              limit=1, offset=0)
 
         if 'error' in mb_artist_browse:
+            _log.debug('Error en el browse de artista %s', mb_artist_browse)
             return mb_artist_browse
 
         mb_artist = mb_artist_browse.get('artists')[0]
-
         jobs.load_artist_on_cache.delay(mb_artist)
 
     return {
@@ -287,39 +303,54 @@ def get_artist_of_disc(mbid):
 
 def get_release(mbid):
     """Obtiene una release desde musicbrainz incluyendo sus artistas"""
+    _log.info('Obteniendo release %s', mbid)
 
     with get_redis_connection() as redis:
+        _log.debug('Intentando obtener release %s desde redis', mbid)
         mb_release = redis.get(f'release:{mbid}')
         if mb_release is None:
+            _log.debug('La release %s no estaba en redis, cargando desde musicbrainz', mbid)
             mb_release = mb.get_release_by_mbid(mbid, includes=['artists'])
         else:
+            _log.debug('La release %s se encontró en redis', mbid)
             mb_release = json.loads(mb_release)
 
         if 'error' in mb_release:
+            _log.error('Error en la release %s', mbid)
             return mb_release
 
         jobs.load_entities_of_release.delay(mbid)
-
         return map_release(mb_release)
 
 
 def get_releases_of_disc(mbid, limit, page):
     """Obtiene las releases de un disco desde musicbrainz"""
+    _log.info('Obteniendo releases del disco %s', mbid)
 
     mb_releases = []
     offset = limit * (page - 1)
     total = 0
 
     with get_redis_connection() as redis:
+        _log.debug('Intentando obtener las releases del disco %s desde redis', mbid)
+
         key_releases = f'release_group:{mbid}:releases'
         if key_releases in redis:
+            # TODO, Misma race condition que en get disc of artist
             if int(redis.get(f'{key_releases}:count')) == redis.zcard(key_releases):
+                _log.debug('Releases del disco %s encontradas en redis', mbid)
                 mb_releases = [get_release(mbid) for mbid in redis.zrange(key_releases,
-                                                                          offset,
+                                                                          offset, limit)]
-                                                                          limit)]
                 total = redis.zcard(key_releases)
+            else:
+                _log.debug('La cantidad de releases que hay almacenadas para el disco %s no '
+                           'coinciden con las totales')
+        else:
+            _log.debug('%s no se encuentra en redis', key_releases)
 
     if len(mb_releases) == 0:
+        _log.debug('Cargar desde musicbrainz las releases del disco %s', mbid)
+
         # Si es que no se encontraron releases antes es probable que nunca se cargo en cache el
         # release group
         jobs.load_entities_of_release_group.delay(mbid)
@@ -329,6 +360,7 @@ def get_releases_of_disc(mbid, limit, page):
                                          limit=limit, offset=limit * (page - 1))
 
         if 'error' in mb_releases:
+            _log.error('Error en las releases %s', mb_releases)
             return mb_releases
 
         total = mb_releases.get('release_count')
@@ -342,20 +374,27 @@ def get_releases_of_disc(mbid, limit, page):
 
 def get_artist_of_release(mbid, limit, page):
     """Obtiene el artista de una release"""
+    _log.info('Obteniendo el artista de la release %s', mbid)
+
     mb_artist = None
 
     with get_redis_connection() as redis:
+        _log.debug('Intentando obtener al artista de la release %s desde redis', mbid)
+
         key = f'release:{mbid}:artist'
         if key in redis:
+            _log.debug('El artista de la release %s se encontro en redis', mbid)
             mb_artist = get_artist(redis.get(key))
 
     if mb_artist is None:
+        _log.debug('El artista de la release %s se no se encontraba en redis', mbid)
         mb_artist_browse = mb.browse_artists(params={'release': mbid},
                                              includes=['tags'],
                                              limit=limit,
                                              offset=limit * (page - 1))
 
         if 'error' in mb_artist_browse:
+            _log.error('El browse de artista retorno con error %s', mb_artist_browse)
             return mb_artist_browse
 
         mb_artist = mb_artist_browse.get('artists')[0]
@@ -373,15 +412,20 @@ def get_artist_of_release(mbid, limit, page):
 
 def get_recording(mbid):
     """Obtiene una grabación"""
+    _log.info('Obteniendo el recording %s', mbid)
 
     with get_redis_connection() as redis:
+        _log.debug('Intentando obtener el recording %s desde redis', mbid)
         mb_recording = redis.get(f'recording:{mbid}')
         if mb_recording is None:
+            _log.debug('El recording %s no estaba en redis, cargando desde musicbrainz', mbid)
             mb_recording = mb.get_recording_by_mbid(mbid)
         else:
+            _log.debug('El recording %s se enontro en redis', mbid)
             mb_recording = json.loads(mb_recording)
 
         if 'error' in mb_recording:
+            _log.error('Error al cargar recording')
             return mb_recording
 
         jobs.load_entities_of_recording.delay(mbid)
@@ -396,10 +440,15 @@ def get_recordings_of_release(mbid):
     los medios físicos en los que esta una grabación, asi que se entrega una lista de medias con sus
     grabaciones acopladas, todo ordenado y con indexes de orden
     """
+    _log.info('Obteniendo recordings de la release %s', mbid)
 
     medias = []
 
     with get_redis_connection() as redis:
+        _log.debug('Intentando obtener los recordings de la release %s', mbid)
+        # TODO hay que checkear si es que medias_keys existe
+        # TODO si es que hay medias y estan todas las que se esperan, se tiene que checkear que
+        # esten todos sus hijos
         medias_key = f'release:{mbid}:media'
         count = redis.get(f'{medias_key}:count')
         if count and redis.zcard(medias_key) == int(count):
@@ -410,8 +459,14 @@ def get_recordings_of_release(mbid):
                 media['recordings'] = []
                 for recording_id in recordings_id:
                     media['recordings'].append(json.loads(redis.get(f'recording:{recording_id}')))
+        else:
+            _log.debug('La cantidad de medias de la release %s encontradas no corresponden al'
+                       'total registrado', mbid)
 
     if len(medias) == 0:
+        _log.debug('No se encontraron recordings de la release %s, se cargara con musicbrainz',
+                   mbid)
+
         # Si es que no habían medias cargadas en cache, puede ser que la release nunca se alla
         # cargado.
         jobs.load_entities_of_release.delay(mbid)
@@ -419,6 +474,7 @@ def get_recordings_of_release(mbid):
         mb_release = mb.get_release_by_mbid(mbid, ['recordings'])
 
         if 'error' in mb_release:
+            _log.debug('Error al cargar recordings %s', mb_release)
             return mb_release
 
         medias = [map_media(media) for media in mb_release.get('media', [])]