EnpassNMHost consumes 100% on 64-bit Linux

Ben Klaasen · March 16, 2018

Hi -

I've been a happy, paid-up Enpass user for several years. I'm using it on several Linux machines - mostly 64-bit Xubuntu 16.04 and 17.10 and a 17.10 Kubuntu machine. All of the machines are configured to use Enpass from the PPA at http://repo.sinew.in/. They're all using Enpass 5.6.5.

Recently I've noticed that EnpassNMHost can get into a loop, consuming 100% of a CPU core until it's killed. I've seen this happen on at least three of the machines; the others could also be exhibiting the bug, but I don't monitor them as often.

What can I do to help you diagnose this issue?

Anshu kumar · March 19, 2018

Hi @Ben Klaasen

We are already tracking this issue, but haven't found anything conclusive yet here on our test systems. It would be a great help if you can share the exact steps that lead to this behavior. e.g: When you bring the system back up from sleep or when you start Enpass for the first time or when the app is running for long time or any other specific scenario.

Thanks for your co-operation.

artemisbot · March 29, 2018

I use Firefox on Arch Linux with Enpass. When I force close the Firefox process from my WM, this is when Enpass begins using 100% of one of my threads. Only solution is to kill the process entirely.

Ben Klaasen · March 29, 2018

Well spotted, @artemisbot. I'll attempt to repro on Ubuntu. More info to follow.

joueiuqidua · April 9, 2018

I've been encountering the same issue. Since I have a process running now consuming 100% CPU, I thought I'd use some system tools to generate diagnostic output that can hopefully get to the bottom of this.

GDB:

(gdb) thread apply all bt

Thread 2 (Thread 0x7f26d0aa3700 (LWP 24640)):
#0  0x00007f26d3ee406d in __GI___libc_read (fd=0, buf=0x7f26cc0051d0, nbytes=4096) at ../sysdeps/unix/sysv/linux/read.c:26
#1  0x00007f26d3e649a0 in _IO_new_file_underflow (fp=0x7f26d41ba9e0 <_IO_2_1_stdin_>) at fileops.c:584
#2  0x00007f26d3e63108 in __GI__IO_file_xsgetn (fp=0x7f26d41ba9e0 <_IO_2_1_stdin_>, data=<optimized out>, n=4) at fileops.c:1406
#3  0x00007f26d3e56f49 in __GI__IO_fread (buf=<optimized out>, size=1, count=4, fp=0x7f26d41ba9e0 <_IO_2_1_stdin_>) at iofread.c:38
#4  0x00007f26d44c545d in __gnu_cxx::stdio_sync_filebuf<char, std::char_traits<char> >::xsgetn(char*, long) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007f26d44d3e9b in std::istream::read(char*, long) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#6  0x0000000000405880 in StdinReadWorker::run() ()
#7  0x00007f26d4a26729 in ?? () from /opt/Enpass/lib/libQt5Core.so.5
#8  0x00007f26d47647fc in start_thread (arg=0x7f26d0aa3700) at pthread_create.c:465
#9  0x00007f26d3ef4b5f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 1 (Thread 0x7f26d5810b80 (LWP 24635)):
#0  0x00007f26d3ee8951 in __GI___poll (fds=0xab97c0, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00007f26d0d61169 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#2  0x00007f26d0d6127c in g_main_context_iteration () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#3  0x00007f26d4c38f07 in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /opt/Enpass/lib/libQt5Core.so.5
#4  0x00007f26d4be776a in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /opt/Enpass/lib/libQt5Core.so.5
#5  0x00007f26d4bef5fd in QCoreApplication::exec() () from /opt/Enpass/lib/libQt5Core.so.5
#6  0x0000000000403afc in main ()

strace:

> sudo strace -s 99 -ffp 24635
strace: Process 24635 attached with 2 threads
[pid 24640] read(0,  <unfinished ...>
[pid 24635] restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
[pid 24640] <... read resumed> ".\0\0\0", 4096) = 4
[pid 24640] read(0, "\"9nL/2uue2i/ApyvQklTLkE5a1ufk65/RiDhuxovtCpE=\"", 4096) = 46
[pid 24640] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] <... restart_syscall resumed> ) = 1
[pid 24640] read(0,  <unfinished ...>
[pid 24635] read(4, "\1\0\0\0\0\0\0\0", 16) = 8
[pid 24635] getppid()                   = 24308
[pid 24635] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] openat(AT_FDCWD, "/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0640) = -1 EEXIST (File exists)
[pid 24635] stat("/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", {st_mode=S_IFREG|0640, st_size=0, ...}) = 0
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|IPC_EXCL|0600) = -1 EEXIST (File exists)
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|0600) = -1 EACCES (Permission denied)
[pid 24635] write(1, "\202\0\0\0\"wXLrXGGjLYpNIlPpwZKhF+GPQ7UnKiY8dLjSK7y0j8ttejcOHlUmvq2ptzA6qlVuIv34+Ebzrt+hTTwhy0C0Ym8PwKh1Mv"..., 134) = 134
[pid 24635] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] poll([{fd=4, events=POLLIN}], 1, 0) = 1 ([{fd=4, revents=POLLIN}])
[pid 24635] read(4, "\2\0\0\0\0\0\0\0", 16) = 8
[pid 24635] poll([{fd=4, events=POLLIN}], 1, -1 <unfinished ...>
[pid 24640] <... read resumed> ".\0\0\0", 4096) = 4
[pid 24640] read(0, "\"9nL/2uue2i/ApyvQklTLkE5a1ufk65/RiDhuxovtCpE=\"", 4096) = 46
[pid 24640] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] <... poll resumed> )        = 1 ([{fd=4, revents=POLLIN}])
[pid 24640] read(0,  <unfinished ...>
[pid 24635] read(4, "\1\0\0\0\0\0\0\0", 16) = 8
[pid 24635] getppid()                   = 24308
[pid 24635] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] openat(AT_FDCWD, "/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0640) = -1 EEXIST (File exists)
[pid 24635] stat("/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", {st_mode=S_IFREG|0640, st_size=0, ...}) = 0
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|IPC_EXCL|0600) = -1 EEXIST (File exists)
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|0600) = -1 EACCES (Permission denied)
[pid 24635] write(1, "\202\0\0\0\"wXLrXGGjLYpNIlPpwZKhF+GPQ7UnKiY8dLjSK7y0j8ttejcOHlUmvq2ptzA6qlVuIv34+Ebzrt+hTTwhy0C0Ym8PwKh1Mv"..., 134) = 134
[pid 24635] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] poll([{fd=4, events=POLLIN}], 1, 0) = 1 ([{fd=4, revents=POLLIN}])
[pid 24635] read(4, "\2\0\0\0\0\0\0\0", 16) = 8
[pid 24635] poll([{fd=4, events=POLLIN}], 1, -1 <unfinished ...>
[pid 24640] <... read resumed> ".\0\0\0", 4096) = 4
[pid 24640] read(0, "\"9nL/2uue2i/ApyvQklTLkE5a1ufk65/RiDhuxovtCpE=\"", 4096) = 46
[pid 24640] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] <... poll resumed> )        = 1 ([{fd=4, revents=POLLIN}])
[pid 24640] read(0,  <unfinished ...>
[pid 24635] read(4, "\1\0\0\0\0\0\0\0", 16) = 8
[pid 24635] getppid()                   = 24308
[pid 24635] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] openat(AT_FDCWD, "/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0640) = -1 EEXIST (File exists)
[pid 24635] stat("/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", {st_mode=S_IFREG|0640, st_size=0, ...}) = 0
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|IPC_EXCL|0600) = -1 EEXIST (File exists)
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|0600) = -1 EACCES (Permission denied)
[pid 24635] write(1, "\202\0\0\0\"wXLrXGGjLYpNIlPpwZKhF+GPQ7UnKiY8dLjSK7y0j8ttejcOHlUmvq2ptzA6qlVuIv34+Ebzrt+hTTwhy0C0Ym8PwKh1Mv"..., 134) = 134
[pid 24635] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] poll([{fd=4, events=POLLIN}], 1, 0) = 1 ([{fd=4, revents=POLLIN}])
[pid 24635] read(4, "\2\0\0\0\0\0\0\0", 16) = 8
[pid 24635] poll([{fd=4, events=POLLIN}], 1, -1 <unfinished ...>
[pid 24640] <... read resumed> ".\0\0\0", 4096) = 4
[pid 24640] read(0, "\"9nL/2uue2i/ApyvQklTLkE5a1ufk65/RiDhuxovtCpE=\"", 4096) = 46
[pid 24640] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] <... poll resumed> )        = 1 ([{fd=4, revents=POLLIN}])
[pid 24640] read(0,  <unfinished ...>
[pid 24635] read(4, "\1\0\0\0\0\0\0\0", 16) = 8
[pid 24635] getppid()                   = 24308
[pid 24635] write(4, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 24635] openat(AT_FDCWD, "/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0640) = -1 EEXIST (File exists)
[pid 24635] stat("/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3", {st_mode=S_IFREG|0640, st_size=0, ...}) = 0
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|IPC_EXCL|0600) = -1 EEXIST (File exists)
[pid 24635] semget(0x731919b6, 1, IPC_CREAT|0600) = -1 EACCES (Permission denied)

/proc/PID/stack:

[<ffffffff9986d5a5>] poll_schedule_timeout+0x45/0x70
[<ffffffff9986e8d0>] do_sys_poll+0x3c0/0x580
[<ffffffff9986ead9>] do_restart_poll+0x49/0x80
[<ffffffff99698b95>] sys_restart_syscall+0x25/0x30
[<ffffffff99603ad7>] do_syscall_64+0x67/0x130
[<ffffffff9a00024d>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

joueiuqidua · April 9, 2018

As a follow-up to my previous post, I should note that I have two user accounts on this system (Ubuntu 17.10) and each of them use Enpass. PID 24635 is owned by Alice, but the file noted in the strace output (/tmp/qipc_systemsem_NativeMessagingSharedMemory7803fea57be87205d085c7bf68ef61263349c3d3) is owned by Bob. The permissions on the file are 0640 and the file is owned by bob:bob.

The EnpassNMHost process from both users is consuming 100%. From the Bob side of things, we have:

GDB:

(gdb) thread apply all bt

Thread 2 (Thread 0x7fabd4010700 (LWP 27418)):
#0  0x00007fabd73dc453 in __GI___libc_free (mem=<optimized out>) at malloc.c:3146
#1  0x000000000040597c in StdinReadWorker::run() ()
#2  0x00007fabd7f93729 in ?? () from /opt/Enpass/lib/libQt5Core.so.5
#3  0x00007fabd7cd17fc in start_thread (arg=0x7fabd4010700) at pthread_create.c:465
#4  0x00007fabd7461b5f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 1 (Thread 0x7fabd8d7db80 (LWP 27413)):
#0  0x00007fabd7455951 in __GI___poll (fds=0x13577c0, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00007fabd42ce169 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#2  0x00007fabd42ce27c in g_main_context_iteration () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#3  0x00007fabd81a5f07 in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /opt/Enpass/lib/libQt5Core.so.5
#4  0x00007fabd815476a in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /opt/Enpass/lib/libQt5Core.so.5
#5  0x00007fabd815c5fd in QCoreApplication::exec() () from /opt/Enpass/lib/libQt5Core.so.5
#6  0x0000000000403afc in main ()

/proc/PID/stack:

[<ffffffff9986d5a5>] poll_schedule_timeout+0x45/0x70
[<ffffffff9986e8d0>] do_sys_poll+0x3c0/0x580
[<ffffffff9986ead9>] do_restart_poll+0x49/0x80
[<ffffffff99698b95>] sys_restart_syscall+0x25/0x30
[<ffffffff9a0001a1>] entry_SYSCALL_64_fastpath+0x24/0xab
[<ffffffffffffffff>] 0xffffffffffffffff

Unfortunately, I can't get any strace output from Bob's process.

Anshu kumar · April 11, 2018

Hi @joueiuqidua,

Thanks for sharing the logs.

I've forwarded it to the dev team to look into it. I'll keep you updated.

Till then please bear with us.

jumi · April 12, 2018

Hi, fyi, on Manjaro Linux 64 bits... working without problems :-)

artemisbot · June 15, 2018

Hi @Anshu kumar have you guys had any luck with fixing this? I've had to stop using Enpass' Firefox extension for the time being, as my laptop becomes unusable.

Sign In

EnpassNMHost consumes 100% on 64-bit Linux

Recommended Posts

Ben Klaasen

Anshu kumar

artemisbot

Ben Klaasen

joueiuqidua

joueiuqidua

Anshu kumar

jumi

artemisbot

Browse

Activity