GNOME Bugzilla – Bug 581103
100% CPU usage and a minute long pause when switching views
Last modified: 2009-12-27 02:27:02 UTC
Please describe the problem: On git master[1] I am seeing 100% CPU usage and pauses where the interface greys out extending beyond several minutes when switching views, e.g. when switching from one smart playlist to another or from the music library to the podcast libray, or when marking artists or albums. This leads Banshee to be practically unusable compared to 1.4.3 No useful output can be seen when running with --debug [1] defined as of this commit: http://git.gnome.org/cgit/banshee/commit/?id=934b511fb25599df2219ddbdc3f98d1d2486d262 Steps to reproduce: 1. compile git master 2. switch views Actual results: 100% cpu usage and extended pausing Expected results: smooth view switching Does this happen every time? 100% Other information: x86_64, da_DK.UTF-8, Ubuntu Karmic Koala
In git master there's a scheduled meta-data refresh compared to 1.4.3. It's probably slow because banshee is rescanning your library.
The metadata scan has completed, if it was that, --debug would have shown that. My database is up to date (v 31)
I am also seeing similar high CPU loads when copying music to my iPod (and no, it is not transcoding the files). I have no idea if it's the same bug but it behaves the same. 5865 david 20 0 827m 303m 16m S 178 15.3 65:56.56 banshee-1 What can I do to figure out what is going on here?
Can you try running this: sqlite3 ~/.config/banshee-1/banshee.db "vacuum; analyze" and see if things are better afterward? We should probably do this after in the db migrations after all the change we are making. How many tracks in your music library, btw?
9783 entries in the music library, 990 entries in the podcast library and one video all amounting to roughly 62gb of data. Additionally I have defined 4 smart playlists to filter out items like audiobooks and special podcast episodes (single downloads) as well as to give me a pure music playlist. I still see problems switching views or to smart playlists after running the requested commands.
I also tried to run sqlite3 ~/.config/banshee-1/banshee.db "vacuum; analyze" And I still get a very high CPU load when switching songs mostly. I had it before when switching views but this is not the case anymore. I'm using ubuntu 09.04 Is everyone on the master branch having this issue? Are there any other suggestions to see where the problem is/ debugging?
While the CPU is pegged at 100%, run kill -s QUIT $(pidof banshee-1) and paste or attach the output here. The output will be in the terminal you ran banshee-1 from, or in your ~/.config/banshee-1/log if you ran it from a launcher.
In addition to the above test, do another test where you run with --debug-sql to see if it's a SQL query getting repeated forever.
Created attachment 134731 [details] This is the output of the banshee-1 that I ran in the terminal during high cpu when I gave the kill command
I've run the kill command during 100% cpu and attached a file with the output of that.
The crux of the problem, from boris via irc: [Debug 21:29:31.271] Executed in 10865ms SELECT COUNT(*), SUM(CoreTracks.FileSize) FROM CoreTracks,CoreAlbums,CoreArtists, CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 3
(In reply to comment #11) > The crux of the problem, from boris via irc: > > [Debug 21:29:31.271] Executed in 10865ms SELECT COUNT(*), > SUM(CoreTracks.FileSize) FROM CoreTracks,CoreAlbums,CoreArtists, > CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND > CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID > = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 3 > I have the feeling that is more the effect then the cause. Would be interesting to know if that query actually took the 100% CPU or that it just took such a long time because it was waiting for CPU time.
[Warn 00:44:50.367] HyenaSqliteConnection command issued from the main thread [Debug 00:45:13.024] Executed in 22657ms SELECT COUNT(*), SUM(CoreTracks.FileSize) FROM CoreTracks,CoreArtists,CoreAlbums, CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 42 [Warn 00:45:13.025] HyenaSqliteConnection command issued from the main thread [Debug 00:45:19.280] Executed in 6256ms DELETE FROM CoreCache WHERE ModelID = 384; INSERT INTO CoreCache (ModelID, ItemID) SELECT 384, CoreTracks.TrackID FROM CoreTracks,CoreArtists,CoreAlbums, CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 42 ORDER BY CoreAlbums.ArtistNameSortKey ASC, CoreAlbums.TitleSortKey ASC, CoreTracks.Disc ASC, CoreTracks.TrackNumber ASC These seem suspect to me. Furthermore I tried deleting the smart playlists as I noticed that those two long queries came right after output that looked like it was poking at my defined lists. Without the smartlists view switching does not display the long pauses and 100% CPU load. I hope that is helpful.
Ok, the problem is SQLite only uses one index per query, and for those it is choosing the CoreSmartPlaylistEntriesPlaylistIndex index. Just dropping that index 'fixes' the problem: sqlite3 ~/.config/banshee-1/banshee.db "drop index CoreSmartPlaylistEntriesPlaylistIndex" I need to run some more performance tests to make sure that dropping it won't negatively impact other queries.
That does improve matters quite a bit. The long pauses are out and timings for sql queries are in a much saner range now.
Yes that helps ALOT! Thanks.
Fixed in master.
(In reply to comment #17) > Fixed in master. > Gabriel, why both indices has been dropped in [1]? As far as I can see, only CoreSmartPlaylistEntries{PlaylistIndex} or rather the presence of two indices on the table has been causing problems. CoreSmartPlaylistEntries{Index} is still needed for shuffle by rating/score, see comments 31-32 in bug 565767. Re-adding it doesn't seem to re-introduce this bug. [1] http://git.gnome.org/cgit/banshee/commit/?id=23274f2ca744391ef3f54e044eb2f7399aa457ff
I committed the new index after discussing the issue with Gabriel and checking that there is no regression with David. If you experienced this bug, please do check that the index doesn't bring it back on your database.
*** Bug 593817 has been marked as a duplicate of this bug. ***
[Debug 01:33:54.300] Executed in 16886ms SELECT COUNT(*), SUM(CoreTracks.FileSize) FROM CoreTracks,CoreArtists,CoreAlbums, CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 44 I think this is still capable of great evil, I just saw the above as well as a 195% CPU load (Core 2 Duo laptop) followed by an entirely to predictable complete stall of the interface for minutes.
David, does it go away if you temporarily drop the CoreSmartPlaylistEntriesIndex?
@Alexander The bug is back in the current PPA version of Banshee and yes, dropping the CoreSmartPlaylistEntriesIndex makes it go away. Dunno yet what functionality is taken away with dropping this index.
(In reply to comment #23) > @Alexander > The bug is back in the current PPA version of Banshee and yes, dropping the > CoreSmartPlaylistEntriesIndex makes it go away. If you don't mind doing it, could you email me your database? Also, which version of sqlite do you have? $ sqlite3 --version > Dunno yet what functionality is > taken away with dropping this index. See comment 18, the index is needed for shuffle by rating/score.
(In reply to comment #24) > > If you don't mind doing it, could you email me your database? Also, which > version of sqlite do you have? > > $ sqlite3 --version SQLite 3.6.10 Banshee 1.6 Beta 2 (1.5.1) (The system is Ubuntu Jaunty 9.04.)
ganjalf.the.green can no longer reproduce it after system upgrade... which smells like a sqlite3 versioning issue. Is anyone still seeing it? If you are, could you open your database in sqlite3: $ sqlite3 ~/.config/banshee-1/banshee.db and run this query: EXPLAIN QUERY PLAN SELECT COUNT(*), SUM(CoreTracks.FileSize) FROM CoreTracks,CoreArtists,CoreAlbums, CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 3; It should take awhile to execute. Please then include its output in your comment. Thanks!
It returns very quickly, with 0|2|TABLE CoreAlbums 1|3|TABLE CoreSmartPlaylistEntries WITH INDEX CoreSmartPlaylistEntriesIndex 2|0|TABLE CoreTracks USING PRIMARY KEY 3|1|TABLE CoreArtists USING PRIMARY KEY
I have a super-slow query taking place: [Debug 19:04:10.090] Executed in 7635ms DELETE FROM CoreCache WHERE ModelID = 41; INSERT INTO CoreCache (ModelID, ItemID) SELECT 41, CoreTracks.TrackID FROM CoreTracks,CoreArtists,CoreAlbums, CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 4 ORDER BY CoreArtists.NameSortKey ASC, CoreAlbums.TitleSortKey ASC, CoreTracks.Disc ASC, CoreTracks.TrackNumber ASC
After playing with Michael's database I found a way to fix the offending query. The query below runs in about 7 seconds: SELECT COUNT(*), SUM(CoreTracks.FileSize) FROM CoreTracks,CoreArtists,CoreAlbums, CoreSmartPlaylistEntries WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 4; Its query plan: 0|2|TABLE CoreAlbums 1|3|TABLE CoreSmartPlaylistEntries WITH INDEX CoreSmartPlaylistEntriesIndex 2|0|TABLE CoreTracks USING PRIMARY KEY 3|1|TABLE CoreArtists USING PRIMARY KEY After changing the query to use CROSS JOINS to force the join order (as explained in section 5.2 of http://www.sqlite.org/optoverview.html), the query runs instantly: SELECT COUNT(*), SUM(CoreTracks.FileSize) FROM CoreArtists CROSS JOIN CoreTracks CROSS JOIN CoreSmartPlaylistEntries CROSS JOIN CoreAlbums WHERE CoreArtists.ArtistID = CoreTracks.ArtistID AND CoreAlbums.AlbumID = CoreTracks.AlbumID AND CoreSmartPlaylistEntries.TrackID = CoreTracks.TrackID AND CoreSmartPlaylistEntries.SmartPlaylistID = 4; 0|0|TABLE CoreArtists 1|1|TABLE CoreTracks WITH INDEX CoreTracksIndex 2|2|TABLE CoreSmartPlaylistEntries WITH INDEX CoreSmartPlaylistEntriesIndex 3|3|TABLE CoreAlbums USING PRIMARY KEY I will try to fix the offending query in the program and attach the patch...
Created attachment 149074 [details] [review] Force the join order This patch should fix the slow queries. Please test.
*** Bug 605358 has been marked as a duplicate of this bug. ***
Why don't you go ahead and commit - it'll probably get wider testing w/ the alpha repos and people building from master that way.
Committed. Feel free to re-open if these queries are still slow or if you notice any side effects. This problem has been fixed in the development version. The fix will be available in the next major software release. Thank you for your bug report.