Improve logging

Better log when an exception is risen.

controllers/subsonic/browsing.py

@@ -1,11 +1,14 @@
 # -*- coding: utf-8 -*-
 
+import logging
 from lxml import etree
 
 from odoo import http
 from odoo.http import request
 from .common import SubsonicREST
 
+_logger = logging.getLogger(__name__)
+
 
 class MusicSubsonicBrowsing(http.Controller):
     @http.route(['/rest/getMusicFolders.view'], type='http', auth='public', csrf=False, methods=['GET', 'POST'])
@@ -36,7 +39,9 @@ def getIndexes(self, **kwargs):
         if ifModifiedSince:
             try:
                 ifModifiedSince = int(ifModifiedSince) // 1000
-            except:
+            except ValueError:
+                _logger.warn(
+                    'Could not convert param "ifModifiedSince" %s to integer', ifModifiedSince)
                 return rest.make_error(code='0', message='Invalid timestamp')
 
         musicFolderId = kwargs.get('musicFolderId')

controllers/subsonic/common.py

@@ -5,6 +5,7 @@
 import logging
 import mimetypes
 import os
+from pprint import pformat
 
 from collections import OrderedDict
 from lxml import etree
@@ -227,8 +228,11 @@ def make_Child_track(self, track, tag_name='child'):
                 track_number = track.track_number.split('/')[0]
                 int(track_number)
                 elem_track.set('track', track_number)
-            except:
-                pass
+            except ValueError:
+                _logger.warn(
+                    'Could not convert track number %s of track id %s to integer',
+                    track.track_number, track.id
+                )
         if track.year:
             elem_track.set('year', track.year[:4])
         if track.genre_id:
@@ -248,8 +252,11 @@ def make_Child_track(self, track, tag_name='child'):
                     disc = track.disc.split('/')[0]
                     int(disc)
                     elem_track.set('discNumber', disc)
-                except:
-                    pass
+                except ValueError:
+                    _logger.warn(
+                        'Could not convert disc number %s of track id %s to integer',
+                        track.disc, track.id
+                    )
             elem_track.set('created', track.create_date.replace(' ', 'T') + 'Z')
             if track.star == '1':
                 elem_track.set('starred', track.write_date.replace(' ', 'T') + 'Z')
@@ -292,8 +299,11 @@ def make_Child_folder(self, folder, tag_name='child'):
                         disc = track.disc.split('/')[0]
                         int(disc)
                         elem_directory.set('discNumber', disc)
-                    except:
-                        pass
+                    except ValueError:
+                        _logger.warn(
+                            'Could not convert disc number %s of track id %s to integer',
+                            track.disc, track.id
+                        )
                 if track.album_id:
                     elem_directory.set('albumId', str(track.album_id.id))
                 if track.artist_id:
@@ -580,7 +590,10 @@ def make_SimilarSongs2(self, track, count=50, tag_name='similarSongs2'):
                 elem_song = self.make_Child_track(s_track, tag_name='song')
                 elem_song_similar.append(elem_song)
         except:
-            pass
+            _logger.warning(
+                'An error occurred while searching similar songs. json contains:\n%s',
+                pformat(req_json), exc_info=True
+            )
 
         return elem_song_similar
 

controllers/subsonic/media_retrieval.py

@@ -136,6 +136,8 @@ def getCoverArt(self, **kwargs):
                 if not found:
                     return rest.make_error(code='70', message='Cover art not found')
             except:
+                _logger.warning(
+                    'An error occurred while searching for folderId %s', folderId, exc_info=True)
                 folder = request.env['oomusic.folder']
         else:
             return rest.make_error(code='10', message='Required int parameter "id" is not present')

models/oomusic_artist.py

@@ -60,18 +60,18 @@ def _compute_fm_image(self):
             try:
                 _logger.debug("Retrieving image for artist %s...", artist.name)
                 for image in req_json['artist']['image']:
-                    if image['size'] == 'large':
+                    if image['size'] == 'large' and image['#text']:
                         image_content = urllib.request.urlopen(image['#text'], timeout=5).read()
                         resized_images = tools.image_get_resized_images(
                             base64.b64encode(image_content),
                             return_big=False, return_medium=True, return_small=False)
                         break
-            except:
-                _logger.warning('Error with image for artist "%s"', artist.name)
-                continue
+            except KeyError:
+                _logger.info('No image found for artist "%s" (id: %s)', artist.name, artist.id)
 
             # Avoid doing a write is nothing has to be done
             if not resized_images['image_medium'] and not artist.fm_image_cache:
+                _logger.info('No image found for artist "%s" (id: %s)', artist.name, artist.id)
                 continue
 
             artist.fm_image = resized_images['image_medium']
@@ -90,7 +90,7 @@ def _compute_fm_getinfo(self):
                 artist.fm_getinfo_bio = req_json['artist']['bio']['summary'].replace('\n', '<br/>')
             except KeyError:
                 artist.fm_getinfo_bio = _('Biography not found')
-                _logger.info("Could not find biography of \"%s\"!", artist.name)
+                _logger.info('Biography not found for artist "%s" (id: %s)', artist.name, artist.id)
 
     def _compute_fm_gettoptracks(self):
         # Create a global cache dict for all artists to avoid multiple search calls.
@@ -109,8 +109,8 @@ def _compute_fm_gettoptracks(self):
                 ]
                 artist.fm_gettoptracks_track_ids = t_tracks[:10]
             except KeyError:
-                _logger.info("Could not find top tracks of \"%s\"!", artist.name)
-                pass
+                _logger.info(
+                    'Top tracks not found for artist "%s" (id: %s)', artist.name, artist.id)
 
     def _compute_fm_getsimilar(self):
         for artist in self:
@@ -125,8 +125,8 @@ def _compute_fm_getsimilar(self):
                         break
                 artist.fm_getsimilar_artist_ids = s_artists.ids
             except KeyError:
-                _logger.info("Could not find simialar artists \"%s\"!", artist.name)
-                pass
+                _logger.info(
+                    'Similar artists not found for artist "%s" (id: %s)', artist.name, artist.id)
 
     @api.multi
     def action_add_to_playlist(self):

models/oomusic_folder.py

@@ -128,7 +128,10 @@ def _compute_image_big(self):
                 resized_images = tools.image_get_resized_images(
                     folder.image_folder, return_big=True, return_medium=False, return_small=False)
             except:
-                _logger.warning('Error with image in folder "%s"', folder.path)
+                _logger.warning(
+                    'Error with image in folder "%s" (id: %s)', folder.path, folder.id,
+                    exc_info=True
+                )
                 continue
 
             folder.image_big = resized_images['image']
@@ -155,7 +158,10 @@ def _compute_image_medium(self):
                 resized_images = tools.image_get_resized_images(
                     folder.image_folder, return_big=False, return_medium=True, return_small=False)
             except:
-                _logger.warning('Error with image in folder "%s"', folder.path)
+                _logger.warning(
+                    'Error with image in folder "%s" (id: %s)', folder.path, folder.id,
+                    exc_info=True
+                )
                 continue
 
             folder.image_medium = resized_images['image_medium']
@@ -182,7 +188,10 @@ def _compute_image_small(self):
                 resized_images = tools.image_get_resized_images(
                     folder.image_folder, return_big=False, return_medium=False, return_small=True)
             except:
-                _logger.warning('Error with image in folder "%s"', folder.path)
+                _logger.warning(
+                    'Error with image in folder "%s" (id: %s)', folder.path, folder.id,
+                    exc_info=True
+                )
                 continue
 
             folder.image_small = resized_images['image_small']
@@ -272,7 +281,10 @@ def cron_scan_folder(self):
             try:
                 self.env['oomusic.folder.scan']._scan_folder(folder.id)
             except:
-                continue
+                _logger.exception(
+                    'Error while scanning folder "%s" (id: %s)', folder.path, folder.id,
+                    exc_info=True
+                )
 
     @api.model
     def cron_build_image_cache(self):

models/oomusic_folder_scan.py

@@ -312,7 +312,7 @@ def _get_tags(self, file_path):
             if not song:
                 raise
         except:
-            _logger.warning('Error while opening file "%s"', file_path)
+            _logger.warning('Error while opening file "%s"', file_path, exc_info=True)
             return False, {}
         if tag.__name__ == 'taglib':
             return song, song.tags

models/oomusic_lastfm.py

@@ -49,8 +49,7 @@ def get_query(self, url, sleep=0.0):
                 if r.status_code == 200:
                     content = r.content.decode('utf-8')
             except:
-                _logger.info("Error while fetching URL \"%s\"...", url)
-                pass
+                _logger.info('Error while fetching URL "%s"', url, exc_info=True)
 
             expiry_date = datetime.datetime.utcnow() + datetime.timedelta(days=fm_cache)
             removal_date = datetime.datetime.utcnow() + datetime.timedelta(days=fm_cache + 14)