So I've set logging to debug, which seems to give a bit more
information, but still doesn't really show why it's failing (redacted
MACs, Usernames, hostnames etc)

Trying a manual authentication with the user/pass is logging this

[22-10-28 19:06:15.2635]
Plugins::Spotty::Connect::DaemonManager::initHelpers (92) Checking
Spotty Connect helper daemons...
[22-10-28 19:06:15.2637]
Plugins::Spotty::Connect::DaemonManager::initHelpers (126) This is a
standalone player with Spotify Connect disabled: ****

[22-10-28 19:06:17.8324] Plugins::Spotty::Helper::_findBin (192) Trying
helper application:
C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe
[22-10-28 19:06:17.8874] Plugins::Spotty::Helper::helperCheck (118)
Found helper capabilities table: do {
my $a = {
autoplay               => bless(do{\(my $o = 1)},
"JSON::XS::Boolean"),
debug                  => bless(do{\(my $o = 0)},
"JSON::XS::Boolean"),
"lms-auth"             => 'fix',
"ogg-direct"           => 'fix',
podcasts               => 'fix',
"save-token"           => 'fix',
version                => "1.3.0",
"volume-normalisation" => 'fix',
"zeroconf-port"        => 'fix',
};
$a->{"lms-auth"} = \${$a->{autoplay}};
$a->{"ogg-direct"} = \${$a->{autoplay}};
$a->{podcasts} = \${$a->{autoplay}};
$a->{"save-token"} = \${$a->{autoplay}};
$a->{"volume-normalisation"} = \${$a->{autoplay}};
$a->{"zeroconf-port"} = \${$a->{autoplay}};
$a;
}
[22-10-28 19:06:17.8875] Plugins::Spotty::Helper::_findBin (195) Found
helper application:
C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe
[22-10-28 19:06:17.8879] Plugins::Spotty::Settings::Auth::handler (69)
Trying to authenticate using:
"C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe"
-c "C:\ProgramData\Squeezebox\Cache\spotty\__AUTHENTICATE__" -n "Spotify
Authorization (****)" -u "******" -p "********" -a --disable-discovery
--ap-port 12321 --verbose
[22-10-28 19:06:18.0100] Plugins::Spotty::Settings::Auth::handler (74)
Got response: 
[22-10-28 19:06:18.0101] Plugins::Spotty::Settings::Auth::handler (83)
Authorization failed: 
[22-10-28 19:06:18.0333] Plugins::Spotty::Helper::_findBin (192) Trying
helper application:
C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe
[22-10-28 19:06:18.0869] Plugins::Spotty::Helper::_findBin (195) Found
helper application:
C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe

So the command it's trying to use is slightly different from yours - I
tried that (with the .) and it seemed to just end straight away, and
without it seemed to be actually running but didn't display or log
anything.

Periodically it seems to be putting the below through the logs 
[22-10-28 19:07:15.2779]
Plugins::Spotty::Connect::DaemonManager::initHelpers (92) Checking
Spotty Connect helper daemons...
[22-10-28 19:07:15.2781]
Plugins::Spotty::Connect::DaemonManager::initHelpers (126) This is a
standalone player with Spotify Connect disabled:  ***

If I try the player method whilst watching the log it seems to be doing
this
[22-10-28 19:09:19.2032] Plugins::Spotty::Helper::_findBin (192) Trying
helper application:
C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe
[22-10-28 19:09:19.2601] Plugins::Spotty::Helper::helperCheck (118)
Found helper capabilities table: do {
my $a = {
autoplay               => bless(do{\(my $o = 1)},
"JSON::XS::Boolean"),
debug                  => bless(do{\(my $o = 0)},
"JSON::XS::Boolean"),
"lms-auth"             => 'fix',
"ogg-direct"           => 'fix',
podcasts               => 'fix',
"save-token"           => 'fix',
version                => "1.3.0",
"volume-normalisation" => 'fix',
"zeroconf-port"        => 'fix',
};
$a->{"lms-auth"} = \${$a->{autoplay}};
$a->{"ogg-direct"} = \${$a->{autoplay}};
$a->{podcasts} = \${$a->{autoplay}};
$a->{"save-token"} = \${$a->{autoplay}};
$a->{"volume-normalisation"} = \${$a->{autoplay}};
$a->{"zeroconf-port"} = \${$a->{autoplay}};
$a;
}
[22-10-28 19:09:19.2602] Plugins::Spotty::Helper::_findBin (195) Found
helper application:
C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe
[22-10-28 19:09:19.2605] Plugins::Spotty::Settings::Auth::startHelper
(163) Starting Spotty Connect deamon: 
C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\Spotty\Bin\MSWIN3~1\spotty.exe
-c C:\ProgramData\Squeezebox\Cache\spotty\__AUTHENTICATE__ -n Spotify
Authorization (**) -a --ap-port=12321

The spotty authentication thing is picking up the spotty player on the
machine so that side of things is working but it then just doesn't log
anything more and comes back to repeating the previous two lines every
minute or so.

Running your spotty command from the command prompt doesn't seem to be
logging anything at all, unless these are going somewhere else.

I can't see a credentials.json file anywhere (and nor can searching) so
not sure where that should be popping up.

It's also difficult to see when this actually started (to see what might
have broken it before) but the first error issues are
[22-10-11 01:30:47.0353] Plugins::Spotty::API::Token::_killTokenHelper
(182) Timed out waiting for a token

yet this is some time after the previous server start which was
[22-10-10 16:26:22.2791] main::init (377) Starting Logitech Media Server
(v8.3.0, 1664261103, Tue Sep 27 08:46:52 WEDT 2022) perl 5.014001 -
MSWin32-x86-multi-thread
(and before MS patches released on 11th...)

The same line then pops back in 48 hours later
[22-10-13 01:33:07.5291] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
(this would then presumably be a background task as I wouldn't be
listening to spotty at 1.30 in the morning)

then a few days later
[22-10-19 20:22:25.5838] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
and a few of these again when nothing's actually trying to use the
plugin
[22-10-21 22:23:17.5429] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-21 23:23:18.5306] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-22 00:23:18.5347] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-22 01:23:18.5396] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-22 02:23:18.5223] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-22 03:23:18.5371] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-22 04:23:18.5233] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-22 05:23:18.5181] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
[22-10-22 06:23:18.5183] Plugins::Spotty::API::Token::_gotTokenInfo
(168) Failed to create session or connect to servers.
which then appears to be repeating itself in the log every hour until
last night when I tried to use it again

Not sure that this correlates to anything on the machine which has
changed which could have broken it, not really sure what is stopping it
from doing anything really. I've also tried with both KTS and Windows
security turned off and still neither authentication method is doing
anything different.


------------------------------------------------------------------------
ForestChav's Profile: http://forums.slimdevices.com/member.php?userid=54064
View this thread: http://forums.slimdevices.com/showthread.php?t=111923

_______________________________________________
plugins mailing list
plugins@lists.slimdevices.com
http://lists.slimdevices.com/mailman/listinfo/plugins

Reply via email to