wkchu icon

spotifyd.crash.verbose.online

wkchu | PRO | 12/18/18 09:07:13 PM UTC | 0 ⭐ | 827 👁️ | Never ⏰ | []
text |

166.76 KB

|

None

|

0 👍

/

0 👎

Script started on 2018-12-18 22:44:33+01:00 [TERM="screen" TTY="/dev/pts/3" COLUMNS="213" LINES="56"]
[alarm@alarmpi ~]$ 
(reverse-i-search)`': s': lso': sudo vim /etc/asound.conf 
([8@failed reverse-i-search)`sop': sudo vim /etc/a^C
[alarm@alarmpi ~]$ 
(reverse-i-search)`': s': lsp': spotifyd --no-daemon -v[1@o': [1@t': [1@i': [1@f': [1@y': [1@d': 
[alarm@alarmpi ~]$ 
22:44:40 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:44:40 [TRACE] tokio_threadpool::builder: [<unknown>:401] build; num-workers=4
22:44:40 [DEBUG] tokio_reactor::background: starting background reactor
22:44:40 [INFO] Using software volume controller.
22:44:40 [DEBUG] librespot_connect::discovery: Zeroconf server listening on 0.0.0.0:0
22:44:40 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:44:40 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:44:40 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:44:40 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:44:40 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:40 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:44:40 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(8388610)
22:44:40 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:40 [DEBUG] tokio_core::reactor: consuming notification queue
22:44:40 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(12582915)
22:44:40 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:40 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:44:40 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(224.0.0.251:5353)
22:44:40 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:44:40 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:40 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:44:40 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:40 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:44:40 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V6([ff02::fb]:5353)
22:44:40 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(8388610)
22:44:40 [DEBUG] tokio_core::reactor: loop poll - 1.440659ms
22:44:40 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23616, tv_nsec: 905879627 }
22:44:40 [DEBUG] tokio_core::reactor: loop process, 160.102µs
22:44:40 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:40 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.253:5353)
22:44:40 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(8388610)
22:44:40 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:40 [TRACE] mdns::fsm: [<unknown>:88] received packet from V4(192.168.3.253:5353) with no query
22:44:40 [TRACE] mdns::fsm: [<unknown>:77] received packet from V6([fe80::ba27:ebff:fe42:e843]:5353)
22:44:40 [TRACE] mdns::fsm: [<unknown>:88] received packet from V6([fe80::ba27:ebff:fe42:e843]:5353) with no query
22:44:40 [DEBUG] tokio_core::reactor: loop poll - 403.224µs
22:44:40 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23616, tv_nsec: 906505660 }
22:44:40 [DEBUG] tokio_core::reactor: loop process, 79.374µs
22:44:42 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:44:42 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:42 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.26:5353)
22:44:42 [DEBUG] mdns::fsm: received question: IN _D2CA5178._sub._googlecast._tcp.local
22:44:42 [DEBUG] mdns::fsm: received question: IN _googlecast._tcp.local
22:44:42 [DEBUG] tokio_core::reactor: loop poll - 1.905254963s
22:44:42 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23618, tv_nsec: 811882653 }
22:44:42 [DEBUG] tokio_core::reactor: loop process, 167.03µs
22:44:57 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:44:57 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:57 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:36574)
22:44:57 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:44:57 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:44:57 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:36574)
22:44:57 [DEBUG] tokio_core::reactor: loop poll - 15.59096128s
22:44:57 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23634, tv_nsec: 403087732 }
22:44:57 [DEBUG] tokio_core::reactor: loop process, 98.175µs
22:44:57 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:44:57 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:57 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:44:57 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:57 [DEBUG] tokio_core::reactor: loop poll - 10.143933ms
22:44:57 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23634, tv_nsec: 413376871 }
22:44:57 [DEBUG] tokio_core::reactor: loop process, 131.04µs
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:44:57 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:44:57 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(16777220)
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:44:57 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:57 [DEBUG] tokio_core::reactor: loop poll - 447.39µs
22:44:57 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23634, tv_nsec: 414004727 }
22:44:57 [DEBUG] tokio_core::reactor: loop process, 127.707µs
22:44:57 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(16777220)
22:44:57 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:44:57 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:44:57 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:44:57 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:44:57 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:44:57 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:44:57 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:44:57 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:44:57 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:44:57 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:44:57 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:44:57 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:44:57 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:44:57 [DEBUG] tokio_core::reactor: loop poll - 1.335192ms
22:44:57 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23634, tv_nsec: 415510750 }
22:44:57 [DEBUG] tokio_core::reactor: loop process, 86.613µs
22:44:57 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(16777220)
22:44:57 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:44:57 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:44:57 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:44:57 [DEBUG] hyper::proto::h1::conn: read eof
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:44:57 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:44:57 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:44:57 [DEBUG] tokio_reactor: dropping I/O source: 4
22:44:57 [DEBUG] tokio_core::reactor: loop poll - 2.297314ms
22:44:57 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23634, tv_nsec: 417943270 }
22:44:57 [DEBUG] tokio_core::reactor: loop process, 82.239µs
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:5353)
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [DEBUG] mdns::fsm: received question: IN _CC32E753._sub._googlecast._tcp.local
22:45:00 [DEBUG] mdns::fsm: received question: IN _googlecast._tcp.local
22:45:00 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:5353)
22:45:00 [DEBUG] mdns::fsm: received question: IN _CC32E753._sub._googlecast._tcp.local
22:45:00 [DEBUG] mdns::fsm: received question: IN _googlecast._tcp.local
22:45:00 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:36574)
22:45:00 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:00 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:00 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:5353)
22:45:00 [DEBUG] mdns::fsm: received question: IN _CC32E753._sub._googlecast._tcp.local
22:45:00 [DEBUG] mdns::fsm: received question: IN _googlecast._tcp.local
22:45:00 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:36574)
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 2.337957925s
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23636, tv_nsec: 756029319 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 292.757µs
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 184.737µs
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23636, tv_nsec: 756605249 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 164.685µs
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(20971524)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 650.512µs
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23636, tv_nsec: 757495810 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 156.665µs
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:00 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:00 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:00 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:00 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:00 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:00 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:00 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:00 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 1.980651ms
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23636, tv_nsec: 759714792 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 152.603µs
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(20971524)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:00 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:00 [DEBUG] hyper::proto::h1::conn: read eof
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:00 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:00 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 21.745242ms
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23636, tv_nsec: 781692011 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 177.498µs
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(20971524)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.001s
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:40972)
22:45:00 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:00 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:00 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:40972)
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 603.641749ms
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 385596257 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 228.851µs
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 1.577219ms
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 387492170 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 231.976µs
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(25165828)
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 800.823µs
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 388614291 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 194.581µs
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:00 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:00 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:00 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:00 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:00 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:00 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:00 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:00 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? true
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:00 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:00 [DEBUG] hyper::proto::h1::conn: read eof
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:00 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:00 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 3.227927ms
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 392334608 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 171.665µs
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 154.321µs
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 392743874 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 281.871µs
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(29360132)
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 503.223µs
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 393611259 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 287.704µs
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:00 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:00 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:00 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:00 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:00 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:00 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:00 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:00 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:00 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 2.037057ms
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 396025134 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 162.289µs
22:45:00 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(29360132)
22:45:00 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:00 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:00 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:00 [DEBUG] hyper::proto::h1::conn: read eof
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:00 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:00 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:00 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:00 [DEBUG] tokio_core::reactor: loop poll - 5.713417ms
22:45:00 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23637, tv_nsec: 401988912 }
22:45:00 [DEBUG] tokio_core::reactor: loop process, 158.435µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 1.290219208s
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 692453169 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 188.122µs
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:02 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(33554436)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 759.001µs
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 693486958 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 212.132µs
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:02 [DEBUG] hyper::proto::h1::io: read 906 bytes
22:45:02 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 906])
22:45:02 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(227)
22:45:02 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:02 [DEBUG] hyper::proto::h1::io: parsed 7 headers (227 bytes)
22:45:02 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (679 bytes)
22:45:02 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:02 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:02 [DEBUG] librespot_connect::discovery: Post "/" {}
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:279] Conn::read_body
22:45:02 [TRACE] hyper::proto::h1::decode: [<unknown>:88] decode; state=Length(679)
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Body(Length(0)), writing: Init, keep_alive: Busy, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 1.775811ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 695558598 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 161.195µs
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:279] Conn::read_body
22:45:02 [TRACE] hyper::proto::h1::decode: [<unknown>:88] decode; state=Length(0)
22:45:02 [DEBUG] hyper::proto::h1::conn: incoming body completed
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:02 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:02 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Post)
22:45:02 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 57B
22:45:02 [DEBUG] hyper::proto::h1::io: flushed 152 bytes
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 67.327836ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 763130076 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 119.582µs
22:45:02 [TRACE] hyper::client::pool: [<unknown>:125] park; waiting for idle connection: "http://apresolve.spotify.com"
22:45:02 [TRACE] hyper::client::connect: [<unknown>:118] Http::connect("http://apresolve.spotify.com/")
22:45:02 [DEBUG] hyper::client::dns: resolving host="apresolve.spotify.com", port=80
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 328.485µs
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 764932136 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 86.926µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(33554436)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:02 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:02 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:02 [DEBUG] hyper::proto::h1::conn: read eof
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:02 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:02 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 3.590631ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 768653703 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 90.728µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.26:5353)
22:45:02 [DEBUG] mdns::fsm: received question: IN _D2CA5178._sub._googlecast._tcp.local
22:45:02 [DEBUG] mdns::fsm: received question: IN _googlecast._tcp.local
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 32.881142ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 801673958 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 190.831µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:40972)
22:45:02 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:02 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:02 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:40972)
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 17.858ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 819816277 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 373.225µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 49.9141ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 870220632 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 299.996µs
22:45:02 [DEBUG] hyper::client::connect: connecting to 104.199.64.136:80
22:45:02 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(37748740)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 110.050413ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 981348167 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 367.912µs
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=false
22:45:02 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:02 [TRACE] hyper::proto::h1::role: [<unknown>:349] Client::encode has_body=false, method=None
22:45:02 [TRACE] hyper::proto::h1::io: [<unknown>:546] reclaiming write buf Vec
22:45:02 [DEBUG] hyper::proto::h1::io: flushed 47 bytes
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: KeepAlive, keep_alive: Busy, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 1.031706ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23638, tv_nsec: 983070125 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 184.685µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(37748740)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:02 [DEBUG] hyper::proto::h1::io: read 686 bytes
22:45:02 [TRACE] hyper::proto::h1::role: [<unknown>:254] Response.parse([Header; 100], [u8; 686])
22:45:02 [TRACE] hyper::proto::h1::role: [<unknown>:259] Response.parse Complete(268)
22:45:02 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:02 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Vary"
22:45:02 [DEBUG] hyper::proto::h1::io: parsed 9 headers (268 bytes)
22:45:02 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (418 bytes)
22:45:02 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:02 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:279] Conn::read_body
22:45:02 [TRACE] hyper::proto::h1::decode: [<unknown>:88] decode; state=Length(418)
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Body(Length(0)), writing: KeepAlive, keep_alive: Busy, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 77.824525ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 61170427 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 175.31µs
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:279] Conn::read_body
22:45:02 [TRACE] hyper::proto::h1::decode: [<unknown>:88] decode; state=Length(0)
22:45:02 [DEBUG] hyper::proto::h1::conn: incoming body completed
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=false
22:45:02 [TRACE] want: [<unknown>:268] signal: Want
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [TRACE] want: [<unknown>:132] poll_want: taker wants!
22:45:02 [TRACE] hyper::client::pool: [<unknown>:306] pool dropped, dropping pooled ("http://apresolve.spotify.com")
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 1.020924ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 62672386 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 185.206µs
22:45:02 [INFO] Connecting to AP "******"
22:45:02 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=false
22:45:02 [TRACE] hyper::proto::h1::dispatch: [<unknown>:414] client tx closed
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:914] State::close_write()
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Closed, keep_alive: Disabled, error: None }
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:02 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:02 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:02 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:02 [TRACE] want: [<unknown>:261] signal: Closed
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 1.131965ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 204089534 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 195.102µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(41943045)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 85.936139ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 290312805 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 911.186µs
22:45:02 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:02 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:02 [DEBUG] tokio_core::reactor: loop poll - 95.585495ms
22:45:02 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 455433347 }
22:45:02 [DEBUG] tokio_core::reactor: loop process, 281.559µs
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:191] writing; remaining=268
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 232.946392ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 757033391 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 828.636µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [INFO] Authenticated as "****" !
22:45:03 [DEBUG] librespot_core::session: new Session[0]
22:45:03 [DEBUG] librespot_connect::spirc: new Spirc[0]
22:45:03 [DEBUG] librespot::component: new MercuryManager
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [DEBUG] librespot_playback::player: new Player[0]
22:45:03 [DEBUG] librespot_playback::audio_backend::pulseaudio: Using PulseAudio sink
22:45:03 [DEBUG] librespot_connect::spirc: input volume:65535 to mixer: 65535
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [DEBUG] librespot_core::session: Session[0] strong=3 weak=2
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [INFO] Country: "CH"
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:191] writing; remaining=398
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 2.670852ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 764677721 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 173.487µs
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.002s
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 366.349µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 765303181 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 151.561µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 98.871807ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 864404725 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 159.477µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [DEBUG] librespot_core::mercury: unknown subscription uri=hm://remote/3/user/****/2474f3a27a3a14398ce839d7094d6e96a1ad34ba
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 57.543534ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 922198308 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 148.227µs
22:45:03 [DEBUG] librespot_core::mercury: subscribed uri=hm://remote/3/user/****/ count=0
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 27.343µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 922627677 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 155.884µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 705.668µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 923560530 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 206.299µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 492.65µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 924348541 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 149.894µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 533.795µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23639, tv_nsec: 925113739 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 146.509µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 106.525563ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 31854716 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 158.696µs
22:45:03 [DEBUG] librespot_connect::spirc: kMessageTypeNotify "BAH-W09" f4e1aff727d403458a4ff5d3bee0b289d7c6b1fd 1128761214 1545169503407
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 27.812µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 32806058 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 180.571µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 129.088555ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 162153881 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 168.436µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 708.22µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 163115275 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 137.811µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 1.888987ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 165214155 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 194.476µs
22:45:03 [DEBUG] librespot_connect::spirc: kMessageTypeLoad "BAH-W09" f4e1aff727d403458a4ff5d3bee0b289d7c6b1fd 2 1545169503407
22:45:03 [DEBUG] librespot_playback::player: command=Load(SpotifyId(u128!(310569114975204433575564076815579724266)), true, 26782)
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:191] writing; remaining=2415
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 701.136µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 167561572 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 159.686µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 173.478977ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 341278359 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 157.81µs
22:45:03 [DEBUG] librespot_connect::spirc: kMessageTypeNotify "Web Player (Chrome)" 2474f3a27a3a14398ce839d7094d6e96a1ad34ba 1128761593 1545169503786
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 18.229µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 341826008 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 153.696µs
22:45:03 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:03 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:03 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:03 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 42.460342ms
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 384511086 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 161.873µs
22:45:03 [DEBUG] librespot_connect::spirc: kMessageTypeNotify "BAH-W09" f4e1aff727d403458a4ff5d3bee0b289d7c6b1fd 1128761675 1545169503868
22:45:03 [DEBUG] tokio_core::reactor: loop poll - 28.385µs
22:45:03 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 385099152 }
22:45:03 [DEBUG] tokio_core::reactor: loop process, 159.425µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 124.430386ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 509764066 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 146.925µs
22:45:04 [INFO] Loading track "Ivory Gardens" with Spotify URI "spotify:track:76SOCUGCiF3tgkm9FwEPSG"
22:45:04 [DEBUG] librespot::component: new AudioKeyManager
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 29.114µs
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 510190050 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 326.975µs
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:191] writing; remaining=49
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 375.672µs
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 510971602 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 150.467µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [DEBUG] librespot_audio::fetch: Downloading file 562391fdb29101f16123809e0f00ea47f2df11d0
22:45:04 [TRACE] librespot_audio::fetch: [/home/alarm/.cargo/git/checkouts/librespot-06fda9f186b35c32/3614404/audio/src/fetch.rs:173] requesting chunk 0
22:45:04 [DEBUG] librespot::component: new ChannelManager
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 105.256829ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 616456710 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 162.134µs
22:45:04 [DEBUG] tokio_core::reactor: consuming notification queue
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:191] writing; remaining=53
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 492.546µs
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 617194774 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 163.07µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:04 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 141.513189ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 758948532 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 146.873µs
22:45:04 [DEBUG] librespot_connect::spirc: kMessageTypeNotify "BAH-W09" f4e1aff727d403458a4ff5d3bee0b289d7c6b1fd 1128761955 1545169504148
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 20.26µs
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 759465712 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 136.665µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:04 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:04 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:04 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 63.208045ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 822873703 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 182.862µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 1.560866ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 824707742 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 184.529µs
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:04 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(46137348)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 847.542µs
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 825825957 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 159.893µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(46137348)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(46137348)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:04 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:04 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:04 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:04 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:04 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:04 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:04 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:04 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:04 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:04 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:04 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:04 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:04 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? true
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:04 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:04 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:04 [DEBUG] hyper::proto::h1::conn: read eof
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:04 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:04 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 5.228266ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 831294584 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 163.071µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 2.412105ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 833952832 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 183.226µs
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:04 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 491.244µs
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 834747353 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 152.914µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(50331652)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:04 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:04 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:04 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:04 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:04 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:04 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:04 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:04 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:04 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:04 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:04 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:04 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 4.266664ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 839295055 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 177.81µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(50331652)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(50331652)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:04 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:04 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:04 [DEBUG] hyper::proto::h1::conn: read eof
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:04 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:04 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:04 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 7.885055ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 847442190 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 90.103µs
22:45:04 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:04 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:04 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
2222:45:04 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
:4522:45:04 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
:022:45:04 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
4 [ERROR] 22:45:04 [DEBUG] tokio_core::reactor: loop poll - 48.292923ms
channel error: 22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 895872924 }
2 22:45:04 [DEBUG] tokio_core::reactor: loop process, 281.142µs
1
22:45:04 [ERROR] Caught panic with message: called `Result::unwrap()` on an `Err` value: ChannelError
22:45:04 [DEBUG] librespot_playback::player: drop Player[0]
22:45:04 [DEBUG] tokio_core::reactor: loop poll - 1.957735ms
22:45:04 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23640, tv_nsec: 898211436 }
22:45:04 [DEBUG] tokio_core::reactor: loop process, 300.048µs
22:45:06 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:06 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:06 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:06 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:06 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:06 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:06 [DEBUG] tokio_core::reactor: loop poll - 1.924627806s
22:45:06 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23642, tv_nsec: 823297309 }
22:45:06 [DEBUG] tokio_core::reactor: loop process, 191.82µs
22:45:06 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:06 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:06 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:06 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:06 [DEBUG] tokio_core::reactor: loop poll - 2.835016ms
22:45:06 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23642, tv_nsec: 826424144 }
22:45:06 [DEBUG] tokio_core::reactor: loop process, 234.112µs
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:06 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:06 [DEBUG] tokio_core::reactor: loop poll - 472.494µs
22:45:06 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23642, tv_nsec: 827210644 }
22:45:06 [DEBUG] tokio_core::reactor: loop process, 165.832µs
22:45:06 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(54525956)
22:45:06 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:06 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:06 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:06 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:06 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:06 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:06 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:06 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:06 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:06 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:06 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:06 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:06 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:06 [DEBUG] tokio_core::reactor: loop poll - 2.423719ms
22:45:06 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23642, tv_nsec: 829888995 }
22:45:06 [DEBUG] tokio_core::reactor: loop process, 273.539µs
22:45:06 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(54525956)
22:45:06 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:06 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:06 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:06 [DEBUG] hyper::proto::h1::conn: read eof
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:06 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:06 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:06 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:06 [DEBUG] tokio_core::reactor: loop poll - 7.294698ms
22:45:06 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23642, tv_nsec: 837553220 }
22:45:06 [DEBUG] tokio_core::reactor: loop process, 153.8µs
22:45:08 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:08 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:08 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:08 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:08 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:08 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:08 [DEBUG] tokio_core::reactor: loop poll - 1.986724669s
22:45:08 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23644, tv_nsec: 824514865 }
22:45:08 [DEBUG] tokio_core::reactor: loop process, 201.664µs
22:45:08 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:08 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:08 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:08 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:08 [DEBUG] tokio_core::reactor: loop poll - 1.050195ms
22:45:08 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23644, tv_nsec: 825865369 }
22:45:08 [DEBUG] tokio_core::reactor: loop process, 180.778µs
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:08 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:08 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(58720260)
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:08 [DEBUG] tokio_core::reactor: loop poll - 618.378µs
22:45:08 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23644, tv_nsec: 826754420 }
22:45:08 [DEBUG] tokio_core::reactor: loop process, 171.977µs
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:08 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:08 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:08 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:08 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:08 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:08 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:08 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:08 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:08 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:08 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:08 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:08 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:08 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:08 [DEBUG] tokio_core::reactor: loop poll - 2.197784ms
22:45:08 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23644, tv_nsec: 829216471 }
22:45:08 [DEBUG] tokio_core::reactor: loop process, 161.196µs
22:45:08 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(58720260)
22:45:08 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:08 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:08 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:08 [DEBUG] hyper::proto::h1::conn: read eof
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:08 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:08 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:08 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:08 [DEBUG] tokio_core::reactor: loop poll - 4.924676ms
22:45:08 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23644, tv_nsec: 834391405 }
22:45:08 [DEBUG] tokio_core::reactor: loop process, 164.165µs
22:45:10 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:10 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:10 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:10 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:10 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:10 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:10 [DEBUG] tokio_core::reactor: loop poll - 2.004670743s
22:45:10 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23646, tv_nsec: 839309072 }
22:45:10 [DEBUG] tokio_core::reactor: loop process, 188.278µs
22:45:10 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:10 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:10 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:10 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:10 [DEBUG] tokio_core::reactor: loop poll - 1.133631ms
22:45:10 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23646, tv_nsec: 840716397 }
22:45:10 [DEBUG] tokio_core::reactor: loop process, 173.019µs
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:10 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:10 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(62914564)
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:10 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:10 [DEBUG] tokio_core::reactor: loop poll - 617.023µs
22:45:10 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23646, tv_nsec: 841587792 }
22:45:10 [DEBUG] tokio_core::reactor: loop process, 316.298µs
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:10 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:10 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:10 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:10 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:10 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:10 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:10 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:10 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:10 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:10 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:10 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:10 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:10 [DEBUG] tokio_core::reactor: loop poll - 1.96435ms
22:45:10 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23646, tv_nsec: 843950158 }
22:45:10 [DEBUG] tokio_core::reactor: loop process, 153.852µs
22:45:10 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(62914564)
22:45:10 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:10 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:10 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:10 [DEBUG] hyper::proto::h1::conn: read eof
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:10 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:10 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:10 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:10 [DEBUG] tokio_core::reactor: loop poll - 5.492534ms
22:45:10 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23646, tv_nsec: 849675085 }
22:45:10 [DEBUG] tokio_core::reactor: loop process, 157.602µs
22:45:12 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:12 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:12 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:12 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:12 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:12 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:12 [DEBUG] tokio_core::reactor: loop poll - 1.989680519s
22:45:12 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23648, tv_nsec: 839594924 }
22:45:12 [DEBUG] tokio_core::reactor: loop process, 181.352µs
22:45:12 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:12 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:12 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:12 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:12 [DEBUG] tokio_core::reactor: loop poll - 1.179881ms
22:45:12 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23648, tv_nsec: 841057353 }
22:45:12 [DEBUG] tokio_core::reactor: loop process, 270.934µs
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:12 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:12 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(67108868)
22:45:12 [DEBUG] tokio_core::reactor: loop poll - 489.16µs
22:45:12 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23648, tv_nsec: 841897759 }
22:45:12 [DEBUG] tokio_core::reactor: loop process, 301.194µs
22:45:12 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:12 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:12 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:12 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:12 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:12 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:12 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:12 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:12 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:12 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:12 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:12 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:12 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:12 [DEBUG] tokio_core::reactor: loop poll - 2.067109ms
22:45:12 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23648, tv_nsec: 844346790 }
22:45:12 [DEBUG] tokio_core::reactor: loop process, 150.884µs
22:45:12 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(67108868)
22:45:12 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:12 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:12 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:12 [DEBUG] hyper::proto::h1::conn: read eof
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:12 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:12 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:12 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:12 [DEBUG] tokio_core::reactor: loop poll - 6.112734ms
22:45:12 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23648, tv_nsec: 850691917 }
22:45:12 [DEBUG] tokio_core::reactor: loop process, 171.248µs
22:45:14 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:14 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:14 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:14 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:14 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:14 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:14 [DEBUG] tokio_core::reactor: loop poll - 1.989736354s
22:45:14 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23650, tv_nsec: 840683528 }
22:45:14 [DEBUG] tokio_core::reactor: loop process, 200.987µs
22:45:14 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:14 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:14 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:14 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:14 [DEBUG] tokio_core::reactor: loop poll - 1.13509ms
22:45:14 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23650, tv_nsec: 842118041 }
22:45:14 [DEBUG] tokio_core::reactor: loop process, 188.956µs
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:14 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:14 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(71303172)
22:45:14 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:14 [DEBUG] tokio_core::reactor: loop poll - 744.001µs
22:45:14 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23650, tv_nsec: 843133184 }
22:45:14 [DEBUG] tokio_core::reactor: loop process, 147.602µs
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:14 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:14 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:14 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:14 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:14 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:14 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:14 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:14 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:14 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:14 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:14 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:14 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:14 [DEBUG] tokio_core::reactor: loop poll - 1.934715ms
22:45:14 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23650, tv_nsec: 845288313 }
22:45:14 [DEBUG] tokio_core::reactor: loop process, 155.675µs
22:45:14 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(71303172)
22:45:14 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:14 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:14 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:14 [DEBUG] hyper::proto::h1::conn: read eof
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:14 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:14 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:14 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:14 [DEBUG] tokio_core::reactor: loop poll - 5.630865ms
22:45:14 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23650, tv_nsec: 851155633 }
22:45:14 [DEBUG] tokio_core::reactor: loop process, 144.894µs
22:45:16 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:16 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:16 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:16 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:16 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:16 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:16 [DEBUG] tokio_core::reactor: loop poll - 1.991890285s
22:45:16 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23652, tv_nsec: 843273103 }
22:45:16 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:16 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:16 [DEBUG] tokio_core::reactor: loop process, 182.498µs
22:45:16 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:16 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:16 [DEBUG] tokio_core::reactor: loop poll - 4.901447ms
22:45:16 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23652, tv_nsec: 848688867 }
22:45:16 [DEBUG] tokio_core::reactor: loop process, 177.706µs
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:16 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:16 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(75497476)
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:16 [DEBUG] tokio_core::reactor: loop poll - 647.335µs
22:45:16 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23652, tv_nsec: 849597345 }
22:45:16 [DEBUG] tokio_core::reactor: loop process, 179.842µs
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:16 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:16 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:16 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:16 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:16 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:16 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:16 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:16 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:16 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:16 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:16 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:16 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:16 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:16 [DEBUG] tokio_core::reactor: loop poll - 2.094869ms
22:45:16 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23652, tv_nsec: 851949919 }
22:45:16 [DEBUG] tokio_core::reactor: loop process, 166.509µs
22:45:16 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(75497476)
22:45:16 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:16 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:16 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:16 [DEBUG] hyper::proto::h1::conn: read eof
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:16 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:16 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:16 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:16 [DEBUG] tokio_core::reactor: loop poll - 6.428459ms
22:45:16 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23652, tv_nsec: 858626240 }
22:45:16 [DEBUG] tokio_core::reactor: loop process, 153.644µs
22:45:18 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:18 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:18 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:18 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:18 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:18 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:18 [DEBUG] tokio_core::reactor: loop poll - 1.968184185s
22:45:18 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23654, tv_nsec: 827044901 }
22:45:18 [DEBUG] tokio_core::reactor: loop process, 189.372µs
22:45:18 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:18 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:18 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:18 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:18 [DEBUG] tokio_core::reactor: loop poll - 3.415164ms
22:45:18 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23654, tv_nsec: 830809696 }
22:45:18 [DEBUG] tokio_core::reactor: loop process, 618.69µs
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:18 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:18 [DEBUG] tokio_core::reactor: loop poll - 494.525µs
22:45:18 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23654, tv_nsec: 832027285 }
22:45:18 [DEBUG] tokio_core::reactor: loop process, 159.581µs
22:45:18 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(79691780)
22:45:18 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:18 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:18 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:18 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:18 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:18 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:18 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:18 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:18 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:18 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:18 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:18 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:18 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:18 [DEBUG] tokio_core::reactor: loop poll - 2.221117ms
22:45:18 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23654, tv_nsec: 834507409 }
22:45:18 [DEBUG] tokio_core::reactor: loop process, 149.998µs
22:45:18 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(79691780)
22:45:18 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:18 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:18 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:18 [DEBUG] hyper::proto::h1::conn: read eof
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:18 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:18 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:18 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:18 [DEBUG] tokio_core::reactor: loop poll - 6.142474ms
22:45:18 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23654, tv_nsec: 840881026 }
22:45:18 [DEBUG] tokio_core::reactor: loop process, 164.789µs
22:45:20 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:20 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:20 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:5353)
22:45:20 [DEBUG] mdns::fsm: received question: IN _CC32E753._sub._googlecast._tcp.local
22:45:20 [DEBUG] mdns::fsm: received question: IN _googlecast._tcp.local
22:45:20 [DEBUG] tokio_core::reactor: loop poll - 1.819113177s
22:45:20 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23656, tv_nsec: 660241022 }
22:45:20 [DEBUG] tokio_core::reactor: loop process, 166.977µs
22:45:20 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:20 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:20 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:20 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:20 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:20 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:20 [DEBUG] tokio_core::reactor: loop poll - 167.135673ms
22:45:20 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23656, tv_nsec: 827625234 }
22:45:20 [DEBUG] tokio_core::reactor: loop process, 177.81µs
22:45:20 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:20 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:20 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:20 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:20 [DEBUG] tokio_core::reactor: loop poll - 2.656633ms
22:45:20 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23656, tv_nsec: 830560405 }
22:45:20 [DEBUG] tokio_core::reactor: loop process, 177.185µs
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:20 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:20 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(83886084)
22:45:20 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:20 [DEBUG] tokio_core::reactor: loop poll - 733.323µs
22:45:20 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23656, tv_nsec: 831554298 }
22:45:20 [DEBUG] tokio_core::reactor: loop process, 148.019µs
22:45:20 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(83886084)
22:45:20 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:20 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:20 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:20 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:20 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:20 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:20 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:20 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:20 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:20 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:20 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:20 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:20 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:20 [DEBUG] tokio_core::reactor: loop poll - 3.943699ms
22:45:20 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23656, tv_nsec: 835720651 }
22:45:20 [DEBUG] tokio_core::reactor: loop process, 158.8µs
22:45:20 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(83886084)
22:45:20 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:20 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:20 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:20 [DEBUG] hyper::proto::h1::conn: read eof
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:20 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:20 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:20 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:20 [DEBUG] tokio_core::reactor: loop poll - 6.177004ms
22:45:20 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23656, tv_nsec: 842133746 }
22:45:20 [DEBUG] tokio_core::reactor: loop process, 161.717µs
22:45:22 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:22 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:22 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.26:5353)
22:45:22 [DEBUG] mdns::fsm: received question: IN _D2CA5178._sub._googlecast._tcp.local
22:45:22 [DEBUG] mdns::fsm: received question: IN _googlecast._tcp.local
22:45:22 [DEBUG] tokio_core::reactor: loop poll - 1.964117728s
22:45:22 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23658, tv_nsec: 806494857 }
22:45:22 [DEBUG] tokio_core::reactor: loop process, 166.3µs
22:45:22 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:22 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:22 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:22 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:22 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:22 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:22 [DEBUG] tokio_core::reactor: loop poll - 21.847064ms
22:45:22 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23658, tv_nsec: 828592752 }
22:45:22 [DEBUG] tokio_core::reactor: loop process, 193.122µs
22:45:22 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:22 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:22 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:22 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:22 [DEBUG] tokio_core::reactor: loop poll - 2.62257ms
22:45:22 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23658, tv_nsec: 831508235 }
22:45:22 [DEBUG] tokio_core::reactor: loop process, 183.123µs
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:22 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:22 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(88080388)
22:45:22 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:22 [DEBUG] tokio_core::reactor: loop poll - 966.602µs
22:45:22 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23658, tv_nsec: 832743844 }
22:45:22 [DEBUG] tokio_core::reactor: loop process, 151.405µs
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:22 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:22 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:22 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:22 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:22 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:22 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:22 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:22 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:22 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:22 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:22 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:22 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:22 [DEBUG] tokio_core::reactor: loop poll - 1.997266ms
22:45:22 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23658, tv_nsec: 834964597 }
22:45:22 [DEBUG] tokio_core::reactor: loop process, 156.352µs
22:45:22 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(88080388)
22:45:22 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:22 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:22 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:22 [DEBUG] hyper::proto::h1::conn: read eof
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:22 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:22 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:22 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:22 [DEBUG] tokio_core::reactor: loop poll - 5.204413ms
22:45:22 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23658, tv_nsec: 840402653 }
22:45:22 [DEBUG] tokio_core::reactor: loop process, 155.571µs
22:45:24 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:24 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:24 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:24 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:24 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:24 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:24 [DEBUG] tokio_core::reactor: loop poll - 2.00478997s
22:45:24 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23660, tv_nsec: 845428401 }
22:45:24 [DEBUG] tokio_core::reactor: loop process, 176.56µs
22:45:24 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:24 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:24 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:24 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:24 [DEBUG] tokio_core::reactor: loop poll - 1.562115ms
22:45:24 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23660, tv_nsec: 847253638 }
22:45:24 [DEBUG] tokio_core::reactor: loop process, 167.706µs
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:24 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:24 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(92274692)
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:24 [DEBUG] tokio_core::reactor: loop poll - 622.127µs
22:45:24 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23660, tv_nsec: 848125814 }
22:45:24 [DEBUG] tokio_core::reactor: loop process, 175.05µs
22:45:24 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:24 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:24 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:24 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:24 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:24 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:24 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:24 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:24 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:24 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:24 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:24 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:24 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:24 [DEBUG] tokio_core::reactor: loop poll - 2.173879ms
22:45:24 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23660, tv_nsec: 850564742 }
22:45:24 [DEBUG] tokio_core::reactor: loop process, 159.268µs
22:45:24 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(92274692)
22:45:24 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:24 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:24 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:24 [DEBUG] hyper::proto::h1::conn: read eof
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:24 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:24 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:24 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:24 [DEBUG] tokio_core::reactor: loop poll - 5.971487ms
22:45:24 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23660, tv_nsec: 856779298 }
22:45:24 [DEBUG] tokio_core::reactor: loop process, 164.737µs
22:45:26 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:26 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:26 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:26 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:26 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:26 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:26 [DEBUG] tokio_core::reactor: loop poll - 1.990688694s
22:45:26 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23662, tv_nsec: 847715332 }
22:45:26 [DEBUG] tokio_core::reactor: loop process, 200.831µs
22:45:26 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:26 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:26 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:26 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:26 [DEBUG] tokio_core::reactor: loop poll - 1.556594ms
22:45:26 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23662, tv_nsec: 849577391 }
22:45:26 [DEBUG] tokio_core::reactor: loop process, 360.204µs
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:26 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:26 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(96468996)
22:45:26 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:26 [DEBUG] tokio_core::reactor: loop poll - 1.831956ms
22:45:26 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23662, tv_nsec: 851957986 }
22:45:26 [DEBUG] tokio_core::reactor: loop process, 186.195µs
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:26 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:26 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:26 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:26 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:26 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:26 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:26 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:26 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:26 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:26 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:26 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:26 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:26 [DEBUG] tokio_core::reactor: loop poll - 2.24169ms
22:45:26 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23662, tv_nsec: 854468787 }
22:45:26 [DEBUG] tokio_core::reactor: loop process, 155.415µs
22:45:26 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(96468996)
22:45:26 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:26 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(96468996)
22:45:26 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:26 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:26 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:26 [DEBUG] hyper::proto::h1::conn: read eof
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:26 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:26 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:26 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:26 [DEBUG] tokio_core::reactor: loop poll - 5.266131ms
22:45:26 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23662, tv_nsec: 859974550 }
22:45:26 [DEBUG] tokio_core::reactor: loop process, 264.788µs
22:45:28 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:28 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:28 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:28 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:28 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:28 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:28 [DEBUG] tokio_core::reactor: loop poll - 1.98857992s
22:45:28 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23664, tv_nsec: 848905403 }
22:45:28 [DEBUG] tokio_core::reactor: loop process, 198.748µs
22:45:28 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:28 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:28 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:28 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:28 [DEBUG] tokio_core::reactor: loop poll - 1.901955ms
22:45:28 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23664, tv_nsec: 851104906 }
22:45:28 [DEBUG] tokio_core::reactor: loop process, 197.029µs
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:28 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:28 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(100663300)
22:45:28 [DEBUG] tokio_core::reactor: loop poll - 548.378µs
22:45:28 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23664, tv_nsec: 851944687 }
22:45:28 [DEBUG] tokio_core::reactor: loop process, 325.256µs
22:45:28 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:28 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:28 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:28 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:28 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:28 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:28 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:28 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:28 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:28 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:28 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:28 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:28 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:28 [DEBUG] tokio_core::reactor: loop poll - 2.151848ms
22:45:28 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23664, tv_nsec: 854510644 }
22:45:28 [DEBUG] tokio_core::reactor: loop process, 156.769µs
22:45:28 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(100663300)
22:45:28 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:28 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(100663300)
22:45:28 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:28 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:28 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:28 [DEBUG] hyper::proto::h1::conn: read eof
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:28 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:28 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:28 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:28 [DEBUG] tokio_core::reactor: loop poll - 4.782699ms
22:45:28 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23664, tv_nsec: 859533288 }
22:45:28 [DEBUG] tokio_core::reactor: loop process, 156.456µs
22:45:30 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:30 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:30 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:30 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:30 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:30 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:30 [DEBUG] tokio_core::reactor: loop poll - 1.986608489s
22:45:30 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23666, tv_nsec: 846381409 }
22:45:30 [DEBUG] tokio_core::reactor: loop process, 199.685µs
22:45:30 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:30 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:30 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:30 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:30 [DEBUG] tokio_core::reactor: loop poll - 1.62123ms
22:45:30 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23666, tv_nsec: 848308676 }
22:45:30 [DEBUG] tokio_core::reactor: loop process, 171.195µs
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:30 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:30 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(104857604)
22:45:30 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:30 [DEBUG] tokio_core::reactor: loop poll - 742.23µs
22:45:30 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23666, tv_nsec: 849298663 }
22:45:30 [DEBUG] tokio_core::reactor: loop process, 156.977µs
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:30 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:30 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:30 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:30 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:30 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:30 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:30 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:30 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:30 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:30 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:30 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:30 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:30 [DEBUG] tokio_core::reactor: loop poll - 2.123619ms
22:45:30 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23666, tv_nsec: 851663737 }
22:45:30 [DEBUG] tokio_core::reactor: loop process, 160.206µs
22:45:30 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(104857604)
22:45:30 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:30 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:30 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:30 [DEBUG] hyper::proto::h1::conn: read eof
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:30 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:30 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:30 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:30 [DEBUG] tokio_core::reactor: loop poll - 6.151536ms
22:45:30 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23666, tv_nsec: 858058811 }
22:45:30 [DEBUG] tokio_core::reactor: loop process, 152.759µs
22:45:32 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:32 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:32 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:32 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:32 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:32 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:32 [DEBUG] tokio_core::reactor: loop poll - 1.992448155s
22:45:32 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23668, tv_nsec: 850740661 }
22:45:32 [DEBUG] tokio_core::reactor: loop process, 192.55µs
22:45:32 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:32 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:32 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:32 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:32 [DEBUG] tokio_core::reactor: loop poll - 1.083111ms
22:45:32 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23668, tv_nsec: 852109914 }
22:45:32 [DEBUG] tokio_core::reactor: loop process, 179.685µs
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:32 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:32 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(109051908)
22:45:32 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:32 [DEBUG] tokio_core::reactor: loop poll - 807.646µs
22:45:32 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23668, tv_nsec: 853181203 }
22:45:32 [DEBUG] tokio_core::reactor: loop process, 169.581µs
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:32 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:32 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:32 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:32 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:32 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:32 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:32 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:32 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:32 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:32 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:32 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:32 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:32 [DEBUG] tokio_core::reactor: loop poll - 2.444604ms
22:45:32 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23668, tv_nsec: 855881689 }
22:45:32 [DEBUG] tokio_core::reactor: loop process, 180.571µs
22:45:32 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(109051908)
22:45:32 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:32 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:32 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:32 [DEBUG] hyper::proto::h1::conn: read eof
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:32 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:32 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:32 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:32 [DEBUG] tokio_core::reactor: loop poll - 5.238267ms
22:45:32 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23668, tv_nsec: 861382296 }
22:45:32 [DEBUG] tokio_core::reactor: loop process, 154.581µs
22:45:34 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:34 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:34 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:34 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:34 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:34 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:34 [DEBUG] tokio_core::reactor: loop poll - 1.974775569s
22:45:34 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23670, tv_nsec: 836389112 }
22:45:34 [DEBUG] tokio_core::reactor: loop process, 621.086µs
22:45:34 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:34 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:34 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:34 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:34 [DEBUG] tokio_core::reactor: loop poll - 2.783141ms
22:45:34 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23670, tv_nsec: 839961775 }
22:45:34 [DEBUG] tokio_core::reactor: loop process, 317.548µs
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:34 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:34 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(113246212)
22:45:34 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:34 [DEBUG] tokio_core::reactor: loop poll - 630.773µs
22:45:34 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23670, tv_nsec: 841001137 }
22:45:34 [DEBUG] tokio_core::reactor: loop process, 499.629µs
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:34 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:34 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:34 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:34 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:34 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:34 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:34 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:34 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:34 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:34 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:34 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:34 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:34 [DEBUG] tokio_core::reactor: loop poll - 3.302978ms
22:45:34 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23670, tv_nsec: 844888795 }
22:45:34 [DEBUG] tokio_core::reactor: loop process, 201.456µs
22:45:34 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(113246212)
22:45:34 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:34 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:34 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:34 [DEBUG] hyper::proto::h1::conn: read eof
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:34 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:34 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:34 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:34 [DEBUG] tokio_core::reactor: loop poll - 5.430764ms
22:45:34 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23670, tv_nsec: 850630701 }
22:45:34 [DEBUG] tokio_core::reactor: loop process, 178.279µs
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(4194305)
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [TRACE] mdns::fsm: [<unknown>:77] received packet from V4(192.168.3.23:35829)
22:45:36 [DEBUG] mdns::fsm: received question: IN _spotify-connect._tcp.local
22:45:36 [TRACE] mdns::fsm: [<unknown>:183] found interface Interface { name: "eth0", addr: V4(Ifv4Addr { ip: 192.168.3.253, netmask: 255.255.255.0, broadcast: Some(192.168.3.255) }) }
22:45:36 [TRACE] mdns::fsm: [<unknown>:247] sending packet to V4(192.168.3.23:35829)
22:45:36 [DEBUG] tokio_core::reactor: loop poll - 1.985563454s
22:45:36 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23672, tv_nsec: 836462589 }
22:45:36 [DEBUG] tokio_core::reactor: loop process, 174.477µs
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Writable Token(4194305)
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(0)
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [DEBUG] tokio_core::reactor: loop poll - 2.994441ms
22:45:36 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23672, tv_nsec: 839719839 }
22:45:36 [DEBUG] tokio_core::reactor: loop process, 176.508µs
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:36 [TRACE] mio::poll: [<unknown>:785] registering with poller
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(117440516)
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None }
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:36 [DEBUG] tokio_core::reactor: loop poll - 714.574µs
22:45:36 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23672, tv_nsec: 840695347 }
22:45:36 [DEBUG] tokio_core::reactor: loop process, 171.561µs
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:36 [DEBUG] hyper::proto::h1::io: read 220 bytes
22:45:36 [TRACE] hyper::proto::h1::role: [<unknown>:46] Request.parse([Header; 100], [u8; 220])
22:45:36 [TRACE] hyper::proto::h1::role: [<unknown>:50] Request.parse Complete(220)
22:45:36 [TRACE] hyper::header: [<unknown>:355] maybe_literal not found, copying "Keep-Alive"
22:45:36 [DEBUG] hyper::proto::h1::io: parsed 6 headers (220 bytes)
22:45:36 [DEBUG] hyper::proto::h1::conn: incoming body is content-length (0 bytes)
22:45:36 [TRACE] hyper::proto: [<unknown>:133] expecting_continue(version=Http11, header=None) = false
22:45:36 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:36 [TRACE] hyper::proto: [<unknown>:122] should_keep_alive(version=Http11, header=None) = true
22:45:36 [TRACE] hyper::proto::h1::role: [<unknown>:129] Server::encode has_body=true, method=Some(Get)
22:45:36 [TRACE] hyper::proto::h1::encode: [<unknown>:100] encoding chunked 453B
22:45:36 [DEBUG] hyper::proto::h1::io: flushed 549 bytes
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:460] maybe_notify; read_from_io blocked
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None }
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:36 [DEBUG] tokio_core::reactor: loop poll - 2.066953ms
22:45:36 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23672, tv_nsec: 843019328 }
22:45:36 [DEBUG] tokio_core::reactor: loop process, 152.29µs
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable | Hup Token(117440516)
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:193] Conn::read_head
22:45:36 [DEBUG] hyper::proto::h1::io: read 0 bytes
22:45:36 [TRACE] hyper::proto::h1::io: [<unknown>:127] parse eof
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:904] State::close_read()
22:45:36 [DEBUG] hyper::proto::h1::conn: read eof
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:317] read_keep_alive; is_mid_message=true
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:654] flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None }
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:337] wants_read_again? false
22:45:36 [TRACE] hyper::proto::h1::conn: [<unknown>:662] shut down IO
22:45:36 [TRACE] mio::poll: [<unknown>:905] deregistering handle with poller
22:45:36 [DEBUG] tokio_reactor: dropping I/O source: 4
22:45:36 [DEBUG] tokio_core::reactor: loop poll - 6.628977ms
22:45:36 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23672, tv_nsec: 849882938 }
22:45:36 [DEBUG] tokio_core::reactor: loop process, 230.779µs
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Readable | Writable Token(41943045)
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:36 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:36 [TRACE] tokio_io::framed_read: [<unknown>:198] frame decoded from buffer
22:45:36 [TRACE] tokio_io::framed_read: [<unknown>:195] attempting to decode a frame
22:45:36 [TRACE] tokio_io::framed_write: [<unknown>:188] flushing framed transport
22:45:36 [TRACE] tokio_io::framed_write: [<unknown>:208] framed transport flushed
22:45:36 [DEBUG] tokio_core::reactor: loop poll - 225.374565ms
22:45:36 [DEBUG] tokio_core::reactor: loop time - Instant { tv_sec: 23673, tv_nsec: 75579999 }
22:45:36 [DEBUG] tokio_core::reactor: loop process, 141.092µs
22:45:36 [DEBUG] librespot_connect::spirc: kMessageTypePause "BAH-W09" f4e1aff727d403458a4ff5d3bee0b289d7c6b1fd 3 1545169504148
22:45:36 [ERROR] Caught panic with message: called `Result::unwrap()` on an `Err` value: "SendError(..)"
22:45:36 [DEBUG] librespot_connect::spirc: drop Spirc[0]
22:45:36 [DEBUG] librespot_playback::player: Shutting down player thread ...
22:45:36 [ERROR] Player thread panicked!
22:45:36 [DEBUG] librespot_core::session: drop Session[0]
22:45:36 [DEBUG] librespot::component: drop AudioKeyManager
22:45:36 [DEBUG] librespot::component: drop ChannelManager
22:45:36 [DEBUG] librespot::component: drop MercuryManager
22:45:36 [TRACE] tokio_threadpool::pool: [<unknown>:137] shutdown; state=pool::State { lifecycle: Running, num_futures: 0 }
22:45:36 [TRACE] tokio_threadpool::pool: [<unknown>:183]   -> transitioned to shutdown
22:45:36 [TRACE] tokio_threadpool::pool: [<unknown>:214]   -> shutting down workers
22:45:36 [TRACE] tokio_reactor: [<unknown>:368] event Readable Token(4194303)
22:45:36 [DEBUG] tokio_reactor: loop process - 1 events, 0.000s
22:45:36 [DEBUG] tokio_reactor::background: shutting background reactor down NOW
22:45:36 [DEBUG] tokio_reactor::background: background reactor has shutdown
22:45:36 [DEBUG] librespot_core::session: drop Dispatch
[alarm@alarmpi ~]$ exit
 Script done on 2018-12-18 22:45:45+01:00 [COMMAND_EXIT_CODE="101"]

Comments