Bugzilla – Bug 3942
Unable to play streaming Internet radio with 6.5b1
Last modified: 2011-03-16 04:34:06 UTC
SlimServer 6.5b1 2006-08-16 Solaris SPARC 9 12/03 (Solaris 9 Update 5) Perl 5.8.7 Squeezbox 3 v59 While I could listen to Internet Radio with SlimServer 6.3.1, I cannot with 6.5b1 2006-08-16. For example from the "home" web page for SlimServer, Slim Devices Picks -> Best of Internet Radio -> Alt | KCRW Music -> play button works fine with 6.3.1 but with 6.5b1 I eventually see on the SB3's display Problem: can't connect to server for: (#1 - 124/22235) KCRWmusic An excerpt from the server's log file with some diagnostics enabled shows ----- 6.5b1 excerpt begin ---- 2006-08-16 20:56:14.4793 scanRemoteURL: opening remote location http://www.kcrw.com/pls/kcrwmusic.pls 2006-08-16 20:56:14.6505 scanRemoteURL: Content-Type is pls for http://www.kcrw.com/pls/kcrwmusic.pls 2006-08-16 20:56:14.6663 scanRemoteURL: found that http://www.kcrw.com/pls/kcrwmusic.pls is a playlist 2006-08-16 20:56:14.7767 scanPlaylistFileHandle: found 2 items in playlist: 2006-08-16 20:56:14.7782 http://64.236.34.196/stream/1045 2006-08-16 20:56:14.7789 http://205.188.215.230:8016/ 2006-08-16 20:56:14.7817 scanPlaylistURLs: Found an audio URL: http://64.236.34.196/stream/1045 2006-08-16 20:56:14.8222 This player supports direct streaming for http://64.236.34.196/stream/1045 as http://64.236.34.196/stream/1045, let's do it. 2006-08-16 20:56:14.8230 cracked: http://64.236.34.196/stream/1045 with [64.236.34.196],[80],[/stream/1045] 2006-08-16 20:56:14.8236 cracked: http://64.236.34.196/stream/1045 with [64.236.34.196],[80],[/stream/1045] 2006-08-16 20:56:14.8261 setting up direct stream (1089217220:80) autostart: 2. 2006-08-16 20:56:14.8264 request string: GET /stream/1045 HTTP/1.0 Accept: */* Cache-Control: no-cache User-Agent: iTunes/4.7.1 (Unix; N; solaris; sun4-solaris; EN; iso-8859-1) SlimServer/6.5b1/8984 Icy-MetaData: 1 Connection: close Host: 64.236.34.196 2006-08-16 20:56:24.8389 Oh, well failed to do a direct stream for: http://64.236.34.196/stream/1045 2006-08-16 20:56:24.9033 This player supports direct streaming for http://205.188.215.230:8016/ as http://205.188.215.230:8016/, let's do it. 2006-08-16 20:56:24.9039 cracked: http://205.188.215.230:8016/ with [205.188.215.230],[8016],[/] 2006-08-16 20:56:24.9045 cracked: http://205.188.215.230:8016/ with [205.188.215.230],[8016],[/] 2006-08-16 20:56:24.9100 setting up direct stream (3451705318:8016) autostart: 2. 2006-08-16 20:56:24.9104 request string: GET / HTTP/1.0 Accept: */* Cache-Control: no-cache User-Agent: iTunes/4.7.1 (Unix; N; solaris; sun4-solaris; EN; iso-8859-1) SlimServer/6.5b1/8984 Icy-MetaData: 1 Connection: close Host: 205.188.215.230:8016 2006-08-16 20:56:34.9132 Oh, well failed to do a direct stream for: http://205.188.215.230:8016/ ----- 6.5b1 excerpt end ------- My apologies if I failed to provide other relevant parts of the log file: ask and you shall receive.... FWIW (and probably not much), here's a snippet from 6.3.1 with logging where the direct stream is established successfully. ------ 6.3.1 excerpt begin ---- 2006-08-16 20:47:36.8339 Opening connection to http://www.kcrw.com/pls/kcrwmusic.pls: [www.kcrw.com on port 80 with path /pls/kcrwmusic.pls with timeout 5] 2006-08-16 20:47:36.8529 Request: GET /pls/kcrwmusic.pls HTTP/1.0 Accept: */* Cache-Control: no-cache User-Agent: iTunes/4.7.1 (Unix; N; solaris; sun4-solaris; EN; iso-8859-1) SlimServer/6.3.1/8476 Icy-MetaData: 1 Connection: close Host: www.kcrw.com 2006-08-16 20:47:36.8770 Response: HTTP/1.0 200 OK 2006-08-16 20:47:36.8858 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:36.8864 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:36.9576 header: Date: Mon, 14 Aug 2006 18:27:23 GMT 2006-08-16 20:47:36.9594 header: Server: Apache/1.3.31 (Unix) PHP/4.3.8 2006-08-16 20:47:36.9608 header: Last-Modified: Fri, 04 Aug 2006 20:49:41 GMT 2006-08-16 20:47:36.9619 header: ETag: "22377c-d2-44d3b2e5" 2006-08-16 20:47:36.9628 header: Accept-Ranges: bytes 2006-08-16 20:47:36.9639 header: Content-Length: 210 2006-08-16 20:47:36.9659 header: Content-Type: audio/x-scpls 2006-08-16 20:47:36.9692 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:36.9698 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.0052 header: X-Cache: HIT from www.kcrw.com 2006-08-16 20:47:37.0064 header: Connection: close 2006-08-16 20:47:37.0072 header: 2006-08-16 20:47:37.0075 Recieved final blank line... 2006-08-16 20:47:37.0077 opened stream! 2006-08-16 20:47:37.0142 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.0155 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.0471 Use of uninitialized value in numeric gt (>) at /usr/local/src/SlimServer_v6.3.1/Slim/Player/Protocols/HTTP.pm line 396. 2006-08-16 20:47:37.0509 Use of uninitialized value in numeric gt (>) at /usr/local/src/SlimServer_v6.3.1/Slim/Player/Protocols/HTTP.pm line 396. 2006-08-16 20:47:37.0634 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509, <GEN21> line 9. 2006-08-16 20:47:37.0640 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509, <GEN21> line 9. 2006-08-16 20:47:37.1133 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509, <GEN21> line 9. 2006-08-16 20:47:37.1141 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509, <GEN21> line 9. 2006-08-16 20:47:37.1467 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.1475 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.2085 Opening connection to http://64.236.34.196:80/stream/1045: [64.236.34.196 on port 80 with path /stream/1045 with timeout 5] 2006-08-16 20:47:37.2596 Request: GET /stream/1045 HTTP/1.0 Accept: */* Cache-Control: no-cache User-Agent: iTunes/4.7.1 (Unix; N; solaris; sun4-solaris; EN; iso-8859-1) SlimServer/6.3.1/8476 Icy-MetaData: 1 Connection: close Host: 64.236.34.196 2006-08-16 20:47:37.3107 Response: ICY 200 OK 2006-08-16 20:47:37.3196 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.3202 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.3533 header: icy-notice1: <BR>This stream requires <a href="http://www.winamp.com/">Winamp</a><BR> 2006-08-16 20:47:37.3560 header: icy-notice2: SHOUTcast Distributed Network Audio Server/SolarisSparc v1.9.5<BR> 2006-08-16 20:47:37.3573 header: icy-name: KCRWmusic 2006-08-16 20:47:37.3602 header: icy-genre: Eclectic 2006-08-16 20:47:37.3614 header: icy-url: http://www.kcrwmusic.com 2006-08-16 20:47:37.3623 header: icy-pub: 1 2006-08-16 20:47:37.3632 header: icy-metaint: 8192 2006-08-16 20:47:37.3642 header: icy-br: 128 2006-08-16 20:47:37.3710 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.3716 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509. 2006-08-16 20:47:37.3999 header: icy-irc: #shoutcast 2006-08-16 20:47:37.4011 header: icy-icq: 0 2006-08-16 20:47:37.4020 header: icy-aim: N/A 2006-08-16 20:47:37.4027 header: 2006-08-16 20:47:37.4030 Recieved final blank line... 2006-08-16 20:47:37.4034 opened stream! 2006-08-16 20:47:37.4436 Slim::Player::Protocols::HTTP - in DESTROY 2006-08-16 20:47:37.4441 Slim::Player::Protocols::HTTP About to close socket to: [http://www.kcrw.com/pls/kcrwmusic.pls] 2006-08-16 20:47:37.4863 Read bitrate from stream: 128 CBR 2006-08-16 20:47:37.4931 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509, <GEN24> line 4. 2006-08-16 20:47:37.4938 Use of uninitialized value in substitution (s///) at /usr/local/src/SlimServer_v6.3.1/Slim/DataStores/DBI/DBIStore.pm line 1509, <GEN24> line 4. 2006-08-16 20:47:37.5233 processing headers for direct streaming 2006-08-16 20:47:37.5253 $VAR1 = 'HTTP/1.0 200 OK Date: Thu, 17 Aug 2006 03:47:37 GMT Server: SlimServer (6.3.1 - 8476) Connection: close Content-Type: audio/mpeg Set-Cookie: SlimServer-player=00%3A04%3A20%3A06%3Ab1%3A60; path=/; expires=Fri, 17-Aug-2007 03:47:37 GMT '; 2006-08-16 20:47:37.5262 Backtrace: frame 0: Slim::Player::Squeezebox2::directHeaders (/usr/local/src/SlimServer_v6.3.1/Slim/Networking/Slimproto.pm line 439) frame 1: Slim::Networking::Slimproto::process_slimproto_frame (/usr/local/src/SlimServer_v6.3.1/Slim/Networking/Slimproto.pm line 256) frame 2: Slim::Networking::Slimproto::client_readable (/usr/local/src/SlimServer_v6.3.1/Slim/Networking/Select.pm line 141) frame 3: Slim::Networking::Select::select (/usr/local/src/SlimServer_v6.3.1/slimserver.pl line 705) frame 4: main::idle (/usr/local/src/SlimServer_v6.3.1/slimserver.pl line 641) frame 5: main::main (/usr/local/src/SlimServer_v6.3.1/slimserver.pl line 1281) 2006-08-16 20:47:37.7765 metadata size: 0 2006-08-16 20:47:37.9467 metadata size: 64 2006-08-16 20:47:37.9472 metadata: StreamTitle='KCRWmusic.com';StreamUrl='still here'; 2006-08-16 20:47:37.9538 shoutcast title = KCRWmusic.com 2006-08-16 20:47:38.1067 metadata size: 0 2006-08-16 20:47:38.2672 Use of uninitialized value in pattern match (m//) at /usr/local/src/SlimServer_v6.3.1/Slim/Player/Source.pm line 2255. 2006-08-16 20:47:38.2683 Use of uninitialized value in concatenation (.) or string at /usr/local/src/SlimServer_v6.3.1/Slim/Player/Squeezebox.pm line 751. 2006-08-16 20:47:38.2775 metadata size: 0 .... ------ 6.3.1 excerpt end -----
From the 6.3 log it looks like you're using a proxy server. Does your network require a proxy server to access port 80? Try disabling your proxy server and see if that fixes the problem. I keep meaning to look at fixing this, will try to get around to it soon.
I most definitely have no proxy servers. Not too sure what in the 6.3 log led you to suspect that. Also, I got that 6.3 log by stopping 6.5b1 on the server machine and starting 6.3 on the same machine, but using a different TCP port for --httpaddr. I did the test, then stopped the 6.3 server and restarted the 6.5b1 server (again on the same machine). I then repeated the test with the 6.5b1 server and again no luck. Sooo, tests with both 6.3 and 6.5b1 were done running on the same server box, on the same network, etc. No proxies of any flavour are in use on my network. (I'm my own ISP with my own block of static IPs, my own routers, my own connection to the Internet, etc., etc. So, I am quite familiar with my network setup.)
This is what made me ask: X-Cache: HIT from www.kcrw.com
Hmmmm. Well, given that I'm not running a proxy and I'd be alarmed and surprised if my upstream Internet connection was being so actively involved in my HTTP conversations (I figure they route the packets using BGP and that's it -- no http caching for performance), I figure that that particular header line in the HTTP response from kcrw.com came from the kcrw.com side of things. If I can remember how to get a tcp packet trace on Solaris, I'll dump the HTTP dialog and see if a HTTP response is coming back from kcrw.com at all to the 6.5b1 SlimServer or if there's something malformed in the HTTP request from SlimServer, or a half-close problem on the socket, or whatever.
Yeah, so if you don't have a proxy entered under Network settings page, I'm not really sure what's up. In 6.5, the Squeezebox will make a direct HTTP connection to the stream, bypassing SlimServer completely. You might want to check your firewall to make sure this is allowed.
No proxy is set under Network settings in the SlimServer 6.5b1 Server Settings pages. I can from the host running SlimServer telnet to port 80 of those two IPs. For example, # telnet 64.236.34.196 80 Trying 64.236.34.196... Connected to 64.236.34.196. Escape character is '^]'. GET /stream/1045 HTTP/1.0 Accept: */* Cache-Control: no-cache User-Agent: iTunes/4.7.1 (Unix; N; solaris; sun4-solaris; EN; iso-8859-1) SlimServer/6.5b1/8984 Icy-MetaData: 1 Connection: close Host: 64.236.34.196 ICY 404 Resource Not Found icy-notice1:SHOUTcast Distributed Network Audio Server/posix v1.8.1<BR> icy-notice2:The resource requested was not found<BR> Connection to 64.236.34.196 closed by foreign host. ----- and ----- # telnet 205.188.215.230 8016 Trying 205.188.215.230... Connected to 205.188.215.230. Escape character is '^]'. GET / HTTP/1.0 Accept: */* Cache-Control: no-cache User-Agent: iTunes/4.7.1 (Unix; N; solaris; sun4-solaris; EN; iso-8859-1) SlimServer/6.5b1/8984 Icy-MetaData: 1 Connection: close Host: 205.188.215.230:8016 ICY 200 OK icy-notice1:<BR>This stream requires <a href="http://www.winamp.com/">Winamp</a><BR> icy-notice2:SHOUTcast Distributed Network Audio Server/SolarisSparc v1.9.5<BR> P2?M(?z/:??5^`??7^?U????i?9" j?e?6????=h?`??32?)q?"8fjW??R .... lots more lovely bits and bytes ....
Aha.... I reread your last comment... I'm pretty sure that my firewall will not let the SB3 punch through the firewall. It's on a private IP which isn't in the privileged pool of private IPs who can NAT out to the Internet. So, let me punch a hole in the firewall for the SB3 and report back. Anyhow that the SB3 is doing the connection itself out is the tidbit I missed on my first read and that is crucial. Punching the hole should work -- used to do it with my AudioTrons....
OK, that's almost certainly your problem. :)
Bingo -- works. Okay, if I missed reading that in the release notes for 6.5 then it obviously needs to be stated 8 times, each time with more emphasis ;-) Oh, and my apologies and my thanks for your time. If it isn't in the release notes, then may I suggest that your time is valuable and putting it in may save some of your time? Yes, I subscribe to the to the silly notion that users actually read the documentation and release notes. But, like they say, you can lead a user to the docs, but you cannot make them read 'em. P.S. I just scanned the release notes and I don't see mention that in 6.5, the sb now opens the http stream itself and as such needs to be permitted. P.P.S. I'll leave you to close this out as you see fit (i.e., invalid, won't fix, useful diversion, etc.).
Dan has plans to write a firewall wizard of some kind in the future, and we will bear this problem in mind.