Bug 7240 - Jive's wifi icon remains BLUE even if server is running
: Jive's wifi icon remains BLUE even if server is running
Status: CLOSED FIXED
Product: SB Controller
Classification: Unclassified
Component: Setup
: unspecified
: PC Windows XP
: P1 normal (vote)
: 7.0
Assigned To: Ben Klaas
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2008-02-20 09:59 UTC by Dan Evans
Modified: 2008-05-15 13:04 UTC (History)
2 users (show)

See Also:
Category: ---


Attachments
debug log from this issue; note that I was able to reconnect to player after entering choose player, and that is also in the log (505.44 KB, text/plain)
2008-02-21 08:31 UTC, Ben Klaas
Details
Patch to allow jive to reconnect even if SC changes it's IP address (3.46 KB, patch)
2008-02-22 03:36 UTC, Richard Titmuss
Details | Diff
Patch (3.60 KB, patch)
2008-02-22 07:50 UTC, Richard Titmuss
Details | Diff
Patch to allow jive to reconnect even if SC changes it's IP address (7.33 KB, patch)
2008-02-22 12:57 UTC, Richard Titmuss
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Dan Evans 2008-02-20 09:59:25 UTC
Occasionally I've seen my Jive at home not recover its connection to the server after I've booted my computer system.  The Receiver reconnects successfully, but the wireless icon remains BLUE on the Controller.  Power-cycling the controller appears to fix this.

Does Jive have code that allows it to find the server even if the IP of the server has changed?  I find this happens frequently in my home, and I filed bugs on this for Ray and Squeezebox. (see bug 6478)
Comment 1 James Richardson 2008-02-20 10:20:23 UTC
I have been able to replicate this error as well.  Was about to post a bug when I saw this on.

Steps to Reproduce:

1) Connect a Jive/Ray to SN
2) Using the Jive, switch connected ray to SC7 local server
3) Make sure the Ray can play something 
4) Shut Down SC7 Server
5) Notice that Ray goes into BLUE mode
6) Using Jive, attempt to connect back to SN, At this point, both the Jive and Ray are in a confused state, and the Jive will display an error message.
Comment 2 Dan Evans 2008-02-20 12:24:52 UTC
Good addition, James.  I do want to mention though that I've never used SqueezeNetwork at home.  My issue was purely with connecting to SqueezeCenter.  Maybe investigation is warranted on both sides.
Comment 3 Blackketter Dean 2008-02-20 20:33:34 UTC
Richard/Ben: Can you take a look at this?

Comment 4 Ben Klaas 2008-02-21 07:10:48 UTC
James, your description in comment #1 is not the same issue as what Dan is seeing. I can reproduce what you are seeing to some extent, and opened bug 7258 against it.

I will try to reproduce Dan's issue with comet debugging, as suggested by Richard.
Comment 5 Ben Klaas 2008-02-21 07:48:18 UTC
(Richard, you know this discovery code better than I, so correct me if I'm wrong)

Dan, if your SqueezeCenter IP address changes on reboot, Jive would consider that a newly discovered server. So, if you have a jive connected to an SC at 192.168.1.1, and then it goes away and comes back later as 192.168.1.2, I'd expect the wifi icon to go BLUE and remain that way until you go into Choose Music Source and select the "new" server. Further, I'd expect that if you actually try to browse into any items in your music library (e.g., Music Library->Artists), you'll get a "Trouble connecting to server" error message.

Topic for discussion: I'm not sure how resilient we need to be for users with server IPs that change. We have to id the server with something to identify it, right? If not IP...MAC? IMO this is above and beyond what we need to support. If a user has a dynamic IP for their home SC server, then they should expect to need to go through some hoops on Jive to connect to it.
Comment 6 Richard Titmuss 2008-02-21 07:57:40 UTC
I don't think a change of ip address should matter. Jive will be trying to reconnect to a player, so even if the server ip changes but that server 'owns' the current player then jive should reconnect to the player correctly.

Ben have you tested this? First it would be good to retest starting and stopping SC to see if it reconnects ok. Then test again while changing the ip address of the server.
Comment 7 Ben Klaas 2008-02-21 08:07:29 UTC
I started investigating this by testing it, and the first time I tried it did not reconnect and icon remained BLUE. When I went into "Choose Music Source" I saw two entries for the server (presumably for IP address A and B), which is what led me to that comment.

BUT, I've now tested it several times since then and had it work every time at reconnecting, even after IP address change.


Comment 8 Ben Klaas 2008-02-21 08:16:16 UTC
okay, I've reproduced it a couple times. Will work on getting quality debug output now.
Comment 9 Ben Klaas 2008-02-21 08:31:01 UTC
Created attachment 2948 [details]
debug log from this issue; note that I was able to reconnect to player after entering choose player, and that is also in the log

When I reproduce this issue and then go into Choose Player, I am presented with a blank window for 3-5 seconds. After this period, the players show up, I get a spinny saying "Connecting to <player", and it successfully reconnects only at this point (including wifi icon from BLUE->WHITE).

The reconnection of this player after going into Choose Player is also in the attached log.
Comment 10 Chris Owens 2008-02-21 09:20:10 UTC
Leaving target open until Richard looks at it.
Comment 11 Dan Evans 2008-02-21 09:46:02 UTC
We should always strive to make things as easy for our users as possible.  Expecting the user to reconfigure their SBC in the event of a dynamic IP change is unreasonable.  Especially since the vast majority of our users fall into that catagory.  Dynamic DHCP is the default for all mainstream routers.

Jive needs to rediscover the server on its own, even if the IP has changed.  This is how Squeezebox works.  This is how Ray works.  And this needs to be seamless and invisible to the user.

Just my 2c
Comment 12 Ben Klaas 2008-02-21 10:02:56 UTC
Dan, sorry to steer you the wrong direction-- I was incorrect in my earlier comment. SBC should rediscover the server on the event of an IP change.

Comment 13 Ben Klaas 2008-02-21 11:52:43 UTC
changed the SlimServer:idFor() method to return name:port instead of ip:port for a given slimserver

=== SlimServer.lua
==================================================================
--- SlimServer.lua      (revision 19544)
+++ SlimServer.lua      (local)
@@ -405,7 +405,9 @@
 =cut
 --]]
 function idFor(self, ip, port, name)
-       return tostring(ip) .. ":" .. tostring(port)
+       log:warn('******************************** idFor: ', tostring(name) , ":", tostring(port))
+       --return tostring(ip) .. ":" .. tostring(port)
+       return tostring(name) .. ":" .. tostring(port)
 end


