INFO 2016-12-24 13:13:56,649 [27039:MainThread] mopidy.__main__ Starting Mopidy 2.0.1 DEBUG 2016-12-24 13:13:56,672 [27039:MainThread] mopidy.ext Loading entry point: mpd = mopidy.mpd:Extension DEBUG 2016-12-24 13:13:56,672 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-MPD 2.0.1 DEBUG 2016-12-24 13:13:56,672 [27039:MainThread] mopidy.ext Loading entry point: http = mopidy.http:Extension DEBUG 2016-12-24 13:13:56,672 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-HTTP 2.0.1 DEBUG 2016-12-24 13:13:56,672 [27039:MainThread] mopidy.ext Loading entry point: stream = mopidy.stream:Extension DEBUG 2016-12-24 13:13:56,672 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-Stream 2.0.1 DEBUG 2016-12-24 13:13:56,672 [27039:MainThread] mopidy.ext Loading entry point: m3u = mopidy.m3u:Extension DEBUG 2016-12-24 13:13:56,673 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-M3U 2.0.1 DEBUG 2016-12-24 13:13:56,673 [27039:MainThread] mopidy.ext Loading entry point: softwaremixer = mopidy.softwaremixer:Extension DEBUG 2016-12-24 13:13:56,673 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-SoftwareMixer 2.0.1 DEBUG 2016-12-24 13:13:56,673 [27039:MainThread] mopidy.ext Loading entry point: file = mopidy.file:Extension DEBUG 2016-12-24 13:13:56,673 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-File 2.0.1 DEBUG 2016-12-24 13:13:56,673 [27039:MainThread] mopidy.ext Loading entry point: local = mopidy.local:Extension DEBUG 2016-12-24 13:13:56,674 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-Local 2.0.1 DEBUG 2016-12-24 13:13:56,675 [27039:MainThread] mopidy.ext Loading entry point: spotify = mopidy_spotify:Extension DEBUG 2016-12-24 13:13:56,675 [27039:MainThread] mopidy.ext Loaded extension: Mopidy-Spotify 3.0.0 DEBUG 2016-12-24 13:13:56,676 [27039:MainThread] mopidy.ext Discovered extensions: mpd, http, stream, m3u, softwaremixer, file, local, spotify DEBUG 2016-12-24 13:13:56,677 [27039:MainThread] mopidy.config.keyring Fetching passwords from your keyring failed. Any passwords stored in the keyring will not be available. (dbus not installed) INFO 2016-12-24 13:13:56,677 [27039:MainThread] mopidy.config Loading config from builtin defaults DEBUG 2016-12-24 13:13:56,678 [27039:MainThread] mopidy.config Loading config from /etc/xdg/mopidy/mopidy.conf failed; it does not exist INFO 2016-12-24 13:13:56,678 [27039:MainThread] mopidy.config Loading config from /home/spenserw/.config/mopidy/mopidy.conf INFO 2016-12-24 13:13:56,679 [27039:MainThread] mopidy.config Loading config from command line options DEBUG 2016-12-24 13:13:56,682 [27039:MainThread] mopidy.ext Validating extension: mpd DEBUG 2016-12-24 13:13:56,683 [27039:MainThread] mopidy.ext Validating extension: http DEBUG 2016-12-24 13:13:56,706 [27039:MainThread] mopidy.ext Validating extension: stream DEBUG 2016-12-24 13:13:56,707 [27039:MainThread] mopidy.ext Validating extension: m3u DEBUG 2016-12-24 13:13:56,707 [27039:MainThread] mopidy.ext Validating extension: softwaremixer DEBUG 2016-12-24 13:13:56,708 [27039:MainThread] mopidy.ext Validating extension: file DEBUG 2016-12-24 13:13:56,709 [27039:MainThread] mopidy.ext Validating extension: local DEBUG 2016-12-24 13:13:56,710 [27039:MainThread] mopidy.ext Validating extension: spotify INFO 2016-12-24 13:13:56,715 [27039:MainThread] mopidy.__main__ Enabled extensions: spotify, mpd, http, stream, m3u, softwaremixer, file INFO 2016-12-24 13:13:56,715 [27039:MainThread] mopidy.__main__ Disabled extensions: local WARNING 2016-12-24 13:13:56,715 [27039:MainThread] mopidy.__main__ Found local configuration errors, the extension has been automatically disabled: WARNING 2016-12-24 13:13:56,715 [27039:MainThread] mopidy.__main__ local/media_dir must be set. WARNING 2016-12-24 13:13:56,715 [27039:MainThread] mopidy.__main__ Please fix the extension configuration errors or disable the extensions to silence these messages. DEBUG 2016-12-24 13:13:56,769 [27039:MainThread] mopidy.commands Available Mopidy mixers: SoftwareMixer INFO 2016-12-24 13:13:56,770 [27039:MainThread] mopidy.commands Starting Mopidy mixer: SoftwareMixer DEBUG 2016-12-24 13:13:56,771 [27039:MainThread] mopidy.commands Mixer volume left unchanged INFO 2016-12-24 13:13:56,771 [27039:MainThread] mopidy.commands Starting Mopidy audio INFO 2016-12-24 13:13:56,772 [27039:MainThread] mopidy.commands Starting Mopidy backends: StreamBackend, M3UBackend, FileBackend, SpotifyBackend DEBUG 2016-12-24 13:13:56,780 [27039:MainThread] mopidy.file.library Failed expanding path ($XDG_MUSIC_DIR) from file/media_dirs config value. INFO 2016-12-24 13:13:56,786 [27039:Audio-2] mopidy.audio.actor Audio output set to "autoaudiosink" INFO 2016-12-24 13:13:56,852 [27039:MainThread] mopidy.commands Starting Mopidy core INFO 2016-12-24 13:13:56,860 [27039:SpotifyEventLoop] mopidy_spotify.backend Logged in to Spotify in offline mode INFO 2016-12-24 13:13:57,022 [27039:MainThread] mopidy.commands Starting Mopidy frontends: MpdFrontend, HttpFrontend INFO 2016-12-24 13:13:57,023 [27039:MainThread] mopidy.mpd.actor MPD server running at [::ffff:127.0.0.1]:6600 DEBUG 2016-12-24 13:13:57,024 [27039:MpdFrontend-10] mopidy.zeroconf Zeroconf service "None" (_mpd._tcp at []:6600): dbus not installed; publish failed. DEBUG 2016-12-24 13:13:57,024 [27039:MainThread] mopidy.http.actor Starting HTTP server INFO 2016-12-24 13:13:57,025 [27039:HttpFrontend-12] mopidy.http.actor HTTP server running at [::ffff:127.0.0.1]:6680 INFO 2016-12-24 13:13:57,025 [27039:MainThread] mopidy.commands Starting GLib mainloop DEBUG 2016-12-24 13:13:57,025 [27039:HttpServer] mopidy.http.actor Loaded HTTP extension: mopidy DEBUG 2016-12-24 13:13:57,026 [27039:HttpFrontend-12] mopidy.zeroconf Zeroconf service "None" (_http._tcp at []:6680): dbus not installed; publish failed. DEBUG 2016-12-24 13:13:57,026 [27039:HttpServer] mopidy.http.actor HTTP routes from extensions: u'/mopidy': u'/mopidy/ws/?': u'/mopidy/rpc': u'/mopidy/(.+)': u'/mopidy/': u'/': DEBUG 2016-12-24 13:13:57,026 [27039:HttpFrontend-12] mopidy.zeroconf Zeroconf service "None" (_mopidy-http._tcp at []:6680): dbus not installed; publish failed. INFO 2016-12-24 13:13:57,242 [27039:MpdSession-13] mopidy.mpd.session New MPD connection from [::ffff:127.0.0.1]:41576 DEBUG 2016-12-24 13:13:57,246 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: status DEBUG 2016-12-24 13:13:57,318 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: volume: 100 repeat: 0 random: 0 single: 0 consume: 0 playlist: 0 playlistlength: 0 xfade: 0 state: stop OK DEBUG 2016-12-24 13:13:57,318 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: plchanges "0" DEBUG 2016-12-24 13:13:57,319 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: OK DEBUG 2016-12-24 13:13:57,319 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: outputs DEBUG 2016-12-24 13:13:57,320 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: outputid: 0 outputname: Mute outputenabled: 0 OK DEBUG 2016-12-24 13:13:57,320 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: decoders DEBUG 2016-12-24 13:13:57,321 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: OK DEBUG 2016-12-24 13:13:57,321 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: outputs DEBUG 2016-12-24 13:13:57,321 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: outputid: 0 outputname: Mute outputenabled: 0 OK DEBUG 2016-12-24 13:13:57,322 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: outputs DEBUG 2016-12-24 13:13:57,323 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: outputid: 0 outputname: Mute outputenabled: 0 OK DEBUG 2016-12-24 13:13:57,323 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: idle INFO 2016-12-24 13:13:57,506 [27039:SpotifyEventLoop] mopidy_spotify.backend Logged in to Spotify in online mode DEBUG 2016-12-24 13:14:03,648 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: noidle DEBUG 2016-12-24 13:14:03,648 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: OK DEBUG 2016-12-24 13:14:03,649 [27039:MpdSession-13] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41576: list Artist DEBUG 2016-12-24 13:14:03,688 [27039:SpotifyBackend-6] mopidy_spotify.distinct Getting distinct artists: {} INFO 2016-12-24 13:14:08,655 [27039:MpdSession-14] mopidy.mpd.session New MPD connection from [::ffff:127.0.0.1]:41578 DEBUG 2016-12-24 13:14:08,656 [27039:MpdSession-14] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41578: status INFO 2016-12-24 13:14:13,662 [27039:MpdSession-15] mopidy.mpd.session New MPD connection from [::ffff:127.0.0.1]:41580 DEBUG 2016-12-24 13:14:13,662 [27039:MpdSession-15] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41580: status ERROR 2016-12-24 13:14:13,706 [27039:Core-9] mopidy.core.library SpotifyBackend backend caused an exception. Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mopidy/core/library.py", line 19, in _backend_error_handling yield File "/usr/lib/python2.7/site-packages/mopidy/core/library.py", line 142, in get_distinct values = future.get() File "/usr/lib/python2.7/site-packages/pykka/future.py", line 299, in get exec('raise exc_info[0], exc_info[1], exc_info[2]') File "/usr/lib/python2.7/site-packages/pykka/actor.py", line 200, in _actor_loop response = self._handle_receive(message) File "/usr/lib/python2.7/site-packages/pykka/actor.py", line 294, in _handle_receive return callee(*message['args'], **message['kwargs']) File "/usr/lib/python2.7/site-packages/mopidy_spotify/library.py", line 32, in get_distinct field, query) File "/usr/lib/python2.7/site-packages/mopidy_spotify/distinct.py", line 20, in get_distinct config, session, requests_session, query) File "/usr/lib/python2.7/site-packages/mopidy_spotify/distinct.py", line 45, in _get_distinct_artists for track in _get_playlist_tracks(config, session) File "/usr/lib/python2.7/site-packages/mopidy_spotify/distinct.py", line 44, in artist.name File "/usr/lib/python2.7/site-packages/mopidy_spotify/distinct.py", line 119, in _get_playlist_tracks playlist.load() File "/usr/lib/python2.7/site-packages/spotify/playlist.py", line 118, in load return utils.load(self._session, self, timeout=timeout) File "/usr/lib/python2.7/site-packages/spotify/utils.py", line 246, in load raise spotify.Timeout(timeout) Timeout: Operation did not complete in 10.000s DEBUG 2016-12-24 13:14:13,708 [27039:MpdSession-13] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41576: OK DEBUG 2016-12-24 13:14:13,708 [27039:MpdSession-13] mopidy.internal.network Client most likely disconnected. DEBUG 2016-12-24 13:14:13,709 [27039:MpdSession-13] mopidy.internal.network Already stopping: Actor is shutting down. DEBUG 2016-12-24 13:14:13,710 [27039:MpdSession-15] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41580: volume: 100 repeat: 0 random: 0 single: 0 consume: 0 playlist: 0 playlistlength: 0 xfade: 0 state: stop OK DEBUG 2016-12-24 13:14:13,710 [27039:MpdSession-14] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41578: volume: 100 repeat: 0 random: 0 single: 0 consume: 0 playlist: 0 playlistlength: 0 xfade: 0 state: stop OK DEBUG 2016-12-24 13:14:13,711 [27039:MpdSession-15] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41580: plchanges "0" DEBUG 2016-12-24 13:14:13,711 [27039:MpdSession-14] mopidy.internal.network Client most likely disconnected. DEBUG 2016-12-24 13:14:13,712 [27039:MpdSession-15] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41580: OK DEBUG 2016-12-24 13:14:13,712 [27039:MpdSession-14] mopidy.internal.network Already stopping: Actor is shutting down. DEBUG 2016-12-24 13:14:13,713 [27039:MpdSession-15] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41580: outputs DEBUG 2016-12-24 13:14:13,713 [27039:MpdSession-15] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41580: outputid: 0 outputname: Mute outputenabled: 0 OK DEBUG 2016-12-24 13:14:13,714 [27039:MpdSession-15] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41580: decoders DEBUG 2016-12-24 13:14:13,714 [27039:MpdSession-15] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41580: OK DEBUG 2016-12-24 13:14:13,715 [27039:MpdSession-15] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41580: outputs DEBUG 2016-12-24 13:14:13,716 [27039:MpdSession-15] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41580: outputid: 0 outputname: Mute outputenabled: 0 OK DEBUG 2016-12-24 13:14:13,716 [27039:MpdSession-15] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41580: outputs DEBUG 2016-12-24 13:14:13,717 [27039:MpdSession-15] mopidy.mpd.session Response to [::ffff:127.0.0.1]:41580: outputid: 0 outputname: Mute outputenabled: 0 OK DEBUG 2016-12-24 13:14:13,720 [27039:MpdSession-15] mopidy.mpd.session Request from [::ffff:127.0.0.1]:41580: idle