Logging out of the Unity8 desktop preview session hangs

[Christopher Townsend]

When logging out of a Unity8 desktop preview session, it hangs and keeps displaying the Logout dialogue but nothing else happens.

[Christopher Townsend (townsend)]

I watched dbus when I tried logging out of the Unity 8 desktop session and to my untrained eye, it looks like unity8-dash is not getting killed as it should which then holds up the rest of the logout.

[Christopher Townsend (townsend)]

Here is the relevant snippet from ~/.cache/upstart/unity8.conf:

qtmir.applications: ApplicationManager::stopApplication - appId= "unity8-dash"
qtmir.applications: ApplicationManager::remove - appId= "unity8-dash"
qtmir.applications: ApplicationManager::focusApplication - appId= "unity8-dash"
No such running application with appId= "unity8-dash"
qtmir.applications: TaskController::stop - appId= "unity8-dash"
ApplicationController::stopApplication FAILED to stop appId= "unity8-dash"
qtmir.applications: TaskController::stopApplication - FAILED to stop appId= "unity8-dash"
FAILED to ask Upstart to stop application with appId "unity8-dash" Sending SIGTERM to process: 3264
qtmir.applications: Application::~Application
qtmir.applications: Application::removeSurface "Unity Dash" from "Unity 8 Dash"
qtmir.applications: Application::setSurface - appId= "unity8-dash" surface= QQuickItem(0)
qtmir.applications: Application::setFullscreen - appId= "unity8-dash" fullscreen= false
qtmir.surfaces: MirSurfaceItem::~MirSurfaceItem - this= qtmir::MirSurfaceItem (this = 0x3106b20 , name= "" , parent = 0x2a51df0 , geometry = QRectF(0,24 1280x776) , z = 1 )
qtmir.applications: DesktopFileReader::~DesktopFileReader
QtCompositor::setAllWindowsExposed false
qtmir.applications: ApplicationManager::~ApplicationManager
qtmir.surfaces: MirSurfaceManager::~MirSurfaceManager - this= qtmir::MirSurfaceManager(0x1f01e70, name = "qtmir::SurfaceManager")

If I try killing unity8-dash manually, it respawns immediately. I'm wondering if something is a little out of sync in the upstart scripts...

[Michał Sawicz (saviq)]

unity8-dash job only exits on unity8 stopping, the desktop session used a different job until now, there's branches fixing this now:

lp:~bregma/unity8/merge-desktop-upstart-job
lp:~bregma/unity8-desktop-session/merge-upstart-jobs

[Christopher Townsend (townsend)]

Hi saviq,

I'm actually using those branches, along with a couple of others, and log out still is not working correctly. It's not really clear to me what is going on. After trying to log out, the unity8 and unity8-dash upstart jobs are still in the start/running state.

If you have any other ideas or other logs I should check, let me know.

Thanks!

[Launchpad Janitor (janitor)]

This bug was fixed in the package unity8-desktop-session - 1.0.12+14.10.20140811-0ubuntu1

