Listener logging parity

This commit is contained in:
RemixDev 2021-06-29 01:37:34 +02:00
parent d8ecb244f5
commit b8e8d27357
No known key found for this signature in database
GPG Key ID: B33962B465BDB51C
2 changed files with 51 additions and 33 deletions

View File

@ -44,7 +44,11 @@ def streamTrack(outputStream, track, start=0, downloadObject=None, listener=None
headers= {'User-Agent': USER_AGENT_HEADER} headers= {'User-Agent': USER_AGENT_HEADER}
chunkLength = start chunkLength = start
itemName = f"[{track.mainArtist.name} - {track.title}]" itemData = {
'id': track.id,
'title': track.title,
'artist': track.mainArtist.name
}
try: try:
with get(track.downloadUrl, headers=headers, stream=True, timeout=10) as request: with get(track.downloadUrl, headers=headers, stream=True, timeout=10) as request:
@ -57,7 +61,7 @@ def streamTrack(outputStream, track, start=0, downloadObject=None, listener=None
if listener: if listener:
listener.send('downloadInfo', { listener.send('downloadInfo', {
'uuid': downloadObject.uuid, 'uuid': downloadObject.uuid,
'itemName': itemName, 'data': itemData,
'state': "downloading", 'state': "downloading",
'alreadyStarted': True, 'alreadyStarted': True,
'value': responseRange 'value': responseRange
@ -66,7 +70,7 @@ def streamTrack(outputStream, track, start=0, downloadObject=None, listener=None
if listener: if listener:
listener.send('downloadInfo', { listener.send('downloadInfo', {
'uuid': downloadObject.uuid, 'uuid': downloadObject.uuid,
'itemName': itemName, 'data': itemData,
'state': "downloading", 'state': "downloading",
'alreadyStarted': False, 'alreadyStarted': False,
'value': complete 'value': complete
@ -86,7 +90,6 @@ def streamTrack(outputStream, track, start=0, downloadObject=None, listener=None
downloadObject.updateProgress(listener) downloadObject.updateProgress(listener)
except (SSLError, u3SSLError): except (SSLError, u3SSLError):
logger.info('%s retrying from byte %s', itemName, chunkLength)
streamTrack(outputStream, track, chunkLength, downloadObject, listener) streamTrack(outputStream, track, chunkLength, downloadObject, listener)
except (RequestsConnectionError, ReadTimeout, ChunkedEncodingError): except (RequestsConnectionError, ReadTimeout, ChunkedEncodingError):
sleep(2) sleep(2)
@ -97,7 +100,11 @@ def streamCryptedTrack(outputStream, track, start=0, downloadObject=None, listen
headers= {'User-Agent': USER_AGENT_HEADER} headers= {'User-Agent': USER_AGENT_HEADER}
chunkLength = start chunkLength = start
itemName = f"[{track.mainArtist.name} - {track.title}]" itemData = {
'id': track.id,
'title': track.title,
'artist': track.mainArtist.name
}
try: try:
with get(track.downloadUrl, headers=headers, stream=True, timeout=10) as request: with get(track.downloadUrl, headers=headers, stream=True, timeout=10) as request:
@ -111,7 +118,7 @@ def streamCryptedTrack(outputStream, track, start=0, downloadObject=None, listen
if listener: if listener:
listener.send('downloadInfo', { listener.send('downloadInfo', {
'uuid': downloadObject.uuid, 'uuid': downloadObject.uuid,
'itemName': itemName, 'data': itemData,
'state': "downloading", 'state': "downloading",
'alreadyStarted': True, 'alreadyStarted': True,
'value': responseRange 'value': responseRange
@ -120,7 +127,7 @@ def streamCryptedTrack(outputStream, track, start=0, downloadObject=None, listen
if listener: if listener:
listener.send('downloadInfo', { listener.send('downloadInfo', {
'uuid': downloadObject.uuid, 'uuid': downloadObject.uuid,
'itemName': itemName, 'data': itemData,
'state': "downloading", 'state': "downloading",
'alreadyStarted': False, 'alreadyStarted': False,
'value': complete 'value': complete
@ -143,7 +150,6 @@ def streamCryptedTrack(outputStream, track, start=0, downloadObject=None, listen
downloadObject.updateProgress(listener) downloadObject.updateProgress(listener)
except (SSLError, u3SSLError): except (SSLError, u3SSLError):
logger.info('%s retrying from byte %s', itemName, chunkLength)
streamCryptedTrack(outputStream, track, chunkLength, downloadObject, listener) streamCryptedTrack(outputStream, track, chunkLength, downloadObject, listener)
except (RequestsConnectionError, ReadTimeout, ChunkedEncodingError): except (RequestsConnectionError, ReadTimeout, ChunkedEncodingError):
sleep(2) sleep(2)

View File

@ -177,6 +177,14 @@ class Downloader:
else: else:
self.listener.send("finishDownload", self.downloadObject.uuid) self.listener.send("finishDownload", self.downloadObject.uuid)
def log(self, data, state):
if self.listener:
self.listener.send('downloadInfo', {'uuid': self.downloadObject.uuid, 'data': data, 'state': state})
def warn(self, data, state, solution):
if self.listener:
self.listener.send('downloadWarn', {'uuid': self.downloadObject.uuid, 'data': data, 'state': state, 'solution': solution})
def download(self, extraData, track=None): def download(self, extraData, track=None):
returnData = {} returnData = {}
trackAPI_gw = extraData['trackAPI_gw'] trackAPI_gw = extraData['trackAPI_gw']
@ -186,11 +194,15 @@ class Downloader:
if self.downloadObject.isCanceled: raise DownloadCanceled if self.downloadObject.isCanceled: raise DownloadCanceled
if trackAPI_gw['SNG_ID'] == "0": raise DownloadFailed("notOnDeezer") if trackAPI_gw['SNG_ID'] == "0": raise DownloadFailed("notOnDeezer")
itemName = f"[{trackAPI_gw['ART_NAME']} - {trackAPI_gw['SNG_TITLE']}]" itemData = {
'id': trackAPI_gw['SNG_ID'],
'title': trackAPI_gw['SNG_TITLE'].strip(),
'artist': trackAPI_gw['ART_NAME']
}
# Create Track object # Create Track object
if not track: if not track:
logger.info("%s Getting the tags", itemName) self.log(itemData, "getTags")
try: try:
track = Track().parseData( track = Track().parseData(
dz=self.dz, dz=self.dz,
@ -203,13 +215,19 @@ class Downloader:
raise DownloadError('albumDoesntExists') from e raise DownloadError('albumDoesntExists') from e
except MD5NotFound as e: except MD5NotFound as e:
raise DownloadError('notLoggedIn') from e raise DownloadError('notLoggedIn') from e
self.log(itemData, "gotTags")
itemName = f"[{track.mainArtist.name} - {track.title}]" itemData = {
'id': track.id,
'title': track.title,
'artist': track.mainArtist.name
}
# Check if track not yet encoded # Check if track not yet encoded
if track.MD5 == '': raise DownloadFailed("notEncoded", track) if track.MD5 == '': raise DownloadFailed("notEncoded", track)
# Choose the target bitrate # Choose the target bitrate
self.log(itemData, "getBitrate")
try: try:
selectedFormat = getPreferredBitrate( selectedFormat = getPreferredBitrate(
track, track,
@ -223,6 +241,7 @@ class Downloader:
raise DownloadFailed("no360RA") from e raise DownloadFailed("no360RA") from e
track.bitrate = selectedFormat track.bitrate = selectedFormat
track.album.bitrate = selectedFormat track.album.bitrate = selectedFormat
self.log(itemData, "gotBitrate")
# Apply settings # Apply settings
track.applySettings(self.settings) track.applySettings(self.settings)
@ -248,8 +267,9 @@ class Downloader:
track.album.embeddedCoverPath = TEMPDIR / ((f"pl{track.playlist.id}" if track.album.isPlaylist else f"alb{track.album.id}") + f"_{self.settings['embeddedArtworkSize']}{ext}") track.album.embeddedCoverPath = TEMPDIR / ((f"pl{track.playlist.id}" if track.album.isPlaylist else f"alb{track.album.id}") + f"_{self.settings['embeddedArtworkSize']}{ext}")
# Download and cache coverart # Download and cache coverart
logger.info("%s Getting the album cover", itemName) self.log(itemData, "getAlbumArt")
track.album.embeddedCoverPath = downloadImage(track.album.embeddedCoverURL, track.album.embeddedCoverPath) track.album.embeddedCoverPath = downloadImage(track.album.embeddedCoverURL, track.album.embeddedCoverPath)
self.log(itemData, "gotAlbumArt")
# Save local album art # Save local album art
if coverPath: if coverPath:
@ -322,7 +342,6 @@ class Downloader:
writepath = Path(currentFilename) writepath = Path(currentFilename)
if not trackAlreadyDownloaded or self.settings['overwriteFile'] == OverwriteOption.OVERWRITE: if not trackAlreadyDownloaded or self.settings['overwriteFile'] == OverwriteOption.OVERWRITE:
logger.info("%s Downloading the track", itemName)
track.downloadUrl = generateStreamURL(track.id, track.MD5, track.mediaVersion, track.bitrate) track.downloadUrl = generateStreamURL(track.id, track.MD5, track.mediaVersion, track.bitrate)
try: try:
@ -335,14 +354,14 @@ class Downloader:
if writepath.is_file(): writepath.unlink() if writepath.is_file(): writepath.unlink()
if e.errno == errno.ENOSPC: raise DownloadFailed("noSpaceLeft") from e if e.errno == errno.ENOSPC: raise DownloadFailed("noSpaceLeft") from e
raise e raise e
self.log(itemData, "downloaded")
else: else:
logger.info("%s Skipping track as it's already downloaded", itemName) self.log(itemData, "alreadyDownloaded")
self.downloadObject.completeTrackProgress(self.listener) self.downloadObject.completeTrackProgress(self.listener)
# Adding tags # Adding tags
if (not trackAlreadyDownloaded or self.settings['overwriteFile'] in [OverwriteOption.ONLY_TAGS, OverwriteOption.OVERWRITE]) and not track.local: if (not trackAlreadyDownloaded or self.settings['overwriteFile'] in [OverwriteOption.ONLY_TAGS, OverwriteOption.OVERWRITE]) and not track.local:
logger.info("%s Applying tags to the track", itemName) self.log(itemData, "tagging")
if extension == '.mp3': if extension == '.mp3':
tagID3(writepath, track, self.settings['tags']) tagID3(writepath, track, self.settings['tags'])
elif extension == '.flac': elif extension == '.flac':
@ -350,17 +369,17 @@ class Downloader:
tagFLAC(writepath, track, self.settings['tags']) tagFLAC(writepath, track, self.settings['tags'])
except (FLACNoHeaderError, FLACError): except (FLACNoHeaderError, FLACError):
writepath.unlink() writepath.unlink()
logger.warning("%s Track not available in FLAC, falling back if necessary", itemName) logger.warning("%s Track not available in FLAC, falling back if necessary", f"{itemData['artist']} - {itemData['title']}")
self.downloadObject.removeTrackProgress(self.listener) self.downloadObject.removeTrackProgress(self.listener)
track.filesizes['FILESIZE_FLAC'] = "0" track.filesizes['FILESIZE_FLAC'] = "0"
track.filesizes['FILESIZE_FLAC_TESTED'] = True track.filesizes['FILESIZE_FLAC_TESTED'] = True
return self.download(trackAPI_gw, track=track) return self.download(trackAPI_gw, track=track)
self.log(itemData, "tagged")
if track.searched: returnData['searched'] = True if track.searched: returnData['searched'] = True
self.downloadObject.downloaded += 1 self.downloadObject.downloaded += 1
self.downloadObject.files.append(str(writepath)) self.downloadObject.files.append(str(writepath))
self.downloadObject.extrasPath = str(self.extrasPath) self.downloadObject.extrasPath = str(self.extrasPath)
logger.info("%s Track download completed\n%s", itemName, writepath)
if self.listener: self.listener.send("updateQueue", { if self.listener: self.listener.send("updateQueue", {
'uuid': self.downloadObject.uuid, 'uuid': self.downloadObject.uuid,
'downloaded': True, 'downloaded': True,
@ -368,11 +387,7 @@ class Downloader:
'extrasPath': str(self.extrasPath) 'extrasPath': str(self.extrasPath)
}) })
returnData['filename'] = str(writepath)[len(str(extrasPath))+ len(pathSep):] returnData['filename'] = str(writepath)[len(str(extrasPath))+ len(pathSep):]
returnData['data'] = { returnData['data'] = itemData
'id': track.id,
'title': track.title,
'artist': track.mainArtist.name
}
return returnData return returnData
def downloadWrapper(self, extraData, track=None): def downloadWrapper(self, extraData, track=None):
@ -382,15 +397,13 @@ class Downloader:
del extraData['trackAPI_gw']['_EXTRA_TRACK'] del extraData['trackAPI_gw']['_EXTRA_TRACK']
del trackAPI_gw['_EXTRA_TRACK'] del trackAPI_gw['_EXTRA_TRACK']
# Temp metadata to generate logs # Temp metadata to generate logs
tempTrack = { itemData = {
'id': trackAPI_gw['SNG_ID'], 'id': trackAPI_gw['SNG_ID'],
'title': trackAPI_gw['SNG_TITLE'].strip(), 'title': trackAPI_gw['SNG_TITLE'].strip(),
'artist': trackAPI_gw['ART_NAME'] 'artist': trackAPI_gw['ART_NAME']
} }
if trackAPI_gw.get('VERSION') and trackAPI_gw['VERSION'] not in trackAPI_gw['SNG_TITLE']: if trackAPI_gw.get('VERSION') and trackAPI_gw['VERSION'] not in trackAPI_gw['SNG_TITLE']:
tempTrack['title'] += f" {trackAPI_gw['VERSION']}".strip() itemData['title'] += f" {trackAPI_gw['VERSION']}".strip()
itemName = f"[{tempTrack['artist']} - {tempTrack['title']}]"
try: try:
result = self.download(extraData, track) result = self.download(extraData, track)
@ -398,13 +411,13 @@ class Downloader:
if error.track: if error.track:
track = error.track track = error.track
if track.fallbackID != "0": if track.fallbackID != "0":
logger.warning("%s %s Using fallback id", itemName, error.message) self.warn(itemData, error.errid, 'fallback')
newTrack = self.dz.gw.get_track_with_fallback(track.fallbackID) newTrack = self.dz.gw.get_track_with_fallback(track.fallbackID)
track.parseEssentialData(newTrack) track.parseEssentialData(newTrack)
track.retriveFilesizes(self.dz) track.retriveFilesizes(self.dz)
return self.downloadWrapper(extraData, track) return self.downloadWrapper(extraData, track)
if not track.searched and self.settings['fallbackSearch']: if not track.searched and self.settings['fallbackSearch']:
logger.warning("%s %s Searching for alternative", itemName, error.message) self.warn(itemData, error.errid, 'search')
searchedId = self.dz.api.get_track_id_from_metadata(track.mainArtist.name, track.title, track.album.title) searchedId = self.dz.api.get_track_id_from_metadata(track.mainArtist.name, track.title, track.album.title)
if searchedId != "0": if searchedId != "0":
newTrack = self.dz.gw.get_track_with_fallback(searchedId) newTrack = self.dz.gw.get_track_with_fallback(searchedId)
@ -423,17 +436,16 @@ class Downloader:
return self.downloadWrapper(extraData, track) return self.downloadWrapper(extraData, track)
error.errid += "NoAlternative" error.errid += "NoAlternative"
error.message = errorMessages[error.errid] error.message = errorMessages[error.errid]
logger.error("%s %s", itemName, error.message)
result = {'error': { result = {'error': {
'message': error.message, 'message': error.message,
'errid': error.errid, 'errid': error.errid,
'data': tempTrack 'data': itemData
}} }}
except Exception as e: except Exception as e:
logger.exception("%s %s", itemName, e) logger.exception("%s %s", f"{itemData['artist']} - {itemData['title']}", e)
result = {'error': { result = {'error': {
'message': str(e), 'message': str(e),
'data': tempTrack 'data': itemData
}} }}
if 'error' in result: if 'error' in result: