PDA

View Full Version : Spotify has stopped working plus the dreaded Helper App problems.



Tim-Ann
2013-09-06, 07:41
Hi there,

I'm not sure why but all of a sudden today my Spotify plugin has stopped working prior to today it has worked flawlessly, I'm using LMS 7.8 and V2.2.16 plugin.

I need to add this is only not working on my SB Booms it works fine on my SB Radios.

These are my LMS Spotify plugin logs

Helper App: Running
Current logged in to Spotify
Login Error: No error
Last Error: No error

I'm running LMS on a HP Intel Server, running WHS 2011 with all the latest updates.

When I run the Start Test I get Helper App Not Running I've tried port 9006 and 9090 still no joy the latest log notes


[12:20:00.541] main:1600 bad request for socket or no track
[12:20:00.853] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:20:00.853] main:691 no remembered user
[12:20:00.853] main:1600 bad request for socket or no track
[12:20:01.165] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:20:01.165] main:691 no remembered user
[12:20:01.165] main:1600 bad request for socket or no track
[12:20:17.248] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:20:17.264] process_status:1279 process status
[12:20:32.707] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:20:32.707] process_status:1279 process status
[12:20:34.314] log_message:80 log: 11:20:34.314 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[12:20:34.314] log_message:80 log: 11:20:34.314 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[12:20:34.407] log_message:80 log: 11:20:34.407 I [ap:1224] Connected to AP: 193.182.8.67:4070
[12:20:42.254] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:20:42.254] process_status:1279 process status
[12:33:20.968] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[12:33:35.881] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:33:35.881] process_status:1279 process status
[12:33:57.362] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[12:33:57.815] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:57.815] main:684 different remembered user - forgetting
[12:33:57.815] process_status:1279 process status
[12:33:58.127] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:58.127] main:691 no remembered user
[12:33:58.127] main:1600 bad request for socket or no track
[12:33:58.438] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:58.438] main:691 no remembered user
[12:33:58.438] main:1600 bad request for socket or no track
[12:33:58.750] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:58.750] main:691 no remembered user
[12:33:58.750] main:1600 bad request for socket or no track
[12:33:59.062] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:59.062] main:691 no remembered user
[12:33:59.062] main:1600 bad request for socket or no track
[12:33:59.374] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:59.374] main:691 no remembered user
[12:33:59.374] main:1600 bad request for socket or no track
[12:34:05.412] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:34:05.412] process_status:1279 process status
[12:34:18.063] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:34:18.063] process_status:1279 process status
[12:34:19.670] log_message:80 log: 11:34:19.670 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[12:34:19.670] log_message:80 log: 11:34:19.670 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[12:34:19.685] log_message:80 log: 11:34:19.685 I [ap:1224] Connected to AP: 193.235.232.88:4070
[12:34:29.076] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:34:29.076] process_status:1279 process status
[12:44:29.943] logged_out:60 logged out
[15:01:01.388] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:01:01.388] process_status:1279 process status
[15:12:16.378] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:12:16.378] process_status:1279 process status
[15:13:56.016] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:13:56.016] process_status:1279 process status
[15:15:35.889] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:15:35.889] process_status:1279 process status


I have started my mac mini as a LMS server and guess what Spotify plugin is working fine on the mac.

I have noticed a few Spotify updates and wondered could it be them.

I would like to not have to use the Mac mini as a server so any ideas as to what could be going wrong would be much appreciated I have restarted both LMS and the Server after most changes.

Many thanks, Tim.

Tim-Ann
2013-09-07, 04:48
Hi there,

This log is with debug streaming.

[12:44:36.879] process_status:1279 process status
[12:44:38.486] log_message:80 log: 11:44:38.486 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[12:44:38.486] log_message:80 log: 11:44:38.486 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[12:44:38.502] log_message:80 log: 11:44:38.502 I [ap:1224] Connected to AP: 78.31.8.83:4070
[12:44:45.335] main:539 new connection
[12:44:45.335] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:44:45.335] process_status:1279 process status


Does this make any sense?

Thanks, Tim.

Triode
2013-09-07, 04:58
"no remembered user" suggests that the username and password have not been remembered - try reentering the password and clicking apply, what does this add to the log?

Tim-Ann
2013-09-07, 05:13
Hi there,

I've just gone into plugins and re-entered the username and password as I have many times and still helper app is not running,

Here's the latest log,



[13:00:41.542] logged_out:60 logged out
[13:06:43.237] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[13:06:43.237] process_status:1279 process status
[13:07:02.363] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[13:07:02.363] process_status:1279 process status
[13:07:03.954] log_message:80 log: 12:07:03.954 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[13:07:03.954] log_message:80 log: 12:07:03.954 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[13:07:04.048] log_message:80 log: 12:07:04.048 I [ap:1224] Connected to AP: 193.182.8.50:4070


Just gone in to the web browser clicked on settings and this is what it reads,

Helper App: Running
Current logged in to Spotify
Login Error: No error
Last Error: No error

But if I start test it says Helper App not running this is really odd as it was working then it has just stopped.

Thanks, Tim.

Triode
2013-09-07, 05:49
Hi there,

I've just gone into plugins and re-entered the username and password as I have many times and still helper app is not running,

Here's the latest log,



[13:00:41.542] logged_out:60 logged out
[13:06:43.237] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[13:06:43.237] process_status:1279 process status
[13:07:02.363] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[13:07:02.363] process_status:1279 process status
[13:07:03.954] log_message:80 log: 12:07:03.954 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[13:07:03.954] log_message:80 log: 12:07:03.954 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[13:07:04.048] log_message:80 log: 12:07:04.048 I [ap:1224] Connected to AP: 193.182.8.50:4070


Just gone in to the web browser clicked on settings and this is what it reads,

Helper App: Running
Current logged in to Spotify
Login Error: No error
Last Error: No error

But if I start test it says Helper App not running this is really odd as it was working then it has just stopped.

Thanks, Tim.

Have you rebooted the whole machine - looks like there may be two helper apps running?

Tim-Ann
2013-09-07, 06:29
Hi there,

I'm busy uninstalling the whole setup including preferences and reinstalling the latest version od LMS 7.8 to see if that makes a difference.

Lucky I've got the mac Mini a the back up.

Thanks for your help thus far lets hope a clean install cures the issue.

Tim.

Tim-Ann
2013-09-07, 06:42
Hi there,

So a new install of 7.8 (98243) latest version, it seems to login but again Helper App not running.

Helper App: Running
Current logged in to Spotify
Login Error: No error
Last Error: No error




[14:31:13.429] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:33:49.337] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:33:49.352] process_status:1279 process status
[14:33:58.089] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:33:58.089] process_status:1279 process status
[14:34:17.776] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:34:18.244] log_message:80 log: 13:34:18.244 I [c:/spotify/libspotify/client/core/offline_authorizer.cpp:289] Unable to login offline: no such user
[14:34:18.259] log_message:80 log: 13:34:18.259 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[14:34:18.353] log_message:80 log: 13:34:18.353 I [ap:1224] Connected to AP: 193.182.8.65:4070
[14:34:19.258] log_message:80 log: 13:34:19.258 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[14:34:20.350] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:34:20.350] process_status:1279 process status
[14:34:38.384] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:34:38.384] main:450 Config: username: Tim-Ann cachedir: C:\ProgramData\Squeezebox\Cache\spotifycache bitrate: 320 volnorm: 1 httpport: 9005 cliport: 9090 cacheaudio: 1
[14:34:38.836] main:539 new connection
[14:34:38.836] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:38.836] main:691 no remembered user
[14:34:38.836] main:1600 bad request for socket or no track
[14:34:39.148] main:539 new connection
[14:34:39.148] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.148] main:691 no remembered user
[14:34:39.148] main:1600 bad request for socket or no track
[14:34:39.460] main:539 new connection
[14:34:39.460] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.460] main:691 no remembered user
[14:34:39.460] main:1600 bad request for socket or no track
[14:34:39.772] main:539 new connection
[14:34:39.772] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.772] main:691 no remembered user
[14:34:39.772] main:1600 bad request for socket or no track
[14:34:40.084] main:539 new connection
[14:34:40.084] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:40.084] main:691 no remembered user
[14:34:40.084] main:1600 bad request for socket or no track
[14:34:40.396] main:539 new connection
[14:34:40.396] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:40.396] main:691 no remembered user
[14:34:40.396] main:1600 bad request for socket or no track
[14:34:55.481] main:539 new connection
[14:34:55.481] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:34:55.481] process_status:1279 process status
[14:35:07.993] main:539 new connection
[14:35:07.993] main:649 attempting login for user: Tim-Ann
[14:35:08.071] log_message:80 log: 13:35:08.071 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[14:35:08.071] logged_in:53 logged in
[14:35:08.086] log_message:80 log: 13:35:08.086 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[14:35:08.180] log_message:80 log: 13:35:08.180 I [ap:1224] Connected to AP: 193.182.8.83:4070
[14:35:09.163] main:539 new connection
[14:35:09.163] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:35:09.163] process_status:1279 process status


