Browse New Music in LMS 7.8 is incredibly slow

[Philip Meyer]

Sometimes I find that the first time I access New Music in LMS 7.8, it is really slow to respond. Doesn't appear to be every time after a reboot, perhaps some cache expiry time?

When New Music is slow, it causes connection to be lost to Squeezebox 3, and takes several minutes for the server to return.

Is this a known issue with 7.8? Is any branch of 7.7 any better? Perhaps a plugin is causing the problem?

[gharris999]

Sometimes I find that the first time I access New Music in LMS 7.8, it is really slow to respond. Doesn't appear to be every time after a reboot, perhaps some cache expiry time?

When New Music is slow, it causes connection to be lost to Squeezebox 3, and takes several minutes for the server to return.

Is this a known issue with 7.8? Is any branch of 7.7 any better? Perhaps a plugin is causing the problem?

Phil: this is an issue that's plagued me, off and on, for the past several years. I originally added an "autoexec" function to SrvrPowerCtrl over a year ago to address this very issue. A SrvrPowerCtrl custom command that's labeled ".autoexec" will get executed when LMS first starts and the plugin gets loaded. The custom command can be anything you wish.

Based on this thread: http://forums.slimdevices.com/showth...se-more-memory

..my "autoexec" custom command is now set to:

.autoexec

cli://PRAGMA cache_size = 800000&&tracks 0 500 new

That command tells the SQLite driver to increase it's memory cache size and then issues a "browse for new" query in the background. My theory is that this has the effect of "seeding" the SQLite cache.

That .autoexec command gets scheduled to fire off some 45 seconds or so after the plugin is loaded. If I reboot my server and wait 3 minutes for everything to settle down and for the .autoexec command to have time to run its course, I find that my 1st browse of new music returns the 100 items in less than 3 seconds. All other types of subsequent browse queries appear equally fast. No single segment of drilling down to "All Songs" though my biggest genre and my most prolific composer takes more than 6 seconds. (And I have my webUI configured to show the maximum 500 items per page.)

Of course, this doesn't really solve the problem you point out. It just makes living with it relatively painless.

[Mnyb]

I've fond that having the web-UI showing 500 items ( instead of the default 50 ) makes most menus slower

[Philip Meyer]

I'm tempted to give up again and go back to trusty reliable SBS 7.5.6.

I tried switching LMS 7.7 to use MySQL, which initially seemed to work much better. Whilst scanning my library into my MySQL DB, I tried to browse the library, and it was very responsive. I left the scan running, which seemed to be going through quickly.

However, after scanning half of my library, it seems to have got a lot slower. For some reason, there seems to be 03:30min pauses occasionally between "Handling new audio file" trace lines:

[08:15:06.5945] Slim::Utils::Scanner::Local::new (773) Handling new audio track file:///M:/Music/Phil%27s%20Music/Electronic/Popol%20Vuh/Herz%20aus%20Glas%20-%20Coeur%20de%20Verre/07%20-%20Geimenschaft.mp3
[08:18:36.7187] Slim::Utils::Scanner::Local::new (773) Handling new audio track file:///M:/Music/Phil%27s%20Music/Electronic/Popol%20Vuh/Herz%20aus%20Glas%20-%20Coeur%20de%20Verre/08%20-%20Auf%20Dem%20Weg-On%20The%20Way.mp3


Also, I have some plugins that don't work with MySQL any more. Erland's trackstat causes exceptions:

[07:57:42.8811] Slim::Schema::Storage::throw_exception (122) Error: DBI Exception: DBD::mysql::st bind_param failed: Illegal parameter number [for Statement "INSERT INTO track_statistics (url, urlmd5, musicbrainz_id, playCount, added, lastPlayed) values (?, 'b0a8305c1780c4b1216e895aa9a5b0dc', NULL, 1, 1185091320, 1341817062)" with ParamValues: 0='file:///M:/Music/Phil%27s%20Music/Electronic/Mind%20Over%20Matter/Music%20For%20Paradise/04%20-%20Paradise%20-%20Being%20Home%20Again%20(Earth).mp3']
[07:57:42.8823] Slim::Schema::Storage::throw_exception (122) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (P:/Music/SlimServer/Beta/server/Slim/Schema/Storage.pm line 122)
frame 1: Slim::Schema::Storage::throw_exception (P:\Music\SlimServer\Beta\server\CPAN/DBIx/Class/Storage/DBI.pm line 1006)
frame 2: DBIx::Class::Storage:BI::__ANON__ (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/TrackStat/Storage.pm line 788)
frame 3: (eval) (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/TrackStat/Storage.pm line 786)
frame 4: Plugins::TrackStat::Storage::savePlayCountAndLastP layed (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/TrackStat/Plugin.pm line 4489)
frame 5: Plugins::TrackStat::Plugin::markedAsPlayed (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/TrackStat/Plugin.pm line 4364)
frame 6: Plugins::TrackStat::Plugin::stopTimingSong (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/TrackStat/Plugin.pm line 4035)
frame 7: Plugins::TrackStat::Plugin:penCommand (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/TrackStat/Plugin.pm line 4184)
frame 8: Plugins::TrackStat::Plugin::commandCallback65 (P:/Music/SlimServer/Beta/server/Slim/Control/Request.pm line 2082)
frame 9: (eval) (P:/Music/SlimServer/Beta/server/Slim/Control/Request.pm line 2082)
frame 10: Slim::Control::Request::notify (P:/Music/SlimServer/Beta/server/Slim/Control/Request.pm line 860)
frame 11: Slim::Control::Request::checkNotifications (P:\Music\SlimServer\Beta\server\slimserver.pl line 676)
frame 12: main::idle (P:\Music\SlimServer\Beta\server\slimserver.pl line 645)
frame 13: main::main (P:\Music\SlimServer\Beta\server\slimserver.pl line 1177)

[07:57:42.8830] Plugins::TrackStat::Storage::savePlayCountAndLastP layed (795) Database error: Illegal parameter number
while executing:
INSERT INTO track_statistics (url, urlmd5, musicbrainz_id, playCount, added, lastPlayed) values (?, 'b0a8305c1780c4b1216e895aa9a5b0dc', NULL, 1, 1185091320, 1341817062)


>Phil: this is an issue that's plagued me, off and on, for the past
>several years. I originally added an "autoexec" function to
>SrvrPowerCtrl over a year ago to address this very issue.
>
Thanks, I might give that a go. Does it solve the slow responses until next restart for you? Because I think i've noticed the occasional slowdown again after a period of time has elapsed, or maybe if I browse new music from a different player? It didn't seem to be just first query after a restart.

[erland]

Also, I have some plugins that don't work with MySQL any more. Erland's trackstat causes exceptions:

If you have the time, try to change the section around row 788 in TrackStat/Storage.pm from:

                $sth->bind_param(1, $key , SQL_VARCHAR);
                if(!$trackHandle) {
                        $sth->bind_param(2, md5_hex($url), SQL_VARCHAR);
                }
                $sth->execute();

To:

                $sth->bind_param(1, $key , SQL_VARCHAR);
                $sth->execute();

I don't think the TrackStat issue is related to MySQL, it looks like it's a bug which nobody has found yet, but since the latest TrackStat version only is used in 7.6.0 or later you did get a newer TrackStat version when upgraded which unfortunately contains this bug. I suspect you have startup refresh disabled in TrackStat and that's the reason the bug appears in your system but not in most other peoples setup. I'll try to fix it as soon as possible, but if you have an easy way to verify the above patch any help with this would be greatly appreciated.

As a side note, I would generally recommend you to either switch to SQLite or stay on 7.5.x forever, trying to use MySQL in 7.6.0 and later is likely going to create all sorts of strange issues since nobody tests the system with MySQL these days.

[gharris999]

Thanks, I might give that a go. Does it solve the slow responses until next restart for you? Because I think i've noticed the occasional slowdown again after a period of time has elapsed, or maybe if I browse new music from a different player? It didn't seem to be just first query after a restart.

My sense is that, yes, it does.

