Bug 104447

More info.  It looks like when it starts misbehaving, there is a process having locking problems.  Here's a snippet of an strace from an amarokapp subprocess.  FD 13 and 17 are both the collection.db file.  The process continues doing this over and over until it exits.

nanosleep({0, 100000000}, NULL)         = 0
fcntl64(13, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff1e4) = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({0, 100000000}, NULL)         = 0
fcntl64(13, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff1e4) = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({0, 100000000}, NULL)         = 0
fcntl64(13, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff1e4) = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({0, 100000000}, NULL)         = 0
fcntl64(13, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff1e4) = -1 EAGAIN (Resource temporarily unavailable)
_llseek(13, 1938432, [1938432], SEEK_SET) = 0
read(13, "\n\0\0\0+\0\334\0\0\334\0\356\1\0\1\22\1$\0016\1I\1\\\1"..., 1024) = 1024
_llseek(13, 2091008, [2091008], SEEK_SET) = 0
read(13, "\r\0\0\0\5\3[\0\3\337\3\307\3\237\3\201\3[\0\0\0\0\0\0"..., 1024) = 1024
_llseek(13, 0, [0], SEEK_SET)           = 0
read(13, "SQLite format 3\0\4\0\1\1\0@  \0\0\0\241\0\0\0\0"..., 1024) = 1024
close(24)                               = 0
unlink("/home/satwell/.kde/share/apps/amarok/collection.db-journal") = 0
fcntl64(13, F_SETLK64, {type=F_RDLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff784) = 0
fcntl64(13, F_SETLK64, {type=F_UNLCK, whence=SEEK_SET, start=1073741824, len=2}, 0xbe7ff784) = 0
fcntl64(13, F_SETLK64, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}, 0xbe7ff774) = 0
times({tms_utime=0, tms_stime=1, tms_cutime=0, tms_cstime=0}) = 47920976
fcntl64(17, F_SETLK64, {type=F_RDLCK, whence=SEEK_SET, start=1073741824, len=1}, 0xbe7ff234) = 0
fcntl64(17, F_SETLK64, {type=F_RDLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff234) = 0
fcntl64(17, F_SETLK64, {type=F_UNLCK, whence=SEEK_SET, start=1073741824, len=1}, 0xbe7ff234) = 0
access("/home/satwell/.kde/share/apps/amarok/collection.db-journal", F_OK) = -1 ENOENT (No such file or directory)
fstat64(17, {st_mode=S_IFREG|0644, st_size=2092032, ...}) = 0
_llseek(17, 0, [0], SEEK_SET)           = 0
read(17, "SQLite format 3\0\4\0\1\1\0@  \0\0\0\241\0\0\0\0"..., 1024) = 1024
fcntl64(17, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741825, len=1}, 0xbe7ff314) = 0
access("/home/satwell/.kde/share/apps/amarok/collection.db-journal", F_OK) = -1 ENOENT (No such file or directory)
open("/home/satwell/.kde/share/apps/amarok/collection.db-journal", O_RDWR|O_CREAT|O_EXCL|O_LARGEFILE, 0600) = 24
fstat64(24, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
open("/home/satwell/.kde/share/apps/amarok", O_RDONLY|O_LARGEFILE) = 38
_llseek(24, 0, [0], SEEK_SET)           = 0
write(24, "\331\325\5\371 \241c\327", 8) = 8
write(24, "\0\0\0\0", 4)                = 4
write(24, "\303t\0001", 4)              = 4
write(24, "\0\0\7\373", 4)              = 4
write(24, "\0\0\2\0", 4)                = 4
_llseek(24, 511, [511], SEEK_SET)       = 0
write(24, "\0", 1)                      = 1
_llseek(17, 9216, [9216], SEEK_SET)     = 0
read(17, "\5\0\0\0002\2\327\0\0\0\7\373\3\373\3\366\3\361\3\353\3"..., 1024) = 1024
_llseek(17, 28672, [28672], SEEK_SET)   = 0
read(17, "\2\2f\0 \0\251\25\0\0\7\210\0013\2u\1 \1\353\1\320\0\251"..., 1024) = 1024
_llseek(17, 2091008, [2091008], SEEK_SET) = 0
read(17, "\r\0\0\0\5\3[\0\3\337\3\307\3\237\3\201\3[\0\0\0\0\0\0"..., 1024) = 1024
_llseek(17, 1938432, [1938432], SEEK_SET) = 0
read(17, "\n\0\0\0+\0\334\0\0\334\0\356\1\0\1\22\1$\0016\1I\1\\\1"..., 1024) = 1024
write(24, "\0\0\7f\n\0\0\0+\0\334\0\0\334\0\356\1\0\1\22\1$\0016\1"..., 1032) = 1032
write(24, "\0\0\7\373\r\0\0\0\5\3[\0\3\337\3\307\3\237\3\201\3[\0"..., 1032) = 1032
write(24, "\0\0\0\1SQLite format 3\0\4\0\1\1\0@  \0\0\0\241"..., 1032) = 1032
fsync(24)                               = 0
fsync(38)                               = 0
close(38)                               = 0
_llseek(24, 8, [8], SEEK_SET)           = 0
write(24, "\0\0\0\3", 4)                = 4
_llseek(24, 3608, [3608], SEEK_SET)     = 0
fsync(24)                               = 0
fcntl64(17, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741824, len=1}, 0xbe7ff1e4) = 0
fcntl64(17, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff1e4) = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({0, 100000000}, NULL)         = 0
fcntl64(17, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff1e4) = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({0, 100000000}, NULL)         = 0
fcntl64(17, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1073741826, len=510}, 0xbe7ff1e4) = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({0, 100000000}, NULL)         = 0

Try disabling the "Watch for changes" option, and see if you still have this problem.
Also, make sure your collection Database file is on a local file system, as SQLite is known to misbehave when on NFS.

I have similar behavior with 1.2.3 on KDE 3.3.2, gstreamer osssink.

I do not have "Watch for Changes" enabled.  My collection is accessed over an smb file system on a remote linux machine.

One other behavior during the "deterioration phase" is that song changes become increasingly sluggish.  Sometimes taking up to 15 seconds to switch songs.  Also, during this time, the UI of other interactive applications (like firefox or kate or thunderbird) "freeze" (stop accepting input).

Another anomaly I observed is that the OSD sometimes gets impromperly drawn (usually the top and bottom of the image are truncated).

Again, just to make sure, is the file that holds your collection (.kde/share/apps/amarok/collection.db) in a local file system? SQlite doesn't work well when its database file is on a NFS file system.
If it's not the case, it would be good if somebody that can reproduce this could test with MySQL.

My collection.db file is on a local file system.

I will attempt to reproduce the problem with MySQL.

You didn't mention anything about the smbfs for the actual collection (the music files), so I take it you don't suspect that?  If you have a strong suspicion about that, I'd be willing to try to reproduce the problem by moving some part of my collection to a local file system, but that will take some effort.

OK, it's a little too early to be sure, but I'm pretty psyched that since switching to MySQL, I've been running amaroK for a couple of hours and doing heavy file manipulation (updating tags, covers, doing re-scans, re-builds of the collection, adding/removing files, etc.) and haven't seen ANY of these symptoms.  I'll report back in a day or two, but so far, this looks very promising.  Thanks for the suggestion, and others seeing problems like these might want to try switching to MySQL.

Just another quick note to confirm that since switching to MySQL, all of my amaroK problems seem to be gone.  I've had enough time with it, and enough of the kind of usage that seemed to provoke the problem (lots of adds/deletes/changes to the collection and playlist) without a recurrence to feel pretty confident that this was the root of the problem.  Thanks so much for pointing me in the right direction.

john

Np John Biundo, though we'd like to understand why that would happen. As I said, sqlite is known not work well when it's database file is on NFS, but the file system that holds your media files shouldn't matter.
Anyway, changing summary to better reflect the problem.

If you'd like to suggest some further investigation that I can contribute to, please do so and I'll try to help.  I've been running fine with MySQL for several days now.  Once I'm sure things are stable for a while, I could try to temporarily switch back to sqlite to see if, indeed, the problem recurs.  At that point, I would need guidance in conducting tests to isolate the specific problem.

Just to provide my own input on the matter: I running amarok 1.2.3 on KDE 3.2 and have experienced the same symptoms (gradual deterioration, rampant forking after shutdown). However, all of my music and my collection database are on a local drive, so I don't think that NFS or SMB would be the problem.

Further information: If you haven't found the source of the problem yet, I have found one way around it when using SQLite (that may point to the source of the problem). As I said above, I have been having the same problems as described by everyone else. I haven't switched to MySQL yet, but I have been able to avoid the degradation by leaving my playlist off random play. However, when I turn random play back on, the gradual slowdown inevitably begins.

(I've also upgraded to 1.2.4 and still have the same problems)

Hope that helps!

From playlist.cpp Playlist::playNextTrack:
else if( AmarokConfig::randomMode() )
{
    QValueVector<PlaylistItem*> tracks;
    //make a list of everything we can play
    for( MyIt it( this ); *it; ++it )
       if ( !m_prevTracks.containsRef( *it ) )
            tracks.push_back( *it );

I'm not familiar with all the code involved. But it looks like for every track switch, it compares every item in the playlist with every item in m_prevTracks. So it makes sense that it would be slower as time goes on. I guess the simple solution would be to keep m_prevTracks at ~100 tracks. Seems like a more ideal solution would be possible though.

It's not just random mode that this problem happens in.  Although I believe I have seen it more frequently while in random mode, I have definitely seen it in non-random mode.

I've also noticed that the problem seems to occur much more frequently when in the context browser tab.  I have taken to staying in the collection browser tab instead of the context browser tab, and the problem seems much less frequent now than it used to be.

Eean, it is!

if ( m_prevTracks.count() <= 80 ) {
    m_prevTracks.clear();

    int count = 0;
    for( MyIterator it( this, MyIterator::Visible ); *it; ++it )
         ++count;

   if ( count > 1 )
         m_prevTracks.append( m_currentTrack );
}

On Tue, 24 May 2005 02:04 am, Ian Monroe wrote:
[bugs.kde.org quoted mail]

Actually its the else { } of that if statement where it keeps its under 80, but yes. :)

Oh well. Still a mystery.

I found this bug by looking through amarok-forum. Got the same problems as described above.
One thing i recognized: when this behavior occus it helps just to remove all songs from playlist.

Havent testeed Switching to MySQL yet, but will do so this afternoon. So maybe this is at least a workaround.

Hi,
same Problem here.When switching to the next song amarok hangs for some Time ~10sec. But I got the Problem just today after installing amarok-1.3. All Files are on local Drives. And I use arts and sqlite.

I switch to mysql, still the same Problem. But I fogot to write that it just apears in dynamic Mode.

Disable "Retrieve similar artists" from the last.fm settings page. I have a feeling that might be it.

> 
> ------- Additional Comments From markey web de  2005-10-06 23:13 -------
> Disable "Retrieve similar artists" from the last.fm settings page. I have a feeling that might be it.
>

Well a quick test suggests you're right.  I'll report back later if the problem recurs.  Thanks!
 

SVN commit 469832 by markey:

* Fixed problems with "Retrieve Similar Artists" feature in combination
  with SQLite, which could lead to 100% CPU usage.

Everyone please enable the Retrieve Similar Artists feature and test this! For me it solves the locking issues with SQLite, but it also seems to have a somewhat negative performance impact, with lots of HDD activity on trackchange.

BUG: 104447



 M  +2 -0      ChangeLog  
 M  +23 -20    src/collectiondb.cpp  
 M  +7 -4      src/collectiondb.h  


--- trunk/extragear/multimedia/amarok/ChangeLog #469831:469832
@@ -14,6 +14,8 @@
       icon, respectively.
 
   BUGFIXES:
+    * Fixed problems with "Retrieve Similar Artists" feature in combination
+      with SQLite, which could lead to 100% CPU usage. (BUG 104447)
     * Tabbing between items and cells in the playlist while editing them now
       works much nicer (goes in order and doesn't tab to invisible columns),
       and you can also now use Alt+Up, Down, Left, Right to navigate between
--- trunk/extragear/multimedia/amarok/src/collectiondb.cpp #469831:469832
@@ -72,8 +72,9 @@
 }
 
 
-CollectionDB::CollectionDB()
+CollectionDB::CollectionDB( bool temporary )
         : EngineObserver( EngineController::instance() )
+        , m_isTemporary( temporary )
         , m_cacheDir( amaroK::saveLocation() )
         , m_coverDir( amaroK::saveLocation() )
         , m_noCover ( locate( "data", "amarok/images/nocover.png" ) )
@@ -94,15 +95,18 @@
     initialize();
     //</OPEN DATABASE>
 
-    // TODO: Should write to config in dtor, but it crashes...
-    KConfig* config = amaroK::config( "Collection Browser" );
-    config->writeEntry( "Database Version", DATABASE_VERSION );
-    config->writeEntry( "Database Stats Version", DATABASE_STATS_VERSION );
+    if ( !temporary )
+    {
+        // TODO Should write to config in dtor, but it crashes...
+        KConfig* config = amaroK::config( "Collection Browser" );
+        config->writeEntry( "Database Version", DATABASE_VERSION );
+        config->writeEntry( "Database Stats Version", DATABASE_STATS_VERSION );
 
-    startTimer( MONITOR_INTERVAL * 1000 );
+        startTimer( MONITOR_INTERVAL * 1000 );
 
-    connect( Scrobbler::instance(), SIGNAL( similarArtistsFetched( const QString&, const QStringList& ) ),
-             this,                  SLOT( similarArtistsFetched( const QString&, const QStringList& ) ) );
+        connect( Scrobbler::instance(), SIGNAL( similarArtistsFetched( const QString&, const QStringList& ) ),
+                 this,                    SLOT( similarArtistsFetched( const QString&, const QStringList& ) ) );
+    }
 }
 
 CollectionDB::~CollectionDB()
@@ -110,11 +114,6 @@
     DEBUG_FUNC_INFO
 
     destroy();
-
-//     This crashes so it's done at the end of ctor.
-//     KConfig* const config = amaroK::config( "Collection Browser" );
-//     config->writeEntry( "Database Version", DATABASE_VERSION );
-//     config->writeEntry( "Database Stats Version", DATABASE_STATS_VERSION );
 }
 
 
@@ -1865,11 +1864,14 @@
 {
     virtual bool doJob()
     {
-        CollectionDB::instance()->query( QString( "DELETE FROM related_artists WHERE artist = '%1';" ).arg( escapedArtist ) );
+        // Create a temporary CollectionDB object, to prevent threading problems
+        CollectionDB db( true );
 
+        db.query( QString( "DELETE FROM related_artists WHERE artist = '%1';" ).arg( escapedArtist ) );
+
         const QString sql = "INSERT INTO related_artists ( artist, suggestion, changedate ) VALUES ( '%1', '%2', 0 );";
         foreach( suggestions )
-            CollectionDB::instance()->insert( sql
+            db.insert( sql
                     .arg( escapedArtist )
                     .arg( CollectionDB::instance()->escapeString( *it ) ), NULL );
 
@@ -1908,7 +1910,7 @@
 void
 CollectionDB::initialize()
 {
-    m_dbConnPool = new DbConnectionPool();
+    m_dbConnPool = new DbConnectionPool( this );
     DbConnection *dbConn = m_dbConnPool->getDbConnection();
     m_dbConnPool->putDbConnection( dbConn );
 
@@ -2491,15 +2493,16 @@
 PostgresqlConfig::PostgresqlConfig(
     const QString& conninfo )
     : m_conninfo( conninfo )
-{
-}
+{}
 
 
 //////////////////////////////////////////////////////////////////////////////////////////
 // CLASS DbConnectionPool
 //////////////////////////////////////////////////////////////////////////////////////////
 
-DbConnectionPool::DbConnectionPool() : m_semaphore( POOL_SIZE )
+DbConnectionPool::DbConnectionPool( bool temporary )
+    : m_isTemporary( temporary )
+    , m_semaphore( POOL_SIZE )
 {
 #ifdef USE_MYSQL
     if ( AmarokConfig::databaseEngine().toInt() == DbConnection::mysql )
@@ -2554,7 +2557,7 @@
 {
     m_semaphore += POOL_SIZE;
     DbConnection *conn;
-    bool vacuum = true;
+    bool vacuum = !m_isTemporary;
 
     while ( ( conn = dequeue() ) != 0 )
     {
--- trunk/extragear/multimedia/amarok/src/collectiondb.h #469831:469832
@@ -164,7 +164,7 @@
 class DbConnectionPool : QPtrQueue<DbConnection>
 {
     public:
-        DbConnectionPool();
+        DbConnectionPool( bool temporary );
        ~DbConnectionPool();
 
         const DbConnection::DbConnectionType getDbConnectionType() const { return m_dbConnType; }
@@ -188,6 +188,8 @@
 
     private:
         static const int POOL_SIZE = 5;
+
+        bool m_isTemporary;
         QSemaphore m_semaphore;
         DbConnection::DbConnectionType m_dbConnType;
         DbConfig *m_dbConfig;
@@ -214,6 +216,9 @@
         void tagsChanged( const MetaBundle &bundle );
 
     public:
+        CollectionDB( bool temporary = false );
+        ~CollectionDB();
+
         static CollectionDB *instance();
 
         const QString escapeString( const QString &string ) { return m_dbConnPool->escapeString(string); }
@@ -343,9 +348,6 @@
         QStringList staleImages();
 
     protected:
-        CollectionDB();
-        ~CollectionDB();
-
         QCString md5sum( const QString& artist, const QString& album, const QString& file = QString::null );
         void engineTrackEnded( int finalPosition, int trackLength );
         /** Manages regular folder monitoring scan */
@@ -398,6 +400,7 @@
 
         DbConnectionPool *m_dbConnPool;
 
+        bool m_isTemporary;
         bool m_monitor;
         QDir m_cacheDir;
         QDir m_coverDir;