One thought I have my Mac Mini running using port 9005 is that the cause but the Mac Mini was not running when the problem began, just a thought.

Tim.

Mnyb
2013-09-07, 06:46
Hi there,

So a new install of 7.8 (98243) latest version, it seems to login but again Helper App not running.

Helper App: Running
Current logged in to Spotify
Login Error: No error
Last Error: No error




[14:31:13.429] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:33:49.337] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:33:49.352] process_status:1279 process status
[14:33:58.089] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:33:58.089] process_status:1279 process status
[14:34:17.776] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:34:18.244] log_message:80 log: 13:34:18.244 I [c:/spotify/libspotify/client/core/offline_authorizer.cpp:289] Unable to login offline: no such user
[14:34:18.259] log_message:80 log: 13:34:18.259 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[14:34:18.353] log_message:80 log: 13:34:18.353 I [ap:1224] Connected to AP: 193.182.8.65:4070
[14:34:19.258] log_message:80 log: 13:34:19.258 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[14:34:20.350] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:34:20.350] process_status:1279 process status
[14:34:38.384] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:34:38.384] main:450 Config: username: Tim-Ann cachedir: C:\ProgramData\Squeezebox\Cache\spotifycache bitrate: 320 volnorm: 1 httpport: 9005 cliport: 9090 cacheaudio: 1
[14:34:38.836] main:539 new connection
[14:34:38.836] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:38.836] main:691 no remembered user
[14:34:38.836] main:1600 bad request for socket or no track
[14:34:39.148] main:539 new connection
[14:34:39.148] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.148] main:691 no remembered user
[14:34:39.148] main:1600 bad request for socket or no track
[14:34:39.460] main:539 new connection
[14:34:39.460] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.460] main:691 no remembered user
[14:34:39.460] main:1600 bad request for socket or no track
[14:34:39.772] main:539 new connection
[14:34:39.772] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.772] main:691 no remembered user
[14:34:39.772] main:1600 bad request for socket or no track
[14:34:40.084] main:539 new connection
[14:34:40.084] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:40.084] main:691 no remembered user
[14:34:40.084] main:1600 bad request for socket or no track
[14:34:40.396] main:539 new connection
[14:34:40.396] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:40.396] main:691 no remembered user
[14:34:40.396] main:1600 bad request for socket or no track
[14:34:55.481] main:539 new connection
[14:34:55.481] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:34:55.481] process_status:1279 process status
[14:35:07.993] main:539 new connection
[14:35:07.993] main:649 attempting login for user: Tim-Ann
[14:35:08.071] log_message:80 log: 13:35:08.071 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[14:35:08.071] logged_in:53 logged in
[14:35:08.086] log_message:80 log: 13:35:08.086 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[14:35:08.180] log_message:80 log: 13:35:08.180 I [ap:1224] Connected to AP: 193.182.8.83:4070
[14:35:09.163] main:539 new connection
[14:35:09.163] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:35:09.163] process_status:1279 process status


One thought I have my Mac Mini running using port 9005 is that the cause but the Mac Mini was not running when the problem began, just a thought.

Tim.

Is the spotify plugin running on the mini too ?
If so I think spotify migth get cranky if you try to run your account on several devices simultainiusly ;)

One at the time is fine.

Triode
2013-09-07, 07:00
Hi there,

So a new install of 7.8 (98243) latest version, it seems to login but again Helper App not running.

Helper App: Running
Current logged in to Spotify
Login Error: No error
Last Error: No error




[14:31:13.429] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:33:49.337] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:33:49.352] process_status:1279 process status
[14:33:58.089] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:33:58.089] process_status:1279 process status
[14:34:17.776] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:34:18.244] log_message:80 log: 13:34:18.244 I [c:/spotify/libspotify/client/core/offline_authorizer.cpp:289] Unable to login offline: no such user
[14:34:18.259] log_message:80 log: 13:34:18.259 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[14:34:18.353] log_message:80 log: 13:34:18.353 I [ap:1224] Connected to AP: 193.182.8.65:4070
[14:34:19.258] log_message:80 log: 13:34:19.258 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[14:34:20.350] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:34:20.350] process_status:1279 process status
[14:34:38.384] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[14:34:38.384] main:450 Config: username: Tim-Ann cachedir: C:\ProgramData\Squeezebox\Cache\spotifycache bitrate: 320 volnorm: 1 httpport: 9005 cliport: 9090 cacheaudio: 1
[14:34:38.836] main:539 new connection
[14:34:38.836] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:38.836] main:691 no remembered user
[14:34:38.836] main:1600 bad request for socket or no track
[14:34:39.148] main:539 new connection
[14:34:39.148] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.148] main:691 no remembered user
[14:34:39.148] main:1600 bad request for socket or no track
[14:34:39.460] main:539 new connection
[14:34:39.460] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.460] main:691 no remembered user
[14:34:39.460] main:1600 bad request for socket or no track
[14:34:39.772] main:539 new connection
[14:34:39.772] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:39.772] main:691 no remembered user
[14:34:39.772] main:1600 bad request for socket or no track
[14:34:40.084] main:539 new connection
[14:34:40.084] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:40.084] main:691 no remembered user
[14:34:40.084] main:1600 bad request for socket or no track
[14:34:40.396] main:539 new connection
[14:34:40.396] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[14:34:40.396] main:691 no remembered user
[14:34:40.396] main:1600 bad request for socket or no track
[14:34:55.481] main:539 new connection
[14:34:55.481] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:34:55.481] process_status:1279 process status
[14:35:07.993] main:539 new connection
[14:35:07.993] main:649 attempting login for user: Tim-Ann
[14:35:08.071] log_message:80 log: 13:35:08.071 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[14:35:08.071] logged_in:53 logged in
[14:35:08.086] log_message:80 log: 13:35:08.086 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[14:35:08.180] log_message:80 log: 13:35:08.180 I [ap:1224] Connected to AP: 193.182.8.83:4070
[14:35:09.163] main:539 new connection
[14:35:09.163] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[14:35:09.163] process_status:1279 process status


One thought I have my Mac Mini running using port 9005 is that the cause but the Mac Mini was not running when the problem began, just a thought.

Tim.

Suggest reading the logs you are posting... If it says no remembered user then you need to add the username/password again. Until this goes away it can't work. If you don't get log messages related to storing the password then check there is only one version of the help app running - its easiest to do this by rebooting the machine - did you do this?

Tim-Ann
2013-09-07, 07:53
Hi there,

Is there a reason why it is not remembering me I am restarting the server each time but when I open the plugin page after each restart it says not logged into Spotify so I then enter my password click apply close the page re-open it and it then says I'm logged in then do a server restart it makes me have to re-enter my password, this seems to be happening at every restart.

Spotify Premium allows several machines to be logged in and we've never had this problem nor was the Mac running Spotify when the original problem occurred I'll now log out of all Spotify programs that are running.

Will report back I will find a resolve for this, just such a pain having to restart the server all the time.

But worth it for such a good program.

Tim.

Tim-Ann
2013-09-07, 08:49
Hi there,

Okay this is just getting weird, firstly the Mac Mini Spotify was not logged in yet as soon as I choose Spotify on any of my SB devices it would automatically log in so I downed the mac and logged into the Windows Server LMS on my SB radio when I tried to login to Spotify and play a track before the track would paly it said I had to be logged into mysqueezbox.com so I logged in and it played on the Radio but it would not play on the Boom that was the original issue, it said something like error connecting and then after every 10 seconds it would jump to the next track.

Now can I ask does having both yours and the Logitech Spotify plugins loaded make any difference? Currently I go into My Apps and run the Orange Spotify icon this is on the Radio again in the App Gallery if I go in there is a Green Spotify icon if I click on that it says Spotify is already installed and there is an uninstall icon, I won't uninstall but on the Boom there is a Spotify in My Apps and a Spotify in the main menu both work on the boom. Talk about strange.