---------------
unity8-desktop-session (1.0.12+14.10.20140811-0ubuntu1) utopic; urgency=medium

  [ Stephen M. Webb ]
  * upstream release 1.0.12
  * move LightDM desktop files to lightdm session directory
  * remove the separate unity8-mir upstart job because the unity8
    upstart job does everything necessary (LP: #1353041)
 -- Ubuntu daily release <email address hidden> Mon, 11 Aug 2014 11:47:54 +0000

[Christopher Townsend (townsend)]

After hitting this condition, I attached gdb to the main unity8 process and did a bt full. This is what I got:

(gdb) bt full
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
No locals.
#1 0x00007f8a7eb2bb03 in QWaitCondition::wait(QMutex*, unsigned long) () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5
No symbol table info available.
#2 0x00007f8a7eb26415 in QThreadPoolPrivate::waitForDone(int) () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5
No symbol table info available.
#3 0x00007f8a7eb269f1 in QThreadPool::waitForDone(int) () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5
No symbol table info available.
#4 0x00007f8a7ed5216d in QCoreApplication::~QCoreApplication() () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5
No symbol table info available.
#5 0x00007f8a80198149 in QGuiApplication::~QGuiApplication() () from /usr/lib/x86_64-linux-gnu/libQt5Gui.so.5
No symbol table info available.
#6 0x0000000000404fb2 in ?? ()
No symbol table info available.
#7 0x00007f8a7e1c4ec5 in __libc_start_main (main=0x404500, argc=1, argv=0x7ffffc0de938, init=<optimized out>, fini=<optimized out>,
    rtld_fini=<optimized out>, stack_end=0x7ffffc0de928) at libc-start.c:287
        result = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0, 6695199899429293394, 4217504, 140737422158128, 0, 0, -6695206891045860014,
                -6629618689277899438}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x409fb0 <__libc_csu_init>, 0x7ffffc0de938}, data = {
              prev = 0x0, cleanup = 0x0, canceltype = 4235184}}}
        not_first_call = <optimized out>
#8 0x0000000000405ac9 in _start ()

At this point, I'm not sure what condition it is waiting on.

[Christopher Townsend (townsend)]

Digging a bit further, it looks it's getting stuck somewhere in the Qt.quit() call in onLogoutReady in qml/Components/Dialogs.qml. Now to try to educate myself on what this does...

[Christopher Townsend (townsend)]

I take back my last comment. It's not getting stuck in the Qt.quit() method, but looks to be getting stuck in the application destructor in src/main.cpp. Here is the end of the unity8.log upstart log when trying to log out:

qtmir.applications: ApplicationManager::stopApplication - appId= "unity8-dash"
qtmir.applications: ApplicationManager::remove - appId= "unity8-dash"
qtmir.applications: ApplicationManager::focusApplication - appId= "unity8-dash"
No such running application with appId= "unity8-dash"
qtmir.applications: TaskController::stop - appId= "unity8-dash"
ApplicationController::stopApplication FAILED to stop appId= "unity8-dash"
qtmir.applications: TaskController::stopApplication - FAILED to stop appId= "unity8-dash"
FAILED to ask Upstart to stop application with appId "unity8-dash" Sending SIGTERM to process: 4059
qtmir.applications: Application::~Application
qtmir.applications: Application::removeSurface "Unity Dash" from "Unity 8 Dash"
qtmir.applications: Application::setSurface - appId= "unity8-dash" surface= QQuickItem(0)
qtmir.applications: Application::setFullscreen - appId= "unity8-dash" fullscreen= false
qtmir.surfaces: MirSurfaceItem::~MirSurfaceItem - this= qtmir::MirSurfaceItem (this = 0x226b520 , name= "" , parent = 0x2ec3130 , geometry = QRectF(0,24 1280x776) , z = 1 )
qtmir.applications: DesktopFileReader::~DesktopFileReader
QtCompositor::setAllWindowsExposed false
qtmir.applications: ApplicationManager::~ApplicationManager
qtmir.surfaces: MirSurfaceManager::~MirSurfaceManager - this= qtmir::MirSurfaceManager(0x1a66b00, name = "qtmir::SurfaceManager")

Looking at the code, it looks like it's a simple return of an exit code after the application destructor, so I don't think it's getting to the return and is stuck in the destructor somewhere.

[Launchpad Janitor (janitor)]

This bug was fixed in the package unity8 - 8.00+14.10.20140811-0ubuntu1