From a user-perspective, the behavior got worse. After stopping/restarting SC with a different IP address, the player never reappeared in choose player. Jive log is showing the server being rediscovered, but that's where it stops.

I also tried having idFor only return the server name and not the port (though I think that wouldn't be correct). Same behavior.
Comment 14 Richard Titmuss 2008-02-21 11:56:09 UTC
ok, thanks Ben. I'll take a look at this in (my) morning.
Comment 15 Ben Klaas 2008-02-21 12:18:17 UTC
FYI, how I did the test that produced results for comment #9 and comment #13:

1. Started up SC on an Ubuntu machine configured on eth0 to 192.168.1.220/24
2. Connect SB3 to this server
3. Connect Jive to this player
4. Ctrl-C kill the SC
5. verify wifi icon goes blue on jive
6. on Ubuntu machine, ifconfig eth0 down && ifconfig 192.168.1.219/24 && ifconfig eth0 up
7. restart SC
8. observer behavior of Jive after SB3 reconnects to Ubuntu machine successfully

I don't think it's relevant to the test, but I had two other running SCs on the network with (different) connected players.
Comment 16 Richard Titmuss 2008-02-22 03:36:03 UTC
Created attachment 2971 [details]
Patch to allow jive to reconnect even if SC changes it's IP address
Comment 17 Richard Titmuss 2008-02-22 03:46:27 UTC
Ben, please try the attached patch. This:

1) Uses the server name as the unique key, not the ip:port value.
2) Creates a new Comet connection for the server if the ip:port value change, and reconnects to this server if already trying to connect.
3) Starts UDP discovery if the current server is disconnected (to allow discovery of the new ip:port value).
4) Fixes Comet class to always update isactive, otherwise old connections could keep retrying forever.

I've tested this patch on the desktop. Ben could you please review the patch and  verify it on a jive. Thanks.
Comment 18 Ben Klaas 2008-02-22 06:19:28 UTC
Isn't server name:port a better model than just server name? There are people that run multiple servers on the same machine on different ports, particularly our venerable beta-testing types.
Comment 19 Richard Titmuss 2008-02-22 06:23:30 UTC
Maybe, but Squeezebox won't work if you have two SC's on the same ip address. You have to use virutal ip addresses to do this. So with this patch Jive works the same as a Squeezebox.
Comment 20 Ben Klaas 2008-02-22 06:28:48 UTC
Okay, fair enough. Just wanted to make sure we weren't creating another bug by fixing this one. As long as we're consistent with squeezebox it's fine with me.

Will test the patch and report back on this one shortly
Comment 21 Ben Klaas 2008-02-22 06:43:30 UTC
after applying the patch the player does not come back after a SC restart (this is without even changing the IP address)

comet debug output after stopping server "cheesypoofs":