Final test on a Radio I'm logged into the Intel LMS server and I run the orange Spotify icon when I go into settings it shows connected to Spotify but if I run the test it says Helper not running of course the Boom just doesn't play.

Anyway not sure if this helps but as I've said before it is the Boom that will not play Spotify through the Intel LMS server radio's are fine.

Many thanks, Tim.

garym
2013-09-07, 09:25
I only use the triode spotify plugin and do not have the official Logitech app installed in my apps or as a plugin. All works fine with all types of players. Sounds like you are having an odd interaction between the two spotify apps. Note that the official spotify app will ONLY work with radio or Touch. I don't know that you can't have them both installed, but I'd test with only the triode plugin to see if that works.

atomjohan
2013-09-07, 09:37
I only use the triode spotify plugin and do not have the official Logitech app installed in my apps or as a plugin. All works fine with all types of players. Sounds like you are having an odd interaction between the two spotify apps. Note that the official spotify app will ONLY work with radio or Touch. I don't know that you can't have them both installed, but I'd test with only the triode plugin to see if that works.


Thank you!

Been having the same problem and this did it for me:D

Triode
2013-09-07, 10:00
Hi there,

Is there a reason why it is not remembering me I am restarting the server each time but when I open the plugin page after each restart it says not logged into Spotify so I then enter my password click apply close the page re-open it and it then says I'm logged in then do a server restart it makes me have to re-enter my password, this seems to be happening at every restart.

Spotify Premium allows several machines to be logged in and we've never had this problem nor was the Mac running Spotify when the original problem occurred I'll now log out of all Spotify programs that are running.

Will report back I will find a resolve for this, just such a pain having to restart the server all the time.

But worth it for such a good program.

Tim.

I would check the helper app log when you add the password - does it say it is setting the password ok. Have you definitely rebooted the machined running LMS between the restarts?

Lopern
2013-09-07, 22:40
Hi there,

I'm not sure why but all of a sudden today my Spotify plugin has stopped working prior to today it has worked flawlessly, I'm using LMS 7.8 and V2.2.16 plugin.

I need to add this is only not working on my SB Booms it works fine on my SB Radios.

These are my LMS Spotify plugin logs

Helper App: Running
Current logged in to Spotify
Login Error: No error
Last Error: No error

I'm running LMS on a HP Intel Server, running WHS 2011 with all the latest updates.

When I run the Start Test I get Helper App Not Running I've tried port 9006 and 9090 still no joy the latest log notes


[12:20:00.541] main:1600 bad request for socket or no track
[12:20:00.853] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:20:00.853] main:691 no remembered user
[12:20:00.853] main:1600 bad request for socket or no track
[12:20:01.165] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:20:01.165] main:691 no remembered user
[12:20:01.165] main:1600 bad request for socket or no track
[12:20:17.248] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:20:17.264] process_status:1279 process status
[12:20:32.707] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:20:32.707] process_status:1279 process status
[12:20:34.314] log_message:80 log: 11:20:34.314 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[12:20:34.314] log_message:80 log: 11:20:34.314 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[12:20:34.407] log_message:80 log: 11:20:34.407 I [ap:1224] Connected to AP: 193.182.8.67:4070
[12:20:42.254] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:20:42.254] process_status:1279 process status
[12:33:20.968] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[12:33:35.881] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:33:35.881] process_status:1279 process status
[12:33:57.362] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[12:33:57.815] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:57.815] main:684 different remembered user - forgetting
[12:33:57.815] process_status:1279 process status
[12:33:58.127] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:58.127] main:691 no remembered user
[12:33:58.127] main:1600 bad request for socket or no track
[12:33:58.438] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:58.438] main:691 no remembered user
[12:33:58.438] main:1600 bad request for socket or no track
[12:33:58.750] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:58.750] main:691 no remembered user
[12:33:58.750] main:1600 bad request for socket or no track
[12:33:59.062] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:59.062] main:691 no remembered user
[12:33:59.062] main:1600 bad request for socket or no track
[12:33:59.374] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[12:33:59.374] main:691 no remembered user
[12:33:59.374] main:1600 bad request for socket or no track
[12:34:05.412] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:34:05.412] process_status:1279 process status
[12:34:18.063] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:34:18.063] process_status:1279 process status
[12:34:19.670] log_message:80 log: 11:34:19.670 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[12:34:19.670] log_message:80 log: 11:34:19.670 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[12:34:19.685] log_message:80 log: 11:34:19.685 I [ap:1224] Connected to AP: 193.235.232.88:4070
[12:34:29.076] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[12:34:29.076] process_status:1279 process status
[12:44:29.943] logged_out:60 logged out
[15:01:01.388] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:01:01.388] process_status:1279 process status
[15:12:16.378] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:12:16.378] process_status:1279 process status
[15:13:56.016] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:13:56.016] process_status:1279 process status
[15:15:35.889] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[15:15:35.889] process_status:1279 process status


I have started my mac mini as a LMS server and guess what Spotify plugin is working fine on the mac.

I have noticed a few Spotify updates and wondered could it be them.

I would like to not have to use the Mac mini as a server so any ideas as to what could be going wrong would be much appreciated I have restarted both LMS and the Server after most changes.

Many thanks, Tim.

Tim Any news regarding your prob
i have the same issue on my WHS-2011
also tried the same ports as you with no luck

the god thing is that your not ALONE :)

Tim-Ann
2013-09-08, 03:27
Hi there,

I had tried removing the Logitech Spotify but still Triodes Spotify does not work on the Boom I need to repeat the problem is with the Boom not the Radio's.

As I've said I'm lucky in having a Mac Mini to run LMS on but I'd like my HP Intel Server to work as it used to I can only think this has something to do with maybe an updated but I could be very wrong.

Here's todays Debug Streaming log with the Logitech Spotify plugin removed still the helper app is not running (Fail).

[11:07:11.524] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:07:28.076] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:07:28.076] process_status:1279 process status
[11:16:50.972] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:16:50.972] main:670 relogging in as user: tim-ann
[11:16:51.986] process_playlists:990 process playlists: user
[11:16:51.986] log_message:80 log: 10:16:51.986 I [offline-mgr:2143] Storage has been cleaned
[11:16:51.986] metadata_updated:85 new meta
[11:16:53.609] log_message:80 log: 10:16:53.609 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[11:16:53.609] log_message:80 log: 10:16:53.609 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[11:16:53.702] log_message:80 log: 10:16:53.702 I [ap:1224] Connected to AP: 193.182.8.58:4070
[11:16:56.370] main:591 req: playlists.json res: spotify:user:tim-ann:playlist:4m9EP4uktUyQBD1ZPyuxu6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:56.370] main:1223 requesting playlist
[11:16:56.370] process_singleplaylist:1104 process single playlist
[11:16:58.164] main:591 req: playlists.json res: spotify:user:tim-ann:playlist:4m9EP4uktUyQBD1ZPyuxu6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.164] main:1223 requesting playlist
[11:16:58.164] process_singleplaylist:1104 process single playlist
[11:16:58.164] main:591 req: browse.json res: spotify:track:5CEg8rDHioM9aJpf5mVpf6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.164] main:1050 queuing track browse
[11:16:58.164] process_track:1229 process track
[11:16:58.164] process_track:1253 browse track: ok
[11:16:58.180] main:591 req: browse.json res: spotify:track:3JYvH4TrhlDWmpVCr0V43t par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.180] main:1050 queuing track browse
[11:16:58.180] process_track:1229 process track
[11:16:58.180] process_track:1253 browse track: ok
[11:16:58.180] main:591 req: browse.json res: spotify:track:3MH3oRNyFb5mNm663xcK7T par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.180] main:1050 queuing track browse
[11:16:58.180] process_track:1229 process track
[11:16:58.180] process_track:1253 browse track: ok
[11:17:02.407] log_message:80 log: 10:17:02.407 E [ap:4355] ChannelError(1, 1, link-tracks)
[11:17:03.016] log_message:80 log: 10:17:03.016 I [offline-mgr:2090] 0 files are locked. 0 images are locked
[11:17:03.016] log_message:80 log: 10:17:03.016 I [offline-mgr:2116] 0 files unlocked. 0 images unlocked
[11:17:10.504] log_message:80 log: 10:17:10.504 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:18.195] main:591 req: browse.json res: spotify:track:6tqzOYuE3lrNVPDgtF3MjM par: (null) prot: HTTP/1.0 auth: (null)
[11:17:18.195] main:1050 queuing track browse
[11:17:18.195] process_track:1229 process track
[11:17:18.195] process_track:1253 browse track: ok
[11:17:18.195] main:591 req: browse.json res: spotify:track:48BEYwb2HXiBXOJ7q02UoC par: (null) prot: HTTP/1.0 auth: (null)
[11:17:18.195] main:1050 queuing track browse
[11:17:18.195] process_track:1229 process track
[11:17:18.195] process_track:1253 browse track: ok
[11:17:18.616] log_message:80 log: 10:17:18.616 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:26.713] log_message:80 log: 10:17:26.713 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:40.519] log_message:80 log: 10:17:40.519 I [offline-mgr:2116] 0 files unlocked. 0 images unlocked
[11:22:17.318] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:23:36.941] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:23:36.956] process_status:1279 process status
[11:23:57.033] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:23:57.033] main:450 Config: username: tim-ann cachedir: C:\ProgramData\Squeezebox\Cache\spotifycache bitrate: 320 volnorm: 1 httpport: 9006 cliport: 9090 cacheaudio: 1
[11:23:57.486] main:539 new connection
[11:23:57.486] main:649 attempting login for user: tim-ann
[11:23:57.673] logged_in:53 logged in
[11:23:58.687] main:539 new connection
[11:23:58.687] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:23:58.687] process_status:1279 process status
[11:24:00.294] log_message:80 log: 10:24:00.294 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[11:24:00.294] log_message:80 log: 10:24:00.294 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[11:24:00.387] log_message:80 log: 10:24:00.387 I [ap:1224] Connected to AP: 193.182.8.58:4070
[11:24:20.574] main:539 new connection
[11:24:20.574] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:24:20.574] process_status:1279 process status

