Spotify - no connect possible

[crosenbe]

I used the plugin since years, but with the issues the last days i installed 4.11.9 and moved back to 4.11.2 later on. But the spotty binary does not start anymore. I removed the plugin, the prefs and cache and tried it again. I just arrive at the plugin config page and nothing happens. There was an issue with SSL.pm, which is solved in the meanwhile.

My understanding was the plugin need the client ID somehow before it initiate the connect?

[michaelherger]

Please check your server.log file (Settings/Information) for hints about the failure.

[crosenbe]

i just see endless entries to start the helper app

[24-09-14 00:11:45.4997] Plugins::Spotty::Settings::Auth::startHelper (126) Starting Spotty Connect deamon:
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/Spotty/Bin/i386-linux/spotty-x86_64 -c /var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__ -n Spotify Anmeldung (fs) -a --ap-port=12321
[24-09-14 00:11:47.5079] Plugins::Spotty::Settings::Auth::startHelper (126) Starting Spotty Connect deamon:
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/Spotty/Bin/i386-linux/spotty-x86_64 -c /var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__ -n Spotify Anmeldung (fs) -a --ap-port=12321
[24-09-14 00:11:49.5122] Plugins::Spotty::Settings::Auth::startHelper (126) Starting Spotty Connect deamon:
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/Spotty/Bin/i386-linux/spotty-x86_64 -c /var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__ -n Spotify Anmeldung (fs) -a --ap-port=12321
[24-09-14 00:11:51.5136] Plugins::Spotty::Settings::Auth::startHelper (126) Starting Spotty Connect deamon:
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/Spotty/Bin/i386-linux/spotty-x86_64 -c /var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__ -n Spotify Anmeldung (fs) -a --ap-port=12321
[24-09-14 00:11:53.5185] Plugins::Spotty::Settings::Auth::startHelper (126) Starting Spotty Connect deamon:
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/Spotty/Bin/i386-linux/spotty-x86_64 -c /var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__ -n Spotify Anmeldung (fs) -a --ap-port=12321

Running this command on command line produce an error because of the brackets. Don't know if the real call of the command use -n "Spotify Anmeldung (fs)" instead.

[crosenbe]

Running the command with strace i got following output ...

14:31:41 execve("/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/Spotty/Bin/i386-linux/spotty-x86_64", ["/var/lib/squeezeboxserver/cache/"..., "-c", "/var/lib/squeezeboxserver/cache/"..., "-n", "Spotify Anmeldung (fs)", "-a", "--ap-port=12321"], [/* 17 vars */]) = 0 <0.000247>
14:31:41 mmap(NULL, 768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f95e8a96000 <0.000037>
14:31:41 arch_prctl(ARCH_SET_FS, 0x7f95e8a96220) = 0 <0.000032>
14:31:41 set_tid_address(0xa39678)      = 17839 <0.000034>
14:31:41 poll([{fd=0, events=0}, {fd=1, events=0}, {fd=2, events=0}], 3, 0) = 0 (Timeout) <0.000035>
14:31:41 rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER|SA_RESTART, 0x710431}, {SIG_DFL, [], 0}, 8) = 0 <0.000025>
14:31:41 rt_sigaction(SIGSEGV, NULL, {SIG_DFL, [], 0}, 8) = 0 <0.000023>
14:31:41 rt_sigprocmask(SIG_UNBLOCK, [RT_1 RT_2], NULL, 8) = 0 <0.000023>
14:31:41 rt_sigaction(SIGSEGV, {0x6b9a40, [], SA_RESTORER|SA_STACK|SA_SIGINFO, 0x710431}, NULL, 8) = 0 <0.000024>
14:31:41 rt_sigaction(SIGBUS, NULL, {SIG_DFL, [], 0}, 8) = 0 <0.000023>
14:31:41 rt_sigaction(SIGBUS, {0x6b9a40, [], SA_RESTORER|SA_STACK|SA_SIGINFO, 0x710431}, NULL, 8) = 0 <0.000023>
14:31:41 sigaltstack(NULL, {ss_sp=0, ss_flags=SS_DISABLE, ss_size=0}) = 0 <0.000023>
14:31:41 mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f95e8a93000 <0.000025>
14:31:41 mprotect(0x7f95e8a93000, 4096, PROT_NONE) = 0 <0.000026>
14:31:41 sigaltstack({ss_sp=0x7f95e8a94000, ss_flags=0, ss_size=8192}, NULL) = 0 <0.000023>
14:31:41 brk(0)                         = 0x1fe9000 <0.000023>
14:31:41 brk(0x1fea000)                 = 0x1fea000 <0.000023>
14:31:41 rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1 RT_2], [], 8) = 0 <0.000026>
14:31:41 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000022>
14:31:41 epoll_create1(O_CLOEXEC)       = 3 <0.000026>
14:31:41 eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 4 <0.000024>
14:31:41 epoll_ctl(3, EPOLL_CTL_ADD, 4, {EPOLLIN|EPOLLET|0x2000, {u32=2147483648, u64=2147483648}}) = 0 <0.000025>
14:31:41 fcntl(3, F_DUPFD_CLOEXEC, 3)   = 5 <0.000023>
14:31:41 fcntl(5, F_SETFD, FD_CLOEXEC)  = 0 <0.000023>
14:31:41 brk(0x1fee000)                 = 0x1fee000 <0.000024>
14:31:41 socketpair(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0, [6, 7]) = 0 <0.000029>
14:31:41 clock_gettime(CLOCK_MONOTONIC, {11642100, 55606187}) = 0 <0.000024>
14:31:41 brk(0x1fef000)                 = 0x1fef000 <0.000023>
14:31:41 brk(0x1ff0000)                 = 0x1ff0000 <0.000024>
14:31:41 fcntl(6, F_DUPFD_CLOEXEC, 0)   = 8 <0.000024>
14:31:41 fcntl(8, F_SETFD, FD_CLOEXEC)  = 0 <0.000022>
14:31:41 brk(0x1ff1000)                 = 0x1ff1000 <0.000033>
14:31:41 epoll_ctl(5, EPOLL_CTL_ADD, 8, {EPOLLIN|EPOLLOUT|EPOLLET|0x2000, {u32=0, u64=0}}) = 0 <0.000026>
14:31:41 clock_gettime(CLOCK_MONOTONIC, {11642100, 56176226}) = 0 <0.000023>
14:31:41 brk(0x1ff3000)                 = 0x1ff3000 <0.000023>
14:31:41 syscall_318(0x7fff7dec45b0, 0x10, 0x1, 0x1ff2070, 0xfc0, 0x3a8, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de, 0x70d5de) = -1 (errno 38) <0.000029>
14:31:41 open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 9 <0.000028>
14:31:41 fcntl(9, F_SETFD, FD_CLOEXEC)  = 0 <0.000023>
14:31:41 read(9, "\x35\xd8\x45\x66\xf3\x1a\x62\xd7\x39\xc4\x1d\xb1\x18\xeb\x27\x16", 16) = 16 <0.000025>
14:31:41 close(9)                       = 0 <0.000023>
14:31:41 brk(0x1ff4000)                 = 0x1ff4000 <0.000025>
14:31:41 brk(0x1ff5000)                 = 0x1ff5000 <0.000024>
14:31:41 brk(0x1ff6000)                 = 0x1ff6000 <0.000024>
14:31:41 brk(0x1ff8000)                 = 0x1ff8000 <0.000024>
14:31:41 brk(0x1ff9000)                 = 0x1ff9000 <0.000025>
14:31:41 mkdir("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__", 0777) = -1 EEXIST (File exists) <0.000029>
14:31:41 stat("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000027>
14:31:41 mkdir("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__", 0777) = -1 EEXIST (File exists) <0.000025>
14:31:41 stat("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000026>
14:31:41 mkdir("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__/files", 0777) = -1 EEXIST (File exists) <0.000026>
14:31:41 stat("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__/files", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000026>
14:31:41 open("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__/credentials.json", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory) <0.000028>
14:31:41 open("/var/lib/squeezeboxserver/cache/spotty/__AUTHENTICATE__/volume", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory) <0.000027>
14:31:41 syscall_318(0, 0, 0x1, 0x1ff7c70, 0x1ff7a30, 0x1fe90c0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0, 0x7fff7dec2ef0) = -1 (errno 38) <0.000052>
14:31:41 open("/dev/random", O_RDONLY|O_CLOEXEC) = 9 <0.000038>
14:31:41 fcntl(9, F_SETFD, FD_CLOEXEC)  = 0 <0.000032>
14:31:41 poll([{fd=9, events=POLLIN}], 1, -1) = 1 ([{fd=9, revents=POLLIN}]) <0.000032>
14:31:41 close(9)                       = 0 <0.000032>
14:31:41 open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 9 <0.000034>
14:31:41 fcntl(9, F_SETFD, FD_CLOEXEC)  = 0 <0.000032>
14:31:41 read(9, "\x33\x80\x6c\xb0\x06\x99\x87\xc1\x5e\x15\x70\x47\x7f\x72\xa5\xba\x9a\xde\xcf\x10\xab\x60\xbb\x03\x32\x83\x51\x4d\x90\x13\x95\xea", 32) = 32 <0.000036>
14:31:41 socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_IP) = 10 <0.000045>
14:31:41 setsockopt(10, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 <0.000034>
14:31:41 bind(10, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 <0.000035>
14:31:41 listen(10, 128)                = 0 <0.000038>
14:31:41 ioctl(10, FIONBIO, [1])        = 0 <0.000032>
14:31:41 epoll_ctl(5, EPOLL_CTL_ADD, 10, {EPOLLIN|EPOLLOUT|EPOLLET|0x2000, {u32=1, u64=1}}) = 0 <0.000034>
14:31:41 getsockname(10, {sa_family=AF_INET, sin_port=htons(54106), sin_addr=inet_addr("0.0.0.0")}, [16]) = 0 <0.000032>
14:31:41 uname({sys="Linux", node="fs", ...}) = 0 <0.000034>
14:31:41 socket(PF_INET, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_UDP) = 11 <0.000034>
14:31:41 setsockopt(11, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 <0.000035>
14:31:41 fcntl(11, F_GETFL)             = 0x2 (flags O_RDWR) <0.000033>
14:31:41 fcntl(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000033>
14:31:41 setsockopt(11, SOL_SOCKET, 0xf /* SO_??? */, [1], 4) = -1 ENOPROTOOPT (Protocol not available) <0.000032>
14:31:41 close(11)                      = 0 <0.000034>
14:31:41 socket(PF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_UDP) = 11 <0.000034>
14:31:41 setsockopt(11, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 <0.000033>
14:31:41 fcntl(11, F_GETFL)             = 0x2 (flags O_RDWR) <0.000030>
14:31:41 fcntl(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000030>
14:31:41 setsockopt(11, SOL_SOCKET, 0xf /* SO_??? */, [1], 4) = -1 ENOPROTOOPT (Protocol not available) <0.000033>
14:31:41 close(11)                      = 0 <0.000034>
14:31:41 sigaltstack({ss_sp=0, ss_flags=SS_DISABLE, ss_size=8192}, NULL) = 0 <0.000034>
14:31:41 munmap(0x7f95e8a93000, 12288)  = 0 <0.000036>
14:31:41 exit_group(1)                  = ?

[michaelherger]

What if you run the command with quotes where they need to be? Or simplify the name (you can put anything there, just a single word is simplest)?

[crosenbe]

i used the command with quotes of course, i also used just the word spotty instead, as mentioned in the help as default value. There is also no difference. The command does not raise anything on the network. No DNS request, no connect to any IP.

i have seen two lines which may be related to the issue ...

15:21:33 setsockopt(11, SOL_SOCKET, 0xf /* SO_??? */, [1], 4) = -1 ENOPROTOOPT (Protocol not available) <0.000033>
15:21:33 setsockopt(11, SOL_SOCKET, 0xf /* SO_??? */, [1], 4) = -1 ENOPROTOOPT (Protocol not available) <0.000033>