Spotify API does not list Librespot as device after some time of no playback

[jcv8-dev]

Describe the bug Some time (haven't measured) after playback has stopped, the spotify get-available-devices api endpoint stops listing the librespot player as a device. Only after starting playback via the desktop app on the librespot player (it still shows up there) it shows up again in the api response. I can't tell if the fault is on spotify's end or with librespot or my configuration.

To reproduce Steps to reproduce the behavior:

1. Start Librespot with librespot --name "Librespot" -b 320 -c /tmp --enable-volume-normalisation --initial-volume 30 --device-type speaker -v -u username -p "password"

Log Never had the terminal open when it happened, might add later if needed.

Host (what you are running librespot on):

• OS: Ubuntu 22.04.1 Server

[roderickvd]

Please add a verbose log.

[jcv8-dev]

This is the log from before the device disappears in the api response. Currently waiting for it to disappear again, will add extra log entries then.

[2023-01-16T21:26:14Z INFO  librespot] librespot 0.4.2 UNKNOWN (Built on 2023-01-06, Build ID: V28ESijR, Profile: release)
[2023-01-16T21:26:14Z TRACE librespot] Command line argument(s):
[2023-01-16T21:26:14Z TRACE librespot]      name "Librespot"
[2023-01-16T21:26:14Z TRACE librespot]      b "320"
[2023-01-16T21:26:14Z TRACE librespot]      c "/tmp"
[2023-01-16T21:26:14Z TRACE librespot]      enable-volume-normalisation
[2023-01-16T21:26:14Z TRACE librespot]      initial-volume "30"
[2023-01-16T21:26:14Z TRACE librespot]      device-type "speaker"
[2023-01-16T21:26:14Z TRACE librespot]      v
[2023-01-16T21:26:14Z TRACE librespot]      u "XXXXXXXX"
[2023-01-16T21:26:14Z TRACE librespot]      p "XXXXXXXX"
[2023-01-16T21:26:14Z DEBUG librespot_discovery::server] Zeroconf server listening on 0.0.0.0:42127
[2023-01-16T21:26:14Z WARN  librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:4070
[2023-01-16T21:26:14Z WARN  librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:443
[2023-01-16T21:26:14Z WARN  librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:80
[2023-01-16T21:26:14Z INFO  librespot_core::session] Connecting to AP "ap-guc3.spotify.com:4070"
[2023-01-16T21:26:15Z INFO  librespot_core::session] Authenticated as "username" !
[2023-01-16T21:26:15Z WARN  librespot_core::cache] Cannot save credentials to cache: Permission denied (os error 13)
[2023-01-16T21:26:15Z DEBUG librespot_core::session] new Session[0]
[2023-01-16T21:26:15Z INFO  librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0)
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] Normalisation Type: Auto
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] Normalisation Pregain: 0.0 dB
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] Normalisation Threshold: -2.0 dBFS
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] Normalisation Method: Dynamic
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] Normalisation Attack: 5 ms
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] Normalisation Release: 100 ms
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] Normalisation Knee: 5 dB
[2023-01-16T21:26:15Z DEBUG librespot_connect::spirc] new Spirc[0]
[2023-01-16T21:26:15Z DEBUG librespot_connect::spirc] canonical_username: username
[2023-01-16T21:26:15Z DEBUG librespot::component] new MercuryManager
[2023-01-16T21:26:15Z DEBUG librespot_playback::mixer::mappings] Input volume 19660 mapped to: 0.79%
[2023-01-16T21:26:15Z WARN  librespot_core::cache] Cannot save volume to cache: Permission denied (os error 13)
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] new Player[0]
[2023-01-16T21:26:15Z INFO  librespot_playback::convert] Converting with ditherer: tpdf
[2023-01-16T21:26:15Z INFO  librespot_playback::audio_backend::rodio] Using Rodio sink with format S16 and cpal host: ALSA
[2023-01-16T21:26:15Z INFO  librespot_playback::audio_backend::rodio] Using audio device: default
[2023-01-16T21:26:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:26:15Z INFO  librespot_core::session] Country: "DE"
[2023-01-16T21:26:15Z DEBUG librespot_playback::audio_backend::rodio] Rodio sink was created
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] command=AddEventSender
[2023-01-16T21:26:15Z DEBUG librespot_playback::player] command=VolumeSet(19660)
[2023-01-16T21:26:15Z DEBUG librespot_core::mercury] subscribed uri=hm://remote/user/username/ count=0
[2023-01-16T21:26:15Z DEBUG librespot_connect::spirc] kMessageTypeNotify "Caspar’s Mac Pro" 6cfc1adb7e702ed05eaeff77fc5024eb2ed242f6 1014614530 1673904375543 kPlayStatusPause
[2023-01-16T21:26:16Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:18Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:20Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:22Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:24Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:26Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:28Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:30Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:32Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:34Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:36Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:38Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:40Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:42Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:44Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:46Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:48Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:50Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:52Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:54Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:56Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:26:58Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:27:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:27:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:28:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:29:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:30:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:31:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:32:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:33:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:34:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:35:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:36:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:37:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:38:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:39:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:40:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:40:54Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:41:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:42:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:43:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:44:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:45:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:46:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:47:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:48:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:49:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:50:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:51:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:52:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:53:00Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
[2023-01-16T21:54:15Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
[2023-01-16T21:54:21Z DEBUG librespot_connect::spirc] kMessageTypeNotify "Caspar’s Mac Pro" 6cfc1adb7e702ed05eaeff77fc5024eb2ed242f6 1016300055 1673906061068 kPlayStatusPause

[jcv8-dev]

I tried using the e-mail address of my spotify-account instead of the username and the error did not occur over one day. I will report back if that was not the solution.

[roderickvd]

If it pops up again, let's try and see if that way of authentication matters. For my own listening I always use zeroconf-based authentication, not username-based, I wonder if that makes a difference.

[jcv8-dev]

Ok, it happened again, but since I run librespot as a service, i don't have any logs on hand. Is it practical to redirect the output (stdout i guess) to a file?

This is what systemctl status librespot gave me after the player disappeared from the api (i have the librespot command in a .sh file that also contains pulseaudio -D):

● librespot.service - librespot
     Loaded: loaded (/etc/systemd/system/librespot.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2023-01-17 23:00:41 CET; 1h 39min ago
   Main PID: 1139 (sudo)
      Tasks: 9 (limit: 18994)
     Memory: 240.4M
     CGroup: /system.slice/librespot.service
             ├─1139 sudo /home/jcvb/librespot/service.sh
             ├─1362 sh /home/jcvb/librespot/service.sh
             ├─1391 pulseaudio -D
             └─1492 librespot --name "Librespot" -b 320 -c /tmp --enable-volume-normalisation --initial-volume 30 --device-type speaker -v -u username@gmail.com -p "xxxxxxxxx">

Jan 18 00:19:03 jcvbserv sudo[1492]: [2023-01-17T23:19:03Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 18 00:20:46 jcvbserv sudo[1492]: [2023-01-17T23:20:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 18 00:22:46 jcvbserv sudo[1492]: [2023-01-17T23:22:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 18 00:24:46 jcvbserv sudo[1492]: [2023-01-17T23:24:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 18 00:26:46 jcvbserv sudo[1492]: [2023-01-17T23:26:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 18 00:28:46 jcvbserv sudo[1492]: [2023-01-17T23:28:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 18 00:30:46 jcvbserv sudo[1492]: [2023-01-17T23:30:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 18 00:32:46 jcvbserv sudo[1492]: [2023-01-17T23:32:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 18 00:33:07 jcvbserv sudo[1492]: [2023-01-17T23:33:07Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 18 00:34:46 jcvbserv sudo[1492]: [2023-01-17T23:34:46Z DEBUG librespot_core::session] Session[0] strong=3 weak=4

[roderickvd]

We indeed still need that log. And am still interested if it’s different if you authenticate using Connect (zeroconf).

Note that most zeroconf problems are network related, can you rule that out?

It’s also possible that we need to send some ping message that we don’t know about. Is it different between 0.4.x and dev?

The cannot bind message is probably harmless, and probably that it cannot bind to an IPv6 address. Correct?

[jcv8-dev]

Switched to zeroconf and set up a automation in Home Assistant that notifies my when the player does not show up anymore. couldn't parse packet pretty much lines up with the first notification and the rest of the log messages shows up all day. Yes, i have disabled IPv6 on my network.

Jan 19 05:08:06 jcvbserv sudo[135885]: [2023-01-19T04:08:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:10:06 jcvbserv sudo[135885]: [2023-01-19T04:10:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:10:14 jcvbserv sudo[135885]: [2023-01-19T04:10:14Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 05:12:06 jcvbserv sudo[135885]: [2023-01-19T04:12:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:14:06 jcvbserv sudo[135885]: [2023-01-19T04:14:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:16:06 jcvbserv sudo[135885]: [2023-01-19T04:16:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:18:06 jcvbserv sudo[135885]: [2023-01-19T04:18:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:20:06 jcvbserv sudo[135885]: [2023-01-19T04:20:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:22:06 jcvbserv sudo[135885]: [2023-01-19T04:22:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:24:06 jcvbserv sudo[135885]: [2023-01-19T04:24:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:24:18 jcvbserv sudo[135885]: [2023-01-19T04:24:18Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 05:26:06 jcvbserv sudo[135885]: [2023-01-19T04:26:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:28:06 jcvbserv sudo[135885]: [2023-01-19T04:28:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:30:06 jcvbserv sudo[135885]: [2023-01-19T04:30:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:32:06 jcvbserv sudo[135885]: [2023-01-19T04:32:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:34:06 jcvbserv sudo[135885]: [2023-01-19T04:34:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:36:06 jcvbserv sudo[135885]: [2023-01-19T04:36:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:38:06 jcvbserv sudo[135885]: [2023-01-19T04:38:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:38:22 jcvbserv sudo[135885]: [2023-01-19T04:38:22Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 05:40:06 jcvbserv sudo[135885]: [2023-01-19T04:40:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:42:06 jcvbserv sudo[135885]: [2023-01-19T04:42:06Z DEBUG librespot_core::session] Session[0] strong=3 weak=4
Jan 19 05:52:25 jcvbserv sudo[135885]: [2023-01-19T04:52:25Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 06:06:29 jcvbserv sudo[135885]: [2023-01-19T05:06:29Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 06:20:33 jcvbserv sudo[135885]: [2023-01-19T05:20:33Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 06:34:37 jcvbserv sudo[135885]: [2023-01-19T05:34:37Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 06:48:40 jcvbserv sudo[135885]: [2023-01-19T05:48:40Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 07:02:44 jcvbserv sudo[135885]: [2023-01-19T06:02:44Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 07:16:48 jcvbserv sudo[135885]: [2023-01-19T06:16:48Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 07:30:52 jcvbserv sudo[135885]: [2023-01-19T06:30:52Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 07:44:55 jcvbserv sudo[135885]: [2023-01-19T06:44:55Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 07:58:59 jcvbserv sudo[135885]: [2023-01-19T06:58:59Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 08:13:03 jcvbserv sudo[135885]: [2023-01-19T07:13:03Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 08:27:07 jcvbserv sudo[135885]: [2023-01-19T07:27:07Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 08:41:10 jcvbserv sudo[135885]: [2023-01-19T07:41:10Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 08:49:15 jcvbserv sudo[135885]: [2023-01-19T07:49:15Z WARN  libmdns::fsm] couldn't parse packet from 192.168.2.110:5353: query type 65 is invalid
Jan 19 08:49:15 jcvbserv sudo[135885]: [2023-01-19T07:49:15Z WARN  libmdns::fsm] couldn't parse packet from 192.168.2.86:5353: query type 65 is invalid
Jan 19 08:49:15 jcvbserv sudo[135885]: [2023-01-19T07:49:15Z WARN  libmdns::fsm] couldn't parse packet from [fe80::18b4:6c66:84d5:50f7%3]:5353: query type 65 is invalid
Jan 19 08:49:15 jcvbserv sudo[135885]: [2023-01-19T07:49:15Z WARN  libmdns::fsm] couldn't parse packet from [fe80::14a4:ea64:f6d:5652%3]:5353: query type 65 is invalid
Jan 19 08:49:16 jcvbserv sudo[135885]: [2023-01-19T07:49:16Z WARN  libmdns::fsm] couldn't parse packet from 192.168.2.110:5353: query type 65 is invalid
Jan 19 08:49:16 jcvbserv sudo[135885]: [2023-01-19T07:49:16Z WARN  libmdns::fsm] couldn't parse packet from [fe80::18b4:6c66:84d5:50f7%3]:5353: query type 65 is invalid
Jan 19 08:49:16 jcvbserv sudo[135885]: [2023-01-19T07:49:16Z WARN  libmdns::fsm] couldn't parse packet from 192.168.2.86:5353: query type 65 is invalid
Jan 19 08:49:16 jcvbserv sudo[135885]: [2023-01-19T07:49:16Z WARN  libmdns::fsm] couldn't parse packet from [fe80::14a4:ea64:f6d:5652%3]:5353: query type 65 is invalid
Jan 19 08:55:14 jcvbserv sudo[135885]: [2023-01-19T07:55:14Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:06 jcvbserv sudo[135885]: [2023-01-19T08:00:06Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:07 jcvbserv sudo[135885]: [2023-01-19T08:00:07Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:09 jcvbserv sudo[135885]: [2023-01-19T08:00:09Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:11 jcvbserv sudo[135885]: [2023-01-19T08:00:11Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:13 jcvbserv sudo[135885]: [2023-01-19T08:00:13Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:15 jcvbserv sudo[135885]: [2023-01-19T08:00:15Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:17 jcvbserv sudo[135885]: [2023-01-19T08:00:17Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:19 jcvbserv sudo[135885]: [2023-01-19T08:00:19Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:21 jcvbserv sudo[135885]: [2023-01-19T08:00:21Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:23 jcvbserv sudo[135885]: [2023-01-19T08:00:23Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:25 jcvbserv sudo[135885]: [2023-01-19T08:00:25Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:27 jcvbserv sudo[135885]: [2023-01-19T08:00:27Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:29 jcvbserv sudo[135885]: [2023-01-19T08:00:29Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }
Jan 19 09:00:31 jcvbserv sudo[135885]: [2023-01-19T08:00:31Z WARN  libmdns::fsm] error sending packet Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" }

[roderickvd]

And is it now still happening to you with zeroconf?

[jcv8-dev]

Yes

[jcv8-dev]

I finally found the culprit: Librespot becomes unavailable everytime my isp assigns me a new IP address (usually once a day). Librespot still shows up in the spotify app, because it also scans the local network (thats what i guess at least).

Edit: look at the correlation between "librespot shows up" (top) and the ip address from my router (bottom) imgur

[kingosticks]

Good digging. So if you are playing music when librespot's IP changes, the regular outgoing status messages from librespot will fail at some point (server can't ack), librespot will notice and presumably reconnect. I'm surprised there are no log messages about this in your workinh situation.

When not playing music, librespot doesn't send anything so there's nothing to fail. Although it will stop receiving Ping messages from the server, I don't think we notice. The Dealer in dev does have code to check for regular websocket pings from the server and you'd expect that to trigger (and log); unless the Dealer is only alive when librespot is the active device / playing?

I didn't look what the stable branch does.

[jcv8-dev]

Just messed arround with requesting new ip addresses through my router and can confirm the change of the ip address does not affect librespot while it is active. When it is not active ("is_active": false in the api response), it disappears.

I guess the easiest (temporary?) fix for me would be to write a simple (bash)script that detects a change of the ip address and just restarts librespot.

[kingosticks]

You could also try the dev branch. I think the websocket connection that uses will notice the server pings have stopped and hopefully do something about it.

[jcv8-dev]

I think I am using the dev branch. At least the readme in my librespot folder is the one from dev. I don't actually remember which one i ended up running as i tried both when I had issues getting audio output.

[kingosticks]

Oh, I see. The original log shows v0.4.2 which is the master (stable) branch.

[roderickvd]

dev hasn’t hooked up the dealer yet. That’s actually the next huge piece of work that should be for 0.6 I think.

[kingosticks]

We should add something like https://github.com/librespot-org/librespot-java/blob/c3473bda8a70fad209c8525b04c2fd23ccc0d2fa/lib/src/main/java/xyz/gianlu/librespot/core/Session.java#L1437-L1442

[roderickvd]

Yes that might work!

[T-vK]

Why was the issue closed? Has it been resolved?

[roderickvd]

Yes, by #1129 as mentioned above.

[nullr0ute]

Might be useful to tag a new release to make that more clear?

[kingosticks]

It would be useful if someone could verify it in this context. If you're hitting the issue that should be easy to do.

[T-vK]

@roderickvd Thank you. Can anyone explain in more detail in what way it has been fixed? Does it automatically reconnect now? Or does it exit now when the connection is dropped or throw an error? Are there new flags? Can anyone provide an example on how to launch librespot in a way that it stays connected or automatically reconnects when it loses the connection? :)

[kingosticks]

There are no flags, the detection happens automatically in the latest code. You need to test and see if your issue here is fixed. If it's not, we'll reopen the issue. That's how this works.

[T-vK]

When the automatic detection happens, does it just print an error or quit or does it automatically reconnect as well? I'm just asking because if it doesn't reconnect automatically, I'd have to write some wrapper code in order to test it.

[roderickvd]

Let’s not confuse this with automatically reconnecting after loss of network or peer disconnection. That’s not this.

This sends pings when the player is idle, so the server knows we’re alive and doesn’t disconnect us.

Other than that: what @kingosticks said.

[T-vK]

I see, sorry for the confusion. A new release tag would be greatly appreciated. Is there anything in particular that needs to be done first?

[eladyn]

Let’s not confuse this with automatically reconnecting after loss of network or peer disconnection. That’s not this.

This sends pings when the player is idle, so the server knows we’re alive and doesn’t disconnect us.

Other than that: what @kingosticks said.

Well, it also makes sure that librespot regularly receives those pings and otherwise invalidates the session. Usually, it should then try to reconnect with the last credentials. (not preserving the playback state, however)