---------------
unity8 (8.00+14.10.20140811-0ubuntu1) utopic; urgency=low

  [ Andrea Cimitan ]
  * Add emblem support in dash cards.

  [ Michael Terry ]
  * Fix a variety of design nits with the current lockscreen: * disable
    indicators and launcher when locked * when reversing the direction
    of a greeter flick, treat it as a cancel * don't animate dots when
    changing the infographic data source * make cancelling a login
    nicer: * reduce the delay before greeter starts animating * show the
    greeter from the same side of the screen that it hid to * don't re-
    animate the infographic (LP: #1351027)

  [ Stephen M. Webb ]
  * enables the unity8 upstart job for desktop sessions (LP: #1353041)

  [ Albert Astals ]
  * Dash Overview (LP: #1317683)
  * GenericScopeView: On click only activate scope:// uris and
    clickscope items The rest of clicks result in a preview, also
    scope:// uris don't get a preview
  * Pass the scope search hint up to the search line
 -- Ubuntu daily release <email address hidden> Mon, 11 Aug 2014 19:03:41 +0000

[Christopher Townsend (townsend)]

Marking bugs as confirmed since the associated branches *do not* fix this issue.

[Christopher Townsend (townsend)]

Since the branches associated with this bug do not fix the issue, I'm removing them to avoid confusion.

[Christopher Townsend (townsend)]

unity8.log from ~/.cache/upstart

[Gerry Boland (gerboland)]

Ok reproduced! From the backtrace, I see these 2 threads, the main thread (thread1) owns the threadpool and is waiting for one of these threads to complete. Thread 2 has a QThreadPoolThread which is blocked at QFutureInterfaceBase::waitForResult due to some PAM lightdm stuff.

Thread 2 (Thread 0x7fcd243be700 (LWP 7347)):
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007fcd6f408b03 in wait (time=18446744073709551615, this=0x7fcd4440a120) at thread/qwaitcondition_unix.cpp:136
#2 QWaitCondition::wait (this=<optimized out>, mutex=0x7fcd444254d8, time=time@entry=18446744073709551615) at thread/qwaitcondition_unix.cpp:208
#3 0x00007fcd6f3fd340 in QFutureInterfaceBase::waitForResult (this=this@entry=0x7fcd243bdae0, resultIndex=resultIndex@entry=0) at thread/qfutureinterface.cpp:313
#4 0x00007fcd39b9cbd2 in result (this=0x7fcd243bdae0) at /usr/include/x86_64-linux-gnu/qt5/QtCore/qfuture.h:171
#5 QLightDM::GreeterImpl::converseWithPam (num_msg=<optimized out>, msg=<optimized out>, resp=0x7fcd243bdb30, appdata_ptr=<optimized out>)
    at /build/buildd/unity8-8.00+14.10.20140811/tests/mocks/LightDM/demo/GreeterPrivate.cpp:153
#6 0x00007fcd3974be40 in pam_vprompt () from /lib/x86_64-linux-gnu/libpam.so.0
#7 0x00007fcd3974c05d in pam_prompt () from /lib/x86_64-linux-gnu/libpam.so.0
#8 0x00007fcd26bd647d in ?? () from /lib/x86_64-linux-gnu/security/pam_unix.so
#9 0x00007fcd26bd34fb in pam_sm_authenticate () from /lib/x86_64-linux-gnu/security/pam_unix.so
#10 0x00007fcd39746dff in ?? () from /lib/x86_64-linux-gnu/libpam.so.0
#11 0x00007fcd3974664d in pam_authenticate () from /lib/x86_64-linux-gnu/libpam.so.0
#12 0x00007fcd39b9a840 in QLightDM::GreeterImpl::authenticateWithPam (pamHandle=0x18bba70) at /build/buildd/unity8-8.00+14.10.20140811/tests/mocks/LightDM/demo/GreeterPrivate.cpp:83
#13 0x00007fcd39b9a950 in runFunctor (this=0x18c0cd0) at /usr/include/x86_64-linux-gnu/qt5/QtConcurrent/qtconcurrentstoredfunctioncall.h:265
#14 QtConcurrent::RunFunctionTask<int>::run (this=0x18c0cd0) at /usr/include/x86_64-linux-gnu/qt5/QtConcurrent/qtconcurrentrunbase.h:104
#15 0x00007fcd6f404ad2 in QThreadPoolThread::run (this=0x1855390) at thread/qthreadpool.cpp:101
#16 0x00007fcd6f407a7f in QThreadPrivate::start (arg=0x1855390) at thread/qthread_unix.cpp:345
#17 0x00007fcd6dc67165 in start_thread (arg=0x7fcd243be700) at pthread_create.c:309
#18 0x00007fcd6eb7b4dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 1 (Thread 0x7fcd7128c780 (LWP 7094)):
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007fcd6f408b03 in wait (time=18446744073709551615, this=0x18c58a0) at thread/qwaitcondition_unix.cpp:136
#2 QWaitCondition::wait (this=this@entry=0x18c6128, mutex=mutex@entry=0x18c6100, time=time@entry=18446744073709551615) at thread/qwaitcondition_unix.cpp:208
#3 0x00007fcd6f403415 in QThreadPoolPrivate::waitForDone (this=this@entry=0x18c6090, msecs=msecs@entry=-1) at thread/qthreadpool.cpp:295
#4 0x00007fcd6f4039f1 in QThreadPool::waitForDone (this=<optimized out>, msecs=msecs@entry=-1) at thread/qthreadpool.cpp:618
#...

[Gerry Boland (gerboland)]

Hmm, it's the Mock LightDM implementation being used
QLightDM::GreeterImpl::converseWithPam (num_msg=<optimized out>, msg=<optimized out>, resp=0x7fcd243bdb30, appdata_ptr=<optimized out>)
    at /build/buildd/unity8-8.00+14.10.20140811/tests/mocks/LightDM/demo/GreeterPrivate.cpp:153

[Launchpad Janitor (janitor)]

This bug was fixed in the package unity8 - 8.00+14.10.20140822-0ubuntu1

---------------
unity8 (8.00+14.10.20140822-0ubuntu1) utopic; urgency=low

  [ Albert Astals ]
  * More stable dash overview tests
  * PreviewExpandable: "widgets" is a model, not an array

  [ Alberto Aguirre ]
  * Proxy inactivity timeout values from gsettings into Unity.Screen
    (LP: #1230345)

  [ Gerry Boland ]
  * Cancel open PAM interactions on shutdown - fixes hang on logout on
    desktop (LP: #1353041)

  [ Diego Sarmentero ]
  * Show progress bar on payment button click The payment process has a
    small delay before the UI comes up which might cause confusion. Show
    a progress bar with unknown value to indicate activity. (LP:
    #1354139)

  [ Mirco Müller ]
  * Made notification qml-test pass again by using Component.onCompleted
    instead of onOpacityChanged for the time being.

  [ Michael Zanetti ]
  * Implement new lockscreen designs

  [ Michael Terry ]
  * Show the SIM unlock dialog immediately after booting, and enable its
    emergency call button.
  * Always keep indicator/launcher locked state in sync with whether the
    user is authenticated. (LP:# 1357230) (LP: #1357230)
  * Allow logging into a desktop or tablet session again, by properly
    dismissing old PAM conversations. (LP: #1350878) In a desktop or
    tablet, we were accidentally starting two PAM conversations in
    sequence on startup. Which is a small bug; it shouldn't normally be
    a problem, since each new PAM conversation should kill the old
    one.But the way we were killing the old one was subject to a thread
    race condition. See, a PAM conversation thread won't exit until all
    its prompts are answered. And what we do when we kill a PAM
    conversation is to answer all prompts with empty strings.But it's
    possible that when we want to kill a PAM conversation that it hasn't
    actually gotten to the point of prompting us yet. And when those
    prompts do come through, we were treating them as prompts for the
    new PAM conversation.So I've changed the PAM conversation logic to
    include a pam_handle and compare the handle with the current handle
    when being prompted. If it's an old handle, we just dismiss the
    prompt with an empty string response.Oh, and I fixed the bug that
    caused two prompts on startup in the first place. (But we still need
    the above logic anyway, for when you switch users quickly.) (LP:
    #1350878)

  [ Martin Pitt ]
  * Mark for using language packs.
 -- Ubuntu daily release <email address hidden> Fri, 22 Aug 2014 09:29:41 +0000