I just checked my server uptime. I last rebooted the server 22 hours ago when I penned my previous post. During those hours, the box has served up perhaps 10 hours of audio via LMS, served up several hours of video via minidlna last evening and then spent all of the wee hours in S3 sleep. I just tried another webUI->Browse->Genre->Big Genre->Prolific Composer->All Songs. (This is without the benefit of all the caffeine I've consumed this morning having yet passed the blood-brain barrier, so some of the time quoted here is just plain slow human reaction time.) Anyway, total time to execute that sequence (4 mouse scrolls & 4 clicks plus the LMS query time): 20 seconds. For my needs, that's perfectly acceptable.

I have my server set to automatically reboot weekly. I have yet to notice any particular slow-down in LMS browsing towards the end of the week's uptime.

[Philip Meyer]

>I have my server set to automatically reboot weekly. I have yet to
>notice any particular slow-down in LMS browsing towards the end of the
>week's uptime.
>
Sounds very encouraging. I've only noticed a problem with Browse New Music, not browsing any other list. Also Search Songs, but perhaps that has always been a bit slow.

[Philip Meyer]

>I don't think the TrackStat issue is related to MySQL, it looks like
>it's a bug which nobody has found yet, but since the latest TrackStat
>version only is used in 7.6.0 or later you did get a newer TrackStat
>version when upgraded which unfortunately contains this bug.
I've had LMS 7.8 with SQLite running for quite a while, and not noticed any issues with TrackStat (no stack trace errors in log).
I was getting a bit fed up with the occasional slow DB performance, so yesterday tried switching to MySQL, which seemed better.
I haven't downloaded a newer version of TrackStat for a while, certainly not as part of switching from SQLite to MySQL.

> I suspect you have startup refresh disabled in TrackStat
Yes.

>and that's the reason the
>bug appears in your system but not in most other peoples setup. I'll try
>to fix it as soon as possible, but if you have an easy way to verify the
>above patch any help with this would be greatly appreciated.
>
I haven't noticed a problem with LMS 7.8 using SQLite.

>As a side note, I would generally recommend you to either switch to
>SQLite or stay on 7.5.x forever, trying to use MySQL in 7.6.0 and later
>is likely going to create all sorts of strange issues since nobody tests
>the system with MySQL these days.
>
I was using 7.5.6 for normal day-to-day music playing, as it was reliable, and also running LMS (SQLite) in parallel to see what it was like and ensure my plugins were compatible.

Unfortunately, this was a pain with ratings being set, as I had to backup and restore to share ratings across the two builds.

Then, because of the occasional really slow response using Browse New Music (which my family uses quite a lot), I read a thread that suggested that MySQL was working much better in 7.8 now, so I thought I'd try switching over to see if it would put any light to the issue. Could be a DB engine issue, bad query or bad caching, etc.

I tried making the TrackStat code change and restarting LMS. I don't see the exception that I mentioned before, but I do see:

[00:41:23.9422] Slim::Schema::Storage::throw_exception (122) Error: DBI Exception: DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near ''\'
) and


tracks.audio=1
group by tracks.id' at line 6 [for Statement "INSERT INTO multilibrary_track (library,track)
select 1,tracks.id from tracks
where

(
tracks.url like 'file:///M:/Music/Live\%20Concerts/Electronic/Tangerine\%20Dream%' ESCAPE '\'
) and


tracks.audio=1
group by tracks.id
"]
[00:41:23.9434] Slim::Schema::Storage::throw_exception (122) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (P:/Music/SlimServer/Beta/server/Slim/Schema/Storage.pm line 122)
frame 1: Slim::Schema::Storage::throw_exception (P:\Music\SlimServer\Beta\server\CPAN/DBIx/Class/Storage/DBI.pm line 1006)
frame 2: DBIx::Class::Storage:BI::__ANON__ (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/MultiLibrary/Plugin.pm line 1174)
frame 3: (eval) (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/MultiLibrary/Plugin.pm line 1139)
frame 4: (eval) (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/MultiLibrary/Plugin.pm line 1072)
frame 5: Plugins::MultiLibrary::Plugin::refreshLibraries (D:\Squeezebox Server\beta\Cache\InstalledPlugins/Plugins/MultiLibrary/Plugin.pm line 865)
frame 6: Plugins::MultiLibrary::Plugin::initPlugin (P:/Music/SlimServer/Beta/server/Slim/Utils/PluginManager.pm line 346)
frame 7: (eval) (P:/Music/SlimServer/Beta/server/Slim/Utils/PluginManager.pm line 346)
frame 8: Slim::Utils::PluginManager::load (P:\Music\SlimServer\Beta\server\slimserver.pl line 562)
frame 9: main::init (P:\Music\SlimServer\Beta\server\slimserver.pl line 643)
frame 10: main::main (P:\Music\SlimServer\Beta\server\slimserver.pl line 1177)

[00:41:23.9447] Plugins::MultiLibrary::Plugin::refreshLibraries (1219) Database error: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near ''\'

[Philip Meyer]

>Sometimes I find that the first time I access New Music in LMS 7.8, it is really slow to respond. Doesn't appear to be every time after a reboot, perhaps some cache expiry time?
>
>When New Music is slow, it causes connection to be lost to Squeezebox 3, and takes several minutes for the server to return.
>
Just revisiting this, having been away for a bit. I haven't tried the proposed fix of seeding the Sqlite cache yet, but it seems to me that something else is going on.

This morning I noticed that I could browse Artists, Albums, Years, etc, and my SB3 was very responsive. But as soon as I went into New Music, it locked up for several minutes. It seems to me that Sqlite cache will already have been populated by accessing the other Browse queries.

Phil

[Jeff Flowerday]

This is an issue with 7.7.2 as well, I filed a bug on it, but we all know those don't get addressed anymore.

Anyway, the only way I could solve it was to start using a ram disk.

http://forums.slimdevices.com/showth...-quot-function

Sent from my Galaxy Nexus using Tapatalk 2