Skip to content

Instantly share code, notes, and snippets.

@blueo
Last active March 18, 2018 03:00
Show Gist options
  • Save blueo/071e064ac212c78e1b210e60c66a0fe9 to your computer and use it in GitHub Desktop.
Save blueo/071e064ac212c78e1b210e60c66a0fe9 to your computer and use it in GitHub Desktop.
spotifyd log
[global]
username = username
password = password
backend = alsa
mixer = PCM
device_name = SpotifyD
cache_path = /tmp
volume-normalisation = true
normalisation-pregain = -10
02:47:24 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:24 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:523] build; num-workers=1
02:47:24 [INFO] (BUsing software volume controller.
02:47:24 [DEBUG] (Btokio_reactor::background: starting background reactor
02:47:24 [DEBUG] (Blibrespot_connect::discovery: Zeroconf server listening on 0.0.0.0:0
02:47:24 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:24 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:24 [TRACE] (Btokio_reactor: [<unknown>:330] event Writable Token(2)
02:47:24 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:24 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:24 [TRACE] (Btokio_reactor: [<unknown>:330] event Writable Token(3)
02:47:24 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:24 [DEBUG] (Btokio_core::reactor: added a timeout: 0
02:47:24 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:24 [TRACE] (Btokio_reactor: [<unknown>:330] event Writable Token(4)
02:47:24 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:24 [TRACE] (Bhyper::client::pool: [<unknown>:178] park; waiting for idle connection: "http://apresolve.spotify.com"
02:47:24 [TRACE] (Bhyper::client::connect: [<unknown>:118] Http::connect("http://apresolve.spotify.com/")
02:47:24 [DEBUG] (Bhyper::client::dns: resolving host="apresolve.spotify.com", port=80
02:47:24 [DEBUG] (Btokio_core::reactor: consuming notification queue
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:275] sending packet to V4(224.0.0.251:5353)
02:47:24 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(2)
02:47:24 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:24 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(2)
02:47:24 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:275] sending packet to V6([ff02::fb]:5353)
02:47:24 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(3)
02:47:24 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:24 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(3)
02:47:24 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:24 [DEBUG] (Btokio_core::reactor: updating a timeout: 0
02:47:24 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 16736724 }
02:47:24 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 383711873 }
02:47:24 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 553991 }
02:47:24 [DEBUG] (Bhyper::client::connect: connecting to 104.199.240.211:80
02:47:24 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V4(10.0.1.4:5353)
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:87] received packet from V4(10.0.1.4:5353) with no query
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V4(10.0.1.4:5353)
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:87] received packet from V4(10.0.1.4:5353) with no query
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V6([fe80::ba27:ebff:fe6a:db43]:5353)
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:87] received packet from V6([fe80::ba27:ebff:fe6a:db43]:5353) with no query
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V6([fe80::ba27:ebff:fe6a:db43]:5353)
02:47:24 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:87] received packet from V6([fe80::ba27:ebff:fe6a:db43]:5353) with no query
02:47:24 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 3225946 }
02:47:24 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 389302780 }
02:47:24 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 693989 }
02:47:24 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 18000 }
02:47:24 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 390738757 }
02:47:24 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 546991 }
02:47:25 [TRACE] (Btokio_reactor: [<unknown>:330] event Writable Token(5)
02:47:25 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 154266454 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 545829197 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 591990 }
02:47:25 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=false
02:47:25 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
02:47:25 [TRACE] (Bhyper::proto::h1::role: [<unknown>:327] ClientTransaction::encode has_body=false, method=None
02:47:25 [TRACE] (Bhyper::proto::h1::io: [<unknown>:542] reclaiming write buf Vec
02:47:25 [DEBUG] (Bhyper::proto::h1::io: flushed 47 bytes
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Init, writing: KeepAlive, keep_alive: Busy, error: None, read_task: None }
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 3161948 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 550335123 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 579990 }
02:47:25 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(5)
02:47:25 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:25 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:25 [DEBUG] (Bhyper::proto::h1::io: read 686 bytes
02:47:25 [TRACE] (Bhyper::proto::h1::role: [<unknown>:231] Response.parse([Header; 100], [u8; 686])
02:47:25 [TRACE] (Bhyper::proto::h1::role: [<unknown>:236] Response.parse Complete(268)
02:47:25 [TRACE] (Bhyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
02:47:25 [TRACE] (Bhyper::header: [<unknown>:355] maybe_literal not found, copying "Vary"
02:47:25 [DEBUG] (Bhyper::proto::h1::io: parsed 9 headers (268 bytes)
02:47:25 [DEBUG] (Bhyper::proto::h1::conn: incoming body is content-length (418 bytes)
02:47:25 [TRACE] (Bhyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
02:47:25 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:246] Conn::read_body
02:47:25 [TRACE] (Bhyper::proto::h1::decode: [<unknown>:88] decode; state=Length(418)
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Body(Length(0)), writing: KeepAlive, keep_alive: Busy, error: None, read_task: None }
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 164329288 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 715527397 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 554991 }
02:47:25 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:246] Conn::read_body
02:47:25 [TRACE] (Bhyper::proto::h1::decode: [<unknown>:88] decode; state=Length(0)
02:47:25 [DEBUG] (Bhyper::proto::h1::conn: incoming body completed
02:47:25 [TRACE] (Bhyper::client::pool: [<unknown>:332] pool dropped, dropping pooled ("http://apresolve.spotify.com")
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:829] State::close()
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:426] maybe_notify; no task to notify
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:423] maybe_notify; notifying task
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Closed, writing: Closed, keep_alive: Disabled, error: None, read_task: Some(Task) }
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:588] shut down IO
02:47:25 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:74] Dispatch::poll done
02:47:25 [TRACE] (Bmio::poll: [<unknown>:905] deregistering handle with poller
02:47:25 [DEBUG] (Btokio_reactor: dropping I/O source: 4
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 5062916 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 724905242 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 580990 }
02:47:25 [INFO] (BConnecting to AP "gae2-accesspoint-b-drh8.ap.spotify.com:4070"
02:47:25 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 21999 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 760947647 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 585991 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 14000 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 761828633 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 525991 }
02:47:25 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable Token(1)
02:47:25 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 42423300 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 805050919 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 643990 }
02:47:25 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:25 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:25 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(6)
02:47:25 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:25 [DEBUG] (Bhyper::proto::h1::io: read 220 bytes
02:47:25 [TRACE] (Bhyper::proto::h1::role: [<unknown>:32] Request.parse([Header; 100], [u8; 220])
02:47:25 [TRACE] (Bhyper::proto::h1::role: [<unknown>:36] Request.parse Complete(220)
02:47:25 [TRACE] (Bhyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
02:47:25 [DEBUG] (Bhyper::proto::h1::io: parsed 6 headers (220 bytes)
02:47:25 [DEBUG] (Bhyper::proto::h1::conn: incoming body is content-length (0 bytes)
02:47:25 [TRACE] (Bhyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
02:47:25 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:25 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
02:47:25 [TRACE] (Bhyper::proto::h1::role: [<unknown>:115] ServerTransaction::encode has_body=true, method=Some(Get)
02:47:25 [TRACE] (Bhyper::proto::h1::encode: [<unknown>:91] encoding chunked 419B
02:47:25 [DEBUG] (Bhyper::proto::h1::io: flushed 515 bytes
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:413] maybe_notify; read_from_io blocked
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None, read_task: Some(Task) }
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 7997868 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 814105770 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 571991 }
02:47:25 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable | Hup Token(6)
02:47:25 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:25 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:25 [DEBUG] (Bhyper::proto::h1::io: read 0 bytes
02:47:25 [TRACE] (Bhyper::proto::h1::io: [<unknown>:127] parse eof
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:836] State::close_read()
02:47:25 [DEBUG] (Bhyper::proto::h1::conn: read eof
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:423] maybe_notify; notifying task
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None, read_task: Some(Task) }
02:47:25 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:588] shut down IO
02:47:25 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:74] Dispatch::poll done
02:47:25 [TRACE] (Bmio::poll: [<unknown>:905] deregistering handle with poller
02:47:25 [DEBUG] (Btokio_reactor: dropping I/O source: 5
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 7250880 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 822213636 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 580991 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 19000 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 823100622 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 964984 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 17000 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 824411600 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 547991 }
02:47:25 [TRACE] (Btokio_reactor: [<unknown>:330] event Writable Token(5)
02:47:25 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 93189463 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5531, tv_nsec: 918535047 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 595990 }
02:47:25 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(5)
02:47:25 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:25 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 161841329 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5532, tv_nsec: 318579445 }
02:47:25 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 615990 }
02:47:26 [TRACE] (Btokio_io::framed_write: [<unknown>:182] flushing framed transport
02:47:26 [TRACE] (Btokio_io::framed_write: [<unknown>:185] writing; remaining=123
02:47:26 [TRACE] (Btokio_io::framed_write: [<unknown>:202] framed transport flushed
02:47:26 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable Token(1)
02:47:26 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:26 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 845135056 }
02:47:26 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 401324580 }
02:47:26 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 635989 }
02:47:26 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:26 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:26 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(6)
02:47:26 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:26 [DEBUG] (Bhyper::proto::h1::io: read 220 bytes
02:47:26 [TRACE] (Bhyper::proto::h1::role: [<unknown>:32] Request.parse([Header; 100], [u8; 220])
02:47:26 [TRACE] (Bhyper::proto::h1::role: [<unknown>:36] Request.parse Complete(220)
02:47:26 [TRACE] (Bhyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
02:47:26 [DEBUG] (Bhyper::proto::h1::io: parsed 6 headers (220 bytes)
02:47:26 [DEBUG] (Bhyper::proto::h1::conn: incoming body is content-length (0 bytes)
02:47:26 [TRACE] (Bhyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
02:47:26 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:26 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
02:47:26 [TRACE] (Bhyper::proto::h1::role: [<unknown>:115] ServerTransaction::encode has_body=true, method=Some(Get)
02:47:26 [TRACE] (Bhyper::proto::h1::encode: [<unknown>:91] encoding chunked 419B
02:47:26 [DEBUG] (Bhyper::proto::h1::io: flushed 515 bytes
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:413] maybe_notify; read_from_io blocked
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None, read_task: Some(Task) }
02:47:26 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 7973869 }
02:47:26 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 410215433 }
02:47:26 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 640989 }
02:47:26 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable | Hup Token(6)
02:47:26 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:26 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:26 [DEBUG] (Bhyper::proto::h1::io: read 0 bytes
02:47:26 [TRACE] (Bhyper::proto::h1::io: [<unknown>:127] parse eof
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:836] State::close_read()
02:47:26 [DEBUG] (Bhyper::proto::h1::conn: read eof
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:423] maybe_notify; notifying task
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None, read_task: Some(Task) }
02:47:26 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:588] shut down IO
02:47:26 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:74] Dispatch::poll done
02:47:27 [TRACE] (Bmio::poll: [<unknown>:905] deregistering handle with poller
02:47:27 [DEBUG] (Btokio_reactor: dropping I/O source: 5
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 49535183 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 461053594 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 567991 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 19000 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 461924580 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 1102981 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 16000 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 463351556 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 543991 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(2)
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(3)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 2 events, 0.000s
02:47:27 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V4(10.0.1.9:5353)
02:47:27 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V6([fe80::c0d:b80:7f5f:eeb6]:5353)
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 273718484 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 737893027 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 591990 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(2)
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(3)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 2 events, 0.000s
02:47:27 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V4(10.0.1.1:5353)
02:47:27 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:87] received packet from V4(10.0.1.1:5353) with no query
02:47:27 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:76] received packet from V6([fe80::9272:40ff:fe01:fa79]:5353)
02:47:27 [TRACE] (Bmdns::fsm: [/root/.cargo/git/checkouts/rust-mdns-881ed19b93df0e9d/733b2b6/src/fsm.rs:87] received packet from V6([fe80::9272:40ff:fe01:fa79]:5353) with no query
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 47856211 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 786624223 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 592990 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(5)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 10147832 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 797650041 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 712988 }
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [INFO] (BAuthenticated as "xxxxxxxxxx" !
02:47:27 [DEBUG] (Blibrespot_core::session: new Session[0]
02:47:27 [DEBUG] (Blibrespot_connect::spirc: new Spirc[0]
02:47:27 [DEBUG] (Blibrespot::component: new MercuryManager
02:47:27 [DEBUG] (Blibrespot_connect::spirc: input volume:65535 to mixer: 65535
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [DEBUG] (Blibrespot_core::session: Session[0] strong=3 weak=2
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [INFO] (BCountry: "XX"
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:182] flushing framed transport
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:185] writing; remaining=376
02:47:27 [DEBUG] (Blibrespot_playback::player: new Player[0]
02:47:27 [INFO] (BUsing alsa sink
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:202] framed transport flushed
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 7670873 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 811942805 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 554991 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(5)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:182] flushing framed transport
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:202] framed transport flushed
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 141348669 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5533, tv_nsec: 954130460 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 682988 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable Token(1)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 122143985 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 77336427 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 630990 }
02:47:27 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:27 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(6)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:27 [DEBUG] (Bhyper::proto::h1::io: read 220 bytes
02:47:27 [TRACE] (Bhyper::proto::h1::role: [<unknown>:32] Request.parse([Header; 100], [u8; 220])
02:47:27 [TRACE] (Bhyper::proto::h1::role: [<unknown>:36] Request.parse Complete(220)
02:47:27 [TRACE] (Bhyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
02:47:27 [DEBUG] (Bhyper::proto::h1::io: parsed 6 headers (220 bytes)
02:47:27 [DEBUG] (Bhyper::proto::h1::conn: incoming body is content-length (0 bytes)
02:47:27 [TRACE] (Bhyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
02:47:27 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:27 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
02:47:27 [TRACE] (Bhyper::proto::h1::role: [<unknown>:115] ServerTransaction::encode has_body=true, method=Some(Get)
02:47:27 [TRACE] (Bhyper::proto::h1::encode: [<unknown>:91] encoding chunked 419B
02:47:27 [DEBUG] (Bhyper::proto::h1::io: flushed 515 bytes
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:413] maybe_notify; read_from_io blocked
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None, read_task: Some(Task) }
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 7975868 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 86351278 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 572991 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable | Hup Token(6)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:27 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:27 [DEBUG] (Bhyper::proto::h1::io: read 0 bytes
02:47:27 [TRACE] (Bhyper::proto::h1::io: [<unknown>:127] parse eof
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:836] State::close_read()
02:47:27 [DEBUG] (Bhyper::proto::h1::conn: read eof
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:423] maybe_notify; notifying task
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None, read_task: Some(Task) }
02:47:27 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:588] shut down IO
02:47:27 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:74] Dispatch::poll done
02:47:27 [TRACE] (Bmio::poll: [<unknown>:905] deregistering handle with poller
02:47:27 [DEBUG] (Btokio_reactor: dropping I/O source: 5
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 53756113 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 140963377 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 1020984 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 21000 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 142447353 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 548991 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 13000 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 143285339 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 525991 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(5)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [DEBUG] (Blibrespot_core::mercury: unknown subscription uri=hm://remote/3/user/1261136292/
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [DEBUG] (Blibrespot_core::mercury: unknown subscription uri=hm://remote/3/user/1261136292/f1683ae3bb658745dc83bdb53739331f627ad199
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:182] flushing framed transport
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:202] framed transport flushed
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 10866821 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 154948147 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 548991 }
02:47:27 [DEBUG] (Blibrespot_core::mercury: subscribed uri=hm://remote/3/user/1261136292/ count=0
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 16999 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 156247125 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 568991 }
02:47:27 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(5)
02:47:27 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:27 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:182] flushing framed transport
02:47:27 [TRACE] (Btokio_io::framed_write: [<unknown>:202] framed transport flushed
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 150683514 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 307781625 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 547991 }
02:47:27 [DEBUG] (Blibrespot_connect::spirc: kMessageTypeNotify "silverscreen" f1683ae3bb658745dc83bdb53739331f627ad199 922825622 1521341247698
02:47:27 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 17000 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5534, tv_nsec: 309347600 }
02:47:27 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 565990 }
02:47:29 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable Token(1)
02:47:29 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 1, nanos: 191543346 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 502001927 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 755987 }
02:47:29 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:29 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:29 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(6)
02:47:29 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:29 [DEBUG] (Bhyper::proto::h1::io: read 884 bytes
02:47:29 [TRACE] (Bhyper::proto::h1::role: [<unknown>:32] Request.parse([Header; 100], [u8; 884])
02:47:29 [TRACE] (Bhyper::proto::h1::role: [<unknown>:36] Request.parse Complete(227)
02:47:29 [TRACE] (Bhyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
02:47:29 [DEBUG] (Bhyper::proto::h1::io: parsed 7 headers (227 bytes)
02:47:29 [DEBUG] (Bhyper::proto::h1::conn: incoming body is content-length (657 bytes)
02:47:29 [TRACE] (Bhyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
02:47:29 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
02:47:29 [DEBUG] (Blibrespot_connect::discovery: Post "/" {}
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:246] Conn::read_body
02:47:29 [TRACE] (Bhyper::proto::h1::decode: [<unknown>:88] decode; state=Length(657)
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Body(Length(0)), writing: Init, keep_alive: Busy, error: None, read_task: None }
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 5512910 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 508564819 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 556990 }
02:47:29 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:246] Conn::read_body
02:47:29 [TRACE] (Bhyper::proto::h1::decode: [<unknown>:88] decode; state=Length(0)
02:47:29 [DEBUG] (Bhyper::proto::h1::conn: incoming body completed
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:29 [TRACE] (Bhyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
02:47:29 [TRACE] (Bhyper::proto::h1::role: [<unknown>:115] ServerTransaction::encode has_body=true, method=Some(Post)
02:47:29 [TRACE] (Bhyper::proto::h1::encode: [<unknown>:91] encoding chunked 57B
02:47:29 [DEBUG] (Bhyper::proto::h1::io: flushed 152 bytes
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:413] maybe_notify; read_from_io blocked
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None, read_task: Some(Task) }
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 236246104 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 745650909 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 558990 }
02:47:29 [DEBUG] (Btokio_core::reactor: added a timeout: 1
02:47:29 [TRACE] (Bhyper::client::pool: [<unknown>:178] park; waiting for idle connection: "http://apresolve.spotify.com"
02:47:29 [TRACE] (Bhyper::client::connect: [<unknown>:118] Http::connect("http://apresolve.spotify.com/")
02:47:29 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:29 [DEBUG] (Bhyper::client::dns: resolving host="apresolve.spotify.com", port=80
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None, read_task: Some(Task) }
02:47:29 [TRACE] (Btokio_io::framed_write: [<unknown>:182] flushing framed transport
02:47:29 [TRACE] (Btokio_io::framed_write: [<unknown>:185] writing; remaining=306
02:47:29 [TRACE] (Btokio_io::framed_write: [<unknown>:202] framed transport flushed
02:47:29 [DEBUG] (Btokio_core::reactor: updating a timeout: 1
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 7384878 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 757155719 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 549991 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 17000 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 758137703 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 691988 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 681988 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 759789675 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 900985 }
02:47:29 [DEBUG] (Bhyper::client::connect: connecting to 104.199.240.211:80
02:47:29 [TRACE] (Bmio::poll: [<unknown>:785] registering with poller
02:47:29 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable | Hup Token(6)
02:47:29 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:29 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:274] Dispatcher::poll
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:172] Conn::read_head
02:47:29 [DEBUG] (Bhyper::proto::h1::io: read 0 bytes
02:47:29 [TRACE] (Bhyper::proto::h1::io: [<unknown>:127] parse eof
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:836] State::close_read()
02:47:29 [DEBUG] (Bhyper::proto::h1::conn: read eof
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:284] read_keep_alive; is_mid_message=true
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:311] parking current task
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:423] maybe_notify; notifying task
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:580] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None, read_task: Some(Task) }
02:47:29 [TRACE] (Bhyper::proto::h1::conn: [<unknown>:588] shut down IO
02:47:29 [TRACE] (Bhyper::proto::h1::dispatch: [<unknown>:74] Dispatch::poll done
02:47:29 [TRACE] (Bmio::poll: [<unknown>:905] deregistering handle with poller
02:47:29 [DEBUG] (Btokio_reactor: dropping I/O source: 5
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 43896276 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 806391907 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 632989 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 19999 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 807328891 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 979984 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 15000 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 808625870 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 540991 }
02:47:29 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable | Writable Token(5)
02:47:29 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:29 [TRACE] (Btokio_reactor: [<unknown>:330] event Writable Token(7)
02:47:29 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:29 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:29 [TRACE] (Btokio_io::framed_read: [<unknown>:192] frame decoded from buffer
02:47:29 [TRACE] (Btokio_io::framed_read: [<unknown>:189] attempting to decode a frame
02:47:29 [TRACE] (Btokio_io::framed_write: [<unknown>:182] flushing framed transport
02:47:29 [TRACE] (Btokio_io::framed_write: [<unknown>:202] framed transport flushed
02:47:29 [DEBUG] (Btokio_core::reactor: loop poll - Duration { secs: 0, nanos: 113553128 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop time - Instant { tv_sec: 5535, tv_nsec: 922993984 }
02:47:29 [DEBUG] (Btokio_core::reactor: loop process, Duration { secs: 0, nanos: 556991 }
02:47:29 [DEBUG] (Blibrespot_connect::spirc: drop Spirc[0]
02:47:29 [DEBUG] (Blibrespot_playback::player: Shutting down player thread ...
02:47:29 [DEBUG] (Blibrespot_playback::player: drop Player[0]
02:47:29 [DEBUG] (Blibrespot_core::session: drop Session[0]
02:47:29 [DEBUG] (Blibrespot::component: drop MercuryManager
02:47:29 [TRACE] (Btokio_reactor: [<unknown>:330] event Readable Token(0)
02:47:29 [DEBUG] (Btokio_reactor: loop process - 1 events, 0.000s
02:47:29 [DEBUG] (Btokio_reactor::background: shutting background reactor down NOW
02:47:29 [DEBUG] (Btokio_reactor::background: background reactor has shutdown
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:871] shutdown; state=State { lifecycle: 0, num_futures: 0 }
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:917] -> transitioned to shutdown
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:929] -> shutting down workers
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:933] -> shutdown worker; idx=0; state=WorkerState { lifecycle: "WORKER_SHUTDOWN", is_pushed: true }
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:948] signal_stop -- WORKER_SHUTDOWN; idx=0
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:983] worker_terminated; num_workers=0
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:986] notifying shutdown task
02:47:29 [TRACE] (Btokio_threadpool: [/root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-threadpool-0.1.0/src/lib.rs:851] Shutdown::poll
02:47:29 [DEBUG] (Btokio_core::reactor::timeout_token: cancel timeout 0
02:47:29 [DEBUG] (Btokio_core::reactor::timeout_token: cancel timeout 1
02:47:29 [DEBUG] (Blibrespot_core::session: drop Dispatch
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment