unity8 leaks file descriptors cause unresponsive ui but power button works display

For completeness, here are Jean-Baptiste's findings:

"I reproduce the issue by following the "fd leak" lead with the following test case:

1. Open 2 apps
2. Switch from the app scope to app1
3. Switch from app1 to the app scope
4. Switch from the app scope to app2
5 lock the screen (optional but it leaks even more fd)

At the same time monitor the number of file descriptors used by unity8:
$ watch -n1 "ls /proc/$(pidof unity8)/fdinfo/| wc -l "

After a while unity8 runs out of fd and the system hangs. Eventually unity8 will restart a moment later."

As mentioned in the description, one way to leak fds is just opening and closing an app. It leaks an fd of type 'anon_inode:[eventfd]' per app connection. I am attaching a simple script I used to reproduce this and track it over multiple app invocations.

Sample output from a run (omitting the lsof and /proc/*/fd information) is:

#### Starting at 2015-09-15T08:10:55+0000 ####
# Before fds: 119
# During fds: 131
# After fds: 120
#### Starting at 2015-09-15T08:11:02+0000 ####
# Before fds: 120
# During fds: 133
# After fds: 121
#### Starting at 2015-09-15T08:11:09+0000 ####
# Before fds: 121
# During fds: 134
# After fds: 122
#### Starting at 2015-09-15T08:11:16+0000 ####
# Before fds: 122
# During fds: 135
# After fds: 123
...

You can clearly see unity8 leaking one fd every time the app connects and disconnects.

I don't see any eventfd() call in unity8, mir has at least two eventfd calls.

According to alf_ it can't be mir since those eventfd calls are stored in a Mir::Fd that takes care of closing them

Investigating, seems pretty clear mir is not at blame here

Watching the eventfd2 & close calls to see which one leaks:

sudo strace -p `pidof unity8` 2>&1 | grep -P "(eventfd|close)"

I get on app open:

eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 118
eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 117
close(117) = 0
eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 116
close(116) = 0

on app close:

eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 109
close(109) = 0
eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 109
close(109) = 0
eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 109
close(109) = 0
eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 109
close(109) = 0

I saw no close call for FD 118 - the first one.

In gdb the first eventfd call on app launch has this backtrace:

Breakpoint 1, 0xb614ae36 in eventfd () from /lib/arm-linux-gnueabihf/libc.so.6
(gdb) bt
#0 0xffffffff in eventfd () at /lib/arm-linux-gnueabihf/libc.so.6
#1 0xffffffff in g_wakeup_new () at /build/buildd/glib2.0-2.44.1/./glib/gwakeup.c:146
#2 0xffffffff in g_main_context_new () at /build/buildd/glib2.0-2.44.1/./glib/gmain.c:624
#3 0xffffffff in cgroup_manager_connection () at /build/ubuntu-app-launch-qvXALV/ubuntu-app-launch-0.5+15.04.20150827/helpers-shared.c:153
#4 0xffffffff in pids_for_appid (appid=appid@entry=0xa1f1e8 "dialer-app") at /build/ubuntu-app-launch-qvXALV/ubuntu-app-launch-0.5+15.04.20150827/libubuntu-app-launch/ubuntu-app-launch.c:1515
#5 0xffffffff in ubuntu_app_launch_pid_in_app_id (pid=17487, appid=0xa1f1e8 "dialer-app") at /build/ubuntu-app-launch-qvXALV/ubuntu-app-launch-0.5+15.04.20150827/libubuntu-app-launch/ubuntu-app-launch.c:1576
#6 0xffffffff in qtmir::upstart::ApplicationController::appIdHasProcessId(int, QString const&) (this=<optimized out>, pid=17487, appId=...) at /home/gerry/dev/projects/qtmir/multimonitor/src/modules/Unity/Application/upstart/applicationcontroller.cpp:180
#7 0xffffffff in qtmir::TaskController::appIdHasProcessId(QString const&, unsigned long long) const (this=this@entry=0x61b138, appId=..., pid=<optimized out>) at /home/gerry/dev/projects/qtmir/multimonitor/src/modules/Unity/Application/taskcontroller.cpp:94
#8 0xffffffff in qtmir::ApplicationManager::authorizeSession(unsigned long long, bool&) (this=0x618328, pid=<optimized out>, authorized=@0xadefeb2c: false) at /home/gerry/dev/projects/qtmir/multimonitor/src/modules/Unity/Application/application_manager.cpp:557
#9 0xffffffff in QMetaCallEvent::placeMetaCall(QObject*) (a=<optimized out>, r=0x618328, this=0x62c248) at ../../include/QtCore/../../src/corelib/kernel/qobject_impl.h:124
#10 0xffffffff in QMetaCallEvent::placeMetaCall(QObject*) (this=<optimized out>, object=0x618328) at kernel/qobject.cpp:483
#11 0xffffffff in QObject::event(QEvent*) (this=<optimized out>, e=<optimized out>) at kernel/qobject.cpp:1245
#12 0xffffffff in QCoreApplication::notify(QObject*, QEvent*) (this=<optimized out>, receiver=<optimized out>, event=<optimized out>) at kernel/qcoreapplication.cpp:997
#13 0xffffffff in QCoreApplication::notifyInternal(QObject*, QEvent*) (this=0x518f00, receiver=receiver@entr...

From Gerry's backtrace it is clear that the fd leak we get when opening/closing apps can be traced back to u-a-l.

However, Jean-Baptiste found a few other scenarios (see first comment) that lead to leaked fds. Have we confirmed that all the leaks in these scenarios can be traced back to this u-a-l leak? If not, we need to ensure this is reflected in the bug status (by keeping unity8 as affected), or opening a new bug report.

had a question earlier today also if this was on stable (ota6) i just confirmed it is.

> Have we confirmed that all the leaks in these scenarios can be traced back to this u-a-l leak?
No we have not, it'll be easier once this one has been fixed, but given we don't use eventfd nor glib extensibly, there's a high chnange this is not in unity8 itself

> If not, we need to ensure this is reflected in the bug status (by keeping unity8 as affected), or opening a new bug report.
I guess this is a matter of taste, feel free to re-add it if you prefer.

>> If not, we need to ensure this is reflected in the bug status (by keeping unity8 as affected), or opening a new bug report.
> I guess this is a matter of taste, feel free to re-add it if you prefer.

I just want to make sure we track this properly, not close it when the u-a-l part is fixed (unless, of course, u-a-l turns out to be the source of all our leak instances). I guess tracking it in "Canonical System Image" should be enough for this.

I can confirm that Ted's branch seems to fix all the fd leaking for me. A second source would be cool.

It's a bit unfortunate we need ~8 fd per app though, may we need to optimize that at some point in the future.

s/second source/second confirmation

On Wed, 2015-09-16 at 15:22 +0000, Albert Astals Cid wrote:

> It's a bit unfortunate we need ~8 fd per app though, may we need to
> optimize that at some point in the future.

It will go down a bunch with the switch to systemd as we can request on
the system bus instead of building a custom dbus peer-to-peer connection
with CGManager.

using ted's branch
https://code.launchpad.net/~ted/ubuntu-app-launch/lp1495871-unref-context-15.04/+merge/271373
which is conveniently available in silo 60
i tested using the script above to open/close apps...which kept the number of open fd's to a steady state

however, i then modified the script to not open/close apps and just poop out the unity8 process # of open fds
I then manually opened as many apps as possible/available on the basic image
I then watched the ubuntu-app-watch output & ubuntu-app-list to make sure apps were getting closed due to memory pressure, i then would use the spread and pull up the very "last" or front app in spread (e.g. all the way to the right in the spread) app to make sure i was cycling between all the apps available in the spread
when i started with no apps open it was posted 135 fds open, at some point after opening all the apps fresh(no toggling yet) it was at ~200+, upon toggling the number of fds grew to 480, i stopped toggle, allowed steady state/screen blanked...it remained at 480. Then i swiped away every available app in the spread, which reduced the number of open fds down to 255. So that's 120 fds orphaned. Not sure if these are associated with screen shots in the spread or ual somehow.

just out of curiosity, i set up the phone sim, sent text messages - since that's when this seems to happen the most
the fds for unity8 would jump up by 1 but eventually drop back down by one.
I also watched the fd count for message+ & indicator-message-service which stayed constant with sending text messages - altho maybe these aren't the right processes to watch?

ok, watched pulseaudio and mediahub-server using the phonesim
pulseaudio was fine
media-hub-server was leaking fds, leaking 2 per text message alert & phone call

If it's useful to anyone, here is a small script to track the number of fd used per process. By default t takes a sample every 5 minutes. Then you can diff the logs to find which process is suspicious.

The leaks in unity8 when the memory pressure is high can be easily reproduced by:
 * Be on dash
 * Open an app
 * Switch to he dash
 * Use kill -9 to fill the app

We're leaking an anon_inode:dmabuf fd each time that happens.

removing media-hub, spawing bug 1496894

The anon_inode:dmabuf i mention in #18 is not leaked anymore if we make ApplicationScreenshotProvider::requestImage return an empty QImage and is still leaked if we return a QImage with junk data (without calling mir::screenshot) so it seems it's not mir.

I'm investigating now if it's either qtmir, unity8, qt or it's not a fd leak at all and it's just the image cache of Qt being used.

Adding qtmir since i can make the anon_inode:dmabuf fd not leak by making qtmir not free early the session when the app is killed.

FWIW the ubuntu-app-launch fix has landed in the vivid image

I've found two ways (which are effectively the same) to workaround the fd leak caused by killing an app (comment #18)
 * removing surfaceItem.surface = null; in unity8 SurfaceContainer.qml
 * removing the 3 deleteLater in qtmir session.cpp

Both have the same effect. qtmir's session and mirsurface won't be freed when the application is killed, just when the user actually swipes down from the side spread, by doing that the fd leak is gone.

It has two problems:
 * We are delaying freeing memory resources and since the most common occurrence of apps being killed is by the OOM, this is not good
 * If you try to restart the app without swiping down from the side spread, unity8 will crash because the mir surface item has bad data, i think this could be fixed, but the first problem seems strong enough to disqualify these solutions.

The workaround seem to imply that something is wrong when the early free for killed apps is done.

I've read the code and to my non-domain-expert-eye it all seems good.

Valgrind could not find any memory or fd leak either.

Maybe someone from the mir/qtmir fields can have a look at the early free code for killed apps and see if they see anything wrong?

unfortunately gerry's probably the best expert but out, assigning to daniel in hopes he can make some progress

Using comment #18 on arale, I find roughly three fds are leaked at a time:

> lrwx------ 1 phablet phablet 64 Sep 22 07:49 135 -> anon_inode:dmabuf
> lrwx------ 1 phablet phablet 64 Sep 22 07:49 138 -> /dev/pvrsrvkm
> lrwx------ 1 phablet phablet 64 Sep 22 07:49 139 -> /dev/pvrsrvkm

Apparently we fixed a very similar bug on desktop two years ago --> bug 1185183

Invalid for qtmir, but it does seem to be a Mir issue... See bug 1498361.

Actually there might still be a qtmir-specific leak but we need to fix the leaks seen in plain Mir too --> bug 1498361

Considering bug 1498816, and the new-ish bufferstream logic in Mir's SessionMediator, I'm suspicious that Mir might just be indefinitely bloated, never releasing some resources until shutdown. It's a bit scary that the bufferstream logic is passing around raw pointers without any clear ownership. We may well be holding some for too long. Which is exactly the kind of resource that would be seen as "anon_inode:dmabuf".

Mir does associate resources with a client socket that are not released until one of two things happen:

1. The client explicitly disconnects
2. An operation (like the outstanding read attempt) on the socket reports an error

AFAIK there is no *guarantee* that the latter happens in a timely manner when a client disconnects abruptly.

Note that tools like valgrind (memcheck) are unlikely to find the problem. Because C++ and RAII... the offending resources get released on shutdown and never actually leaked. So instead of leaks, you have to hunt for "bloat" and use a memory/resource profiler.

I got distracted for a long time finding lots of similar but unrelated erratic bloat in Mir demo servers on Android. But I think those are specific to Mir demos and not Unity8. Seems plausible Unity8 is possibly avoiding some Mir logic that's bloaty in its own right.

Next stop: Rebuild a qtmir development environment and investigate the snapshot stuff. In theory if the snapshot code is leaking a buffer then that would explain the anon_inode:dmabuf handle. However it's not just the snapshot code but also bug 1498816 and how that affects SessionMediator that's concerning.

Handy tip:
You can see the call stack of (many but not all) fds unity8 has open while it's running. Just start unity8 under valgrind with --track-fds=yes. Then you can get the live list of fds with their backtraces:

    vgdb v.info open_fds

Annoyingly this doesn't show the dmabuf ones we're looking for.

Dropped severity because the bug requires significant time to occur, if at all.

Just noting, i agree with drop in priority, since we have a fix for u-a-l and that was the original culprit.
we do need to eventually get this nailed, so please keep this as a front burner activity

aacid:
Can you please test the attached proposed branches? I'm wondering if I'm imaging things when it seems fixed.

*imagining*

I can confirm that the fd leaking on killing apps like explained in comment #18 also seems to stop for me when using https://code.launchpad.net/~dandrader/qtmir/textureCleanUp-lp1499388/+merge/272452

Awesomtastic

This bug was fixed in the package qtmir - 0.4.6+15.10.20150930.1-0ubuntu1

---------------
qtmir (0.4.6+15.10.20150930.1-0ubuntu1) wily; urgency=medium

  [ CI Train Bot ]
  * New rebuild forced.

  [ Daniel d'Andrada ]
  * MirSurfaceItem: texture must be manipulated only from the scene
    graph thread (LP: #1499388, #1495871)

  [ Gerry Boland ]
  * Add "Closing" state to Application, use it to distinguish user-
    induced close from app-induced close. Don't clear QML cache if user-
    induced. (LP: #1500372)

 -- Michał Sawicz <email address hidden> Wed, 30 Sep 2015 10:08:37 +0000