083909:18197 INFO (Comet.lua:704) - Comet {cheesypoofs}: _getEventSink error: closed
083909:18197 WARN (Comet.lua:882) - Comet {cheesypoofs}: handleAdvice state=CONNECTED
083909:18197 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is UNCONNECTED
083909:18198 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {cheesypoofs}, 0
083909:18198 INFO (SlimServer.lua:398) - SlimServer {cheesypoofs} disconnected
083909:18198 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {cheesypoofs}, 0
083909:18198 INFO (SlimServers.lua:260) - Reconnecting to all servers
083909:18198 INFO (SlimServer.lua:356) - SlimServer {SqueezeNetwork}:connect()
083909:18198 DEBUG (Comet.lua:175) - Comet {SqueezeNetwork}: connect state=UNCONNECTED
083909:18198 DEBUG (Comet.lua:533) - Comet {SqueezeNetwork}: _handshake(), calling: http://www.beta.squeezenetwork.com:9000/cometd
083909:18198 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/serverstatus
083909:18199 DEBUG (Comet.lua:510) - Comet {SqueezeNetwork}: state is CONNECTING
083909:18199 INFO (SlimServer.lua:356) - SlimServer {mediumspicy}:connect()
083909:18199 DEBUG (Comet.lua:175) - Comet {mediumspicy}: connect state=UNCONNECTED
083909:18199 DEBUG (Comet.lua:533) - Comet {mediumspicy}: _handshake(), calling: http://192.168.1.2:9000/cometd
083909:18199 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/serverstatus
083909:18199 DEBUG (Comet.lua:510) - Comet {mediumspicy}: state is CONNECTING
083909:18200 INFO (SlimServer.lua:356) - SlimServer {cheesypoofs}:connect()
083909:18200 DEBUG (Comet.lua:175) - Comet {cheesypoofs}: connect state=UNCONNECTED
083909:18200 DEBUG (Comet.lua:533) - Comet {cheesypoofs}: _handshake(), calling: http://192.168.1.219:9000/cometd
083909:18200 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/serverstatus
083909:18200 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/menustatus/00:04:20:06:33:d0
083909:18201 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/playerstatus/00:04:20:06:33:d0
083909:18201 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/displaystatus/00:04:20:06:33:d0
083909:18201 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is CONNECTING
083909:18201 INFO (Comet.lua:915) - Comet {cheesypoofs}: advice is retry, connect in 3.125 seconds
083909:18214 DEBUG (Comet.lua:605) - Comet {mediumspicy}: _handshake, advice updated from server
083909:18214 DEBUG (Comet.lua:612) - Comet {mediumspicy}: _handshake OK, clientId: 288afa29
083909:18214 DEBUG (Comet.lua:625) - Comet {mediumspicy}: _connect()
083909:18214 DEBUG (Comet.lua:648) - Sending pending request(s):
{ --[[table: 0x1605fcd0]]
  { --[[table: 0x11d5790]]
    clientId = "288afa29",
    connectionType = "streaming",
    channel = "/meta/connect",
  },
  { --[[table: 0x160afd90]]
    clientId = "288afa29",
    subscription = "/288afa29/**",
    channel = "/meta/subscribe",
  },
  { --[[table: 0x160c8c90]]
    id = 1,
    data = { --[[table: 0x160b13c0]]
      request = { --[[table: 0x11d5940]]
        "",
        { --[[table: 0x1198720]]
          "serverstatus",
          0,
          50,
          "subscribe:60",
        },
      },
      response = "/288afa29/slim/serverstatus",
    },
    channel = "/slim/subscribe",
  },
}
083909:18276 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /288afa29/slim/serverstatus id=1 OK
083909:18276 DEBUG (Comet.lua:828) - Comet {mediumspicy}: _response, notifiying callbacks for /slim/serverstatus
083909:18276 DEBUG (Comet.lua:831) -   callback to: function: 0x1608d760
083909:18277 INFO (NetworkThread.lua:246) - NOTIFY playerPower: Player {Officesbr}, 1
083909:18277 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /meta/connect id=nil OK
083909:18277 DEBUG (Comet.lua:510) - Comet {mediumspicy}: state is CONNECTED
083909:18277 INFO (NetworkThread.lua:246) - NOTIFY cometConnected: Comet {mediumspicy}
083909:18277 INFO (SlimServer.lua:387) - SlimServer {mediumspicy} connected
083909:18277 INFO (NetworkThread.lua:246) - NOTIFY serverConnected: SlimServer {mediumspicy}
083909:18277 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /meta/subscribe id=nil OK
083909:18277 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /slim/subscribe id=1 OK
083910:18397 DEBUG (Comet.lua:605) - Comet {SqueezeNetwork}: _handshake, advice updated from server
083910:18398 DEBUG (Comet.lua:612) - Comet {SqueezeNetwork}: _handshake OK, clientId: 84915X8961fbe0b42a507bf495bd5785c9038dX1203691184Xeff8dfbe
083910:18398 DEBUG (Comet.lua:625) - Comet {SqueezeNetwork}: _connect()
083910:18398 DEBUG (Comet.lua:648) - Sending pending request(s):
{ --[[table: 0x160f7560]]
  { --[[table: 0x160cfee0]]
    clientId = "84915X8961fbe0b42a507bf495bd5785c9038dX1203691184Xeff8dfbe",
    connectionType = "streaming",
    channel = "/meta/connect",
  },
  { --[[table: 0x160c6240]]
    clientId = "84915X8961fbe0b42a507bf495bd5785c9038dX1203691184Xeff8dfbe",
    subscription = "/84915X8961fbe0b42a507bf495bd5785c9038dX1203691184Xeff8dfbe/**",
    channel = "/meta/subscribe",
  },
  { --[[table: 0x160b08b0]]
    id = 1,
    data = { --[[table: 0x160c4d20]]
      request = { --[[table: 0x1609d880]]
        "",
        { --[[table: 0x160c5f20]]
          "serverstatus",
          0,
          50,
          "subscribe:60",
        },
      },
      response = "/84915X8961fbe0b42a507bf495bd5785c9038dX1203691184Xeff8dfbe/slim/serverstatus",
    },
    channel = "/slim/subscribe",
  },
}
083910:18490 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /meta/connect id=nil OK
083910:18490 DEBUG (Comet.lua:510) - Comet {SqueezeNetwork}: state is CONNECTED
083910:18490 INFO (NetworkThread.lua:246) - NOTIFY cometConnected: Comet {SqueezeNetwork}
083910:18490 INFO (SlimServer.lua:387) - SlimServer {SqueezeNetwork} connected
083910:18490 INFO (NetworkThread.lua:246) - NOTIFY serverConnected: SlimServer {SqueezeNetwork}
083910:18491 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /meta/subscribe id=nil OK
083910:18491 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /slim/subscribe id=1 OK
083910:18574 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /84915X8961fbe0b42a507bf495bd5785c9038dX1203691184Xeff8dfbe/slim/serverstatus id=1 OK
083910:18574 DEBUG (Comet.lua:828) - Comet {SqueezeNetwork}: _response, notifiying callbacks for /slim/serverstatus
083910:18574 DEBUG (Comet.lua:831) -   callback to: function: 0x160c5e90
083913:21326 DEBUG (Comet.lua:924) - Comet {cheesypoofs}: handleTimer state=CONNECTING advice=table: 0x16057820
083913:21326 DEBUG (Comet.lua:927) - Comet {cheesypoofs}: ignoring timer while CONNECTING
083919:28211 INFO (SlimServers.lua:274) - Disconnecting from idle servers
083919:28211 INFO (SlimServer.lua:366) - SlimServer {SqueezeNetwork}:disconnect()
083919:28211 DEBUG (Comet.lua:194) - Comet {SqueezeNetwork}: disconnect state=CONNECTED
083919:28212 DEBUG (Comet.lua:855) - Comet {SqueezeNetwork}: disconnect()
083919:28212 DEBUG (Comet.lua:859) - Will re-subscribe to /slim/serverstatus on next connect
083919:28212 DEBUG (Comet.lua:510) - Comet {SqueezeNetwork}: state is UNCONNECTING
083919:28212 INFO (SlimServer.lua:366) - SlimServer {mediumspicy}:disconnect()
083919:28212 DEBUG (Comet.lua:194) - Comet {mediumspicy}: disconnect state=CONNECTED
083919:28212 DEBUG (Comet.lua:855) - Comet {mediumspicy}: disconnect()
083919:28212 DEBUG (Comet.lua:859) - Will re-subscribe to /slim/serverstatus on next connect
083919:28213 DEBUG (Comet.lua:510) - Comet {mediumspicy}: state is UNCONNECTING
083919:28219 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /meta/disconnect id=nil OK
083919:28219 DEBUG (Comet.lua:510) - Comet {mediumspicy}: state is UNCONNECTED
083919:28220 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {mediumspicy}, 0
083919:28222 INFO (SlimServer.lua:398) - SlimServer {mediumspicy} disconnected
083919:28223 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {mediumspicy}, 0
083920:28395 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /meta/disconnect id=nil OK
083920:28395 DEBUG (Comet.lua:510) - Comet {SqueezeNetwork}: state is UNCONNECTED
083920:28395 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {SqueezeNetwork}, 0
083920:28396 INFO (SlimServer.lua:398) - SlimServer {SqueezeNetwork} disconnected
083920:28396 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {SqueezeNetwork}, 0

comet debug after restarting "cheesypoofs":

<nothing>