Please note I'm using port 9006 my Mac Mini is using 9005 but what does WinHttpGetProxyForUrl failed mean?

Yes I am constantly rebooting the Server at every change.

Many thanks, Tim.

Triode
2013-09-08, 03:43
Hi there,

I had tried removing the Logitech Spotify but still Triodes Spotify does not work on the Boom I need to repeat the problem is with the Boom not the Radio's.

As I've said I'm lucky in having a Mac Mini to run LMS on but I'd like my HP Intel Server to work as it used to I can only think this has something to do with maybe an updated but I could be very wrong.

Here's todays Debug Streaming log with the Logitech Spotify plugin removed still the helper app is not running (Fail).

[11:07:11.524] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:07:28.076] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:07:28.076] process_status:1279 process status
[11:16:50.972] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:16:50.972] main:670 relogging in as user: tim-ann
[11:16:51.986] process_playlists:990 process playlists: user
[11:16:51.986] log_message:80 log: 10:16:51.986 I [offline-mgr:2143] Storage has been cleaned
[11:16:51.986] metadata_updated:85 new meta
[11:16:53.609] log_message:80 log: 10:16:53.609 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[11:16:53.609] log_message:80 log: 10:16:53.609 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[11:16:53.702] log_message:80 log: 10:16:53.702 I [ap:1224] Connected to AP: 193.182.8.58:4070
[11:16:56.370] main:591 req: playlists.json res: spotify:user:tim-ann:playlist:4m9EP4uktUyQBD1ZPyuxu6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:56.370] main:1223 requesting playlist
[11:16:56.370] process_singleplaylist:1104 process single playlist
[11:16:58.164] main:591 req: playlists.json res: spotify:user:tim-ann:playlist:4m9EP4uktUyQBD1ZPyuxu6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.164] main:1223 requesting playlist
[11:16:58.164] process_singleplaylist:1104 process single playlist
[11:16:58.164] main:591 req: browse.json res: spotify:track:5CEg8rDHioM9aJpf5mVpf6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.164] main:1050 queuing track browse
[11:16:58.164] process_track:1229 process track
[11:16:58.164] process_track:1253 browse track: ok
[11:16:58.180] main:591 req: browse.json res: spotify:track:3JYvH4TrhlDWmpVCr0V43t par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.180] main:1050 queuing track browse
[11:16:58.180] process_track:1229 process track
[11:16:58.180] process_track:1253 browse track: ok
[11:16:58.180] main:591 req: browse.json res: spotify:track:3MH3oRNyFb5mNm663xcK7T par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.180] main:1050 queuing track browse
[11:16:58.180] process_track:1229 process track
[11:16:58.180] process_track:1253 browse track: ok
[11:17:02.407] log_message:80 log: 10:17:02.407 E [ap:4355] ChannelError(1, 1, link-tracks)
[11:17:03.016] log_message:80 log: 10:17:03.016 I [offline-mgr:2090] 0 files are locked. 0 images are locked
[11:17:03.016] log_message:80 log: 10:17:03.016 I [offline-mgr:2116] 0 files unlocked. 0 images unlocked
[11:17:10.504] log_message:80 log: 10:17:10.504 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:18.195] main:591 req: browse.json res: spotify:track:6tqzOYuE3lrNVPDgtF3MjM par: (null) prot: HTTP/1.0 auth: (null)
[11:17:18.195] main:1050 queuing track browse
[11:17:18.195] process_track:1229 process track
[11:17:18.195] process_track:1253 browse track: ok
[11:17:18.195] main:591 req: browse.json res: spotify:track:48BEYwb2HXiBXOJ7q02UoC par: (null) prot: HTTP/1.0 auth: (null)
[11:17:18.195] main:1050 queuing track browse
[11:17:18.195] process_track:1229 process track
[11:17:18.195] process_track:1253 browse track: ok
[11:17:18.616] log_message:80 log: 10:17:18.616 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:26.713] log_message:80 log: 10:17:26.713 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:40.519] log_message:80 log: 10:17:40.519 I [offline-mgr:2116] 0 files unlocked. 0 images unlocked
[11:22:17.318] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:23:36.941] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:23:36.956] process_status:1279 process status
[11:23:57.033] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:23:57.033] main:450 Config: username: tim-ann cachedir: C:\ProgramData\Squeezebox\Cache\spotifycache bitrate: 320 volnorm: 1 httpport: 9006 cliport: 9090 cacheaudio: 1
[11:23:57.486] main:539 new connection
[11:23:57.486] main:649 attempting login for user: tim-ann
[11:23:57.673] logged_in:53 logged in
[11:23:58.687] main:539 new connection
[11:23:58.687] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:23:58.687] process_status:1279 process status
[11:24:00.294] log_message:80 log: 10:24:00.294 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[11:24:00.294] log_message:80 log: 10:24:00.294 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[11:24:00.387] log_message:80 log: 10:24:00.387 I [ap:1224] Connected to AP: 193.182.8.58:4070
[11:24:20.574] main:539 new connection
[11:24:20.574] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:24:20.574] process_status:1279 process status

Please note I'm using port 9006 my Mac Mini is using 9005 but what does WinHttpGetProxyForUrl failed mean?

Yes I am constantly rebooting the Server at every change.

Many thanks, Tim.

"WinHttpGetProxyForUrl failed" comes from within the spotify library - I don't know if this is a problem which will case us issues. However the rest of the log looks like it is working ok. So the question now is why do you see the helper app as having failed - can you check the server log as well with plugin.spotify logging set to debug? What is the actual symptom of the problem now as this appears to be browsing files ok. If it is player related, make sure you have port 9006 open in your filewall for players to connect to?

Tim-Ann
2013-09-08, 04:01
Hi there,

Here's another odd on on the Boom I can access the libraries not a problem but as soon as I press play it fails to connect and about every 10 seconds it jumps to the next track.

I've looked at my WHS 2011 Firewall and I cannot see any errors.

Not sure if you wanted the Spotify Debug log if so it is here,

