LMS-Community / slimserver

Server for Squeezebox and compatible players. This server is also called Lyrion Music Server.
https://lyrion.org
Other
1.21k stars 300 forks source link

Follow-on for Logitech #765 - PlayerStatus not working as expected in 8.3 #769

Closed lynniemagoo closed 2 years ago

lynniemagoo commented 2 years ago

Team,

For the changes we put in for Logitech#765 from PR #767, I have tested with the latest cometD library. All is working well except for 1 thing. I'm getting an error back for playerstatus requests as follows:

**** PLAYER StatusPublishResponse h:{
  error: 'invalid request: Missing client!',
  id: '5',
  channel: '/slim/subscribe',
  successful: false,
  advice: { reconnect: 'retry' }
}
The request I sent is as follows:
channel:/slim/subscribe content:{
  request: [
    '00:30:18:07:ab:95',
    [
      'status',
      '-',
      1,
      'tags:cgABbehldiqtyrSuoKLNTI',
      'subscribe:10',
      [length]: 5
    ],
    [length]: 2
  ],
  response: '/988714af/slim/playerStatus/00:30:18:07:ab:95'
}

When I run my same test harness against code against 8.2 with the hack-fixes I had done earlier to the npm cometd library where I cached the last 'id' from the messages, all is working as expected and I get both serverstatus and playerstatus events.

This is the LMS version running on WHS-1 that works with the hack. Logitech Media Server Version: 8.2.0 - 1627922070 @ Tue Aug 3 11:28:42 WEDT 2021

For the 8.3 fix, note that serverStatus is working fine. I suspect the issue is in the handleRequest method and am still researching. For now, I wanted to open this issue so it can be tracked and possibly to see if @mherger or someone else might be able to point me in the right direction.

@mherger - Any ideas?

lynniemagoo commented 2 years ago

The /slim/subscribe message I'm posting i'm suspecting should have gotten $clid as follows for passing to handleRequest.

Reference line 179 of Cometd.pm

        elsif ( $obj->{channel} =~ m{^/slim/(?:subscribe|request)} && $obj->{data} ) {
            # Pull clientId out of response channel
            ($clid) = $obj->{data}->{response} =~ m{/([0-9a-f]{8})/};
        }

However, looking @ lines 405-407 I see this.

        if ( $request && $response ) {
            # We expect the clientId to be part of the response channel
            my ($responseClid) = $response =~ m{/([0-9a-f]{8})/};

            my $result = handleRequest( {
                id       => $id,
                request  => $request,
                response => $response,
                priority => $priority,
                clid     => $responseClid,
                type     => 'subscribe',
                lang     => $lang,
                ua       => $ua,
            } );

Which appears to be doing the same exact thing except that it does not use $clid but instead $responseClid extracted from the 'reponse' using same RegEx pattern.

Advice on how to enable and what logs need to be enabled to debug would be greatly appreciated.

michaelherger commented 2 years ago

Are you sure the player is connected to LMS when you try to subscribe to its status? A "missing client" would be reported if the player wasn't connected, too.

As for the logging: you can usually see the logger class towards the top of a file:

https://github.com/Logitech/slimserver/blob/99bdfa09c450745600b4513ae5ec9fe7e9026087/Slim/Web/Cometd.pm#L33

lynniemagoo commented 2 years ago

@mherger Many Thanks - Player not connected to LMS is the issue

Dohhhh! NOTE TO SELF!!!!! - Always make sure player is connected to server before running a playerstatus subscribe.

2 additional comments/notes.

  1. Does it make sense to refine the error message such that it emits an 'unknown player' message vs 'missing clientId' as the clientId was good but the player was not?
  2. For the changes I submitted earlier, how can we make that 'injected' id an integer? When it comes from client side in JSON, it is a number. With the changes we made, it becomes a string. Fortunately cometd library handles it gracefully but we are coercing the type to a string. NOTE - All is working properly so this is cosmetic.

Comments appreciated and if we all agree to leave-as-is, I'm good with closing this issue.

michaelherger commented 2 years ago

Renaming error messages can be problematic, as some client might be using it.

As for the integer: Perl isn't typed, so this is problematic. It seems that even if a value initially was an numerical, it could become a string if passed to things like Dumper()... But please give the following a try - and don't use debug logging for comets, as this might use some of those dump calls.

diff --git a/Slim/Web/Cometd.pm b/Slim/Web/Cometd.pm
index ee7e8380b..930e7cae7 100644
--- a/Slim/Web/Cometd.pm
+++ b/Slim/Web/Cometd.pm
@@ -158,6 +158,7 @@ sub handler {
                # Issue #765 - For comet meta messages handshake, connect, reconnect, disconnect, subscribe, unsubscribe populate 'id' field on response to ensure compatibility with the readily available npm comet library.
                # obtain 'id' from outer object if present, otherwise default to  - Here we use different variable name '$msgid' as '$id' is defined for use within slim/subscribe channel.
                my $msgid = $obj->{id} || '';
+               $msgid   *= 1 if $msgid;

                if ( ref $obj ne 'HASH' ) {
                        sendResponse(
lynniemagoo commented 2 years ago

I can't build the source so is this in a PR/Nightly?

That looks like a good fix. If you want to change, I will test it out. Or, as things are indeed working, we could simply just leave things be. :-)

If you do want to make change and prefer I do a PR, just let me know.

I've been working all day on some nodejs test code for managing my players and keeping them connected to same server if they should get disconnected..

michaelherger commented 2 years ago

Sorry, forgot you were on Windows. I pushed the change. Let me know about your findings once the builds are done.

lynniemagoo commented 2 years ago

@mherger

Michael,

If this build has the change, I can confirm it did not break anything.

LogitechMediaServer-8.3.0-1645435178-whs.msi 73.12 MB February 21 2022 10:00

However was noticing that library always receives a string back.

So, checked on how 'id' is being built by the comet library. Below is the code where they generate the message ids. Internally, it deals with numbers but it always sends a string. So, I think the best bet is to revert this last change and call this one my mistake.


        function _nextMessageId() {
            const result = ++_messageId;
            return '' + result;
        }

PR #770 submitted.