After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 642140 - Intermittent scrobbling issues on Windows
Intermittent scrobbling issues on Windows
Status: RESOLVED FIXED
Product: banshee
Classification: Other
Component: Last.fm
git master
Other Windows
: Normal normal
: 1.x
Assigned To: Banshee Maintainers
Banshee Maintainers
Depends on:
Blocks:
 
 
Reported: 2011-02-12 00:42 UTC by Dustin C. Hatch
Modified: 2011-04-16 01:04 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Debug log from first session (38.68 KB, text/plain)
2011-02-12 00:42 UTC, Dustin C. Hatch
  Details
Debug log from second session (41.49 KB, text/plain)
2011-02-12 00:43 UTC, Dustin C. Hatch
  Details
Close HTTP streams when finished with them (1.59 KB, patch)
2011-04-14 03:57 UTC, Dustin C. Hatch
needs-work Details | Review
Close HTTP streams when finished with them (3.88 KB, patch)
2011-04-16 00:09 UTC, Dustin C. Hatch
needs-work Details | Review
Close HTTP streams when finished with them (3.75 KB, patch)
2011-04-16 00:44 UTC, Dustin C. Hatch
committed Details | Review

Description Dustin C. Hatch 2011-02-12 00:42:19 UTC
I've been experiencing some crazy random issues with Last.fm scrobbling on my latest Windows build. Banshee will usually start out okay, scrobbling several songs in a row, and then stop. After a half-dozen songs or so, it will not scrobble again until it is restarted, at which point it will submit any previously unscrobbled songs, and then scrobble a few more.

Now playing only works for the first successful scrobble. Once the song changes, whether it is actually scrobbled or not, Now playing stops working and will not be reported again until Banshee is restarted.

I see a lot of these messages in the debug log::

    Audioscrobbler upload failed - session ID sent was invalid

Sometimes they are followed a few seconds later by these::

   Audioscrobbler sign-on succeeded - Session ID received
   Audioscrobbler upload succeeded

but songs are still not scrobbled.

I will attach the log from a couple of consecutive sessions that exemplify this behavior.
Comment 1 Dustin C. Hatch 2011-02-12 00:42:46 UTC
Created attachment 180695 [details]
Debug log from first session
Comment 2 Dustin C. Hatch 2011-02-12 00:43:03 UTC
Created attachment 180696 [details]
Debug log from second session
Comment 3 Dustin C. Hatch 2011-04-14 03:57:47 UTC
Created attachment 185926 [details] [review]
Close HTTP streams when finished with them