[11:07:11.524] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:07:28.076] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:07:28.076] process_status:1279 process status
[11:16:50.972] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:16:50.972] main:670 relogging in as user: tim-ann
[11:16:51.986] process_playlists:990 process playlists: user
[11:16:51.986] log_message:80 log: 10:16:51.986 I [offline-mgr:2143] Storage has been cleaned
[11:16:51.986] metadata_updated:85 new meta
[11:16:53.609] log_message:80 log: 10:16:53.609 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[11:16:53.609] log_message:80 log: 10:16:53.609 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[11:16:53.702] log_message:80 log: 10:16:53.702 I [ap:1224] Connected to AP: 193.182.8.58:4070
[11:16:56.370] main:591 req: playlists.json res: spotify:user:tim-ann:playlist:4m9EP4uktUyQBD1ZPyuxu6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:56.370] main:1223 requesting playlist
[11:16:56.370] process_singleplaylist:1104 process single playlist
[11:16:58.164] main:591 req: playlists.json res: spotify:user:tim-ann:playlist:4m9EP4uktUyQBD1ZPyuxu6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.164] main:1223 requesting playlist
[11:16:58.164] process_singleplaylist:1104 process single playlist
[11:16:58.164] main:591 req: browse.json res: spotify:track:5CEg8rDHioM9aJpf5mVpf6 par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.164] main:1050 queuing track browse
[11:16:58.164] process_track:1229 process track
[11:16:58.164] process_track:1253 browse track: ok
[11:16:58.180] main:591 req: browse.json res: spotify:track:3JYvH4TrhlDWmpVCr0V43t par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.180] main:1050 queuing track browse
[11:16:58.180] process_track:1229 process track
[11:16:58.180] process_track:1253 browse track: ok
[11:16:58.180] main:591 req: browse.json res: spotify:track:3MH3oRNyFb5mNm663xcK7T par: (null) prot: HTTP/1.0 auth: (null)
[11:16:58.180] main:1050 queuing track browse
[11:16:58.180] process_track:1229 process track
[11:16:58.180] process_track:1253 browse track: ok
[11:17:02.407] log_message:80 log: 10:17:02.407 E [ap:4355] ChannelError(1, 1, link-tracks)
[11:17:03.016] log_message:80 log: 10:17:03.016 I [offline-mgr:2090] 0 files are locked. 0 images are locked
[11:17:03.016] log_message:80 log: 10:17:03.016 I [offline-mgr:2116] 0 files unlocked. 0 images unlocked
[11:17:10.504] log_message:80 log: 10:17:10.504 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:18.195] main:591 req: browse.json res: spotify:track:6tqzOYuE3lrNVPDgtF3MjM par: (null) prot: HTTP/1.0 auth: (null)
[11:17:18.195] main:1050 queuing track browse
[11:17:18.195] process_track:1229 process track
[11:17:18.195] process_track:1253 browse track: ok
[11:17:18.195] main:591 req: browse.json res: spotify:track:48BEYwb2HXiBXOJ7q02UoC par: (null) prot: HTTP/1.0 auth: (null)
[11:17:18.195] main:1050 queuing track browse
[11:17:18.195] process_track:1229 process track
[11:17:18.195] process_track:1253 browse track: ok
[11:17:18.616] log_message:80 log: 10:17:18.616 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:26.713] log_message:80 log: 10:17:26.713 E [ap:4355] ChannelError(0, 1, link-tracks)
[11:17:40.519] log_message:80 log: 10:17:40.519 I [offline-mgr:2116] 0 files unlocked. 0 images unlocked
[11:22:17.318] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:23:36.941] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:23:36.956] process_status:1279 process status
[11:23:57.033] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:23:57.033] main:450 Config: username: tim-ann cachedir: C:\ProgramData\Squeezebox\Cache\spotifycache bitrate: 320 volnorm: 1 httpport: 9006 cliport: 9090 cacheaudio: 1
[11:23:57.486] main:539 new connection
[11:23:57.486] main:649 attempting login for user: tim-ann
[11:23:57.673] logged_in:53 logged in
[11:23:58.687] main:539 new connection
[11:23:58.687] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:23:58.687] process_status:1279 process status
[11:24:00.294] log_message:80 log: 10:24:00.294 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[11:24:00.294] log_message:80 log: 10:24:00.294 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[11:24:00.387] log_message:80 log: 10:24:00.387 I [ap:1224] Connected to AP: 193.182.8.58:4070
[11:24:20.574] main:539 new connection
[11:24:20.574] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:24:20.574] process_status:1279 process status
[11:34:21.833] logged_out:60 logged out
[11:53:16.376] main:539 new connection
[11:53:16.376] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[11:53:16.376] process_status:1279 process status
[11:53:30.510] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[11:53:30.510] main:450 Config: username: tim-ann cachedir: C:\ProgramData\Squeezebox\Cache\spotifycache bitrate: 320 volnorm: 1 httpport: 9006 cliport: 9090 cacheaudio: 1
[11:53:30.962] main:539 new connection
[11:53:30.962] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[11:53:30.962] main:670 relogging in as user: tim-ann
[11:53:30.962] logged_in:53 logged in
[11:53:31.976] process_status:1279 process status
[11:53:33.567] log_message:80 log: 10:53:33.567 E [c:/spotify/libspotify/client/core/network/proxy_resolver_win32.cpp:224] WinHttpGetProxyForUrl failed
[11:53:33.567] log_message:80 log: 10:53:33.567 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[11:53:33.661] log_message:80 log: 10:53:33.661 I [ap:1224] Connected to AP: 193.182.8.35:4070


Hope this is what you need to see?

Again many thanks, Tim.

Triode
2013-09-08, 04:04
Hi there,

Here's another odd on on the Boom I can access the libraries not a problem but as soon as I press play it fails to connect and about every 10 seconds it jumps to the next track.

I've looked at my WHS 2011 Firewall and I cannot see any errors.


This is classic symptoms of a firewall problem - I would focus on this now as you can browse so this means the helper app is working ok. Suggest working out why the player can't connect to the helper app - this is likely to result in an error in the main server log, not the helper app log.

Tim-Ann
2013-09-09, 01:12
Hi there,

Please can I clarify are you talking about the main LMS server log or my HP Server log here?

Many thanks, Tim.

Triode
2013-09-09, 10:58
Hi there,

Please can I clarify are you talking about the main LMS server log or my HP Server log here?

Many thanks, Tim.

The LMS server log from the machine you are running the plugin on and which the players are connected to.

Lopern
2013-09-10, 13:29
Triode
after a new WHS 2011 install i am having problems playing any songs from your plugin
and its driving me crazy not finding what the problem is
when i press play the songs in a album skips after a few sec. whit no sound
raly hope you can help me with this
server ver 7.6.1

i also get that the Helper app is not running when i press the test button
the strange thing is that is saying that is running before i press the button

[20:51:35.931] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[20:58:04.512] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[20:58:04.512] process_status:1279 process status
[20:58:07.632] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[20:58:07.632] process_status:1279 process status
[20:58:25.323] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[20:58:25.697] log_message:80 log: 18:58:25.697 I [c:/spotify/libspotify/client/core/offline_authorizer.cpp:289] Unable to login offline: no such user
[20:58:25.713] log_message:80 log: 18:58:25.713 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[20:58:25.884] log_message:80 log: 18:58:25.884 I [ap:1224] Connected to AP: 193.182.8.61:4070
[20:58:26.711] log_message:80 log: 18:58:26.711 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[20:58:27.834] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[20:58:27.834] process_status:1279 process status
[20:58:42.155] main:591 req: toplist.json res: (null) par: q=albums&r=user prot: HTTP/1.0 auth: (null)
[20:58:42.155] main:1184 toplist type: 1 region: 20047
[20:58:42.452] toplist_callback:803 toplist: ok
[20:58:46.336] main:591 req: browse.json res: spotify:album:2Q9oTK48eb85waX1fFJsvj par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.336] main:1026 created album browse
[20:58:46.476] browse_album_callback:542 browse album: ok
[20:58:46.476] metadata_updated:85 new meta
[20:58:46.554] main:591 req: browse.json res: spotify:track:1DUhAeBCT4r66Gu4P3nirG par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.554] main:1050 queuing track browse
[20:58:46.554] process_track:1229 process track
[20:58:46.554] process_track:1253 browse track: ok
[20:58:46.554] main:591 req: browse.json res: spotify:track:4k80K0b6KZ2QjAYkXON7q6 par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.554] main:1050 queuing track browse
[20:58:46.554] process_track:1229 process track
[20:58:46.554] process_track:1253 browse track: ok
[20:58:46.882] main:591 req: browse.json res: spotify:track:1jF7IL57ayN4Ity3jQqGu0 par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.882] main:1050 queuing track browse
[20:58:46.882] process_track:1229 process track
[20:58:46.882] process_track:1253 browse track: ok
[20:58:46.882] main:591 req: browse.json res: spotify:track:1mKXFLRA179hdOWQBwUk9e par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.882] main:1050 queuing track browse
[20:58:46.882] process_track:1229 process track
[20:58:46.882] process_track:1253 browse track: ok
[20:58:46.882] main:591 req: browse.json res: spotify:track:1QNqrsNQ1JVLEwncov3lEY par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.882] main:1050 queuing track browse
[20:58:46.882] process_track:1229 process track
[20:58:46.882] process_track:1253 browse track: ok
[20:58:46.882] main:591 req: browse.json res: spotify:track:1EzyTh2gxdnU9sq3ivtw4w par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.882] main:1050 queuing track browse
[20:58:46.882] process_track:1229 process track
[20:58:46.882] process_track:1253 browse track: ok
[20:58:46.882] main:591 req: browse.json res: spotify:track:5d4Q9bLZWtsL90vvSh8UWr par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.882] main:1050 queuing track browse
[20:58:46.882] process_track:1229 process track
[20:58:46.882] process_track:1253 browse track: ok
[20:58:46.898] main:591 req: browse.json res: spotify:track:2bq6lTZcVtQ6m8bpaVCwA9 par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.898] main:1050 queuing track browse
[20:58:46.898] process_track:1229 process track
[20:58:46.898] process_track:1253 browse track: ok
[20:58:46.898] main:591 req: browse.json res: spotify:track:3030YT1OMJa4bxthLLHuVM par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.898] main:1050 queuing track browse
[20:58:46.898] process_track:1229 process track
[20:58:46.898] process_track:1253 browse track: ok
[20:58:46.898] main:591 req: browse.json res: spotify:track:6l2Q66TlfZqzbRkFrZOMT1 par: (null) prot: HTTP/1.0 auth: (null)
[20:58:46.898] main:1050 queuing track browse
[20:58:46.898] process_track:1229 process track
[20:58:46.898] process_track:1253 browse track: ok
[20:58:48.052] main:591 req: browse.json res: spotify:track:10Hb1MlXsnI7Yi936C97NA par: (null) prot: HTTP/1.0 auth: (null)
[20:58:48.052] main:1050 queuing track browse
[20:58:48.052] process_track:1229 process track
[20:58:48.052] process_track:1253 browse track: ok
[20:58:48.052] main:591 req: browse.json res: spotify:track:5BIL4QX0mLVQGVR0YqkasO par: (null) prot: HTTP/1.0 auth: (null)
[20:58:48.052] main:1050 queuing track browse
[20:58:48.052] process_track:1229 process track
[20:58:48.052] process_track:1253 browse track: ok
[20:58:48.052] main:591 req: browse.json res: spotify:track:1Vqcqt1QwfjWqWXIlDGaMZ par: (null) prot: HTTP/1.0 auth: (null)
[20:58:48.052] main:1050 queuing track browse
[20:58:48.052] process_track:1229 process track
[20:58:48.052] process_track:1253 browse track: ok
[20:58:48.052] main:591 req: browse.json res: spotify:track:37iUoOyvCGbu3tfjxY1usf par: (null) prot: HTTP/1.0 auth: (null)
[20:58:48.052] main:1050 queuing track browse
[20:58:48.052] process_track:1229 process track
[20:58:48.052] process_track:1253 browse track: ok
[20:58:48.052] main:591 req: browse.json res: spotify:track:3LdF68v3DpGluhLtP97s1a par: (null) prot: HTTP/1.0 auth: (null)
[20:58:48.052] main:1050 queuing track browse
[20:58:48.052] process_track:1229 process track
[20:58:48.052] process_track:1253 browse track: ok
[20:58:48.068] main:591 req: browse.json res: spotify:track:4MXX6eANzr0VvZBmgO8OrI par: (null) prot: HTTP/1.0 auth: (null)
[20:58:48.068] main:1050 queuing track browse
[20:58:48.068] process_track:1229 process track
[20:58:48.068] process_track:1253 browse track: ok
[20:58:48.068] main:591 req: browse.json res: spotify:track:6Ip9pqPGZxFAOSHnepy1AI par: (null) prot: HTTP/1.0 auth: (null)
[20:58:48.068] main:1050 queuing track browse
[20:58:48.068] process_track:1229 process track
[20:58:48.068] process_track:1253 browse track: ok
[20:59:21.124] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[20:59:21.514] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[20:59:21.514] main:691 no remembered user
[20:59:21.514] main:1600 bad request for socket or no track
[20:59:21.826] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[20:59:21.826] main:691 no remembered user
[20:59:21.826] main:1600 bad request for socket or no track
[20:59:22.138] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[20:59:22.138] main:691 no remembered user
[20:59:22.138] main:1600 bad request for socket or no track
[20:59:22.450] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[20:59:22.450] main:691 no remembered user
[20:59:22.450] main:1600 bad request for socket or no track
[20:59:22.762] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[20:59:22.762] main:691 no remembered user
[20:59:22.762] main:1600 bad request for socket or no track
[20:59:23.074] main:591 req: status.json res: (null) par: login prot: HTTP/1.0 auth: (null)
[20:59:23.074] main:691 no remembered user
[20:59:23.074] main:1600 bad request for socket or no track
[21:03:22.004] main:591 req: prefetch.json res: spotify:track:1QNqrsNQ1JVLEwncov3lEY par: (null) prot: HTTP/1.0 auth: (null)
[21:03:22.004] main:691 no remembered user
[21:03:22.004] main:1600 bad request for socket or no track
[21:26:25.134] main:591 req: cover.jpg res: spotify:image:93ba0ad6ae797ddf9adb3e7e9fe29d79dcbb 31de par: (null) prot: HTTP/1.0 auth: (null)
[21:26:25.134] main:691 no remembered user
[21:26:25.134] main:1600 bad request for socket or no track
[21:26:25.149] main:591 req: cover.jpg res: spotify:image:93ba0ad6ae797ddf9adb3e7e9fe29d79dcbb 31de par: (null) prot: HTTP/1.0 auth: (null)
[21:26:25.149] main:691 no remembered user
[21:26:25.180] main:1600 bad request for socket or no track
[21:30:57.510] main:591 req: cover.jpg res: spotify:image:93ba0ad6ae797ddf9adb3e7e9fe29d79dcbb 31de par: (null) prot: HTTP/1.0 auth: (null)
[21:30:57.510] main:691 no remembered user
[21:30:57.510] main:1600 bad request for socket or no track
[21:30:57.510] main:591 req: cover.jpg res: spotify:image:93ba0ad6ae797ddf9adb3e7e9fe29d79dcbb 31de par: (null) prot: HTTP/1.0 auth: (null)
[21:30:57.510] main:691 no remembered user
[21:30:57.510] main:1600 bad request for socket or no track
[21:56:34.331] main:591 req: toplist.json res: (null) par: q=tracks&r=user prot: HTTP/1.0 auth: (null)
[21:56:34.331] main:691 no remembered user
[21:56:34.331] main:1600 bad request for socket or no track
[21:56:39.339] main:591 req: toplist.json res: (null) par: q=tracks&r=user prot: HTTP/1.0 auth: (null)
[21:56:39.339] main:691 no remembered user
[21:56:39.339] main:1600 bad request for socket or no track
[21:56:44.346] main:591 req: toplist.json res: (null) par: q=tracks&r=user prot: HTTP/1.0 auth: (null)
[21:56:44.346] main:691 no remembered user
[21:56:44.346] main:1600 bad request for socket or no track
[21:56:49.354] main:591 req: toplist.json res: (null) par: q=tracks&r=user prot: HTTP/1.0 auth: (null)

rbarron00
2013-09-10, 19:37
Hi Triode,

Are you available for a commercial job to get squeezelite working on android?

Thanks,
Rob

Tim-Ann
2013-09-13, 10:55
Hi there,

Does this LMS 7.8 log make any sense, repeat it is only not working on my Booms, I can get into Spotify see my playlists but as above when I click on a track in my Playlists it says connecting then after a few seconds it jumps to the next track but no sound, again this is only on my Booms. Nor do I see any errors in the Server logs.

