Bugzilla – Bug 9069
Controller goes to spin when accessing music folder on a Ready NAS
Last modified: 2009-07-31 10:26:41 UTC
Created attachment 3758 [details] Scanner log Customer has Duet controller, Transporter and two Squeezeboxes. All of his units are connected to a ReadyNAS with Squeezecenter 7.0.1. Using the controller to access the music folder causes the controller to spin, and after a while the controller gives the message “try again”. Clinking on try again does not make any difference. Use the back arrow key to return to the Music Library menu. Cursor is still spinning. Use the back arrow key to return to the player menu, but the network symbol is blue, and can't select another player or music source without powering down the controller and restarting. The size of the music library about 1500+ albums. Logs attached.
Created attachment 3759 [details] Server log
Please enable debugging for network.cometd. And please also note that the ReadyNAS can take _hours_ to finish the initial scan, during which it is very unresponsive (unusable). Just let the scan finish.
One more point: browsing by music folder can be _very_ slow on the ReadyNAS. I have 317 items in the music folder. It took >30 seconds to list them on the Controller. Depending on how your collection of 1500 albums is organized, I could imagine Controller timing out waiting for the response.
Osama: we need additional logging information. Can you get it? QA Folk: can you try to reproduce/test this for 7.2?
I can get the logs, but is there is any specific logs you guys want or I just get the server log in general?
Do both a regular log and the network.cometd Dean feels like this bug is very important.
Send the customer an email to get the Network and all the server’s logs. We are waiting on the customer’s feedback. RN 080715-001368
Created attachment 3805 [details] Latest server log with debug options enabled
Created attachment 3806 [details] Latest scanner log
Scanned through the other comments. Just to be clear: the audio performance of the system has exceeded my expectations. Yes, the ReadyNAS is slow on initial scan, and is generally not a ball of fire, but have had no other problems with it to date, even running on the same network as three ATT Uverse set-top boxes. Installed max RAM on it awhile back, which did improve performance somewhat. The Uverse boxes are wireless DHCP. The NAS, the Transporter, and one SB are hard-wire Ethernet; one SB is wireless. Am using fixed IPs for the Slim components (the Controller IP is assigned by the router, but have set it to map that MAC to one IP. All the albums are FLAC encoded, all in one directory/share on the NAS, each album in a separate sub-directory. Database functions seem to be fine, only direct browse of the music directory seems to be an issue. Thought that was likely to be related to access time, but there's nothing obvious enough for me to identify.
From the scanner.log: the scanner takes >0.5 seconds per track. It might take a bit less per folder. But still: it's slow. Browse Music Folder (BMF) is suffering a lot from this issue, as it has to read all items in a folder. If you have 1000 items, each one taking 0.5 seconds - you'll have to wait minutes for the list to show up! (it's not as bad as this, just to show the issue). The server log doesn't show anything interesting - did you enable network.cometd (and none of the others)? What I'd suggest is re-organizing your folders: create a sub-folder per artist, then album folders within this sub-folder. Doesn't improve scanning time, but BMF. BTW: how large is your collection? How many items are in the root music folder? The slow BMF is also covered in bug 9117.
Took awhile, but finally got around to setting up a linux box (OpenSUSE 12 64-bit on a Shuttle XPC with an Athlon 64 X2 3800, 2G RAM) and installing SqueezeCenter. After dredging my memory for awhile, remembered how to mount the NAS shares as NFS volumes and pointed SC at them. It certainly is a lot faster, and the browsing problem went away. In ref to previous comment in thread, have about 1500 FLAC-encoded albums on the NAS, so it is timing-related. Guess I'll run it like this for awhile, decide if I want to put together a dedicated RAID array in my copious free time. Really like the hot-swap X-RAID on the NAS.
Created attachment 3924 [details] cache file/folder info This patch should considerably speed up BMF > 200 folders on SBC when connected to a slowish machine like eg. the ReadyNAS by caching the folder information. With this patch I was able to "wrap around" my folder list within a few seconds, where without I had to wait about 20 seconds after the initial list was displayed. (ReadyNAS, 313 folders in top level folder).
Created attachment 3929 [details] alternative approach: don't cache, but only process the items we want This patch doesn't cache any result, but doesn't do any pre-processing of all items even when only one folder is queried, neither. Pros: - faster return to SBC, as <=200 items are processed before list is shown, no matter how long the list - lower memory footprint - no potential stale cache copy issue Cons: - slightly slower to fully return lists >200 items (eg. trying to scroll from the bottom of the list upwards) - potential for incomplete lists/duplicates if items are skipped (for whatever reasons) Time for SBC to display the start of the list when connected to a ReadyNAS, without vs. with patch: 313 folders: 18s vs. 13s 718 folders: 38s vs. 14.5s 1218 folders: connection lost (query finished after 107s, but SBC didn't display it) vs. 15.5 In that last case the ReadyNAS would still take about 100s to return the full list to the SBC. But it does return it without forcing the SBC into timeout.
Created attachment 3930 [details] best of both worlds: add a bit of caching cache the raw directory list to be used in subsequent queries as done by SBC (speeding up 2nd+ queries by another 2-3s on the ReadyNAS)
checked in as change 23038 - this should greatly improve SBC/BMF on slower server systems, even more if you have 200+ items in the music folder. This fixes the issue as initially reported, where the ReadyNAS would never return a list. - don't go through the full list of items for every chunk, but only analyze the number of items requested - cache folder list for subsequent queries (as done by SBC) - rearrange checks to match the most likely order for folders with a large number of items (folder > tracks > playlists) - do cheap tests first Please give the next nightly build some thorough testing
Verified in 7.2.1 - 23530. No wheel, ReadyNAS shows music folder fairly quickly (15 seconds). 2517 songs, If anyone feels this isn't a valid test or they still see this bug please feel free to re-open.
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.
Reduce number of active targets for SC