I have mopidy with spotify extension, installed on a Synology NAS via a debian chroot setup. It worked like a charm for months now. However after a system update on the NAS mopidy stopped working (previous system updates had been no problem). After a bit fiddling I got mopify working but kept getting disconnected to spotify (login seemed to work). I then tried to reinstall mopidy and all its extensions on the system. And after this the spotify extension cant login to spotify. I get following error when staring mopify;
ERROR Spotify login error: Cannot connect to Spotify
Naturally I’ve double and tripple checked the spotify login and password. So I wonder if anyone here can help me get a clue of the error for this…
edit: When uninstalling mopify I did remove ~/.cache/mopidy/spotify folder… in it was a User folder that has’nt been recreated since.
I ran mopidy with the “–save-debug-log” flag and here is the log;
INFO 2015-05-13 14:15:33,289 [18156:MainThread] mopidy.__main__
Starting Mopidy 1.0.4
DEBUG 2015-05-13 14:15:33,308 [18156:MainThread] mopidy.ext
Loading entry point: spotify = mopidy_spotify:Extension
DEBUG 2015-05-13 14:15:33,310 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-Spotify 1.3.0
DEBUG 2015-05-13 14:15:33,325 [18156:MainThread] mopidy.ext
Loading entry point: mopify = mopidy_mopify:MopifyExtension
DEBUG 2015-05-13 14:15:33,677 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-Mopify 1.4.2
DEBUG 2015-05-13 14:15:33,698 [18156:MainThread] mopidy.ext
Loading entry point: mpd = mopidy.mpd:Extension
DEBUG 2015-05-13 14:15:33,699 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-MPD 1.0.4
DEBUG 2015-05-13 14:15:33,699 [18156:MainThread] mopidy.ext
Loading entry point: http = mopidy.http:Extension
DEBUG 2015-05-13 14:15:33,701 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-HTTP 1.0.4
DEBUG 2015-05-13 14:15:33,701 [18156:MainThread] mopidy.ext
Loading entry point: stream = mopidy.stream:Extension
DEBUG 2015-05-13 14:15:33,702 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-Stream 1.0.4
DEBUG 2015-05-13 14:15:33,702 [18156:MainThread] mopidy.ext
Loading entry point: m3u = mopidy.m3u:Extension
DEBUG 2015-05-13 14:15:33,703 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-M3U 1.0.4
DEBUG 2015-05-13 14:15:33,703 [18156:MainThread] mopidy.ext
Loading entry point: softwaremixer = mopidy.softwaremixer:Extension
DEBUG 2015-05-13 14:15:33,704 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-SoftwareMixer 1.0.4
DEBUG 2015-05-13 14:15:33,704 [18156:MainThread] mopidy.ext
Loading entry point: local = mopidy.local:Extension
DEBUG 2015-05-13 14:15:33,706 [18156:MainThread] mopidy.ext
Loaded extension: Mopidy-Local 1.0.4
DEBUG 2015-05-13 14:15:33,708 [18156:MainThread] mopidy.ext
Discovered extensions: spotify, mopify, mpd, http, stream, m3u, softwaremixer, local
DEBUG 2015-05-13 14:15:33,739 [18156:MainThread] mopidy.config.keyring
Fetching passwords from your keyring failed. Any passwords stored in the keyring will not be available. (dbus not installed)
INFO 2015-05-13 14:15:33,740 [18156:MainThread] mopidy.config
Loading config from builtin defaults
DEBUG 2015-05-13 14:15:33,751 [18156:MainThread] mopidy.config
Loading config from /etc/xdg/mopidy/mopidy.conf failed; it does not exist
INFO 2015-05-13 14:15:33,751 [18156:MainThread] mopidy.config
Loading config from /root/.config/mopidy/mopidy.conf
INFO 2015-05-13 14:15:33,757 [18156:MainThread] mopidy.config
Loading config from command line options
DEBUG 2015-05-13 14:15:33,787 [18156:MainThread] mopidy.ext
Validating extension: spotify
DEBUG 2015-05-13 14:15:33,798 [18156:MainThread] mopidy.ext
Validating extension: mopify
DEBUG 2015-05-13 14:15:33,811 [18156:MainThread] mopidy.ext
Validating extension: mpd
DEBUG 2015-05-13 14:15:33,816 [18156:MainThread] mopidy.ext
Validating extension: http
DEBUG 2015-05-13 14:15:33,821 [18156:MainThread] mopidy.ext
Validating extension: stream
DEBUG 2015-05-13 14:15:33,827 [18156:MainThread] mopidy.ext
Validating extension: m3u
DEBUG 2015-05-13 14:15:33,832 [18156:MainThread] mopidy.ext
Validating extension: softwaremixer
DEBUG 2015-05-13 14:15:33,839 [18156:MainThread] mopidy.ext
Validating extension: local
INFO 2015-05-13 14:15:33,844 [18156:MainThread] mopidy.__main__
Enabled extensions: mopify, spotify, mpd, softwaremixer, http
INFO 2015-05-13 14:15:33,846 [18156:MainThread] mopidy.__main__
Disabled extensions: m3u, local, stream
DEBUG 2015-05-13 14:15:34,003 [18156:MainThread] mopidy.commands
Available Mopidy mixers: SoftwareMixer
INFO 2015-05-13 14:15:34,004 [18156:MainThread] mopidy.commands
Starting Mopidy mixer: SoftwareMixer
DEBUG 2015-05-13 14:15:34,009 [18156:MainThread] pykka
Registered SoftwareMixer (urn:uuid:f549fc3d-19e0-4ea4-91a8-c4cc1d8a1ce2)
DEBUG 2015-05-13 14:15:34,010 [18156:MainThread] pykka
Starting SoftwareMixer (urn:uuid:f549fc3d-19e0-4ea4-91a8-c4cc1d8a1ce2)
DEBUG 2015-05-13 14:15:34,013 [18156:MainThread] mopidy.commands
Mixer volume left unchanged
INFO 2015-05-13 14:15:34,014 [18156:MainThread] mopidy.commands
Starting Mopidy audio
DEBUG 2015-05-13 14:15:34,017 [18156:MainThread] pykka
Registered Audio (urn:uuid:be66f0aa-670c-4651-843e-8e2cc9c7ddb7)
DEBUG 2015-05-13 14:15:34,018 [18156:MainThread] pykka
Starting Audio (urn:uuid:be66f0aa-670c-4651-843e-8e2cc9c7ddb7)
INFO 2015-05-13 14:15:34,023 [18156:MainThread] mopidy.commands
Starting Mopidy backends: SpotifyBackend
DEBUG 2015-05-13 14:15:34,046 [18156:MainThread] pykka
Registered SpotifyBackend (urn:uuid:16e579a1-0783-4013-993f-716bfc81e81d)
DEBUG 2015-05-13 14:15:34,047 [18156:MainThread] pykka
Starting SpotifyBackend (urn:uuid:16e579a1-0783-4013-993f-716bfc81e81d)
INFO 2015-05-13 14:15:34,059 [18156:SpotifyBackend-4] mopidy_spotify.backend
Mopidy uses SPOTIFY(R) CORE
DEBUG 2015-05-13 14:15:34,061 [18156:SpotifyBackend-4] mopidy_spotify.backend
Connecting to Spotify
DEBUG 2015-05-13 14:15:34,069 [18156:SpotifyThread] mopidy.utils.process
SpotifyThread: Starting thread
TRACE 2015-05-13 14:15:34,088 [18156:MainThread] mopidy.utils.timer
SpotifyBackend took 62ms
INFO 2015-05-13 14:15:34,089 [18156:MainThread] mopidy.commands
Starting Mopidy core
INFO 2015-05-13 14:15:34,091 [18156:Audio-2] mopidy.audio.actor
Audio output set to "autoaudiosink"
DEBUG 2015-05-13 14:15:34,106 [18156:SpotifyThread] mopidy_spotify.session_manager
System message: 11:15:34.106 I [offline_authorizer.cpp:297] Unable to login offline: no such user
DEBUG 2015-05-13 14:15:34,110 [18156:MainThread] pykka
Registered Core (urn:uuid:cbaece4a-c8de-496b-a5ea-5c5e5642c825)
DEBUG 2015-05-13 14:15:34,111 [18156:MainThread] pykka
Starting Core (urn:uuid:cbaece4a-c8de-496b-a5ea-5c5e5642c825)
DEBUG 2015-05-13 14:15:34,112 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:34.112 I [ap:1752] Connecting to AP ap.spotify.com:4070
DEBUG 2015-05-13 14:15:34,116 [18156:SpotifyThread] pyspotify.manager.session
No message received before timeout. Processing events
DEBUG 2015-05-13 14:15:34,117 [18156:SpotifyThread] pyspotify.manager.session
Will wait 300.398s for next message
INFO 2015-05-13 14:15:34,232 [18156:MainThread] mopidy.commands
Starting Mopidy frontends: MpdFrontend, HttpFrontend
INFO 2015-05-13 14:15:34,246 [18156:MainThread] mopidy.mpd.actor
MPD server running at [::ffff:127.0.0.1]:6600
DEBUG 2015-05-13 14:15:34,248 [18156:MainThread] pykka
Registered MpdFrontend (urn:uuid:d518c338-3293-4036-856d-a142238dd704)
DEBUG 2015-05-13 14:15:34,252 [18156:MainThread] pykka
Starting MpdFrontend (urn:uuid:d518c338-3293-4036-856d-a142238dd704)
TRACE 2015-05-13 14:15:34,260 [18156:MainThread] mopidy.utils.timer
MpdFrontend took 24ms
DEBUG 2015-05-13 14:15:34,262 [18156:MainThread] mopidy.http.actor
Starting HTTP server
DEBUG 2015-05-13 14:15:34,266 [18156:MpdFrontend-7] mopidy.zeroconf
Zeroconf service _mpd._tcp at [Totoro.local]:6600: dbus not installed; publish failed.
DEBUG 2015-05-13 14:15:34,267 [18156:MainThread] pykka
Registered HttpFrontend (urn:uuid:3004135c-f1f3-4f28-bfd9-07119e034ccb)
DEBUG 2015-05-13 14:15:34,268 [18156:MainThread] pykka
Starting HttpFrontend (urn:uuid:3004135c-f1f3-4f28-bfd9-07119e034ccb)
TRACE 2015-05-13 14:15:34,275 [18156:MainThread] mopidy.utils.timer
HttpFrontend took 14ms
INFO 2015-05-13 14:15:34,276 [18156:HttpFrontend-9] mopidy.http.actor
HTTP server running at [::]:6680
DEBUG 2015-05-13 14:15:34,285 [18156:HttpServer] mopidy.http.actor
Loaded HTTP extension: mopify
DEBUG 2015-05-13 14:15:34,286 [18156:HttpServer] mopidy.http.actor
Loaded HTTP extension: mopidy
DEBUG 2015-05-13 14:15:34,287 [18156:HttpServer] mopidy.http.actor
HTTP routes from extensions:
u'/mopify': <class 'mopidy.http.handlers.AddSlashHandler'>
u'/mopify/sync/(.*)': <class 'mopidy_mopify.sync.RootRequestHandler'>
u'/mopify/update': <class 'mopidy_mopify.update.UpdateRequestHandler'>
u'/mopify/(.*)': <class 'tornado.web.StaticFileHandler'>
u'/mopidy': <class 'mopidy.http.handlers.AddSlashHandler'>
u'/mopidy/ws/?': <class 'mopidy.http.handlers.WebSocketHandler'>
u'/mopidy/rpc': <class 'mopidy.http.handlers.JsonRpcHandler'>
u'/mopidy/(.+)': <class 'mopidy.http.handlers.StaticFileHandler'>
u'/mopidy/': <class 'mopidy.http.handlers.ClientListHandler'>
u'/': <class 'tornado.web.RedirectHandler'>
DEBUG 2015-05-13 14:15:34,295 [18156:HttpFrontend-9] mopidy.zeroconf
Zeroconf service _http._tcp at [Totoro.local]:6680: dbus not installed; publish failed.
DEBUG 2015-05-13 14:15:34,296 [18156:HttpFrontend-9] mopidy.zeroconf
Zeroconf service _mopidy-http._tcp at [Totoro.local]:6680: dbus not installed; publish failed.
DEBUG 2015-05-13 14:15:39,115 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:39.115 E [ap:1694] AP Socket Error: Timeout reached (20000)
DEBUG 2015-05-13 14:15:39,116 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:39.116 E [ap:3953] Connection error: 117
DEBUG 2015-05-13 14:15:39,117 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:39.117 I [ap:1752] Connecting to AP ap.spotify.com:443
DEBUG 2015-05-13 14:15:39,121 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
DEBUG 2015-05-13 14:15:39,122 [18156:SpotifyThread] pyspotify.manager.session
Will wait 295.393s for next message
DEBUG 2015-05-13 14:15:44,123 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:44.123 E [ap:1694] AP Socket Error: Timeout reached (20000)
DEBUG 2015-05-13 14:15:44,125 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:44.125 E [ap:3953] Connection error: 117
DEBUG 2015-05-13 14:15:44,157 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:44.157 I [ap:1752] Connecting to AP ap.spotify.com:80
DEBUG 2015-05-13 14:15:44,199 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
DEBUG 2015-05-13 14:15:44,200 [18156:SpotifyThread] pyspotify.manager.session
Will wait 290.315s for next message
DEBUG 2015-05-13 14:15:49,163 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:49.162 E [ap:1694] AP Socket Error: Timeout reached (20000)
DEBUG 2015-05-13 14:15:49,167 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:49.166 E [ap:3953] Connection error: 117
DEBUG 2015-05-13 14:15:49,206 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:49.206 I [ap:1752] Connecting to AP ap.spotify.com:4070
DEBUG 2015-05-13 14:15:49,233 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
DEBUG 2015-05-13 14:15:49,234 [18156:SpotifyThread] pyspotify.manager.session
Will wait 285.281s for next message
DEBUG 2015-05-13 14:15:54,212 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:54.212 E [ap:1694] AP Socket Error: Timeout reached (20000)
DEBUG 2015-05-13 14:15:54,213 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:54.213 E [ap:3953] Connection error: 117
DEBUG 2015-05-13 14:15:54,214 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:54.214 I [ap:1752] Connecting to AP ap.spotify.com:443
DEBUG 2015-05-13 14:15:54,262 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
DEBUG 2015-05-13 14:15:54,263 [18156:SpotifyThread] pyspotify.manager.session
Will wait 280.252s for next message
DEBUG 2015-05-13 14:15:59,260 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:59.260 E [ap:1694] AP Socket Error: Timeout reached (20000)
DEBUG 2015-05-13 14:15:59,262 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:59.262 E [ap:3953] Connection error: 117
DEBUG 2015-05-13 14:15:59,316 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:15:59.316 I [ap:1752] Connecting to AP ap.spotify.com:80
DEBUG 2015-05-13 14:15:59,341 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
DEBUG 2015-05-13 14:15:59,342 [18156:SpotifyThread] pyspotify.manager.session
Will wait 275.173s for next message
DEBUG 2015-05-13 14:16:04,319 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:16:04.319 E [ap:1694] AP Socket Error: Timeout reached (20000)
DEBUG 2015-05-13 14:16:04,321 [18156:Dummy-6] mopidy_spotify.session_manager
System message: 11:16:04.321 E [ap:3953] Connection error: 117
DEBUG 2015-05-13 14:16:04,376 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
DEBUG 2015-05-13 14:16:04,377 [18156:SpotifyThread] pyspotify.manager.session
Will wait 270.138s for next message
DEBUG 2015-05-13 14:16:04,382 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
ERROR 2015-05-13 14:16:04,383 [18156:SpotifyThread] mopidy_spotify.session_manager
Spotify login error: Cannot connect to Spotify
DEBUG 2015-05-13 14:16:04,384 [18156:SpotifyThread] pyspotify.manager.session
Will wait 270.133s for next message
DEBUG 2015-05-13 14:16:04,386 [18156:SpotifyThread] pyspotify.manager.session
Got message; processing events
INFO 2015-05-13 14:16:04,387 [18156:SpotifyThread] mopidy_spotify.session_manager
Disconnected from Spotify
DEBUG 2015-05-13 14:16:04,389 [18156:SpotifyThread] pyspotify.manager.session
Will wait 270.128s for next message
DEBUG 2015-05-13 14:16:04,390 [18156:SpotifyThread] pyspotify.manager.session
Got message; stopping main loop
DEBUG 2015-05-13 14:16:04,390 [18156:SpotifyThread] mopidy.utils.process
SpotifyThread: Exiting thread
INFO 2015-05-13 14:16:15,912 [18156:MainThread] mopidy.commands
Interrupted. Exiting...
INFO 2015-05-13 14:16:15,913 [18156:MainThread] mopidy.commands
Stopping Mopidy frontends
DEBUG 2015-05-13 14:16:15,915 [18156:MainThread] mopidy.utils.process
Stopping 1 instance(s) of MpdFrontend
DEBUG 2015-05-13 14:16:15,917 [18156:MpdFrontend-7] pykka
Unregistered MpdFrontend (urn:uuid:d518c338-3293-4036-856d-a142238dd704)
DEBUG 2015-05-13 14:16:15,917 [18156:MpdFrontend-7] pykka
Stopped MpdFrontend (urn:uuid:d518c338-3293-4036-856d-a142238dd704)
DEBUG 2015-05-13 14:16:15,918 [18156:MpdFrontend-7] mopidy.utils.process
Stopping 0 instance(s) of MpdSession
DEBUG 2015-05-13 14:16:15,920 [18156:MainThread] mopidy.utils.process
Stopping 1 instance(s) of HttpFrontend
DEBUG 2015-05-13 14:16:15,921 [18156:HttpFrontend-9] pykka
Unregistered HttpFrontend (urn:uuid:3004135c-f1f3-4f28-bfd9-07119e034ccb)
DEBUG 2015-05-13 14:16:15,922 [18156:HttpFrontend-9] pykka
Stopped HttpFrontend (urn:uuid:3004135c-f1f3-4f28-bfd9-07119e034ccb)
DEBUG 2015-05-13 14:16:15,923 [18156:HttpFrontend-9] mopidy.http.actor
Stopping HTTP server
DEBUG 2015-05-13 14:16:15,924 [18156:HttpServer] mopidy.http.actor
Stopped HTTP server
INFO 2015-05-13 14:16:15,926 [18156:MainThread] mopidy.commands
Stopping Mopidy core
DEBUG 2015-05-13 14:16:15,928 [18156:MainThread] mopidy.utils.process
Stopping 1 instance(s) of Core
DEBUG 2015-05-13 14:16:15,930 [18156:Core-5] pykka
Unregistered Core (urn:uuid:cbaece4a-c8de-496b-a5ea-5c5e5642c825)
DEBUG 2015-05-13 14:16:15,931 [18156:Core-5] pykka
Stopped Core (urn:uuid:cbaece4a-c8de-496b-a5ea-5c5e5642c825)
INFO 2015-05-13 14:16:15,932 [18156:MainThread] mopidy.commands
Stopping Mopidy backends
DEBUG 2015-05-13 14:16:15,934 [18156:MainThread] mopidy.utils.process
Stopping 1 instance(s) of SpotifyBackend
DEBUG 2015-05-13 14:16:15,936 [18156:SpotifyBackend-4] pykka
Unregistered SpotifyBackend (urn:uuid:16e579a1-0783-4013-993f-716bfc81e81d)
DEBUG 2015-05-13 14:16:15,938 [18156:SpotifyBackend-4] pykka
Stopped SpotifyBackend (urn:uuid:16e579a1-0783-4013-993f-716bfc81e81d)
DEBUG 2015-05-13 14:16:15,939 [18156:SpotifyBackend-4] mopidy_spotify.session_manager
Logging out from Spotify
INFO 2015-05-13 14:16:15,941 [18156:MainThread] mopidy.commands
Stopping Mopidy audio
DEBUG 2015-05-13 14:16:15,943 [18156:MainThread] mopidy.utils.process
Stopping 1 instance(s) of Audio
DEBUG 2015-05-13 14:16:15,944 [18156:Audio-2] pykka
Unregistered Audio (urn:uuid:be66f0aa-670c-4651-843e-8e2cc9c7ddb7)
DEBUG 2015-05-13 14:16:15,945 [18156:Audio-2] pykka
Stopped Audio (urn:uuid:be66f0aa-670c-4651-843e-8e2cc9c7ddb7)
INFO 2015-05-13 14:16:15,948 [18156:MainThread] mopidy.commands
Stopping Mopidy mixer
DEBUG 2015-05-13 14:16:15,950 [18156:MainThread] mopidy.utils.process
Stopping 1 instance(s) of SoftwareMixer
DEBUG 2015-05-13 14:16:15,952 [18156:SoftwareMixer-1] pykka
Unregistered SoftwareMixer (urn:uuid:f549fc3d-19e0-4ea4-91a8-c4cc1d8a1ce2)
DEBUG 2015-05-13 14:16:15,953 [18156:SoftwareMixer-1] pykka
Stopped SoftwareMixer (urn:uuid:f549fc3d-19e0-4ea4-91a8-c4cc1d8a1ce2)
DEBUG 2015-05-13 14:16:15,954 [18156:MainThread] mopidy.utils.process
All actors stopped.
And here is my config:
[logging]
color = true
console_format = %(levelname)-8s %(message)s
debug_format = %(levelname)-8s %(asctime)s [%(process)d:%(threadName)s] %(name)s\n %(message)s
debug_file = mopidy.log
config_file =
[audio]
mixer = software
mixer_volume =
output = autoaudiosink
[proxy]
scheme =
hostname =
port =
username =
password =
[spotify]
enabled = true
username = ********
password = ********
bitrate = 160
timeout = 10
cache_dir = $XDG_CACHE_DIR/mopidy/spotify
settings_dir = $XDG_CONFIG_DIR/mopidy/spotify
toplist_countries =
AD
AR
AU
AT
BE
CO
CY
DK
EE
FI
FR
DE
GR
HK
IS
IE
IT
LV
LI
LT
LU
MY
MX
MC
NL
NZ
NO
PT
ES
SG
SE
CH
TW
TR
GB
US
[mopify]
enabled = true
debug = false
[mpd]
enabled = false ; Extension disabled by user config.
[http]
enabled = true
hostname = ::
port = 6680
static_dir =
zeroconf = Mopidy HTTP server on $hostname
[stream]
enabled = false ; Extension disabled by user config.
[m3u]
enabled = false ; Extension disabled by user config.
[softwaremixer]
enabled = true
[local]
enabled = false ; Extension disabled by user config.