Bugzilla – Bug 10120
controller doesn't reconnect to player when music source goes from SN->SC
Last modified: 2008-12-15 12:10:03 UTC
1. connect to a receiver that's connected to local SC 2. through Settings->Music Source, select SqueezeNetwork 3. allow home menu populate from SN 4. repeat step 2 controller stuck in state of not being connected to a player selecting receiver through Choose Player results in reconnecting to that player, which was successfully reattached to the local SC.
what appears to be happening is that when coming from SN back to SC, no playerCurrent notification is reaching SlimBrowser to trigger the request for the local menus. starting with SBR "Huey", connected to SC Settings->Music Source->SqueezeNetwork: 161127:102885 INFO (SlimServer.lua:201) - SlimServer {SqueezeNetwork}: has no players! 161128:103552 INFO (NetworkThread.lua:253) - NOTIFY: playerDisconnected(Player {Huey}) 161128:103552 INFO (SlimDiscoveryApplet.lua:391) - playerDisconnected 161128:103692 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Huey}) 161128:103692 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103692 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103692 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161128:103705 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Squeezebox 160109}) 161128:103705 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103705 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103705 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161128:103709 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Huey}) 161128:103709 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103709 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103709 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161128:103710 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Squeezebox 160109}) 161128:103711 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103711 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103711 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161128:103897 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Huey}) 161128:103898 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103898 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103898 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161128:103912 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Squeezebox 160109}) 161128:103912 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103912 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103912 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161128:103914 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Huey}) 161128:103914 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103914 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103915 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161128:103916 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Squeezebox 160109}) 161128:103916 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161128:103916 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161128:103916 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161129:104587 INFO (Player.lua:506) - Player {Huey} delete for SlimServer {DaddyMac-520.local} 161129:104587 INFO (NetworkThread.lua:253) - NOTIFY: playerDelete(Player {Huey}) 161129:104587 INFO (NowPlayingApplet.lua:792) - NowPlaying.free() 161129:104587 INFO (NowPlayingApplet.lua:793) - false 161129:104588 INFO (SlimBrowserApplet.lua:2312) - Player gone while browsing it ! -- packing home! 161129:104588 INFO (SlimBrowserApplet.lua:2586) - Unsubscribe /slim/menustatus/00:04:20:16:02:3f 161129:104590 INFO (Player.lua:342) - Player {Huey} new for SlimServer {SqueezeNetwork} 161129:104590 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Huey}) 161129:104590 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d499b0 161129:104590 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {SqueezeNetwork} 161129:104591 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161129:104591 INFO (AppletManager.lua:684) - Store settings: ChooseMusicSource 161129:104592 WARN (AppletManager.lua:727) - ChooseMusicSource:free() returned nil 161129:104592 INFO (AppletManager.lua:737) - Freeing: ChooseMusicSource 161129:104593 INFO (NetworkThread.lua:253) - NOTIFY: playerPower(Player {Huey}, false) there was a delay of 5 seconds, but the SN menu loads via a playerCurrent: 161134:109076 INFO (NetworkThread.lua:253) - NOTIFY: playerConnected(Player {Huey}) 161134:109076 INFO (SlimDiscoveryApplet.lua:404) - playerConnected 161134:109077 INFO (SlimServer.lua:499) - SlimServer {mediumspicy}:disconnect 161134:109077 INFO (SlimServer.lua:499) - SlimServer {DaddyMac-520.local}:disconnect 161134:109078 INFO (NetworkThread.lua:253) - NOTIFY: playerCurrent(Player {Huey}) 161134:109078 INFO (NowPlayingApplet.lua:792) - NowPlaying.free() 161134:109078 INFO (NowPlayingApplet.lua:793) - false 161134:109078 INFO (AppletManager.lua:684) - Store settings: SlimDiscovery 161134:109079 INFO (SetupWallpaperApplet.lua:109) - SetupWallpaper:notify_playerCurrent(Player {Huey}) 161134:109079 INFO (SlimBrowserApplet.lua:2357) - Subscribing to /slim/menustatus/00:04:20:16:02:3f 161134:109081 INFO (SlimBrowserApplet.lua:541) - _connectingToPlayer popup show 161134:109084 INFO (NetworkThread.lua:253) - NOTIFY: cometDisconnected(Comet {DaddyMac-520.local}) 161134:109085 INFO (NetworkThread.lua:253) - NOTIFY: serverDisconnected(SlimServer {DaddyMac-520.local}, 0) 161134:109085 INFO (SlimDiscoveryApplet.lua:422) - serverDisconnected SlimServer {DaddyMac-520.local} 161134:109087 INFO (NetworkThread.lua:253) - NOTIFY: cometDisconnected(Comet {mediumspicy}) 161134:109087 INFO (NetworkThread.lua:253) - NOTIFY: serverDisconnected(SlimServer {mediumspicy}, 0) 161134:109088 INFO (SlimDiscoveryApplet.lua:422) - serverDisconnected SlimServer {mediumspicy} 161134:109411 INFO (NetworkThread.lua:253) - NOTIFY: playerPower(Player {Huey}, true) 161134:109412 INFO (NetworkThread.lua:253) - NOTIFY: playerTrackChange(Player {Huey}, nil) 161134:109412 INFO (NowPlayingApplet.lua:174) - Notification received that track has changed 161134:109413 INFO (NetworkThread.lua:253) - NOTIFY: playerPlaylistChange(Player {Huey}) 161134:109415 INFO (SlimBrowserApplet.lua:1040) - _menuSink() 161134:109415 INFO (SlimBrowserApplet.lua:2568) - _connectingToPlayer popup hide 161134:109675 INFO (SlimBrowserApplet.lua:1040) - _menuSink() connecting back to SC, playerNew notification is sent but no playerCurrent: 161403:39198 INFO (SlimServer.lua:201) - SlimServer {SqueezeNetwork}: has no players! 161403:39198 INFO (Player.lua:506) - Player {Huey} delete for SlimServer {SqueezeNetwork} 161403:39198 INFO (NetworkThread.lua:253) - NOTIFY: playerDelete(Player {Huey}) 161403:39198 INFO (SlimBrowserApplet.lua:2312) - Player gone while browsing it ! -- packing home! 161403:39198 INFO (SlimBrowserApplet.lua:2586) - Unsubscribe /slim/menustatus/00:04:20:16:02:3f 161403:39200 INFO (NowPlayingApplet.lua:792) - NowPlaying.free() 161403:39200 INFO (NowPlayingApplet.lua:793) - false 161405:40834 INFO (Player.lua:506) - Player {Huey} delete for SlimServer {SqueezeNetwork} 161405:40834 INFO (NetworkThread.lua:253) - NOTIFY: playerDelete(Player {Huey}) 161405:40834 INFO (Player.lua:342) - Player {Huey} new for SlimServer {DaddyMac-520.local} 161405:40834 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Huey}) 161405:40834 WARN (ChooseMusicSourceApplet.lua:249) - waitForConnect=table: 0x16d7d5e0 161405:40834 WARN (ChooseMusicSourceApplet.lua:251) - server=SlimServer {DaddyMac-520.local} 161405:40834 WARN (ChooseMusicSourceApplet.lua:252) - player=Player {Huey} 161405:40835 INFO (AppletManager.lua:684) - Store settings: ChooseMusicSource 161405:40835 WARN (AppletManager.lua:727) - ChooseMusicSource:free() returned nil 161405:40835 INFO (AppletManager.lua:737) - Freeing: ChooseMusicSource 161405:40836 INFO (NetworkThread.lua:253) - NOTIFY: playerPower(Player {Huey}, true) 161408:43524 INFO (SlimServer.lua:201) - SlimServer {SqueezeNetwork}: has no players! 161408:43675 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Squeezebox 160109}) 161408:43772 INFO (NetworkThread.lua:253) - NOTIFY: playerNew(Player {Squeezebox 160109})
further debug... after SN->SC, oldInfo.connected is still the same as self.info.connected, thus no playerConnected notification is sent out... -- Check if the player connected status has changed if oldInfo.connected ~= self.info.connected then if self.info.connected then self.jnt:notify('playerConnected', self) else self.jnt:notify('playerDisconnected', self) end end
Ben: I also saw this same behavior when going from SC -> SN Please test that out as well
debug.dump() of self.info in jive.slim.Player.updatePlayerInfo shows SC is not showing the player as being connected after switching to it. This looks like a race condition... { --[[table: 0x16899490]] uuid = "484670c8a37cfe25a2cb966e86db4c47", name = "Huey", model = "receiver", connected = false, needsUpgrade = false, power = true, isUpgrading = false, }
fixed by reverting r3412
Ben: r3435 is only a partial fix. if I'm streaming any content, then switch from SC <-> SN then the player will get lost. The controller will move properly then loose the player Connected Jive/Ray to SC 7.3 Play any type of stream Switch Music Source to SN Notice Jive will move, Ray will get lost along the way Wait 20 seconds Jive will prompt to Choose Player
Created attachment 4343 [details] JIVE error log happens if I switch SN <-> SC rapidly. I.e. less then 20 seconds between connecting and switching. Is there a minimum time limit that should be adhered to? I have to switch 3 times then the error happens. SC, stream -> SN, stream, ->SC, stream, -> SN error:: less then 1 minute for this whole exchange what is reasonably expected of the customer as far as connection time?
James, followed your steps and bounced back and forth between SN and SC 10 times with no issue. Repeated this with both an up-to-date desktop squeezeplay and a controller running r3435. wonder if there's a race condition going on with serverstatus or playerstatus updates coming in and being processed at the same time the player is being switched from one server to the other...
Created attachment 4345 [details] screen shot, missing choose source I see this without switching between sources quickly, I can wait several minutes, switch source and it will fail with option to retry or go back. In this case the player has switched sources. Currently my Controller shows no option to choose player, I guess I switched players too many times? It's connected to a Ray connected to yesterdays 7.3 nightly, there are 3 other players on the local network.
James and I are seeing this while testing against test.squeezenetwork.com, Ben are you using some other SN to test against?
no, I'm not going against test.squeezenetwork -- my tests were with production SN not sure why that would make a difference, but I'll have to align my own tests with what you are doing. Won't get to that until tomorrow...
Interesting: I'm not able to reproduce this using a D-Link DIR-655, but I am able to reproduce using dd-wrt (WRT54G).
I can't really see how different flavors of wifi routers could have anything to do with this, unless packets aren't arriving... As another data point, my basement network is DD-WRT, and I have yet to see this problem since r3435
Factory reset my DD-WRT, I can still reproduce some poor behavior with test.sn. When switching my Transporter from SC7.3 to test.sn Transporter goes to SN just fine but Controller says 'Could not connect transporter to SqueezeNetwork' and offers go back or try again.
I have a hunch there's a problem with the DNS-spoofing to redirect to test SN in Mtn View. Here's a test to run there to see-- 1. first confirm the bug can be reproduced via desktop squeezeplay 2. if so, you can edit a file in the squeezeplay directory to point it directly to test SN windows, it'll be something like: Program Files\Squeezeplay\share\jive\jive\net\NetworkThread.lua os x: right click on squeezeplay.app and say something like "view app contents". Then go to share/jive/jive/net/NetworkThread.lua find the part in the file that says function getSNHostname(self) return "www.squeezenetwork.com" end change www.squeezenetwork.com to www.test.squeezenetwork.com (yes, leave the www in there) 3. save and quit 4. when you restart squeezeplay, you should be using test SN directly now 5. now that you've done that, can the bug be reproduced?
This is reproducible with SqueezePlay as you describe. SqueezePlay pointed to a Transporter if I select SqueezeNetwork as a source the Transporter goes to production SN. After changing C:\Program Files\SqueezePlay\lua\jive\net\NetworkThread.lua to www.test, the Transporter connects to Falco.
...but is the bug reproduced?
(In reply to comment #17) > ...but is the bug reproduced? Yes, sorry. After sending the Transporter back to SC it fails, SP shows Problem Connecting go back/try again, Transporter shows Can't connect to SC.
Try using SB3 or Transporter as the player you SBC is connected to.
James- the "bump" issue is fixed now (bug 10209, checkin r3476) for SB3. Re-reading this bug, this one is *NOT* the SB3-specific bug. This bug is about the controller not reconnecting to the player after the player switches sources. After fixing 10209, using desktop squeezeplay I switched the SB3 "Puppy Wireless" between test.SN and the SC called JR-MB-Nightly.local. I did this 20+ times with no error. I did, however, run into problems with a controller...right now I'm attributing this to "Mtn View weirdness" let's discuss this a bit more tomorrow...
Testing all day with SC 7.3 r24245 and prod.sn, switching several players and combo's of players. No failures yet. Streaming and non-streaming works
This bug has been fixed in the 7.3.0 release version of SqueezeCenter! Please download the new version from http://www.slimdevices.com/su_downloads.html if you haven't already. If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.