From 1c7bdfda1e7c768525a73d1ca104db53ff1cec10 Mon Sep 17 00:00:00 2001 From: Timothy Pearson Date: Wed, 24 Apr 2013 20:22:40 -0500 Subject: Fix long delay at session termination on certain systems This resolves Bug 760 Add shutdown profiling code and disable at compile time --- ksmserver/shutdown.cpp | 79 +++++++++++++++++++++++++++++++++++++++----------- 1 file changed, 62 insertions(+), 17 deletions(-) (limited to 'ksmserver/shutdown.cpp') diff --git a/ksmserver/shutdown.cpp b/ksmserver/shutdown.cpp index 87b9836b1..05bfd0af2 100644 --- a/ksmserver/shutdown.cpp +++ b/ksmserver/shutdown.cpp @@ -95,6 +95,14 @@ CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. #include "shutdowndlg.h" #include "client.h" +// #define PROFILE_SHUTDOWN 1 + +#ifdef PROFILE_SHUTDOWN + #define SHUTDOWN_MARKER(x) printf("[ksmserver] '%s' [%s]\n\r", x, TQTime::currentTime().toString("hh:mm:ss:zzz").ascii()); fflush(stdout); +#else // PROFILE_SHUTDOWN + #define SHUTDOWN_MARKER(x) +#endif // PROFILE_SHUTDOWN + void KSMServer::logout( int confirm, int sdtype, int sdmode ) { shutdown( (TDEApplication::ShutdownConfirm)confirm, @@ -221,7 +229,7 @@ void KSMServer::shutdownInternal( TDEApplication::ShutdownConfirm confirm, } if ( logoutConfirmed ) { - + SHUTDOWN_MARKER("Shutdown initiated"); shutdownType = sdtype; shutdownMode = sdmode; bootOption = bopt; @@ -230,8 +238,9 @@ void KSMServer::shutdownInternal( TDEApplication::ShutdownConfirm confirm, // shall we save the session on logout? saveSession = ( config->readEntry( "loginMode", "restorePreviousLogout" ) == "restorePreviousLogout" ); - if ( saveSession ) + if ( saveSession ) { sessionGroup = TQString("Session: ") + SESSION_PREVIOUS_LOGOUT; + } // Set the real desktop background to black so that exit looks // clean regardless of what was on "our" desktop. @@ -242,6 +251,7 @@ void KSMServer::shutdownInternal( TDEApplication::ShutdownConfirm confirm, wmPhase1WaitingCount = 0; saveType = saveSession?SmSaveBoth:SmSaveGlobal; performLegacySessionSave(); + SHUTDOWN_MARKER("Legacy save complete"); startProtection(); for ( KSMClient* c = clients.first(); c; c = clients.next() ) { c->resetState(); @@ -271,8 +281,9 @@ void KSMServer::shutdownInternal( TDEApplication::ShutdownConfirm confirm, SmsSaveYourself( c->connection(), saveType, true, SmInteractStyleAny, false ); } - if ( clients.isEmpty() ) + if ( clients.isEmpty() ) { completeShutdownOrCheckpoint(); + } } else { if (showLogoutStatusDlg) { @@ -505,12 +516,15 @@ void KSMServer::protectionTimeout() void KSMServer::completeShutdownOrCheckpoint() { - if ( state != Shutdown && state != Checkpoint ) + SHUTDOWN_MARKER("completeShutdownOrCheckpoint"); + if ( state != Shutdown && state != Checkpoint ) { return; + } for ( KSMClient* c = clients.first(); c; c = clients.next() ) { - if ( !c->saveYourselfDone && !c->waitForPhase2 ) + if ( !c->saveYourselfDone && !c->waitForPhase2 ) { return; // not done yet + } } // do phase 2 @@ -522,8 +536,10 @@ void KSMServer::completeShutdownOrCheckpoint() waitForPhase2 = true; } } - if ( waitForPhase2 ) + if ( waitForPhase2 ) { return; + } + SHUTDOWN_MARKER("Phase 2 complete"); bool showLogoutStatusDlg = TDEConfigGroup(TDEGlobal::config(), "Logout").readBoolEntry("showLogoutStatusDlg", true); if (showLogoutStatusDlg && state != Checkpoint) { @@ -544,10 +560,14 @@ void KSMServer::completeShutdownOrCheckpoint() static_cast(shutdownNotifierIPDlg)->setStatusMessage(i18n("Saving your settings...")); } - if ( saveSession ) + if ( saveSession ) { storeSession(); - else + SHUTDOWN_MARKER("Session stored"); + } + else { discardSession(); + SHUTDOWN_MARKER("Session discarded"); + } if ( state == Shutdown ) { bool waitForKNotify = true; @@ -563,8 +583,9 @@ void KSMServer::completeShutdownOrCheckpoint() } // event() can return -1 if KNotifyClient short-circuits and avoids KNotify logoutSoundEvent = KNotifyClient::event( 0, "exitkde" ); // KDE says good bye - if( logoutSoundEvent <= 0 ) + if( logoutSoundEvent <= 0 ) { waitForKNotify = false; + } if( waitForKNotify ) { state = WaitingForKNotify; knotifyTimeoutTimer.start( 20000, true ); @@ -577,15 +598,17 @@ void KSMServer::completeShutdownOrCheckpoint() } state = Idle; } + SHUTDOWN_MARKER("Fully shutdown"); } void KSMServer::startKilling() { + SHUTDOWN_MARKER("startKilling"); knotifyTimeoutTimer.stop(); // kill all clients state = Killing; for ( KSMClient* c = clients.first(); c; c = clients.next() ) { - if( isWM( c ) || isCM( c ) ) // kill the WM and CM as the last one in order to reduce flicker + if( isWM( c ) || isCM( c ) || isNotifier( c ) ) // kill the WM and CM as the last one in order to reduce flicker. Also wait to kill knotify to avoid logout delays continue; kdDebug( 1218 ) << "completeShutdown: client " << c->program() << "(" << c->clientId() << ")" << endl; SmsDie( c->connection() ); @@ -599,12 +622,13 @@ void KSMServer::startKilling() void KSMServer::completeKilling() { + SHUTDOWN_MARKER("completeKilling"); kdDebug( 1218 ) << "KSMServer::completeKilling clients.count()=" << clients.count() << endl; if( state == Killing ) { bool wait = false; for( KSMClient* c = clients.first(); c; c = clients.next()) { - if( isWM( c ) || isCM( c ) ) + if( isWM( c ) || isCM( c ) || isNotifier( c ) ) continue; wait = true; // still waiting for clients to go away } @@ -616,6 +640,7 @@ void KSMServer::completeKilling() void KSMServer::killWM() { + SHUTDOWN_MARKER("killWM"); state = KillingWM; bool iswm = false; if (shutdownNotifierIPDlg) { @@ -631,6 +656,9 @@ void KSMServer::killWM() if( isCM( c )) { SmsDie( c->connection() ); } + if( isNotifier( c )) { + SmsDie( c->connection() ); + } } if( iswm ) { completeKillingWM(); @@ -642,6 +670,7 @@ void KSMServer::killWM() void KSMServer::completeKillingWM() { + SHUTDOWN_MARKER("completeKillingWM"); kdDebug( 1218 ) << "KSMServer::completeKillingWM clients.count()=" << clients.count() << endl; if( state == KillingWM ) { @@ -653,18 +682,26 @@ void KSMServer::completeKillingWM() // shutdown is fully complete void KSMServer::killingCompleted() { + SHUTDOWN_MARKER("killingCompleted"); kapp->quit(); } // called when KNotify performs notification for logout (not when sound is finished though) void KSMServer::notifySlot(TQString event ,TQString app,TQString,TQString,TQString,int present,int,int,int) { - if( state != WaitingForKNotify ) + SHUTDOWN_MARKER("notifySlot"); + if( state != WaitingForKNotify ) { + SHUTDOWN_MARKER("notifySlot state != WaitingForKNotify"); return; - if( event != "exitkde" || app != "ksmserver" ) + } + if( event != "exitkde" || app != "ksmserver" ) { + SHUTDOWN_MARKER("notifySlot event != \"exitkde\" || app != \"ksmserver\""); return; - if( present & KNotifyClient::Sound ) // logoutSoundFinished() will be called + } + if( present & KNotifyClient::Sound ) { // logoutSoundFinished() will be called + SHUTDOWN_MARKER("notifySlot present & KNotifyClient::Sound"); return; + } startKilling(); } @@ -672,23 +709,30 @@ void KSMServer::notifySlot(TQString event ,TQString app,TQString,TQString,TQStri // emitted in KNotify only after the sound is finished playing. void KSMServer::logoutSoundFinished( int event, int ) { - if( state != WaitingForKNotify ) + SHUTDOWN_MARKER("logoutSoundFinished"); + if( state != WaitingForKNotify ) { return; - if( event != logoutSoundEvent ) + } + if( event != logoutSoundEvent ) { return; + } startKilling(); } void KSMServer::knotifyTimeout() { - if( state != WaitingForKNotify ) + SHUTDOWN_MARKER("knotifyTimeout"); + if( state != WaitingForKNotify ) { return; + } startKilling(); } void KSMServer::timeoutQuit() { + SHUTDOWN_MARKER("timeoutQuit"); for (KSMClient *c = clients.first(); c; c = clients.next()) { + SHUTDOWN_MARKER(TQString("SmsDie timeout, client %1 (%2)").arg(c->program()).arg(c->clientId()).ascii()); kdWarning( 1218 ) << "SmsDie timeout, client " << c->program() << "(" << c->clientId() << ")" << endl; } killWM(); @@ -696,6 +740,7 @@ void KSMServer::timeoutQuit() void KSMServer::timeoutWMQuit() { + SHUTDOWN_MARKER("timeoutWMQuit"); if( state == KillingWM ) { kdWarning( 1218 ) << "SmsDie WM timeout" << endl; } -- cgit v1.2.3