Created
January 20, 2020 14:29
-
-
Save freijon/b69d68ac70e85226b7de36f846daa182 to your computer and use it in GitHub Desktop.
ncspot.log
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| [2020-01-20][13:23:29] [ncspot::config] [TRACE] "C:\\Users\\jonas.frei\\.config\\ncspot\\config" | |
| [2020-01-20][13:23:29] [ncspot::config] [TRACE] "C:\\Users\\jonas.frei\\.config\\ncspot\\config" | |
| [2020-01-20][13:23:38] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:38] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:39] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:39] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:40] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:41] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:42] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:42] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:42] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:42] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:43] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:43] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:44] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:45] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:45] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:46] [cursive::views::list_view] [DEBUG] Available: 18 | |
| [2020-01-20][13:23:46] [cursive::views::list_view] [DEBUG] Offset: 9 | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [tokio_threadpool::builder] [TRACE] build; num-workers=8 | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [hyper::client::pool] [TRACE] park; waiting for idle connection: "http://apresolve.spotify.com" | |
| [2020-01-20][13:23:46] [hyper::client::connect] [TRACE] Http::connect("http://127.0.0.1:9999/") | |
| [2020-01-20][13:23:46] [hyper::client::connect] [DEBUG] connecting to 127.0.0.1:9999 | |
| [2020-01-20][13:23:46] [tokio_reactor::background] [DEBUG] starting background reactor | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:23:46] [tokio_reactor] [DEBUG] adding I/O source: 0 | |
| [2020-01-20][13:23:46] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] register Token(0) Readable | Writable | |
| [2020-01-20][13:23:46] [mio::sys::windows::tcp] [TRACE] scheduling a connect | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:23:46] [tokio_reactor::registration] [DEBUG] scheduling Write for: 0 | |
| [2020-01-20][13:23:46] [mio::sys::windows::tcp] [TRACE] finished a connect | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:23:46] [tokio_core::reactor] [DEBUG] consuming notification queue | |
| [2020-01-20][13:23:46] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:23:46] [tokio_reactor] [TRACE] event Writable Token(0) | |
| [2020-01-20][13:23:46] [tokio_core::reactor] [DEBUG] loop poll - 56.727µs | |
| [2020-01-20][13:23:46] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2713.092672394s } | |
| [2020-01-20][13:23:46] [tokio_core::reactor] [DEBUG] loop process, 38.303µs | |
| [2020-01-20][13:23:46] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:23:46] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:23:46] [hyper::proto::h1::conn] [TRACE] read_keep_alive; is_mid_message=false | |
| [2020-01-20][13:23:46] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:23:46] [hyper::proto] [TRACE] should_keep_alive(version=Http11, header=None) = true | |
| [2020-01-20][13:23:46] [hyper::proto::h1::role] [TRACE] Client::encode has_body=false, method=None | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] set readiness to (empty) | |
| [2020-01-20][13:23:46] [mio::sys::windows::tcp] [TRACE] scheduling a write of 75 bytes | |
| [2020-01-20][13:23:46] [mio::sys::windows::tcp] [TRACE] done immediately with 75 bytes | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:23:46] [hyper::proto::h1::io] [TRACE] reclaiming write buf Vec | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:23:46] [tokio_reactor] [TRACE] event Writable Token(0) | |
| [2020-01-20][13:23:46] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:23:46] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:23:46] [hyper::proto::h1::io] [DEBUG] flushed 75 bytes | |
| [2020-01-20][13:23:46] [hyper::proto::h1::conn] [TRACE] flushed State { reading: Init, writing: KeepAlive, keep_alive: Busy, error: None } | |
| [2020-01-20][13:23:46] [hyper::proto::h1::conn] [TRACE] wants_read_again? false | |
| [2020-01-20][13:23:46] [tokio_core::reactor] [DEBUG] loop poll - 407.273µs | |
| [2020-01-20][13:23:46] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2713.093252758s } | |
| [2020-01-20][13:23:46] [tokio_core::reactor] [DEBUG] loop process, 16.969µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(0) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] Conn::read_head | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] read 736 bytes | |
| [2020-01-20][13:24:08] [hyper::proto::h1::role] [TRACE] Response.parse([Header; 100], [u8; 736]) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::role] [TRACE] Response.parse Complete(318) | |
| [2020-01-20][13:24:08] [hyper::header] [TRACE] maybe_literal not found, copying "Via" | |
| [2020-01-20][13:24:08] [hyper::header] [TRACE] maybe_literal not found, copying "Keep-Alive" | |
| [2020-01-20][13:24:08] [hyper::header] [TRACE] maybe_literal not found, copying "Via" | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] parsed 9 headers (318 bytes) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [DEBUG] incoming body is content-length (418 bytes) | |
| [2020-01-20][13:24:08] [hyper::proto] [TRACE] expecting_continue(version=Http11, header=None) = false | |
| [2020-01-20][13:24:08] [hyper::proto] [TRACE] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] Conn::read_body | |
| [2020-01-20][13:24:08] [hyper::proto::h1::decode] [TRACE] decode; state=Length(418) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] flushed State { reading: Body(Length(0)), writing: KeepAlive, keep_alive: Busy, error: None } | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] wants_read_again? false | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 21.137098048s | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.230376503s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 10.182µs | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] Conn::read_body | |
| [2020-01-20][13:24:08] [hyper::proto::h1::decode] [TRACE] decode; state=Length(0) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [DEBUG] incoming body completed | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] read 0 bytes | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] read_keep_alive; is_mid_message=false | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] read 0 bytes | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] try_io_read; found EOF on connection: State { reading: Init, writing: Init, keep_alive: Idle, error: None } | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] State::close_read() | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None } | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] wants_read_again? false | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] shut down IO | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] deregistering handle with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] deregistering | |
| [2020-01-20][13:24:08] [tokio_reactor] [DEBUG] dropping I/O source: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [want] [TRACE] signal: Closed | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 235.152µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.230701352s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 11.636µs | |
| [2020-01-20][13:24:08] [librespot_core::session] [INFO] Connecting to AP "gew1-accesspoint-a-z62p.ap.spotify.com:443" | |
| [2020-01-20][13:24:08] [librespot_core::connection] [INFO] Using proxy "http://127.0.0.1:9999/" | |
| [2020-01-20][13:24:08] [tokio_reactor] [DEBUG] adding I/O source: 4194304 | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] register Token(4194304) Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a connect | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Write for: 0 | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 970ns | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.230971412s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 10.667µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a connect | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 64µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.231051412s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 19.394µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to (empty) | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 63 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 63 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 91.224154ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.322422475s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 83.394µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 151 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 151 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 48.625408ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.376647392s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 20.363µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 36 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 36 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] flushing framed transport | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] writing; remaining=131 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 131 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 131 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] framed transport flushed | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 1.455µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.381650539s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 12.121µs | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 89.389974ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.47106524s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 59.151µs | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [librespot_core::session] [INFO] Authenticated as "1162536800" ! | |
| [2020-01-20][13:24:08] [librespot_core::session] [DEBUG] new Session[0] | |
| [2020-01-20][13:24:08] [librespot_core::session] [DEBUG] drop Session[0] | |
| [2020-01-20][13:24:08] [tokio_threadpool::pool] [TRACE] shutdown; state=pool::State { lifecycle: Running, num_futures: 0 } | |
| [2020-01-20][13:24:08] [tokio_threadpool::pool] [TRACE] -> transitioned to shutdown | |
| [2020-01-20][13:24:08] [tokio_threadpool::pool] [TRACE] -> shutting down workers | |
| [2020-01-20][13:24:08] [librespot_core::session] [DEBUG] drop Dispatch | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] deregistering handle with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] deregistering | |
| [2020-01-20][13:24:08] [tokio_reactor] [DEBUG] dropping I/O source: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [tokio_threadpool::builder] [TRACE] build; num-workers=8 | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [ncspot::spotify] [DEBUG] opening spotify session | |
| [2020-01-20][13:24:08] [tokio_reactor::background] [DEBUG] starting background reactor | |
| [2020-01-20][13:24:08] [hyper::client::pool] [TRACE] park; waiting for idle connection: "http://apresolve.spotify.com" | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [hyper::client::connect] [TRACE] Http::connect("http://127.0.0.1:9999/") | |
| [2020-01-20][13:24:08] [hyper::client::connect] [DEBUG] connecting to 127.0.0.1:9999 | |
| [2020-01-20][13:24:08] [tokio_reactor] [DEBUG] adding I/O source: 0 | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] register Token(0) Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a connect | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Write for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a connect | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] consuming notification queue | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 38.303µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.496949336s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 21.818µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(0) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 87.272µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.497065699s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 30.061µs | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] read_keep_alive; is_mid_message=false | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [hyper::proto] [TRACE] should_keep_alive(version=Http11, header=None) = true | |
| [2020-01-20][13:24:08] [hyper::proto::h1::role] [TRACE] Client::encode has_body=false, method=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to (empty) | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 75 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 75 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [TRACE] reclaiming write buf Vec | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] flushed 75 bytes | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] flushed State { reading: Init, writing: KeepAlive, keep_alive: Busy, error: None } | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] wants_read_again? false | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 129.939µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.49725382s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 10.182µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(0) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(0) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] Conn::read_head | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] read 736 bytes | |
| [2020-01-20][13:24:08] [hyper::proto::h1::role] [TRACE] Response.parse([Header; 100], [u8; 736]) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::role] [TRACE] Response.parse Complete(318) | |
| [2020-01-20][13:24:08] [hyper::header] [TRACE] maybe_literal not found, copying "Via" | |
| [2020-01-20][13:24:08] [hyper::header] [TRACE] maybe_literal not found, copying "Keep-Alive" | |
| [2020-01-20][13:24:08] [hyper::header] [TRACE] maybe_literal not found, copying "Via" | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] parsed 9 headers (318 bytes) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [DEBUG] incoming body is content-length (418 bytes) | |
| [2020-01-20][13:24:08] [hyper::proto] [TRACE] expecting_continue(version=Http11, header=None) = false | |
| [2020-01-20][13:24:08] [hyper::proto] [TRACE] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] Conn::read_body | |
| [2020-01-20][13:24:08] [hyper::proto::h1::decode] [TRACE] decode; state=Length(418) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] flushed State { reading: Body(Length(0)), writing: KeepAlive, keep_alive: Busy, error: None } | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] wants_read_again? false | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 81.819557ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.579089862s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 16.97µs | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] Conn::read_body | |
| [2020-01-20][13:24:08] [hyper::proto::h1::decode] [TRACE] decode; state=Length(0) | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [DEBUG] incoming body completed | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] read 0 bytes | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] read_keep_alive; is_mid_message=false | |
| [2020-01-20][13:24:08] [hyper::proto::h1::io] [DEBUG] read 0 bytes | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] try_io_read; found EOF on connection: State { reading: Init, writing: Init, keep_alive: Idle, error: None } | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] State::close_read() | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None } | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] wants_read_again? false | |
| [2020-01-20][13:24:08] [hyper::proto::h1::conn] [TRACE] shut down IO | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] deregistering handle with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] deregistering | |
| [2020-01-20][13:24:08] [tokio_reactor] [DEBUG] dropping I/O source: 0 | |
| [2020-01-20][13:24:08] [want] [TRACE] signal: Closed | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 352.484µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.579564528s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 11.152µs | |
| [2020-01-20][13:24:08] [librespot_core::session] [INFO] Connecting to AP "gew1-accesspoint-a-jsxt.ap.spotify.com:443" | |
| [2020-01-20][13:24:08] [librespot_core::connection] [INFO] Using proxy "http://127.0.0.1:9999/" | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_reactor] [DEBUG] adding I/O source: 4194304 | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] register Token(4194304) Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a connect | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Write for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a connect | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 969ns | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.579800649s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 136.243µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to (empty) | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 63 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 63 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 970ns | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.580003801s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 10.666µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 85.348281ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.665367597s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 24.242µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 151 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 151 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 9.696µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.670335349s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 21.334µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=Some(0ns) | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 47.194136ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.717602698s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 33.454µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 36 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 36 bytes | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable Token(4194304) | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=Some(0ns) | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] flushing framed transport | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] writing; remaining=131 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 131 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 131 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] framed transport flushed | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 93.252273ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.816418602s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 35.879µs | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [librespot_core::session] [INFO] Authenticated as "1162536800" ! | |
| [2020-01-20][13:24:08] [librespot_core::session] [DEBUG] new Session[1] | |
| [2020-01-20][13:24:08] [ncspot::spotify] [DEBUG] worker thread ready. | |
| [2020-01-20][13:24:08] [ncspot::spotify] [DEBUG] message received! | |
| [2020-01-20][13:24:08] [librespot::component] [DEBUG] new MercuryManager | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [librespot_core::session] [DEBUG] Session[1] strong=3 weak=2 | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [librespot_core::session] [INFO] Country: "CH" | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] flushing framed transport | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] writing; remaining=353 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to (empty) | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a write of 353 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] done immediately with 353 bytes | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] framed transport flushed | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 182.303µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.820370598s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 11.151µs | |
| [2020-01-20][13:24:08] [librespot_playback::player] [DEBUG] new Player[1] | |
| [2020-01-20][13:24:08] [librespot_playback::audio_backend::rodio] [DEBUG] Using rodio sink | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] flushing framed transport | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] framed transport flushed | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 12.547867ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.832935919s } | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 12.121µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] flushing framed transport | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] framed transport flushed | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 51.53595ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.884526657s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 10.667µs | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] frame decoded from buffer | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_read] [TRACE] attempting to decode a frame | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Read for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Writable Token(4194304) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] flushing framed transport | |
| [2020-01-20][13:24:08] [tokio_io::_tokio_codec::framed_write] [TRACE] framed transport flushed | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 71.324537ms | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.955869618s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 11.152µs | |
| [2020-01-20][13:24:08] [ncspot::spotify] [INFO] new token received: Token { access_token: "BQAKSjhOmRweu4M-sXbck8dKoNmIlt2n99irkj2h1CIC3EU4jHoSkS_yOm1fDgr9YouOGdwUt-7PVvwcWxTG5ibgC1vu9qtO1hFqFl5V0feEDF8-M1SgCBVTRdBuNJaKRzzI38WTE3fv3pZ42BV2BpwW18N-jpEOfQOHkKybHiOfZcUj581o1t6-3y15RRks2BMg2qWByrijbGivYIED12QqqYe2bjSExgKGL5WB7BjZdZiDZlyT4s5THMGhInTT-sXy", expires_in: 3600, token_type: "Bearer", scope: ["user-read-private", "playlist-read-private", "playlist-read-collaborative", "playlist-modify-public", "playlist-modify-private", "user-follow-modify", "user-follow-read", "user-library-read", "user-library-modify", "user-top-read", "user-read-recently-played"] } | |
| [2020-01-20][13:24:08] [ncspot::spotify] [INFO] token updated! | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop poll - 1.455µs | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2734.955995194s } | |
| [2020-01-20][13:24:08] [tokio_core::reactor] [DEBUG] loop process, 10.181µs | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable Token(4194303) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [hyper::client::pool] [TRACE] checkout waiting for idle connection: "https://api.spotify.com" | |
| [2020-01-20][13:24:08] [hyper::client::connect::http] [TRACE] Http::connect; scheme=https, host=api.spotify.com, port=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=Some(0ns) | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [hyper::client::connect::dns] [DEBUG] resolving host="api.spotify.com" | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] event Readable Token(4194303) | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:08] [hyper::client::connect::http] [DEBUG] connecting to 35.186.224.53:443 | |
| [2020-01-20][13:24:08] [tokio_reactor] [DEBUG] adding I/O source: 0 | |
| [2020-01-20][13:24:08] [mio::poll] [TRACE] registering with poller | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] register Token(0) Readable | Writable | |
| [2020-01-20][13:24:08] [mio::sys::windows::tcp] [TRACE] scheduling a connect | |
| [2020-01-20][13:24:08] [tokio_reactor::registration] [DEBUG] scheduling Write for: 0 | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=Some(0ns) | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:08] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:08] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:29] [mio::sys::windows::tcp] [TRACE] finished a connect | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:29] [tokio_reactor] [TRACE] event Readable | Writable Token(0) | |
| [2020-01-20][13:24:29] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:29] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:29] [hyper::client::connect::http] [TRACE] connect error Os { code: 10060, kind: TimedOut, message: "A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond." } | |
| [2020-01-20][13:24:29] [mio::poll] [TRACE] deregistering handle with poller | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] deregistering | |
| [2020-01-20][13:24:29] [tokio_reactor] [DEBUG] dropping I/O source: 0 | |
| [2020-01-20][13:24:29] [hyper::client::pool] [TRACE] checkout dropped for "https://api.spotify.com" | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] select; timeout=Some(0ns) | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:29] [tokio_reactor] [TRACE] event Readable Token(4194303) | |
| [2020-01-20][13:24:29] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] select; timeout=Some(0ns) | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:29] [tokio_reactor] [TRACE] loop process - 0 events, 0.000s | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:29] [tokio_core::reactor] [DEBUG] loop poll - 21.0089309s | |
| [2020-01-20][13:24:29] [tokio_core::reactor] [DEBUG] loop time - Instant { t: 2755.964941609s } | |
| [2020-01-20][13:24:29] [tokio_core::reactor] [DEBUG] loop process, 24.243µs | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] select; -> got overlapped | |
| [2020-01-20][13:24:29] [mio::sys::windows::tcp] [TRACE] finished a read: 0 | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:29] [tokio_reactor] [TRACE] event Readable | Writable Token(4194304) | |
| [2020-01-20][13:24:29] [tokio_reactor] [TRACE] loop process - 1 events, 0.000s | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] select; timeout=None | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] set readiness to Writable | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] polling IOCP | |
| [2020-01-20][13:24:29] [mio::sys::windows::tcp] [TRACE] scheduling a read | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] set readiness to Readable | Writable | |
| [2020-01-20][13:24:29] [librespot_core::session] [DEBUG] Invalidating session[1] | |
| [2020-01-20][13:24:29] [librespot_core::session] [DEBUG] drop Dispatch | |
| [2020-01-20][13:24:29] [mio::poll] [TRACE] deregistering handle with poller | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] returning | |
| [2020-01-20][13:24:29] [mio::sys::windows::selector] [TRACE] deregistering |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment