SQLite seems to be very sluggish

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

SQLite seems to be very sluggish

Nick Dokos-2
Running banshee 2.6.2 on Fedora 20. It was working fine back in June or
so but I updated Fedora a few times and eventually noticed that banshee
had become very sluggish. It takes a long time to start up: Gnome offers
to kill the process because it's not responding but after waiting for
about a minute, it does come up and behaves more or less normally most
of the time; but sometimes, it goes into snooze mode again and does not
respond for quite a while: 10 or 20 seconds.

I append the --debug startup log. Why is sqlite taking tens of seconds
to do an operation? I dumped the database, moved the file and restored
it but that did not do anything afaict.

Any ideas?

Thanks,

Nick

--8<---------------cut here---------------start------------->8---
$ banshee --debug
** Running Mono with --debug   **
[1 Debug 22:26:59.136] Bus.Session.RequestName ('org.bansheeproject.Banshee') replied with PrimaryOwner
[1 Info  22:26:59.181] Running Banshee 2.6.2: [Fedora20-2.6.2-2.fc20 (linux-gnu, x86_64) @ 2014-05-21 20:09:19 UTC]
[1 Debug 22:26:59.220] Initializing GTK
[1 Debug 22:27:00.273] Post-Initializing GTK
[1 Debug 22:27:00.294] Configuration client extension loaded (Banshee.GnomeBackend.GConfConfigurationClient)
[1 Debug 22:27:00.300] Using default gconf-base-key
[1 Debug 22:27:00.393] Core service started (DBusServiceManager, 0.001687)
[1 Debug 22:27:00.396] Registering remote object /org/bansheeproject/Banshee/DBusCommandService (Banshee.ServiceStack.DBusCommandService) on org.bansheeproject.Banshee
[1 Debug 22:27:00.404] Core service started (DBusCommandService, 0.01054)
[1 Debug 22:27:00.437] Opened SQLite (version 3.8.6) connection to /home/nick/.config/banshee-1/banshee.db
[1 Debug 22:27:00.438] Core service started (DbConnection, 0.032942)
[1 Debug 22:27:00.444] Database version 45 is up to date
[1 Debug 22:27:00.476] Core service started (PreferenceService, 0.015668)
[1 Warn  22:27:00.483] Cannot connect to NetworkManager or Wicd - An available, working network connection will be assumed
[1 Debug 22:27:00.484] Core service started (Network, 0.007749)
[1 Debug 22:27:00.484] Registering remote object /org/bansheeproject/Banshee/SourceManager (Banshee.Sources.SourceManager) on org.bansheeproject.Banshee
[1 Debug 22:27:00.485] Core service started (SourceManager, 0.000975)
[1 Debug 22:27:00.491] Core service started (MediaProfileManager, 0.000326)
[1 Debug 22:27:00.494] Registering remote object /org/bansheeproject/Banshee/PlayerEngine (Banshee.MediaEngine.PlayerEngineService) on org.bansheeproject.Banshee
[1 Debug 22:27:00.497] Core service started (PlayerEngine, 0.006432)
[1 Debug 22:27:00.522] Registering remote object /org/bansheeproject/Banshee/PlaybackController (Banshee.PlaybackController.PlaybackControllerService) on org.bansheeproject.Banshee
[1 Debug 22:27:00.523] Core service started (PlaybackController, 0.003424)
[1 Debug 22:27:00.529] Starting - Startup Job
[1 Debug 22:27:00.530] Core service started (JobScheduler, 0.007046)
[1 Debug 22:27:00.541] IO provider extension loaded (Banshee.IO.Gio.Provider)
[1 Debug 22:27:00.609] Loaded HardwareManager backend: Banshee.Hardware.Gio
[1 Debug 22:27:00.611] Core service started (HardwareManager, 0.081051)
[1 Debug 22:27:00.613] Bus.Session.RequestName ('org.bansheeproject.CollectionIndexer') replied with PrimaryOwner
[1 Debug 22:27:00.614] Registering remote object /org/bansheeproject/Banshee/CollectionIndexerService (Banshee.Collection.Indexer.CollectionIndexerService) on org.bansheeproject.CollectionIndexer
[1 Debug 22:27:00.616] Core service started (CollectionIndexerService, 0.004568)
[1 Debug 22:27:00.618] Core service started (SaveTrackMetadataService, 0.001551)
[1 Debug 22:27:00.626] Adding icon theme search path: /usr/share/banshee/icons
[1 Debug 22:27:00.627] Core service started (GtkElementsService, 0.009592)
[1 Debug 22:27:00.629] Core service started (InterfaceActionService, 0.001727)
[1 Debug 22:27:00.762] Extension actions loaded: MetadataFixActions
[1 Debug 22:27:00.763] Registering remote object /org/bansheeproject/Banshee/GlobalUIActions (Banshee.Gui.GlobalActions) on org.bansheeproject.Banshee
[1 Debug 22:27:00.768] Album artwork path set to /home/nick/.cache/media-art
[1 Debug 22:27:00.797] Core service started (ArtworkManager, 0.033754)
[1 Debug 22:27:00.797] Core service started (BookmarksService, 0.000191)
[1 Debug 22:27:01.054] Adding context page wikipedia
[1 Debug 22:27:01.072] Adding context page lastfm-recommendations

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkComponent) to class (__gtksharp_49_Hyena_Gui_BaseWidgetAccessible) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkTable) to class (__gtksharp_50_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_TrackInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkSelection) to class (__gtksharp_50_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_TrackInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkTable) to class (__gtksharp_56_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_Database_QueryFilterInfo+601+5b+5bSystem_String+2c+20mscorlib+2c+20Version+3d2_0_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3db77a5c561934e089+5d+5d+2c+20Banshee_Services+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkSelection) to class (__gtksharp_56_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_Database_QueryFilterInfo+601+5b+5bSystem_String+2c+20mscorlib+2c+20Version+3d2_0_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3db77a5c561934e089+5d+5d+2c+20Banshee_Services+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkTable) to class (__gtksharp_62_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_ArtistInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkSelection) to class (__gtksharp_62_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_ArtistInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkTable) to class (__gtksharp_68_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_YearInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkSelection) to class (__gtksharp_68_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_YearInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkTable) to class (__gtksharp_74_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_AlbumInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init

(Banshee:23273): GLib-GObject-WARNING **: attempting to add an interface (AtkSelection) to class (__gtksharp_74_Hyena_Data_Gui_Accessibility_ListViewAccessible+601+5b+5bBanshee_Collection_AlbumInfo+2c+20Banshee_Core+2c+20Version+3d2_6_0_0+2c+20Culture+3dneutral+2c+20PublicKeyToken+3dnull+5d+5d) after class_init
[1 Debug 22:27:01.368] Constructed Nereid interface: 0.531851
[1 Debug 22:27:01.415] Creating new surface cache for 90px images, capped at 0.49 MiB (16 items)
[1 Debug 22:27:01.448] Registering remote object /org/bansheeproject/Banshee/ClientWindow (Nereid.PlayerInterface) on org.bansheeproject.Banshee
[1 Debug 22:27:01.449] Core service started (NereidPlayerInterface, 0.637756)
[1 Debug 22:27:01.455] Extension service started (CoverArtService, 0.005758)
[1 Debug 22:27:01.461] Using GNOME 2.22 API for Multimedia Keys
[1 Debug 22:27:01.461] Extension service started (MultimediaKeysService, 0.006045)
[1 Debug 22:27:01.463] Extension service started (DaapService, 0.00146)
[1 Debug 22:27:01.485] Audioscrobbler state: connected
[1 Debug 22:27:01.490] Extension service started (AudioscrobblerService, 0.026718)
[1 Debug 22:27:01.499] Extension service started (BpmService, 0.00877)
[1 Debug 22:27:01.501] Extension service started (DapService, 0.00186)
[1 Debug 22:27:01.531] Extension service started (EmusicService, 0.030069)
[1 Info  22:27:01.535] Updating web proxy from GConf
[1 Debug 22:27:01.541] Direct connection, no proxy in use
[1 Debug 22:27:01.559] Extension service started (GnomeService, 0.0275)
[1 Debug 22:27:01.586] Extension service started (NotificationAreaService, 0.027806)
[1 Debug 22:27:01.589] Extension service started (AmazonMp3DownloaderService, 0.00291)
[1 Debug 22:27:01.617] Extension service started (AudioCdService, 0.026944)
[1 Debug 22:27:01.624] Extension service started (DvdService, 0.007568)
[1 Debug 22:27:01.670] Extension service started (GStreamerCoreService, 0.04581)
[1 Debug 22:27:01.673] Extension service started (PodcastService, 0.002953)
[1 Debug 22:27:01.675] Extension service started (LibraryWatcherService, 0.00212)
[1 Info  22:27:01.677] All services are started 1.348833
[4 Warn  22:27:07.102] Executed in 4992ms
                    DELETE FROM CoreCache WHERE ModelID = 246;
                        INSERT INTO CoreCache (ModelID, ItemID) SELECT 246, CoreArtists.ArtistID
                FROM CoreArtists WHERE CoreArtists.ArtistID IN
                    (SELECT CoreAlbums.ArtistID FROM CoreAlbums, CoreTracks, CoreCache
                        WHERE CoreCache.ModelID = 39 AND
                              CoreTracks.AlbumID = CoreAlbums.AlbumID AND
                              EXISTS (SELECT 1 FROM CoreArtists WHERE ArtistID = CoreAlbums.ArtistID) AND
                              CoreCache.ItemID = CoreTracks.TrackID )
                        ORDER BY NameSortKey
[4 Warn  22:27:37.523] Executed in 30410ms
                    DELETE FROM CoreCache WHERE ModelID = 1;
                        INSERT INTO CoreCache (ModelID, ItemID) SELECT 1, CoreArtists.ArtistID
                FROM CoreArtists WHERE CoreArtists.ArtistID IN
                    (SELECT CoreTracks.ArtistID FROM CoreTracks, CoreCache
                        WHERE CoreCache.ModelID = 39 AND
                              CoreCache.ItemID = CoreTracks.TrackID )
                    ORDER BY NameSortKey
[1 Debug 22:27:37.703] Creating Pango.Layout, configuring Cairo.Context
[4 Warn  22:27:42.076] Executed in 4141ms
                    DELETE FROM CoreCache WHERE ModelID = 246;
                        INSERT INTO CoreCache (ModelID, ItemID) SELECT 246, CoreArtists.ArtistID
                FROM CoreArtists WHERE CoreArtists.ArtistID IN
                    (SELECT CoreAlbums.ArtistID FROM CoreAlbums, CoreTracks, CoreCache
                        WHERE CoreCache.ModelID = 39 AND
                              CoreTracks.AlbumID = CoreAlbums.AlbumID AND
                              EXISTS (SELECT 1 FROM CoreArtists WHERE ArtistID = CoreAlbums.ArtistID) AND
                              CoreCache.ItemID = CoreTracks.TrackID )
                        ORDER BY NameSortKey
[4 Warn  22:28:13.410] Executed in 31330ms
                    DELETE FROM CoreCache WHERE ModelID = 1;
                        INSERT INTO CoreCache (ModelID, ItemID) SELECT 1, CoreArtists.ArtistID
                FROM CoreArtists WHERE CoreArtists.ArtistID IN
                    (SELECT CoreTracks.ArtistID FROM CoreTracks, CoreCache
                        WHERE CoreCache.ModelID = 39 AND
                              CoreCache.ItemID = CoreTracks.TrackID )
                    ORDER BY NameSortKey
[1 Debug 22:28:13.564] Extension source loaded: Now Playing
[1 Debug 22:28:13.594] Extension source loaded: Last.fm
[1 Debug 22:28:13.599] Extension source loaded: Miro Guide
[4 Warn  22:28:17.973] Executed in 4181ms
                    DELETE FROM CoreCache WHERE ModelID = 246;
                        INSERT INTO CoreCache (ModelID, ItemID) SELECT 246, CoreArtists.ArtistID
                FROM CoreArtists WHERE CoreArtists.ArtistID IN
                    (SELECT CoreAlbums.ArtistID FROM CoreAlbums, CoreTracks, CoreCache
                        WHERE CoreCache.ModelID = 39 AND
                              CoreTracks.AlbumID = CoreAlbums.AlbumID AND
                              EXISTS (SELECT 1 FROM CoreArtists WHERE ArtistID = CoreAlbums.ArtistID) AND
                              CoreCache.ItemID = CoreTracks.TrackID )
                        ORDER BY NameSortKey
[4 Warn  22:28:48.487] Executed in 30508ms
                    DELETE FROM CoreCache WHERE ModelID = 1;
                        INSERT INTO CoreCache (ModelID, ItemID) SELECT 1, CoreArtists.ArtistID
                FROM CoreArtists WHERE CoreArtists.ArtistID IN
                    (SELECT CoreTracks.ArtistID FROM CoreTracks, CoreCache
                        WHERE CoreCache.ModelID = 39 AND
                              CoreCache.ItemID = CoreTracks.TrackID )
                    ORDER BY NameSortKey
[1 Debug 22:28:48.695] Registering remote object /org/bansheeproject/Banshee/SourceManager/PlayQueue (Banshee.PlayQueue.PlayQueueSource) on org.bansheeproject.Banshee
[1 Debug 22:28:48.695] Extension source loaded: Play Queue
[1 Debug 22:28:48.715] Extension source loaded: Internet Archive
[1 Info  22:28:48.722] AmazonMP3 store redirect URL: http://integrated-services.banshee.fm/amz/redirect.do/
[1 Debug 22:28:48.726] Extension source loaded: Amazon MP3 Store
[1 Debug 22:28:48.900] Extension source loaded: File System Queue
[1 Debug 22:28:48.918] Extension source loaded: Radio
[1 Debug 22:28:48.962] Extension source loaded: Audiobooks
[1 Debug 22:28:48.968] Starting GTK main loop
[1 Debug 22:28:49.236] Creating Pango.Layout, configuring Cairo.Context
[1 Debug 22:28:49.289] Creating Pango.Layout, configuring Cairo.Context
[1 Info  22:28:49.510] nereid Client Started
[1 Debug 22:28:49.512] Delayed Initializating Banshee.MediaEngine.PlayerEngineService
[1 Debug 22:28:49.544] (libbanshee:player) Audiosink has volume: YES
[1 Debug 22:28:49.547] (libbanshee:player) Using system (gst-plugins-good) equalizer element
[1 Debug 22:28:49.592] Player state change: NotReady -> Ready
[1 Debug 22:28:49.607] Loaded equalizer presets: 0.009105
[1 Debug 22:28:49.611] Selected equalizer: New Preset
[1 Debug 22:28:49.615] Syncing equalizer to engine: New Preset
[1 Debug 22:28:49.619] Player state change: Ready -> Idle
[1 Debug 22:28:49.623] (libbanshee:player) Disabled ReplayGain
[1 Info  22:28:49.625] GStreamer version 1.2.3.0, gapless: True, replaygain: False
[1 Debug 22:28:49.628] Delayed Initializating Banshee.Daap.DaapService
[1 Debug 22:28:49.629] Delayed Initializating Banshee.Dap.DapService
[1 Debug 22:28:49.665] Dap support extension loaded: Banshee.Dap.AppleDevice
[1 Debug 22:28:49.668] Dap support extension loaded: Banshee.Dap.MassStorage
[1 Debug 22:28:49.670] Dap support extension loaded: Banshee.Dap.Mtp
[1 Debug 22:28:49.677] Delayed Initializating Banshee.Podcasting.PodcastService
[8 Info  22:28:49.712] AppleDeviceSource is ignoring unmounted volume SPACE2
[1 Debug 22:28:49.762] Delayed Initializating Banshee.LibraryWatcher.LibraryWatcherService
[1 Debug 22:28:49.766] Core service started (LibraryImportManager, 0.000251)
[1 Debug 22:28:49.770] Started LibraryWatcher for Music (/home/nick/lib/music/)
[1 Debug 22:28:49.771] Started LibraryWatcher for Videos (/home/nick/lib/videos/)
[9 Debug 22:28:49.772] Refreshing any podcasts that haven't been updated in over an hour
[8 Info  22:28:49.774] AppleDeviceSource is ignoring unmounted volume SPACE1
[8 Info  22:28:49.779] AppleDeviceSource is ignoring unmounted volume ROOT
[8 Info  22:28:49.782] AppleDeviceSource is ignoring unmounted volume 22 GB Volume
[8 Info  22:28:49.784] AppleDeviceSource is ignoring unmounted volume BOOT
[14 Debug 22:28:50.165] DAAP Proxy listening for connections on port 8089
[1 Debug 22:28:50.776] Finished - Startup Job
[1 Debug 22:28:50.781] Starting - Saving Metadata to File
[16 Debug 22:28:50.803] Finished - Saving Metadata to File
[16 Debug 22:28:50.805] Starting - Downloading Cover Art
[17 Debug 22:28:50.809] Finished - Downloading Cover Art
[1 Debug 22:28:52.113] EqualizerManager - Saved equalizers to disk
--8<---------------cut here---------------end--------------->8---



_______________________________________________
banshee-list mailing list
[hidden email]
https://mail.gnome.org/mailman/listinfo/banshee-list  (unsubscribe here)
Reply | Threaded
Open this post in threaded view
|

Re: SQLite seems to be very sluggish

Nick Dokos-2
BTW, sqlite3 says:

--8<---------------cut here---------------start------------->8---
$ sqlite3
SQLite version 3.8.6 2014-08-15 11:46:33
Enter ".help" for usage hints.
Connected to a transient in-memory database.
Use ".open FILENAME" to reopen on a persistent database.
sqlite>
--8<---------------cut here---------------end--------------->8---

--
Nick



_______________________________________________
banshee-list mailing list
[hidden email]
https://mail.gnome.org/mailman/listinfo/banshee-list  (unsubscribe here)
Reply | Threaded
Open this post in threaded view
|

Re: SQLite seems to be very sluggish

Nick Dokos-2
In reply to this post by Nick Dokos-2
... and I found this 2010 bug which looks remarkably similar:

https://bugzilla.gnome.org/show_bug.cgi?id=625783

The culprit then was a code change that changed the execution time of
some queries from O(n*log n) to O(n**2). I wonder if something similar
happened here.

--
Nick



_______________________________________________
banshee-list mailing list
[hidden email]
https://mail.gnome.org/mailman/listinfo/banshee-list  (unsubscribe here)
Reply | Threaded
Open this post in threaded view
|

Re: SQLite seems to be very sluggish

Bertrand Lorentz
Administrator
Hello,

I've just upgraded my machine to Ubuntu GNOME 14.10, which update SQLite to version 3.8.6-1, and I now see the same problems: queries taking several seconds.
Nothing in Banshee itself has changed, so this quite probably a regression in SQLite, like that older bug mentionned below.

It seems the issue is already under discussion on the SQLite mailing list:

I'll look into the workaround suggestions in that thread.

--
Bertrand

On Wed, Oct 15, 2014 at 5:17 AM, Nick Dokos <[hidden email]> wrote:
... and I found this 2010 bug which looks remarkably similar:

https://bugzilla.gnome.org/show_bug.cgi?id=625783

The culprit then was a code change that changed the execution time of
some queries from O(n*log n) to O(n**2). I wonder if something similar
happened here.

--
Nick



_______________________________________________
banshee-list mailing list
[hidden email]
https://mail.gnome.org/mailman/listinfo/banshee-list  (unsubscribe here)


_______________________________________________
banshee-list mailing list
[hidden email]
https://mail.gnome.org/mailman/listinfo/banshee-list  (unsubscribe here)
Reply | Threaded
Open this post in threaded view
|

Re: SQLite seems to be very sluggish

Nick Dokos-2
Bertrand Lorentz
<[hidden email]> writes:

> Hello,
>
> I've just upgraded my machine to Ubuntu GNOME 14.10, which update SQLite to version 3.8.6-1, and I now see the same problems: queries taking several seconds.
> Nothing in Banshee itself has changed, so this quite probably a regression in SQLite, like that older bug mentionned below.
>
> It seems the issue is already under discussion on the SQLite mailing list:
> http://www.mail-archive.com/sqlite-users%40sqlite.org/msg86901.html
>
> I'll look into the workaround suggestions in that thread.
>

Thanks very much for the link! I'll be watching it. If I can help with
testing, please let me know.

--
Nick

_______________________________________________
banshee-list mailing list
[hidden email]
https://mail.gnome.org/mailman/listinfo/banshee-list  (unsubscribe here)