Bugzilla – Bug 2591
Slow searches on 6.2.1
Last modified: 2008-09-15 14:39:24 UTC
There seems to be a distinct slow down of web browser searches on my system since going to 6.2.1. It takes between 25-30 seconds to return a search result for a 4-5 character phrase and can take as long as 45-60 seconds. The problem seems to be time related - after the Mac is restarted, the search results are virtually immediate. After the Mac has been left on for a few hours, the searches take at least 25-30 seconds. My collection is 4500 tracks with a mixture of AAC, ALAC and MP3. System is Mac Mini 1.42GHz 1GB RAM running OSX 10.4.3. I don't use iTunes or many other 3rd party plug-ins (except Music Magic Mixer but this doesn't make any difference) Safari and Firefox both give similar search times. I get these search times with no music playing and the Mac Activity Monitor doesn't show anything unusual - perl ticking along at less than 5% CPU. In Home / Server Settings / Performance I have Database Temporary File Tuning (SQLite) set to "Use RAM as temporary storage" and Database Cache Size Tuning (SQLite) set to 300000. See attached for debug traces with d_sql enabled. First search is with phrase "Speech" - took approx. 30 secs and returned 1 result Second search is with phrase "Softly" - took approx. 30 secs and returned 2 results There seems to be a delay of approx. 6 seconds after each instance of the line with "Bind arguments" for the search phrase.
Created attachment 1025 [details] d_sql traces for slow searches
Created attachment 1026 [details] d_sql traces for slow searches Previous attachment only had one search included. This attachment includes traces for 2 searches.
Michael - any update here?
Created attachment 1046 [details] search for text "london"
The problem still exists - see attached d_sql trace for search of text "london" that took approx. 60 seconds to return results. After the Mac or Slimserver is restarted, the search works within 1-2 seconds. The traces show approx. 7 sec delay after each instance of the line "Bind arguments: [1, 5, LOND%, % LOND%]" and the more of these there are, the longer the search takes to execute. In this trace, there are 10 instances of "Bind arguments..." and the overall search takes approx. 67 seconds) (It seems that the search tries to match text as it is typed so if you type the search text slowly, more searches will be done...?) Is there any debug information that would be useful to determine why there is a 7 sec delay after each "Bind arguments..." When the search works immediately, this delay does not happen.
Michael - is this still happening in the 6.2.2 nightlies, or 6.5 trunk?
Dan - I'm running the 6.2.2 nightly from yesterday and searches seem to be taking 20-30 seconds - not as long as the 45-60 seconds I had with 6.2.1. I'm not sure if this is considered normal with 6.2.2. I haven't yet tried 6.5.
Michael - is this still an issue with the latest nightly? I'm not able to reproduce. If it is - can you try tuning the database paramters in Settings -> Performance? Thanks.
Searches seem a lot more responsive in the latest nightly (SlimServer_6_2_x_v2006-04-22.dmg) I'll monitor this over a couple of days to make sure that the speed doesn't degrade with time, which is what I saw with the original bug.
The issue still appears to exist and it appears to be time related. See attached d_sql traces when I searched for a word shortly after installing 6_2_x_v2006-04-22 and then doing a search for the same word 16 hours later. From the log timestamps, the first query takes less than a second however the second query takes over 45 seconds. In the second query, there seems to be a 15 second delay after each instance of the log "Bind arguments: " The query returns 2 song titles containing the word (Chianti) being searched for. In Home / Server Settings / Performance I have "Database Temporary File Tuning (SQLite)" set as "Use RAM as temporary storage" and "Database Cache Size Tuning (SQLite)" set as 100000. I am running Slimserver on a Mac Mini OSX 10.4.6. The Mac Mini has 1G RAM.
Created attachment 1194 [details] d_sql traces of "fast" and "slow" searches. contains d_sql logs of search done shortly after installing 6_2_x_v2006-04-22 then second search for same word done 16 hours later. First search takes less than 1 second, second trace takes more than 45 seconds.
Michael - as I'm needing to focus on the 6.5 release, I'm moving this bug there. Hopefully with the backend database changes, the problem will have gone away.
Marking this as fixed for 6.5