Okay, I think I've made a breakthrough on this one. Although the symptoms have changed, the issue remains present. Instead of the "session ID sent was invalid" messages, I have been seeing these tracebacks printed in the log::

    [23 Warn  21:18:08.256] Failed to get the request stream - System.Net.WebException: The request was aborted: The request was canceled. (in `System')
       at System.Net.HttpWebRequest.EndGetRequestStream(IAsyncResult asyncResult, TransportContext& context)
       at System.Net.HttpWebRequest.EndGetRequestStream(IAsyncResult asyncResult)
       at Lastfm.AudioscrobblerConnection.TransmitGetRequestStream(IAsyncResult ar) in C:\Users\dustin\src\banshee\src\Libraries\Lastfm\Lastfm\AudioscrobblerConnection.cs:line 279

Upon further investigation, I noticed the following:

* Scrobbling and Now Playing always work for the first song and several songs thereafter
* After a few songs, those timeout errors start popping up and scrobbling and now playing stop working until Banshee is restarted.
* I am able to connect to the Audioscrobbler services without any issue even after the timeouts start occurring

Interestingly, Wiresshark revealed that when a timeout error occurred, no network traffic was actually ever generated, so the timeout wasn't because the server was taking too long to respond. The other explanation for a timeout is lack of available connection slots on the client::

      TCP    172.31.0.13:23775      195.24.233.58:80       CLOSE_WAIT
      TCP    172.31.0.13:23778      195.24.233.58:80       CLOSE_WAIT
      TCP    172.31.0.13:23801      195.24.233.58:80       CLOSE_WAIT
      TCP    172.31.0.13:23804      195.24.233.58:80       CLOSE_WAIT
      TCP    172.31.0.13:23807      195.24.233.58:80       CLOSE_WAIT
      TCP    172.31.0.13:23811      195.24.233.58:80       CLOSE_WAIT

Tada! Six half-open TCP sockets! Looking back on my logs, I found that each time scrobbling stopped working after 6 songs. Ominous.

Anyway, here's a patch to fix the problem: close the sockets.
Comment 4 Gabriel Burt 2011-04-14 17:06:22 UTC
Review of attachment 185926 [details] [review]:

Good catch, Justin!  A few comments:

::: src/Libraries/Lastfm/Lastfm/AudioscrobblerConnection.cs
@@ +291,3 @@
             writer.Write (sb.ToString ());
             writer.Close ();
+            stream.Close ();

this one shouldn't be needed b/c StreamWriter.Close also calls Close on the underlying stream

@@ +371,3 @@
             }
+
+            s.Close ();

this one is needed, though perhaps it'd be better to call Close on the sr StreamReader instead? (it also calls Close on the underlying stream)

@@ +483,2 @@
             state = State.Idle;
+            s.Close ();

same as last comment

@@ +621,3 @@
                 }
+
+                s.Close ();

same with last, close sr instead.  But this one needs to happen either in a finally clause, or add a `using` around the sr and/or stream to ensure they're disposed.
Comment 5 Dustin C. Hatch 2011-04-14 23:35:35 UTC
(In reply to comment #4)
> Review of attachment 185926 [details] [review]:
> 
> Good catch, Justin!  A few comments:
> 
I'm not sure who Justin is, but I'll be sure to pass along your gratitude if I meet him ;)

> ::: src/Libraries/Lastfm/Lastfm/AudioscrobblerConnection.cs
> @@ +291,3 @@
>              writer.Write (sb.ToString ());
>              writer.Close ();
> +            stream.Close ();
> 
> this one shouldn't be needed b/c StreamWriter.Close also calls Close on the
> underlying stream
> 
Good to know.

> @@ +371,3 @@
>              }
> +
> +            s.Close ();
> 
> this one is needed, though perhaps it'd be better to call Close on the sr
> StreamReader instead? (it also calls Close on the underlying stream)
> 
Again, didn't know that; the MS docs only mentioned closing the stream to close the TCP socket, so that's what I did.

> @@ +621,3 @@
>                  }
> +
> +                s.Close ();
> 
> same with last, close sr instead.  But this one needs to happen either in a
> finally clause, or add a `using` around the sr and/or stream to ensure they're
> disposed.
I'm not sure I follow this one. I didn't like adding the `Close` call inside the `try..except`, but I wasn't sure how else to do it. Putting it in a `finally` would raise a `NullReferenceException` if an exception is raised inside the `try` clause before the `StreamReader` is initialized, wouldn't it? With regard to using a `using` statement, wouldn't that just call `StreamReader.Dispose ()`? Will that close the stream as well?

If you can't tell, C# isn't my main language (that'd be Python), so please excuse my ignorance of its subtleties.
Comment 6 Gabriel Burt 2011-04-15 19:44:32 UTC
Sorry for the name mixup, Dustin.  :)

For the last point, you either need to put the variables outside the try {} scope, and then Close in the finally only if not null.  Or you can wrap them both in using () which basically does that for you.  Dispose does call Close.
Comment 7 Dustin C. Hatch 2011-04-16 00:09:10 UTC
Created attachment 186057 [details] [review]
Close HTTP streams when finished with them
Comment 8 Gabriel Burt 2011-04-16 00:15:36 UTC
Review of attachment 186057 [details] [review]:

Looks good, except some formatting issues were now introduced.  You can run `git show -w` to see the diff w/o whitespace changes -- where the }\nelse\n{ etc style issues are easily apparent

::: src/Libraries/Lastfm/Lastfm/AudioscrobblerConnection.cs
@@ +595,2 @@
                 Stream s = my_resp.GetResponseStream ();
+                using (StreamReader sr = new StreamReader(s, Encoding.UTF8))

space between StreamReader and ( needed here and elsewhere

@@ +595,3 @@
                 Stream s = my_resp.GetResponseStream ();
+                using (StreamReader sr = new StreamReader(s, Encoding.UTF8))
+                {

this { and ones below should be on same line as using/if etc
Comment 9 Dustin C. Hatch 2011-04-16 00:44:14 UTC
Created attachment 186059 [details] [review]
Close HTTP streams when finished with them

Visual Studio does not approve of your formatting requirements at all and will apparently go to great lengths to remind me.
Comment 10 Gabriel Burt 2011-04-16 01:04:18 UTC
Review of attachment 186059 [details] [review]:

Thanks Dustin, pushed to master and stable-2.0!  Have you considered using MonoDevelop?  http://monodevelop.com/