[13-09-07 14:19:47.0583] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 14:19:47.7603] Slim::Utils::SQLiteHelper::postConnect (359) Optimizing DB because of missing or empty sqlite_stat1 table
[13-09-07 14:19:47.8132] Slim::Schema::init (162) Warning: Creating new database - empty, outdated or invalid database found
[13-09-07 14:19:58.6959] Slim::Plugin::MusicMagic::Plugin::initPlugin (268) Can't connect to port 10002 - MusicIP disabled.
[13-09-07 14:19:59.3569] main::checkDataSource (1077) Warning: Schema updated or no media found in the database, initiating scan.
[13-09-07 14:20:06.2495] Slim::Utils::SQLiteHelper::postConnect (359) Optimizing DB because of missing or empty sqlite_stat1 table
[13-09-07 14:20:12.8914] Slim::Utils::SQLiteHelper::postConnect (359) Optimizing DB because of missing or empty sqlite_stat1 table
[13-09-07 14:30:55.5523] Slim::Schema::forceCommit (2130) Warning: Trying to commit transactions before DB is initialized!
[13-09-07 14:31:06.3632] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 14:31:07.0808] Slim::Utils::SQLiteHelper::postConnect (359) Optimizing DB because of missing or empty sqlite_stat1 table
[13-09-07 14:34:40.4228] Slim::Networking::IO::Select::__ANON__ (147) Error: Select task failed calling Slim::Networking::Async::_async_read: illegal file descriptor or filehandle (either no attached file descriptor or illegal value): at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 150.
; fh=Slim::Networking::Async::Socket::HTTP=GLOB(0xa7 19c54)
[13-09-07 15:20:36.9701] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 15:26:27.5831] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 15:32:02.6083] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 15:40:18.8856] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 15:49:30.5187] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 16:13:37.6993] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-07 16:30:58.3039] Slim::Control::XMLBrowser::_cliQuery_error (1675) Error: While retrieving [http://www.mysqueezebox.com/api/appgallery/v1/opml]: [A mysqueezebox.com account is required for this service. Please access Logitech Media Server Settings -> mysqueezebox.com with a web browser to configure.]
[13-09-08 11:06:55.9703] Slim::Schema::forceCommit (2130) Warning: Trying to commit transactions before DB is initialized!
[13-09-08 11:07:04.3168] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-08 11:22:02.3270] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-08 21:07:03.5530] Slim::Utils::PluginManager::shutdownPlugins (365) Shutting down plugins...
[13-09-08 21:07:04.5624] Slim::bootstrap::theEND (436) Got to the END
[13-09-08 21:07:17.7448] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-09 13:07:27.0032] Slim::Utils::Cache::cleanup (252) Cache purge: cache - 0.000000 sec
[13-09-09 21:07:23.0079] Slim::Utils::PluginDownloader::checkForUpdates (241) generating apps query to find latest plugin state
[13-09-09 21:07:27.0017] Slim::Utils::Cache::cleanup (252) Cache purge: cache - 0.000000 sec
[13-09-10 01:52:55.6262] Slim::Utils::Firmware::downloadAsyncError (572) Warning: Firmware: Failed to download http://update.mysqueezebox.com/update/firmware/7.8.0/baby.version (Couldn't resolve IP address for: update.mysqueezebox.com), will try again in 10 minutes.
[13-09-10 05:07:27.0004] Slim::Utils::Cache::cleanup (252) Cache purge: cache - 0.000000 sec
[13-09-10 13:07:27.0052] Slim::Utils::Cache::cleanup (252) Cache purge: cache - 0.000000 sec
[13-09-10 20:57:22.4113] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-10 20:58:15.6617] Slim::Plugin::Extensions::Settings::handler (33) attempt to set params with band random number - ignoring
[13-09-11 10:07:59.2714] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-11 16:24:35.6595] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-13 18:51:59.2412] main::init (355) Starting Logitech Media Server (v7.8.0, 1378498243, Sat Sep 7 06:09:27 CUT 2013) perl 5.014001
[13-09-13 18:52:07.8229] Slim::Plugin::Extensions::Settings::handler (33) attempt to set params with band random number - ignoring

Many thanks, Tim.

Triode
2013-09-13, 12:29
Hi there,

Does this LMS 7.8 log make any sense, repeat it is only not working on my Booms, I can get into Spotify see my playlists but as above when I click on a track in my Playlists it says connecting then after a few seconds it jumps to the next track but no sound, again this is only on my Booms. Nor do I see any errors in the Server logs.


Nothing specific in the log. Can you browse via the menus from the 3rd party plugin - if so the helper app is running. In this case I still suspect the firewall as it is all working except playback from a player?

Tim-Ann
2013-09-13, 13:28
Hi there,

Yes on both versions of Spotify I can browse it is just when I click play that it doesn't work. But if it is a Firewall issue why does it work without this problem on my Radio's and with Squeezeplay, yet not on the Booms?

Many thanks, Tim.

Mnyb
2013-09-13, 13:43
Hi there,

Yes on both versions of Spotify I can browse it is just when I click play that it doesn't work. But if it is a Firewall issue why does it work without this problem on my Radio's and with Squeezeplay, yet not on the Booms?

Many thanks, Tim.

Have you simply tried to turn of the fw on the whs just to test ? It would not take many minutes , then you know .

Triode
2013-09-13, 15:25
Hi there,

Yes on both versions of Spotify I can browse it is just when I click play that it doesn't work. But if it is a Firewall issue why does it work without this problem on my Radio's and with Squeezeplay, yet not on the Booms?

Many thanks, Tim.

Radios will stream direct using the firmware spotify processing. Squeezeplay is probably allowed by the firewall? Its definitely a network/firewall problem if squeezeplay works and the boom doesn't.

Tim-Ann
2013-09-14, 02:51
Hi there,

Again you are spot on if I turn off the Home part of WHS 2011 Firewall it works but call me OCD I'm not that keen on the Home part of the Firewall being turned off so is there a way around this and more importantly why would this occur, yet it does not happen on my Mac mini?

I've reinstalled LMS 7.8 and below todays log not sure if that will help?