after descending into Music Library->Albums, player reconnected. Comet debug from that:
084149:177505 WARN (NowPlayingApplet.lua:595) - player=Player {Office SB3} status=table: 0x16015f40
084151:179707 DEBUG (Comet.lua:429) - Comet {cheesypoofs}: request(function: 0x1680b5d0, reqid:7, 00:04:20:06:33:d0, artists,0,200,menu:album, priority:nil)
084151:179707 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {cheesypoofs}, 1
084151:179707 INFO (SlimServer.lua:398) - SlimServer {cheesypoofs} disconnected
084151:179707 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {cheesypoofs}, 1
084151:179708 INFO (SlimServers.lua:165) - Removing server mediumspicy (mediumspicy)
084151:179708 INFO (NetworkThread.lua:246) - NOTIFY serverDelete: SlimServer {mediumspicy}
084151:179708 INFO (Player.lua:432) - Player {Squeezebox 4} delete for SlimServer {mediumspicy}
084151:179708 INFO (NetworkThread.lua:246) - NOTIFY playerDelete: Player {Squeezebox 4}
084151:179708 DEBUG (Comet.lua:480) - Comet {mediumspicy}: startBatch0
084151:179708 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/playerstatus/00:04:20:05:81:92, nil reqid:2)
084151:179708 DEBUG (Comet.lua:396) - No more callbacks for /slim/playerstatus/00:04:20:05:81:92 unsubscribing at server
084151:179708 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/displaystatus/00:04:20:05:81:92, nil reqid:3)
084151:179708 DEBUG (Comet.lua:396) - No more callbacks for /slim/displaystatus/00:04:20:05:81:92 unsubscribing at server
084151:179709 DEBUG (Comet.lua:488) - Comet {mediumspicy}: endBatch 1
084151:179709 INFO (Player.lua:432) - Player {Bedroom} delete for SlimServer {mediumspicy}
084151:179709 INFO (NetworkThread.lua:246) - NOTIFY playerDelete: Player {Bedroom}
084151:179709 DEBUG (Comet.lua:480) - Comet {mediumspicy}: startBatch0
084151:179709 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/playerstatus/00:04:20:07:92:f2, nil reqid:4)
084151:179709 DEBUG (Comet.lua:396) - No more callbacks for /slim/playerstatus/00:04:20:07:92:f2 unsubscribing at server
084151:179709 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/displaystatus/00:04:20:07:92:f2, nil reqid:5)
084151:179709 DEBUG (Comet.lua:396) - No more callbacks for /slim/displaystatus/00:04:20:07:92:f2 unsubscribing at server
084151:179709 DEBUG (Comet.lua:488) - Comet {mediumspicy}: endBatch 1
084151:179709 INFO (Player.lua:432) - Player {Squeezebox 5} delete for SlimServer {mediumspicy}
084151:179709 INFO (NetworkThread.lua:246) - NOTIFY playerDelete: Player {Squeezebox 5}
084151:179710 DEBUG (Comet.lua:480) - Comet {mediumspicy}: startBatch0
084151:179710 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/playerstatus/00:04:20:05:1b:82, nil reqid:6)
084151:179710 DEBUG (Comet.lua:396) - No more callbacks for /slim/playerstatus/00:04:20:05:1b:82 unsubscribing at server
084151:179710 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/displaystatus/00:04:20:05:1b:82, nil reqid:7)
084151:179710 DEBUG (Comet.lua:396) - No more callbacks for /slim/displaystatus/00:04:20:05:1b:82 unsubscribing at server
084151:179710 DEBUG (Comet.lua:488) - Comet {mediumspicy}: endBatch 1
084151:179710 INFO (Player.lua:432) - Player {Living Room} delete for SlimServer {mediumspicy}
084151:179710 INFO (NetworkThread.lua:246) - NOTIFY playerDelete: Player {Living Room}
084151:179710 DEBUG (Comet.lua:480) - Comet {mediumspicy}: startBatch0
084151:179710 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/playerstatus/00:04:20:10:05:7d, nil reqid:8)
084151:179710 DEBUG (Comet.lua:396) - No more callbacks for /slim/playerstatus/00:04:20:10:05:7d unsubscribing at server
084151:179711 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/displaystatus/00:04:20:10:05:7d, nil reqid:9)
084151:179711 DEBUG (Comet.lua:396) - No more callbacks for /slim/displaystatus/00:04:20:10:05:7d unsubscribing at server
084151:179711 DEBUG (Comet.lua:488) - Comet {mediumspicy}: endBatch 1
084151:179711 INFO (Player.lua:432) - Player {Officesbr} delete for SlimServer {mediumspicy}
084151:179711 INFO (NetworkThread.lua:246) - NOTIFY playerDelete: Player {Officesbr}
084151:179711 DEBUG (Comet.lua:480) - Comet {mediumspicy}: startBatch0
084151:179711 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/playerstatus/00:04:20:16:02:3f, nil reqid:10)
084151:179711 DEBUG (Comet.lua:396) - No more callbacks for /slim/playerstatus/00:04:20:16:02:3f unsubscribing at server
084151:179711 DEBUG (Comet.lua:380) - Comet {mediumspicy}: unsubscribe(/slim/displaystatus/00:04:20:16:02:3f, nil reqid:11)
084151:179711 DEBUG (Comet.lua:396) - No more callbacks for /slim/displaystatus/00:04:20:16:02:3f unsubscribing at server
084151:179711 DEBUG (Comet.lua:488) - Comet {mediumspicy}: endBatch 1
084151:179712 DEBUG (Comet.lua:194) - Comet {mediumspicy}: disconnect state=UNCONNECTED
084151:179712 INFO (SlimServers.lua:165) - Removing server cheesypoofs (cheesypoofs)
084151:179712 INFO (NetworkThread.lua:246) - NOTIFY serverDelete: SlimServer {cheesypoofs}
084151:179712 INFO (Player.lua:432) - Player {Office SB3} delete for SlimServer {cheesypoofs}
084151:179712 INFO (NetworkThread.lua:246) - NOTIFY playerDelete: Player {Office SB3}
084151:179712 INFO (SlimBrowserApplet.lua:2100) - Player gone while browsing it ! -- packing home!
084151:179712 INFO (SlimBrowserApplet.lua:2325) - Unsubscribe /slim/menustatus/00:04:20:06:33:d0
084151:179712 DEBUG (Comet.lua:380) - Comet {cheesypoofs}: unsubscribe(/slim/menustatus/00:04:20:06:33:d0, nil reqid:8)
084151:179712 DEBUG (Comet.lua:396) - No more callbacks for /slim/menustatus/00:04:20:06:33:d0 unsubscribing at server
084151:179712 DEBUG (Comet.lua:480) - Comet {cheesypoofs}: startBatch0
084151:179712 DEBUG (Comet.lua:380) - Comet {cheesypoofs}: unsubscribe(/slim/playerstatus/00:04:20:06:33:d0, nil reqid:9)
084151:179713 DEBUG (Comet.lua:396) - No more callbacks for /slim/playerstatus/00:04:20:06:33:d0 unsubscribing at server
084151:179713 DEBUG (Comet.lua:380) - Comet {cheesypoofs}: unsubscribe(/slim/displaystatus/00:04:20:06:33:d0, nil reqid:10)
084151:179713 DEBUG (Comet.lua:396) - No more callbacks for /slim/displaystatus/00:04:20:06:33:d0 unsubscribing at server
084151:179713 DEBUG (Comet.lua:488) - Comet {cheesypoofs}: endBatch 1
084151:179713 INFO (SlimServers.lua:353) - selected player: nil
084151:179714 INFO (NetworkThread.lua:246) - NOTIFY playerCurrent: nil
084151:179714 INFO (SlimBrowserApplet.lua:2109) - SlimBrowserApplet:notify_playerCurrent(nil)
084151:179714 WARN (NowPlayingApplet.lua:678) - NowPlaying.free()
084151:179714 INFO (SlimServers.lua:260) - Reconnecting to all servers
084151:179714 INFO (SlimServer.lua:356) - SlimServer {SqueezeNetwork}:connect()
084151:179714 DEBUG (Comet.lua:175) - Comet {SqueezeNetwork}: connect state=UNCONNECTED
084151:179714 DEBUG (Comet.lua:533) - Comet {SqueezeNetwork}: _handshake(), calling: http://www.beta.squeezenetwork.com:9000/cometd
084151:179714 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/serverstatus
084151:179714 DEBUG (Comet.lua:510) - Comet {SqueezeNetwork}: state is CONNECTING
084151:179716 INFO (SlimServers.lua:279) - Starting discovery
084151:179716 DEBUG (Comet.lua:480) - Comet {cheesypoofs}: startBatch0
084151:179716 DEBUG (Comet.lua:380) - Comet {cheesypoofs}: unsubscribe(/slim/playerstatus/00:04:20:06:33:d0, nil reqid:11)
084151:179716 DEBUG (Comet.lua:396) - No more callbacks for /slim/playerstatus/00:04:20:06:33:d0 unsubscribing at server
084151:179716 DEBUG (Comet.lua:380) - Comet {cheesypoofs}: unsubscribe(/slim/displaystatus/00:04:20:06:33:d0, nil reqid:12)
084151:179716 DEBUG (Comet.lua:396) - No more callbacks for /slim/displaystatus/00:04:20:06:33:d0 unsubscribing at server
084151:179717 DEBUG (Comet.lua:488) - Comet {cheesypoofs}: endBatch 1
084151:179717 DEBUG (Comet.lua:194) - Comet {cheesypoofs}: disconnect state=CONNECTING
084151:179717 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is UNCONNECTED
084151:179717 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {cheesypoofs}, 1
084151:179717 INFO (SlimServer.lua:398) - SlimServer {cheesypoofs} disconnected
084151:179717 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {cheesypoofs}, 1
084151:179720 INFO (SlimServers.lua:82) - Creating server mediumspicy (mediumspicy)
084151:179720 INFO (SlimServer.lua:356) - SlimServer {mediumspicy}:connect()
084151:179721 DEBUG (Comet.lua:175) - Comet {mediumspicy}: connect state=UNCONNECTED
084151:179721 DEBUG (Comet.lua:533) - Comet {mediumspicy}: _handshake(), calling: http://192.168.1.2:9000/cometd
084151:179721 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/serverstatus
084151:179721 DEBUG (Comet.lua:510) - Comet {mediumspicy}: state is CONNECTING
084151:179721 INFO (NetworkThread.lua:246) - NOTIFY serverNew: SlimServer {mediumspicy}
084151:179728 DEBUG (Comet.lua:605) - Comet {mediumspicy}: _handshake, advice updated from server
084151:179729 DEBUG (Comet.lua:612) - Comet {mediumspicy}: _handshake OK, clientId: 3fa37d03
084151:179729 DEBUG (Comet.lua:625) - Comet {mediumspicy}: _connect()
084151:179729 DEBUG (Comet.lua:648) - Sending pending request(s):
{ --[[table: 0x11f1b10]]
  { --[[table: 0x11e05b0]]
    clientId = "3fa37d03",
    connectionType = "streaming",
    channel = "/meta/connect",
  },
  { --[[table: 0x160bfed0]]
    clientId = "3fa37d03",
    subscription = "/3fa37d03/**",
    channel = "/meta/subscribe",
  },
  { --[[table: 0x160d9310]]
    id = 1,
    data = { --[[table: 0x160d9330]]
      request = { --[[table: 0x11d5d30]]
        "",
        { --[[table: 0x1198720]]
          "serverstatus",
          0,
          50,
          "subscribe:60",
        },
      },
      response = "/3fa37d03/slim/serverstatus",
    },
    channel = "/slim/subscribe",
  },
}
084151:179759 INFO (SlimServers.lua:82) - Creating server cheesypoofs (cheesypoofs)
084151:179759 INFO (SlimServer.lua:356) - SlimServer {cheesypoofs}:connect()
084151:179759 DEBUG (Comet.lua:175) - Comet {cheesypoofs}: connect state=UNCONNECTED
084151:179759 DEBUG (Comet.lua:533) - Comet {cheesypoofs}: _handshake(), calling: http://192.168.1.219:9000/cometd
084151:179759 DEBUG (Comet.lua:545) - Will re-subscribe to /slim/serverstatus
084151:179759 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is CONNECTING
084151:179760 INFO (NetworkThread.lua:246) - NOTIFY serverNew: SlimServer {cheesypoofs}
084151:179789 DEBUG (Comet.lua:605) - Comet {cheesypoofs}: _handshake, advice updated from server
084151:179789 DEBUG (Comet.lua:612) - Comet {cheesypoofs}: _handshake OK, clientId: bf25c0e7
084151:179790 DEBUG (Comet.lua:625) - Comet {cheesypoofs}: _connect()
084151:179790 DEBUG (Comet.lua:648) - Sending pending request(s):
{ --[[table: 0x16077bf0]]
  { --[[table: 0x1601bcf0]]
    clientId = "bf25c0e7",
    connectionType = "streaming",
    channel = "/meta/connect",
  },
  { --[[table: 0x1601bd10]]
    clientId = "bf25c0e7",
    subscription = "/bf25c0e7/**",
    channel = "/meta/subscribe",
  },
  { --[[table: 0x160a1ee0]]
    id = 1,
    data = { --[[table: 0x160068e0]]
      request = { --[[table: 0x160867d0]]
        "",
        { --[[table: 0x16091600]]
          "serverstatus",
          0,
          50,
          "subscribe:60",
        },
      },
      response = "/bf25c0e7/slim/serverstatus",
    },
    channel = "/slim/subscribe",
  },
  { --[[table: 0x160c3780]]
    id = 7,
    data = { --[[table: 0x16800580]]
      request = { --[[table: 0x160c3740]]
        "00:04:20:06:33:d0",
        { --[[table: 0x1680b7c0]]
          "artists",
          0,
          200,
          "menu:album",
        },
      },
      response = "/bf25c0e7/slim/request",
    },
    channel = "/slim/request",
  },
}
084151:179799 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /3fa37d03/slim/serverstatus id=1 OK
084151:179799 DEBUG (Comet.lua:828) - Comet {mediumspicy}: _response, notifiying callbacks for /slim/serverstatus
084151:179799 DEBUG (Comet.lua:831) -   callback to: function: 0x1608d760
084151:179799 INFO (NetworkThread.lua:246) - NOTIFY playerNew: Player {Squeezebox 5}
084151:179799 INFO (Player.lua:290) - Player {Squeezebox 5} new for SlimServer {mediumspicy}
084151:179799 INFO (NetworkThread.lua:246) - NOTIFY playerNew: Player {Living Room}
084151:179799 INFO (Player.lua:290) - Player {Living Room} new for SlimServer {mediumspicy}
084151:179799 INFO (NetworkThread.lua:246) - NOTIFY playerNew: Player {Officesbr}
084151:179799 INFO (Player.lua:290) - Player {Officesbr} new for SlimServer {mediumspicy}
084151:179800 INFO (NetworkThread.lua:246) - NOTIFY playerNew: Player {Bedroom}
084151:179800 INFO (Player.lua:290) - Player {Bedroom} new for SlimServer {mediumspicy}
084151:179800 INFO (NetworkThread.lua:246) - NOTIFY playerNew: Player {Squeezebox 4}
084151:179800 INFO (Player.lua:290) - Player {Squeezebox 4} new for SlimServer {mediumspicy}
084151:179800 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /meta/connect id=nil OK
084151:179800 DEBUG (Comet.lua:510) - Comet {mediumspicy}: state is CONNECTED
084151:179800 INFO (NetworkThread.lua:246) - NOTIFY cometConnected: Comet {mediumspicy}
084151:179800 INFO (SlimServer.lua:387) - SlimServer {mediumspicy} connected
084151:179800 INFO (NetworkThread.lua:246) - NOTIFY serverConnected: SlimServer {mediumspicy}
084151:179800 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /meta/subscribe id=nil OK
084151:179801 DEBUG (Comet.lua:768) - Comet {mediumspicy}: _response, /slim/subscribe id=1 OK
084151:179912 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/serverstatus id=1 OK
084151:179912 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/serverstatus
084151:179912 DEBUG (Comet.lua:831) -   callback to: function: 0x160782f0
084151:179913 INFO (NetworkThread.lua:246) - NOTIFY playerNew: Player {Office SB3}
084151:179913 INFO (AppletManager.lua:505) - Store settings: SlimDiscovery
084151:179964 INFO (SlimServers.lua:353) - selected player: Player {Office SB3}
084151:179964 INFO (NetworkThread.lua:246) - NOTIFY playerCurrent: Player {Office SB3}
084151:179965 INFO (SlimBrowserApplet.lua:2109) - SlimBrowserApplet:notify_playerCurrent(Player {Office SB3})
084151:179965 INFO (SlimBrowserApplet.lua:2125) - First load...get the correct wallpaper on screen
084151:179966 INFO (AppletManager.lua:417) - Loaded: SetupWallpaper
084151:179975 INFO (AppletManager.lua:558) - Freeing: SetupWallpaper
084151:179975 INFO (SlimBrowserApplet.lua:2150) - Subscribing to /slim/menustatus/00:04:20:06:33:d0
084151:179975 DEBUG (Comet.lua:349) - Comet {cheesypoofs}: subscribe(/slim/menustatus/00:04:20:06:33:d0 function: 0x160ef930, reqid:13, 00:04:20:06:33:d0, menustatus, priority:nil)
084151:179976 DEBUG (Comet.lua:480) - Comet {cheesypoofs}: startBatch0
084151:179976 DEBUG (Comet.lua:429) - Comet {cheesypoofs}: request(function: 0x160e4840, reqid:14, 00:04:20:06:33:d0, menu,0,100, priority:nil)
084151:179976 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {cheesypoofs}, 1
084151:179976 INFO (SlimServer.lua:398) - SlimServer {cheesypoofs} disconnected
084151:179976 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {cheesypoofs}, 1
084151:179978 DEBUG (Comet.lua:480) - Comet {cheesypoofs}: startBatch1
084151:179978 DEBUG (Comet.lua:349) - Comet {cheesypoofs}: subscribe(/slim/playerstatus/00:04:20:06:33:d0 function: 0x160ea3a0, reqid:15, 00:04:20:06:33:d0, status,-,10,menu:menu,subscribe:30, priority:nil)
084151:179991 DEBUG (Comet.lua:349) - Comet {cheesypoofs}: subscribe(/slim/displaystatus/00:04:20:06:33:d0 function: 0x160e4260, reqid:16, 00:04:20:06:33:d0, displaystatus,subscribe:showbriefly, priority:nil)
084151:179991 DEBUG (Comet.lua:488) - Comet {cheesypoofs}: endBatch 2
084151:179991 DEBUG (Comet.lua:429) - Comet {cheesypoofs}: request(function: 0x160e4840, reqid:17, 00:04:20:06:33:d0, status,0,200,menu:menu, priority:nil)
084151:179991 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {cheesypoofs}, 2
084151:179991 INFO (SlimServer.lua:398) - SlimServer {cheesypoofs} disconnected
084151:179992 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {cheesypoofs}, 2
084151:179992 DEBUG (Comet.lua:488) - Comet {cheesypoofs}: endBatch 1
084151:179992 INFO (SlimBrowserApplet.lua:2189) - power: 1
084151:179992 INFO (SlimBrowserApplet.lua:553) - _connectingToPlayer popup show
084151:179992 WARN (NowPlayingApplet.lua:678) - NowPlaying.free()
084151:179992 INFO (Player.lua:290) - Player {Office SB3} new for SlimServer {cheesypoofs}
084151:180006 DEBUG (Comet.lua:605) - Comet {SqueezeNetwork}: _handshake, advice updated from server
084151:180006 DEBUG (Comet.lua:612) - Comet {SqueezeNetwork}: _handshake OK, clientId: 84915X8961fbe0b42a507bf495bd5785c9038dX1203691346Xab88dd68
084151:180006 DEBUG (Comet.lua:625) - Comet {SqueezeNetwork}: _connect()
084151:180006 DEBUG (Comet.lua:648) - Sending pending request(s):
{ --[[table: 0x1681f0f0]]
  { --[[table: 0x1681f280]]
    clientId = "84915X8961fbe0b42a507bf495bd5785c9038dX1203691346Xab88dd68",
    connectionType = "streaming",
    channel = "/meta/connect",
  },
  { --[[table: 0x1681f310]]
    clientId = "84915X8961fbe0b42a507bf495bd5785c9038dX1203691346Xab88dd68",
    subscription = "/84915X8961fbe0b42a507bf495bd5785c9038dX1203691346Xab88dd68/**",
    channel = "/meta/subscribe",
  },
  { --[[table: 0x1681f490]]
    id = 1,
    data = { --[[table: 0x1681f520]]
      request = { --[[table: 0x1681f3f0]]
        "",
        { --[[table: 0x160c5f20]]
          "serverstatus",
          0,
          50,
          "subscribe:60",
        },
      },
      response = "/84915X8961fbe0b42a507bf495bd5785c9038dX1203691346Xab88dd68/slim/serverstatus",
    },
    channel = "/slim/subscribe",
  },
}
084151:180039 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/request id=7 OK
084151:180039 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/request|7
084151:180039 DEBUG (Comet.lua:831) -   callback to: function: 0x1680b5d0
084151:180040 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /meta/connect id=nil OK
084151:180040 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is CONNECTED
084151:180040 INFO (NetworkThread.lua:246) - NOTIFY cometConnected: Comet {cheesypoofs}
084151:180041 INFO (SlimServer.lua:387) - SlimServer {cheesypoofs} connected
084151:180041 INFO (NetworkThread.lua:246) - NOTIFY serverConnected: SlimServer {cheesypoofs}
084151:180041 DEBUG (Comet.lua:330) - Sending pending request(s):
{ --[[table: 0x160f9550]]
  { --[[table: 0x160e8d90]]
    id = 13,
    data = { --[[table: 0x160cad70]]
      request = { --[[table: 0x160eec50]]
        "00:04:20:06:33:d0",
        { --[[table: 0x160ef7b0]]
          "menustatus",
        },
      },
      response = "/bf25c0e7/slim/menustatus/00:04:20:06:33:d0",
    },
    channel = "/slim/subscribe",
  },
  { --[[table: 0x11f3440]]
    id = 15,
    data = { --[[table: 0x11de250]]
      request = { --[[table: 0x16007250]]
        "00:04:20:06:33:d0",
        { --[[table: 0x16803230]]
          "status",
          "-",
          10,
          "menu:menu",
          "subscribe:30",
        },
      },
      response = "/bf25c0e7/slim/playerstatus/00:04:20:06:33:d0",
    },
    channel = "/slim/subscribe",
  },
  { --[[table: 0x160c18e0]]
    id = 16,
    data = { --[[table: 0x160b6c50]]
      request = { --[[table: 0x16077620]]
        "00:04:20:06:33:d0",
        { --[[table: 0x160ea860]]
          "displaystatus",
          "subscribe:showbriefly",
        },
      },
      response = "/bf25c0e7/slim/displaystatus/00:04:20:06:33:d0",
    },
    channel = "/slim/subscribe",
  },
  { --[[table: 0x160c5a80]]
    id = 14,
    data = { --[[table: 0x1680bd80]]
      request = { --[[table: 0x160f3f90]]
        "00:04:20:06:33:d0",
        { --[[table: 0x160e9350]]
          "menu",
          0,
          100,
        },
      },
      response = "/bf25c0e7/slim/request",
    },
    channel = "/slim/request",
  },
  { --[[table: 0x160c71b0]]
    id = 17,
    data = { --[[table: 0x160b6800]]
      request = { --[[table: 0x1609df80]]
        "00:04:20:06:33:d0",
        { --[[table: 0x16805fb0]]
          "status",
          0,
          200,
          "menu:menu",
        },
      },
      response = "/bf25c0e7/slim/request",
    },
    channel = "/slim/request",
  },
}
084151:180043 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /meta/subscribe id=nil OK
084151:180043 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /slim/subscribe id=1 OK
084151:180043 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /slim/request id=7 OK
084151:180082 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /slim/subscribe id=13 OK
084151:180082 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /slim/subscribe id=15 OK
084151:180082 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /slim/subscribe id=16 OK
084151:180083 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /slim/request id=14 OK
084151:180083 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /slim/request id=17 OK
084151:180083 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/playerstatus/00:04:20:06:33:d0 id=15 OK
084151:180084 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/playerstatus/00:04:20:06:33:d0
084151:180084 DEBUG (Comet.lua:831) -   callback to: function: 0x160ea3a0
084151:180084 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/displaystatus/00:04:20:06:33:d0 id=16 OK
084151:180084 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/displaystatus/00:04:20:06:33:d0
084151:180084 DEBUG (Comet.lua:831) -   callback to: function: 0x160e4260
084151:180085 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/request id=14 OK
084151:180085 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/request|14
084151:180085 DEBUG (Comet.lua:831) -   callback to: function: 0x160e4840
084151:180086 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/request id=17 OK
084151:180086 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/request|17
084151:180086 DEBUG (Comet.lua:831) -   callback to: function: 0x160e4840
084151:180113 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/menustatus/00:04:20:06:33:d0 id=13 OK
084151:180114 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/menustatus/00:04:20:06:33:d0
084151:180114 DEBUG (Comet.lua:831) -   callback to: function: 0x160ef930
084151:180114 INFO (SlimBrowserApplet.lua:856) - _menuSink()
084151:180116 INFO (SlimBrowserApplet.lua:640) - _connectingToPlayer popup hide
084151:180117 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /meta/connect id=nil OK
084151:180117 DEBUG (Comet.lua:510) - Comet {SqueezeNetwork}: state is CONNECTED
084151:180117 INFO (NetworkThread.lua:246) - NOTIFY cometConnected: Comet {SqueezeNetwork}
084151:180117 INFO (SlimServer.lua:387) - SlimServer {SqueezeNetwork} connected
084151:180117 INFO (NetworkThread.lua:246) - NOTIFY serverConnected: SlimServer {SqueezeNetwork}
084151:180117 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /meta/subscribe id=nil OK
084151:180117 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /slim/subscribe id=1 OK
084151:180187 DEBUG (Comet.lua:768) - Comet {SqueezeNetwork}: _response, /84915X8961fbe0b42a507bf495bd5785c9038dX1203691346Xab88dd68/slim/serverstatus id=1 OK
084151:180187 DEBUG (Comet.lua:828) - Comet {SqueezeNetwork}: _response, notifiying callbacks for /slim/serverstatus
084151:180187 DEBUG (Comet.lua:831) -   callback to: function: 0x160c5e90
084152:180391 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /bf25c0e7/slim/playerstatus/00:04:20:06:33:d0 id=15 OK
084152:180391 DEBUG (Comet.lua:828) - Comet {cheesypoofs}: _response, notifiying callbacks for /slim/playerstatus/00:04:20:06:33:d0
084152:180391 DEBUG (Comet.lua:831) -   callback to: function: 0x160ea3a0
084203:191784 INFO (SlimServers.lua:274) - Disconnecting from idle servers
Comment 22 Richard Titmuss 2008-02-22 07:50:02 UTC
Created attachment 2976 [details]
Patch
Comment 23 Richard Titmuss 2008-02-22 07:50:34 UTC
Ben, please try this updated patch.
Comment 24 Ben Klaas 2008-02-22 08:14:31 UTC
with the new patch, I saw a couple new behaviors.

