All keyboard input fails: "IBUS-WARNING **: Events queue growing too big"

[themusicgod1]

Mouse input (eg selecting cells, opening "File/Edit/View" menus, right click context menu) all works fine, but all attempts to use the keyboard (entering content to cells, moving between cells, pasting content into cells) silently fails, with an error message printed to console of

(soffice:22108): IBUS-WARNING **: Events queue growing too big, will start to drop.

about 3 times for every keystroke

Ubuntu 15.04

libreoffice-calc:
  Installed: 1:4.4.0-1ubuntu1
  Candidate: 1:4.4.0-1ubuntu1

ProblemType: Bug
DistroRelease: Ubuntu 15.04
Package: libreoffice-calc 1:4.4.0-1ubuntu1
ProcVersionSignature: Ubuntu 3.18.0-13.14-generic 3.18.5
Uname: Linux 3.18.0-13-generic x86_64
ApportVersion: 2.16.1-0ubuntu2
Architecture: amd64
CurrentDesktop: GNOME
Date: Thu Feb 12 20:28:05 2015
EcryptfsInUse: Yes
InstallationDate: Installed on 2014-07-09 (218 days ago)
InstallationMedia: Ubuntu-GNOME 14.10 "Utopic Unicorn" - Alpha amd64 (20140708)
SourcePackage: libreoffice
UpgradeStatus: No upgrade log present (probably fresh install)

[themusicgod1 (themusicgod1)]

Exact same bug on gnumeric.

[themusicgod1 (themusicgod1)]

libc6:
  Installed: 2.19-15ubuntu1
  Candidate: 2.19-15ubuntu1
libxml2:
  Installed: 2.9.2+dfsg1-3
  Candidate: 2.9.2+dfsg1-3
zlib1g:
  Installed: 1:1.2.8.dfsg-2ubuntu1
  Candidate: 1:1.2.8.dfsg-2ubuntu1
gnumeric:
  Installed: 1.12.18-1
  Candidate: 1.12.18-1

[themusicgod1 (themusicgod1)]

 export GTK_IM_MODULE=xim

executed before gnumeric/libreoffice runs seems to resolve the issue, as per https://trac.torproject.org/projects/tor/ticket/9353

[themusicgod1 (themusicgod1)]

ibus:
  Installed: 1.5.9-1ubuntu2
  Candidate: 1.5.9-1ubuntu2

[themusicgod1 (themusicgod1)]

($GTK_IM_MODULE is normally defined as "ibus").

[themusicgod1 (themusicgod1)]

odd chromium-browser does the exact same thing.

chromium-browser:
  Installed: 40.0.2214.111-0ubuntu1.1121
  Candidate: 40.0.2214.111-0ubuntu1.1121

[themusicgod1 (themusicgod1)]

empathy:
  Installed: 3.12.7-1ubuntu2
  Candidate: 3.12.7-1ubuntu2

Empathy appears also to be affected: actually seems worse than the others: the others work 100% when GTK_IM_MODULE is set as per above but empathy only works in the main window (chat windows still do not allow typing)

[themusicgod1 (themusicgod1)]

Also affects easytag.

easytag:
  Installed: 2.2.4-1ubuntu1
  Candidate: 2.2.4-1ubuntu1

I'm also noticing there might be a few keypresses that do not invoke this error, almost as if there's a buffer that gets full and then starts warning out.

[themusicgod1 (themusicgod1)]

Interestingly with easytag, navigation between different tracks on the left side is *not* affected, only text entry into the ID3 tags themselves is.

[themusicgod1 (themusicgod1)]

After closing and reopening arora (Web browser) ...ibus-daemon seems to be using 100% CPU. gdb suggests that at least part of that 100% cpu use occurs at

thread 1:
#0 0x00007f927f8c586c in g_slice_alloc (magazine_chunks=0xd065a0) at /build/buildd/glib2.0-2.43.3/./glib/gslice.c:536
#1 0x00007f927f8c586c in g_slice_alloc (tmem=<optimized out>, ix=0) at /build/buildd/glib2.0-2.43.3/./glib/gslice.c:842
#2 0x00007f927f8c586c in g_slice_alloc (mem_size=mem_size@entry=16) at /build/buildd/glib2.0-2.43.3/./glib/gslice.c:998
Python Exception <class 'TypeError'> iter() returned non-iterator of type '_iterator':
#3 0x00007f927f8c68a6 in g_slist_prepend (list=0x0, data=0x1cfb950) at /build/buildd/glib2.0-2.43.3/./glib/gslist.c:254
#4 0x00007f927f8a77a0 in g_source_add_child_source (source=0x23eb2a0, child_source=0x1cfb950) at /build/buildd/glib2.0-2.43.3/./glib/gmain.c:1406
#5 0x00007f927fe35af0 in g_socket_create_source (cancellable=0x7f9278003d70 [GCancellable], condition=(G_IO_IN | G_IO_ERR | G_IO_HUP | G_IO_NVAL), socket=0xd54280 [GSocket])
    at /build/buildd/glib2.0-2.43.3/./gio/gsocket.c:3363
#6 0x00007f927fe35af0 in g_socket_create_source (socket=0xd54280 [GSocket], condition=condition@entry=G_IO_IN, cancellable=cancellable@entry=0x7f9278003d70 [GCancellable])
    at /build/buildd/glib2.0-2.43.3/./gio/gsocket.c:3424
#7 0x00007f927fe3da54 in add_sources (listener=listener@entry=0xd53760 [GThreadedSocketService], callback=callback@entry=0x7f927fe3daf0 <accept_ready>, callback_data=callback_data@entry=0xd66d00, cancellable=cancellable@entry=0x7f9278003d70 [GCancellable], context=0x0) at /build/buildd/glib2.0-2.43.3/./gio/gsocketlistener.c:521
#8 0x00007f927fe3e535 in g_socket_listener_accept_socket_async (listener=listener@entry=0xd53760 [GThreadedSocketService], cancellable=0x7f9278003d70 [GCancellable], callback=callback@entry=0x7f927fe425a0 <g_socket_service_ready>, user_data=user_data@entry=0x0) at /build/buildd/glib2.0-2.43.3/./gio/gsocketlistener.c:749
#9 0x00007f927fe3e665 in g_socket_listener_accept_async (listener=listener@entry=0xd53760 [GThreadedSocketService], cancellable=<optimized out>, callback=callback@entry=0x7f927fe425a0 <g_socket_service_ready>, user_data=user_data@entry=0x0) at /build/buildd/glib2.0-2.43.3/./gio/gsocketlistener.c:807
#10 0x00007f927fe42509 in do_accept (service=service@entry=0xd53760 [GThreadedSocketService]) at /build/buildd/glib2.0-2.43.3/./gio/gsocketservice.c:114
#11 0x00007f927fe42635 in g_socket_service_ready (object=0xd53760 [GThreadedSocketService], result=<optimized out>, user_data=<optimized out>)
    at /build/buildd/glib2.0-2.43.3/./gio/gsocketservice.c:307
#12 0x00007f927fe43aab in g_task_return_now (task=0xd66c30 [GTask]) at /build/buildd/glib2.0-2.43.3/./gio/gtask.c:1077
#13 0x00007f927fe44126 in g_task_return (task=0xd66c30 [GTask], type=<optimized out>) at /build/buildd/glib2.0-2.43.3/./gio/gtask.c:1130
#14 0x00007f927fe3dbbc in accept_ready (accept_socket=0xd54280 [GSocket], condition=<optimized out>, user_data=0xd66c30) at /build/buildd/glib2.0-2.43.3/./gio/gsocketlistener.c:708
#15 0x00007f927fe34661 in socket_source_dispatch (source=0x24b15b0, callback=0x7f927fe3daf0 <accept_re...

[themusicgod1 (themusicgod1)]

(also: arora never did open)

[themusicgod1 (themusicgod1)]

libglib2.0-0:
  Installed: 2.43.3-1
  Candidate: 2.43.3-1

Python Exception <class 'TypeError'> iter() returned non-iterator of type '_iterator':

in the above stack trace looks particularly notable.

walking around in the function itself reveals an attempt to log an error: "fail: Error accepting connection: Too many open files". Where is this limit set?

(gdb) bt
#0 0x00007f927f0a0c8f in _int_malloc (av=0x7f927f3de760 <main_arena>, bytes=4) at malloc.c:3352
#1 0x00007f927f0a2f90 in __GI___libc_malloc (bytes=4) at malloc.c:2891
#2 0x00007f927f8aeaee in g_realloc (mem=<optimized out>, n_bytes=4) at /build/buildd/glib2.0-2.43.3/./glib/gmem.c:162
#3 0x00007f927f8c99f7 in g_string_maybe_expand (string=string@entry=0x7f92789367a0, len=len@entry=2) at /build/buildd/glib2.0-2.43.3/./glib/gstring.c:102
#4 0x00007f927f8c9a42 in g_string_sized_new (dfl_size=dfl_size@entry=2) at /build/buildd/glib2.0-2.43.3/./glib/gstring.c:127
#5 0x00007f927f8ca034 in g_string_new (init=init@entry=0x0) at /build/buildd/glib2.0-2.43.3/./glib/gstring.c:148
#6 0x00007f927f8af87c in g_log_default_handler (log_domain=log_domain@entry=0x7f927fec00b8 "GLib-GIO", log_level=log_level@entry=G_LOG_LEVEL_WARNING, message=message@entry=0x22c1cf0 "fail: Error accepting connection: Too many open files", unused_data=unused_data@entry=0x0) at /build/buildd/glib2.0-2.43.3/./glib/gmessages.c:1403
#7 0x00007f927f8aff61 in g_logv (log_domain=0x7f927fec00b8 "GLib-GIO", log_level=G_LOG_LEVEL_WARNING, format=<optimized out>, args=args@entry=0x7fff4f96d330)
    at /build/buildd/glib2.0-2.43.3/./glib/gmessages.c:1020
#8 0x00007f927f8b01cf in g_log (log_domain=log_domain@entry=0x7f927fec00b8 "GLib-GIO", log_level=log_level@entry=G_LOG_LEVEL_WARNING, format=format@entry=0x7f927fecf87b "fail: %s")
    at /build/buildd/glib2.0-2.43.3/./glib/gmessages.c:1079
#9 0x00007f927fe42683 in g_socket_service_ready (object=0xd53760 [GThreadedSocketService], result=<optimized out>, user_data=<optimized out>)
    at /build/buildd/glib2.0-2.43.3/./gio/gsocketservice.c:291
#10 0x00007f927fe43aab in g_task_return_now (task=0xd66d00 [GTask]) at /build/buildd/glib2.0-2.43.3/./gio/gtask.c:1077
#11 0x00007f927fe44126 in g_task_return (task=0xd66d00 [GTask], type=<optimized out>) at /build/buildd/glib2.0-2.43.3/./gio/gtask.c:1130
#12 0x00007f927fe3dbbc in accept_ready (accept_socket=0xd54280 [GSocket], condition=<optimized out>, user_data=0xd66d00) at /build/buildd/glib2.0-2.43.3/./gio/gsocketlistener.c:708
#13 0x00007f927fe34661 in socket_source_dispatch (source=0xd9cc00, callback=0x7f927fe3daf0 <accept_ready>, user_data=0xd66d00) at /build/buildd/glib2.0-2.43.3/./gio/gsocket.c:3265
#14 0x00007f927f8a8ddd in g_main_context_dispatch (context=0xd4bf20) at /build/buildd/glib2.0-2.43.3/./glib/gmain.c:3122
#15 0x00007f927f8a8ddd in g_main_context_dispatch (context=context@entry=0xd4bf20) at /build/buildd/glib2.0-2.43.3/./glib/gmain.c:3737
#16 0x00007f927f8a91b0 in g_main_context_iterate (context=0xd4bf20, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at /build/buildd/glib2.0-2.43.3/./glib/gmain.c:3808
#17 0x00007f927f8a94d2 in g_main_loop_run (loop=0xd657d0) at /build/buildd/glib2.0-2.4...

[themusicgod1 (themusicgod1)]

Is it possible that the attempt to log this error message tries to open a file, and fails because ...wait for it, there's no more open files allowed for the ibus/glib2 using process? (given a default ulimit -n of 1024 for this process?). And that all you need to do is to force ibus to use 1024 files at once to trigger this? Just a thought.

[themusicgod1 (themusicgod1)]

OK here's what I think happened, and why I think it has happened.

Every morning I run an emacs macro

(fset 'traverse-hyperlink-line
   (format "(shell-command \"%s \C-e & sleep 1;\")\C-x\C-e\C-f\C-p\C-k\C-d" web-browser))

that causes about 25-100 calls to web-browser(in this case arora). So long as Arora stays open, it does *not* release its file descriptors in the ibus process. You can confirm this by running emacs with a text file full of 100 URLs, opening arora(it has to be open already, otherwise it will only open one tab)

Esc-100 M-x traverse-hyperlink-line

This will open up about 100 files in the proc fdinfo directory for ibus-daemon reachable by

cd /proc/`ps -ea | grep ibus-dae | awk -F' ' '{print $1}'`/fdinfo

as counted by

ls | wc -w

This is true even after you've closed the tabs that were opened in this fashion and in fact even after you've closed arora and emacs!

[themusicgod1 (themusicgod1)]

Just confirmed it gets to 1024 and these symptoms start happening. It is reproducible from a working system if you follow the above steps, and then open libreoffice-calc and then attempt to start typing with the keyboard.

[themusicgod1 (themusicgod1)]

Apparently you don't have to invoke Arora from within emacs to trigger this: even just invoking it on the commandline will suffice.

 arora &

(wait till it opens)

here's the trigger:

 for x in `seq 1 1024` ; do arora www.purple.com/?q=$x ; sleep 2; done

arora *does* use more fds chromium-browser *does not*.

[themusicgod1 (themusicgod1)]

Firefox leaks fds but at a slower rate than arora: firefox leaks one 1 fd per session, whereas arora leaks 1 per tab. This makes it a bug for firefox (though a minor one in comparison).

firefox:
  Installed: 34.0+build2-0ubuntu2
  Candidate: 34.0+build2-0ubuntu2

[James Cowgill (jcowgill)]

Is the bug fixed if you temporarily remove ibus? It's much more likely that this is just a bug in ibus than a bug affecting this many different packages.

[themusicgod1 (themusicgod1)]

While I try to replicate without ibus(doesn't look like it's replicating without it), really there's 3 things going on here

1) ibus process fds are being used: you could see this as an ibus issue (though that wasn't certain until #17)
2) firefox and arora cause the creation of fds within the ibus process which are never cleaned up : I guess you could view that as an ibus issue, but whether it's an ibus issue or arora/firefox issue isn't clear to me
3) chromium-browser, libreoffice, empathy, easytag and gnumeric: silently failed on ibus failure(though in some cases there was a warning warning that something *could*) happen.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Matteo Dell'Amico (della)]

I'm seeing the same behavior on 16.04's evince.

[Ville Ranki (ville-ranki)]

Still happening with 18.04 with chromium-browser.

I'm running it in a network namespace in a shell started like this:

sudo -E ip netns exec myvpn su username

Is there any workaround?