[13-09-14 10:49:17.1988] Slim::Utils::PluginManager::load (228) Skipping plugin: Podcast - disabled
[13-09-14 10:49:17.1990] Slim::Utils::PluginManager::load (239) Loading plugin: PreventStandby
[13-09-14 10:49:17.2088] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\PreventSta ndby\HTML]
[13-09-14 10:49:17.2089] Slim::Utils::PluginManager::load (228) Skipping plugin: RS232 - disabled
[13-09-14 10:49:17.2091] Slim::Utils::PluginManager::load (239) Loading plugin: RSSNews
[13-09-14 10:49:17.2362] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\RSSNews\HT ML]
[13-09-14 10:49:17.2364] Slim::Utils::PluginManager::load (239) Loading plugin: RadioTime
[13-09-14 10:49:17.2373] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\RadioTime\ HTML]
[13-09-14 10:49:17.2375] Slim::Utils::PluginManager::load (239) Loading plugin: RandomPlay
[13-09-14 10:49:17.2551] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\RandomPlay \HTML]
[13-09-14 10:49:17.2553] Slim::Utils::PluginManager::load (239) Loading plugin: Rescan
[13-09-14 10:49:17.2752] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\Rescan\HTM L]
[13-09-14 10:49:17.2753] Slim::Utils::PluginManager::load (239) Loading plugin: RhapsodyDirect
[13-09-14 10:49:17.3049] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\RhapsodyDi rect\HTML]
[13-09-14 10:49:17.3051] Slim::Utils::PluginManager::load (239) Loading plugin: SN
[13-09-14 10:49:17.3231] Slim::Utils::PluginManager::load (239) Loading plugin: SavePlaylist
[13-09-14 10:49:17.3372] Slim::Utils::PluginManager::load (239) Loading plugin: Sirius
[13-09-14 10:49:17.3548] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\Sirius\HTM L]
[13-09-14 10:49:17.3550] Slim::Utils::PluginManager::load (239) Loading plugin: Slacker
[13-09-14 10:49:17.3771] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\Slacker\HT ML]
[13-09-14 10:49:17.3773] Slim::Utils::PluginManager::load (228) Skipping plugin: SlimTris - disabled
[13-09-14 10:49:17.3774] Slim::Utils::PluginManager::load (228) Skipping plugin: Snow - disabled
[13-09-14 10:49:17.3776] Slim::Utils::PluginManager::load (239) Loading plugin: SongScanner
[13-09-14 10:49:17.3890] Slim::Utils::PluginManager::load (239) Loading plugin: Sounds
[13-09-14 10:49:17.4064] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\Sounds\HTM L]
[13-09-14 10:49:17.4066] Slim::Utils::PluginManager::load (239) Loading plugin: Spotify
[13-09-14 10:49:17.5794] Slim::Utils::PluginManager::load (317) Adding Bin directory: [C:\ProgramData\Squeezebox\Cache\InstalledPlugins\P lugins\Spotify\Bin]
[13-09-14 10:49:17.5798] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\ProgramData\Squeezebox\Cache\InstalledPlugins\P lugins\Spotify\HTML]
[13-09-14 10:49:17.5800] Slim::Utils::PluginManager::load (239) Loading plugin: SpotifyLogi
[13-09-14 10:49:17.6016] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\SpotifyLog i\HTML]
[13-09-14 10:49:17.6018] Slim::Utils::PluginManager::load (239) Loading plugin: TrackStatPlaylist
[13-09-14 10:49:17.6178] Slim::Utils::PluginManager::load (239) Loading plugin: UPnP
[13-09-14 10:49:17.6284] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\UPnP\HTML]
[13-09-14 10:49:17.6286] Slim::Utils::PluginManager::load (239) Loading plugin: Visualizer
[13-09-14 10:49:17.6355] Slim::Utils::PluginManager::load (239) Loading plugin: WiMP
[13-09-14 10:49:17.6492] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\WiMP\HTML]
[13-09-14 10:49:17.6494] Slim::Utils::PluginManager::load (239) Loading plugin: iTunes
[13-09-14 10:49:17.6663] Slim::Utils::PluginManager::load (329) Adding HTML directory: [C:\PROGRA~2\SQUEEZ~1\server\Slim\Plugin\iTunes\HTM L]
[13-09-14 10:49:17.6665] Slim::Utils::PluginManager::load (228) Skipping plugin: xPL - disabled
[13-09-14 10:49:24.2659] Slim::Utils::PluginDownloader::checkForUpdates (241) generating apps query to find latest plugin state
[13-09-14 10:49:24.3575] main::init (565) Server Jive init...
[13-09-14 10:49:24.3580] main::init (568) Remote Metadata init...
[13-09-14 10:49:24.3922] main::init (577) Server checkDataSource...
[13-09-14 10:49:24.3938] main::init (587) Library Browser init...
[13-09-14 10:49:24.3946] main::init (591) Server persist playlists...
[13-09-14 10:49:24.3948] main::init (627) Server HTTP enable...
[13-09-14 10:49:25.4263] main::init (635) Server done init...
[13-09-14 10:49:25.5522] Slim::Utils::Cache::cleanup (256) Cache purge: cache - skipping, purged recently
[13-09-14 10:49:26.8532] Slim::Utils::Strings::storeExtraStrings (413) Reading extrastrings.json file



Again thanks for you patience and most helpful posts.

Tim.

Triode
2013-09-14, 03:41
Hi there,

Again you are spot on if I turn off the Home part of WHS 2011 Firewall it works but call me OCD I'm not that keen on the Home part of the Firewall being turned off so is there a way around this and more importantly why would this occur, yet it does not happen on my Mac mini?



This is now nothing to do with LMS or the plugin - its down to how WHS firewall works - I'm afraid I can't comment on this, but you need to focus on the firewall not LMS logs to fix this!

Mnyb
2013-09-14, 03:49
Most good firewalls have the possibility for you to configure the apropriate ports and applications ?
LMS itself may have auto configured it ports ( if it's windows own fw ) but the helper app and it's port you may have to configure yourself .

Lopern
2013-09-14, 06:00
This is now nothing to do with LMS or the plugin - its down to how WHS firewall works - I'm afraid I can't comment on this, but you need to focus on the firewall not LMS logs to fix this!

Thank you guys that was the Prob!! :D:D:D

Tim give me a head up if you come with a solution regarding your fire wall settings :confused:

Lopern
2013-09-14, 11:35
Ok the Problem is that Spotifyd dosent have Firewall Permission in WHS 2011

Go in to Firewall settings (remote desktop) add new prog browse for spotifyd and add it to the list of firewall program list

problem solved :o

Tim-Ann
2013-09-17, 05:11
Hi there,

Well I decided to do a clean install of WHS 2011 and you've guessed it still Spotify did not work but just seen the post above need to work out how to do that to try it, just out of interest this was my new LMS Debug Streaming log.

[04:31:44.408] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[04:32:21.503] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:32:21.581] process_status:1279 process status
[04:32:27.915] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:32:27.915] process_status:1279 process status
[04:32:50.050] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[04:32:50.518] log_message:80 log: 11:32:50.518 I [c:/spotify/libspotify/client/core/offline_authorizer.cpp:289] Unable to login offline: no such user
[04:32:50.565] log_message:80 log: 11:32:50.565 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[04:32:50.674] log_message:80 log: 11:32:50.674 I [ap:1224] Connected to AP: 193.182.8.60:4070
[04:32:51.673] log_message:80 log: 11:32:51.673 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[04:32:52.765] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:32:52.765] process_status:1279 process status
[04:36:33.139] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[04:37:59.763] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:37:59.763] process_status:1279 process status
[04:38:07.110] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:38:07.110] process_status:1279 process status
[04:38:19.715] log_message:80 log: 11:38:19.715 I [user_cache:138] UserCache::initiateGetUsers() will query for 1 users
[04:38:19.746] log_message:80 log: 11:38:19.746 I [ap:1766] Connecting to AP ap.gslb.spotify.com:4070
[04:38:19.839] log_message:80 log: 11:38:19.839 I [ap:1224] Connected to AP: 193.182.8.86:4070
[04:38:20.822] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:38:20.822] process_status:1279 process status
[04:42:51.545] main:420 C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotif y\Bin\MSWIN3~1\spotifyd.exe 2.2.16 started
[04:45:29.966] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:45:29.982] main:691 no remembered user
[04:45:29.982] main:1600 bad request for socket or no track
[04:45:34.990] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:45:34.990] main:691 no remembered user
[04:45:34.990] main:1600 bad request for socket or no track
[04:45:39.997] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:45:39.997] main:691 no remembered user
[04:45:39.997] main:1600 bad request for socket or no track
[04:45:45.005] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:45:45.005] main:691 no remembered user
[04:45:45.005] main:1600 bad request for socket or no track
[04:45:50.013] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:45:50.013] main:691 no remembered user
[04:45:50.013] main:1600 bad request for socket or no track
[04:45:55.021] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:45:55.021] main:691 no remembered user
[04:45:55.021] main:1600 bad request for socket or no track
[04:46:00.029] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:46:00.029] main:691 no remembered user
[04:46:00.029] main:1600 bad request for socket or no track
[04:46:05.037] main:591 req: playlists.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[04:46:05.037] main:691 no remembered user
[04:46:05.037] main:1600 bad request for socket or no track
[05:05:46.504] main:591 req: status.json res: (null) par: (null) prot: HTTP/1.0 auth: (null)
[05:05:46.504] process_status:1279 process status

Now where and how to add Spotify to the Firewall, wish me luck.

Quick question is it the Spotify.exe that resides in Program Data, Squeezebox/cache/installed plugins/plugins/Spotify/bin/MSwin32x86/Spotify.exe?

Many thanks everyone, Tim.

garym
2013-09-17, 12:22
Quick question is it the Spotify.exe that resides in Program Data, Squeezebox/cache/installed plugins/plugins/Spotify/bin/MSwin32x86/Spotify.exe?

Many thanks everyone, Tim.

it is:
spotifyd.exe

(note the "d" after spotify)

Triode
2013-09-17, 12:28
Hi there,

Well I decided to do a clean install of WHS 2011 and you've guessed it still Spotify did not work but just seen the post above need to work out how to do that to try it, just out of interest this was my new LMS Debug Streaming log.

Now where and how to add Spotify to the Firewall, wish me luck.

Quick question is it the Spotify.exe that resides in Program Data, Squeezebox/cache/installed plugins/plugins/Spotify/bin/MSwin32x86/Spotify.exe?

Many thanks everyone, Tim.

This log shows you still need to enter your password. Once you have this fixed then look to make spotifyd.exe allowed by the firewall.

Tim-Ann
2013-09-17, 13:06
Hi there,

Cheers I misread it as Spotify.exe but there was a d and all is now working, phew.

Thanks everyone for your patience and quick responses I've learnt a little bit more today.

Many thanks, Tim.