GNOME Bugzilla – Bug 667499
Audioscrobbler upload failed
Last modified: 2012-11-28 11:41:00 UTC
Banshee's audioscrobbler seems to be sporadic. Had almost 3 weeks of no scrobbling, then it worked for a few days, and it isn't working again. Restarting Banshee, does not resolve the problem. I decided to run Banshee via terminal so I could see the output. [Warn 11:56:30.883] Audioscrobbler upload failed - The request timed out and was aborted [Warn 11:56:30.912] Failed to get the request stream - System.Net.WebException: Aborted. (in `System') at System.Net.HttpWebRequest.EndGetRequestStream (IAsyncResult asyncResult) [0x00000] in <filename unknown>:0 at Lastfm.AudioscrobblerConnection.TransmitGetRequestStream (IAsyncResult ar) [0x00000] in <filename unknown>:0 [Warn 11:57:32.151] Audioscrobbler upload failed - Plugin bug: Not all request variables are set - Invalid Timestamp This line - "Audioscrobbler upload failed - Plugin bug: Not all request variables are set - Invalid Timestamp" then repeats itself as soon as another song is played. Thanks in advance.
Created attachment 206797 [details] [review] Updates last.fm scrobbler logging What makes this difficult to solve is that we currently do not log what we send to last.fm. We need to see what timestamp we are trying to send to understand what is happening. With that in mind this patch introduces a simple debug logging statement, which should allow us to understand what is going wrong in this case and similar cases. This also updates the web request timeout from 5 to 10 seconds to alleviate the annoying warnings that we get that don't truly indicate a problem.
Comment on attachment 206797 [details] [review] Updates last.fm scrobbler logging Thanks for the patch ! Committed, with a few tweaks to the commit message.
Created attachment 212078 [details] Audioscrobbler error - can't scrobble to last.fm Error message: [Warn 01:52:24.468] Audioscrobbler upload failed - Plugin bug: Not all request variables are set - Invalid Timestamp
Created attachment 212087 [details] Added for checking invalid XML characters ~/.cache/banshee-1/extensions/lastfm/audioscrobbler-queue.xml Due to some invalid XML characters aren't converted. ' != apos; & != & (sometimes)
*** Bug 675335 has been marked as a duplicate of this bug. ***
Created attachment 214534 [details] Example xml to reproduce bug Here is a simplified audioscrobbler-queue.xml example that reproduces this bug for me. Copy to ~/.cache/banshee-1/extensions/lastfm/audioscrobbler-queue.xml and launch banshee with --debug. When you listen to music (and assuming last.fm is set up correctly) you should see the issue. There are two entries, one good and one bad. The second entry is the 'bad' entry that generates the error from Last.fm. The issue is the large negative start-time value. As a side note, based on my testing it seems that Last.fm will accept start-times going back to 1912 without returning a 'failed' message to Banshee. If I went back to dates before 1912 then Last.fm would spit back an actual error. However, even if the submission was 'accepted' by Last.fm I didn't see it scrobbling to my profile with older dates. My guess is that Last.fm 'accepts' dates up to 100 years ago but then rejects them on their side. I searched for a bit on what exactly constitutes an 'invalid' timestamp for Last.fm but the best I could come up with was the link below, which simply says that it cannot be 'too far in the past' without elaborating on what exactly that means: http://www.last.fm/api/scrobbling#filtered-requests A proposed patch to fix this issue is forthcoming, either later tonight or tomorrow evening.
Created attachment 215057 [details] [review] Proposed patch to clean queue upon scrobble failure Adds in a check after a failure is received from Last.fm to verify each track currently in the queue and remove invalid entries before attempting to resubmit. I defined an invalid track as having a null/empty artist or title and having a start-time either before the local epoch or 180 days in the future. As far as I am aware these properties are all that Last.FM absolutely requires. These start-time limits are arbitrary. As I mentioned in my above comment I couldn't find an exact pattern in what Last.fm would accept or reject in terms of start times. I decided it would be better to leave our check wide so we don't get Last.FM errors and run into the submission loop seen in the bug. I welcome any feedback on my proposed limits. I tested this against both XML examples attached to this bug. I was unable to replicate the writing of invalid characters in the XML so I didn't address it with this patch.
(In reply to comment #7) > Created an attachment (id=215057) [details] [review] > Proposed patch to clean queue upon scrobble failure > Hi Phil! Overall the patch looks good, but why removing the invalid tracks in a method call instead of remove one by one just before going to upload? This way we don't have to loop over the whole queue of songs to find the invalid ones (which may be bad for performance). > I tested this against both XML examples attached to this bug. I was unable to > replicate the writing of invalid characters in the XML so I didn't address it > with this patch. Mmm, well, let me be honest: if this patch doesn't fix the root cause of the problem (writing invalid tracks in the queue), then the users affected by this bug will still see their tracks not scrobbled to LastFM. The only thing that this patch does for them is, in the end, remove the warning on the log and save an HTTP call, right? I would prefer to add some more logging on the side that writes the tracks (in the same way you well did in the patch you proposed in comment#1), and then fix the root cause. What do you think?
Created attachment 215596 [details] [review] (V2) Proposed patch to clean queue upon scrobble failure Hi Andrés, after our chat on irc last week I think we are on the same page in terms of what this proposed patch attempts to do. Here are some answers to your points: > Hi Phil! Overall the patch looks good, but why removing the invalid tracks in a > method call instead of remove one by one just before going to upload? This way > we don't have to loop over the whole queue of songs to find the invalid ones > (which may be bad for performance). Since Banshee performs batch submissions and LastFM does not report which exact track failed in the batch we are forced to check the entire queue upon a failure. This patch only attempts to remove invalid tracks after a failure is reported by LastFM to minimize performance concerns. > Mmm, well, let me be honest: if this patch doesn't fix the root cause of the > problem (writing invalid tracks in the queue), then the users affected by this > bug will still see their tracks not scrobbled to LastFM. The only thing that > this patch does for them is, in the end, remove the warning on the log and save > an HTTP call, right? This patch does provide relief for the issue reported in this bug where one or more invalid track(s) muck up scrobbling, causing the queue to grow and grow as submissions fail over and over (an example of which was provided by mail@kl1m.dk in the form of a large audioscrobbler-queue.xml file where only the first track is invalid). It would remove the offending track(s), allowing scrobbling to continue. We would see no more repeating 'invalid timestamp' errors from LastFM but we will most likely see the new warning indicating that tracks are failing validation and must be removed. > I would prefer to add some more logging on the side that writes the tracks (in > the same way you well did in the patch you proposed in comment#1), and then fix > the root cause. What do you think? I agree that additional logging is a great idea. Here is version 2 of the patch. It incorporates your suggestion to log any invalid tracks that are being added to the queue to try to give us an understanding on why this is occurring in the first place. This patch does not solve the root cause, as you said, since I don't know what the root cause is and I don't want to guess. But I believe it is a step in the right direction in helping us solve the problem of why the start-times end up as they do while at the same time providing relief to users in situations where a hiccup on one track breaks scrobbling entirely for them. Let me know what you think!
Committed with minor style changes, thanks Phil and Andrés!
*** Bug 680930 has been marked as a duplicate of this bug. ***