[music] Cleans up last.fm import logging

We weren't tracking import info very well in the original flow, this
should provide better insight into what happened after a run.

vrobbler/apps/music/lastfm.py

@@ -1,14 +1,12 @@
 import logging
 import time
-from datetime import datetime, timedelta
+from datetime import datetime, timedelta, UTC
 
 import pylast
 import pytz
 from django.conf import settings
 from django.utils import timezone
 from music.utils import (
-    get_or_create_album,
-    get_or_create_artist,
     get_or_create_track,
 )
 
@@ -89,9 +87,14 @@ class LastFM:
             new_scrobbles.append(new_scrobble)
 
         created = Scrobble.objects.bulk_create(new_scrobbles)
+        # TODO Add a notification for users that their import is complete
         logger.info(
-            f"Created {len(created)} scrobbles",
-            extra={"created_scrobbles": created},
+            f"Last.fm import fnished",
+            extra={
+                "scrobbles_created": len(created),
+                "user_id": self.vrobbler_user,
+                "lastfm_user": self.user,
+            },
         )
         return created
 
@@ -117,30 +120,43 @@ class LastFM:
             mbid = None
             artist = None
 
+            log_dict = {"scrobble": scrobble}
             try:
                 run_time = int(scrobble.track.get_duration() / 1000)
                 mbid = scrobble.track.get_mbid()
                 artist = scrobble.track.get_artist().name
+                log_dict["artist"] = artist
+                log_dict["mbid"] = mbid
+                log_dict["run_time"] = run_time
             except pylast.MalformedResponseError as e:
-                logger.warn(e)
+                logger.warning(e)
             except pylast.WSError as e:
-                logger.warn(
-                    "LastFM barfed trying to get the track for {scrobble.track}"
+                logger.info(
+                    "LastFM barfed trying to get the track for {scrobble.track}",
+                    extra=log_dict,
                 )
             except pylast.NetworkError as e:
-                logger.warn(
-                    "LastFM barfed trying to get the track for {scrobble.track}"
+                logger.info(
+                    "LastFM barfed trying to get the track for {scrobble.track}",
+                    extra=log_dict,
                 )
 
             if not artist:
-                logger.warn(f"Silly LastFM, no artist found for {scrobble}")
+                logger.info(
+                    f"Silly LastFM, no artist found for scrobble",
+                    extra=log_dict,
+                )
                 continue
 
+            # TODO figure out if this will actually work
+            #timestamp = datetime.fromtimestamp(int(scrobble.timestamp), UTC)
             timestamp = datetime.utcfromtimestamp(
                 int(scrobble.timestamp)
             ).replace(tzinfo=pytz.utc)
 
-            logger.info(f"{artist},{scrobble.track.title},{timestamp}")
+            logger.info(
+                f"Scrobble appended to list for bulk create", extra=log_dict
+            )
             scrobbles.append(
                 {
                     "artist": artist,