keybase / client

Keybase Go Library, Client, Service, OS X, iOS, Android, Electron
BSD 3-Clause "New" or "Revised" License
8.92k stars 1.23k forks source link

Active passphrase window prevents suspend on Ubuntu 14.04.4 LTS #2859

Open RaymondKroon opened 8 years ago

RaymondKroon commented 8 years ago

Keybase GUI Version: 1.0.15-20160517160055+08d3795

Passphrase window

I don't have to much info, but an IO error immediately resumes my machine when suspending with the window open. If I close it, suspends works as normal.

Sat May 21 15:47:17 CEST 2016: performing suspend
sh: echo: I/O error
Sat May 21 15:47:38 CEST 2016: Awake.
Sat May 21 15:47:38 CEST 2016: Running hooks for resume
cjb commented 8 years ago

Could you attach dmesg? You could also share it in a private KBFS folder with me (cjb on Keybase), since the output could be sensitive.

RaymondKroon commented 8 years ago

I have shared it with you

cjb commented 8 years ago

CC @strib

Thanks, I got it. Here's the relevant section:

[45561.396672] PM: Syncing filesystems ... done.
[45561.459622] PM: Preparing system for mem sleep
[45562.089460] Freezing user space processes ... 
[45582.081017] Freezing of tasks failed after 20.002 seconds (1 tasks refusing to freeze, wq_busy=0):
[45582.081060] zeitgeist-datah D ffff88042fa130c0     0  5125   4130 0x00000004
[45582.081062]  ffff8803853b3a38 0000000000000082 ffff880402605bb0 ffff8803853b3fd8
[45582.081063]  00000000000130c0 00000000000130c0 ffffffff81c1a480 ffff8800bd6ee000
[45582.081065]  ffff8803d125e000 ffff8803853b3a60 ffff8800bd6ee0e0 ffff8800bd6ee000
[45582.081066] Call Trace:
[45582.081072]  [<ffffffff817723a9>] schedule+0x29/0x70
[45582.081075]  [<ffffffff812c5a45>] __fuse_request_send+0x115/0x280
[45582.081078]  [<ffffffff810b6c80>] ? prepare_to_wait_event+0x100/0x100
[45582.081080]  [<ffffffff812c5bc2>] fuse_request_send+0x12/0x20
[45582.081082]  [<ffffffff812cbada>] fuse_lookup_name+0x13a/0x2d0
[45582.081083]  [<ffffffff812cbcaf>] fuse_lookup+0x3f/0x120
[45582.081086]  [<ffffffff811e049d>] lookup_real+0x1d/0x50
[45582.081088]  [<ffffffff811e0e03>] __lookup_hash+0x33/0x40
[45582.081090]  [<ffffffff8176a6b3>] lookup_slow+0x42/0xa7
[45582.081091]  [<ffffffff811e363a>] link_path_walk+0x86a/0x8b0
[45582.081093]  [<ffffffff810a0629>] ? ttwu_do_wakeup+0x19/0xe0
[45582.081095]  [<ffffffff811e36db>] path_lookupat+0x5b/0x790
[45582.081096]  [<ffffffff81088874>] ? wake_up_worker+0x24/0x30
[45582.081098]  [<ffffffff810895ab>] ? insert_work+0x6b/0xb0
[45582.081101]  [<ffffffff81012627>] ? __switch_to+0x167/0x5b0
[45582.081102]  [<ffffffff811b9815>] ? kmem_cache_alloc+0x35/0x1f0
[45582.081104]  [<ffffffff811e6a4f>] ? getname_flags+0x4f/0x1a0
[45582.081105]  [<ffffffff811e3e3b>] filename_lookup+0x2b/0xc0
[45582.081106]  [<ffffffff811e78e4>] user_path_at_empty+0x54/0x90
[45582.081109]  [<ffffffff81101582>] ? from_kgid_munged+0x12/0x20
[45582.081110]  [<ffffffff811dbf1d>] ? cp_new_stat+0x13d/0x160
[45582.081112]  [<ffffffff811e7931>] user_path_at+0x11/0x20
[45582.081113]  [<ffffffff811dbac0>] vfs_fstatat+0x50/0xa0
[45582.081115]  [<ffffffff811dbf5f>] SYSC_newstat+0x1f/0x40
[45582.081116]  [<ffffffff811dc1ae>] SyS_newstat+0xe/0x10
[45582.081118]  [<ffffffff8177640d>] system_call_fastpath+0x1a/0x1f
[45582.081154] 
[45582.081154] Restarting tasks ... done.
[45582.091484] video LNXVIDEO:00: Restoring backlight state

So, zeitgeist (a file indexer) tries to open a file under KBFS. The IO access is blocked while we pop up a pinentry. The system tries to suspend, but Zeitgeist is in D state and refuses to freeze, and the suspend aborts.

cjb commented 8 years ago

@strib @patrickxb Any thoughts on e.g. making pinentry time out after a while to help make this less likely? (Which would fail the IO operation.)

patrickxb commented 8 years ago

Enabling the passphrase secret store on non-osx would also solve this problem for those users willing to use it.

strib commented 8 years ago

@cjb That would be ok if the timeout were long enough -- e.g., people need time to paste stuff in from password managers without it being annoying.

I think I would also be ok with the pinentry being completely asynchronous, and failing whatever FS operation caused it. We might need to limit the KBFS exponential backoff time while waiting for login in that case (though it might just work, since I think we react the login events as well).

Though I don't totally understand why zeitgeist was able to cause a pinentry popup -- why wasn't there a pinentry popup on Keybase startup? Maybe the zeitgeist call is just blocking on the pinentry that popped up on startup.

cjb commented 8 years ago

Oh yeah, your last paragraph makes sense, @strib. I agree that's likely what happened.

RaymondKroon commented 8 years ago

In a perfect world I would enter my pin at startup, because it does trigger at startup. However, I might just close it because I don't feel like looking up the password. That is likely what happened when this occurred.

cjb commented 8 years ago

Closing it should unblock the I/O (by failing it), so I think you'd have to have the dialog open but untouched when you suspend..

RaymondKroon commented 8 years ago

It looks like that the update outdated version window also triggers pin entry? That could explain that it occurs more often than only after reboots.