Sometimes when going through the test case (bring down server, bring it back with different IP, observe Jive behavior), there is a long delay between when the player comes back up and jive recognizes it's back. Delay seems to be from 0-60 seconds, which makes me think it's tied to the serverstatus subscription, which on Jive is once/minute.

But I also saw another, worse behavior, which was that after a similar delay of about ~40 secs, Jive behaves as if the player is completely gone (removes all player-specific home menu items), and going into Choose Player shows no players (I have 5 or 6 players that should be in the list)

here's what I saw on the console when that happened:
100644:658514 INFO (SlimServer.lua:356) - SlimServer {cheesypoofs}:connect()
100644:658514 DEBUG (Comet.lua:175) - Comet {cheesypoofs}: connect state=UNCONNECTED
100644:658514 DEBUG (Comet.lua:533) - Comet {cheesypoofs}: _handshake(), calling: http://192.168.1.219:9000/cometd
100644:658514 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is CONNECTING
100644:658514 INFO (NetworkThread.lua:246) - NOTIFY serverNew: SlimServer {cheesypoofs}
100644:658514 INFO (SlimServer.lua:438) - SlimServer {cheesypoofs}: IP Address changed to 192.168.1.220:9000 connecting=true
100644:658514 INFO (SlimServer.lua:366) - SlimServer {cheesypoofs}:disconnect()
100644:658514 DEBUG (Comet.lua:194) - Comet {cheesypoofs}: disconnect state=CONNECTING
100644:658515 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is UNCONNECTED
100644:658515 INFO (NetworkThread.lua:246) - NOTIFY cometDisconnected: Comet {cheesypoofs}, 0
100644:658515 INFO (SlimServer.lua:398) - SlimServer {cheesypoofs} disconnected
100644:658519 INFO (NetworkThread.lua:246) - NOTIFY serverDisconnected: SlimServer {cheesypoofs}, 0
100644:658520 DEBUG (Comet.lua:125) - Comet: __init(cheesypoofs, 192.168.1.220, 9000, /cometd)
100644:658520 INFO (SlimServer.lua:356) - SlimServer {cheesypoofs}:connect()
100644:658520 DEBUG (Comet.lua:175) - Comet {cheesypoofs}: connect state=UNCONNECTED
100644:658520 DEBUG (Comet.lua:533) - Comet {cheesypoofs}: _handshake(), calling: http://192.168.1.220:9000/cometd
100644:658520 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is CONNECTING
100644:658532 DEBUG (Comet.lua:605) - Comet {cheesypoofs}: _handshake, advice updated from server
100644:658532 DEBUG (Comet.lua:612) - Comet {cheesypoofs}: _handshake OK, clientId: e25674a2
100644:658532 DEBUG (Comet.lua:625) - Comet {cheesypoofs}: _connect()
100644:658532 DEBUG (Comet.lua:648) - Sending pending request(s):
{ --[[table: 0x11cdab0]]
  { --[[table: 0x160d0ba0]]
    clientId = "e25674a2",
    connectionType = "streaming",
    channel = "/meta/connect",
  },
  { --[[table: 0x1609d9d0]]
    clientId = "e25674a2",
    subscription = "/e25674a2/**",
    channel = "/meta/subscribe",
  },
}
100644:658563 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /meta/connect id=nil OK
100644:658563 DEBUG (Comet.lua:510) - Comet {cheesypoofs}: state is CONNECTED
100644:658563 INFO (NetworkThread.lua:246) - NOTIFY cometConnected: Comet {cheesypoofs}
100644:658564 INFO (SlimServer.lua:387) - SlimServer {cheesypoofs} connected
100644:658564 INFO (NetworkThread.lua:246) - NOTIFY serverConnected: SlimServer {cheesypoofs}
100644:658564 DEBUG (Comet.lua:768) - Comet {cheesypoofs}: _response, /meta/subscribe id=nil OK
100655:668865 INFO (AppletManager.lua:417) - Loaded: SetupSqueezebox
100700:673967 INFO (AppletManager.lua:558) - Freeing: SelectPlayer
100702:676593 INFO (AppletManager.lua:558) - Freeing: SelectPlayer
100717:691388 INFO (AppletManager.lua:558) - Freeing: SelectPlayer
Comment 25 Richard Titmuss 2008-02-22 12:57:18 UTC
Created attachment 2978 [details]
Patch to allow jive to reconnect even if SC changes it's IP address
Comment 26 Ben Klaas 2008-02-22 13:06:51 UTC
the last patch has my blessing. 6/6 successful trials (3 with IP change on server, 3 without)
Comment 27 Richard Titmuss 2008-02-22 14:00:45 UTC
Fixed in r2000-r2005.
Comment 28 James Richardson 2008-05-15 13:04:04 UTC
This bug has recently been fixed in the latest release of SqueezeCenter 7.0.1

Please try that version, if you still see the error, then reopen this bug.

To download this version, please navigate to: http://www.slimdevices.com/su_downloads.html