su starts behaving oddly sometimes on F19

Adam Williamson awilliam at redhat.com
Mon May 20 19:41:23 UTC 2013


On Mon, 2013-05-20 at 12:29 -0700, Adam Williamson wrote:

> [root at adam Beta-RC2]# strace -p 22182
> Process 22182 attached
> restart_syscall(<... resuming interrupted call ...>) = 0
> open("/run/gdm/auth-for-adamw-szT11D/database-c", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
> rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
> rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0
> open("/run/gdm/auth-for-adamw-szT11D/database-c", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
> rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
> rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0
> open("/run/gdm/auth-for-adamw-szT11D/database-c", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
> rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
> rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0
> open("/run/gdm/auth-for-adamw-szT11D/database-c", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
> rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
> rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0
> open("/run/gdm/auth-for-adamw-szT11D/database-c", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
> rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
> rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0
> open("/run/gdm/auth-for-adamw-szT11D/database-c", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
> rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
> rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0
> open("/run/gdm/auth-for-adamw-szT11D/database-c", O_WRONLY|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
> rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
> rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0
> write(2, "/usr/bin/xauth:  timeout in lock"..., 91) = -1 EBADF (Bad file descriptor)
> write(2, "\0", 1)                       = -1 EBADF (Bad file descriptor)
> exit_group(1)                           = ?
> +++ exited with 1 +++
> 
> The actual child process that is run is:
> 
> /usr/bin/xauth -f /run/gdm/auth-for-adamw-szT11D/database nlist :0
> 
> If we look at the permissions:
> 
> [root at adam Beta-RC2]# ls -lZ /run/gdm/auth-for-adamw-szT11D/database 
> -rw-------. adamw adamw system_u:object_r:xdm_var_run_t:s0 /run/gdm/auth-for-adamw-szT11D/database
> [root at adam Beta-RC2]# ls -dlZ /run/gdm/auth-for-adamw-szT11D/
> drwx--x--x. adamw adamw system_u:object_r:xdm_var_run_t:s0 /run/gdm/auth-for-adamw-szT11D/
> 
> note, the file is just 'database', while the strace shows 'database-c';
> I don't know if that's significant.

So ajax points out that the 'database-c' thing could be caused by "the
'-c' from su's argv not getting a space before it". Sounds good, but
you'd think that would happen *all the time*, and this bug doesn't
happen all the time.

One thing I neglected to note is where precisely the slowness occurs:
what happens is that after each of those:

nanosleep({2, 0}, 0x7fff8b56d5c0)       = 0

lines, the xauth process just sits there not doing anything for a second
or two. So it tries seven times, sleeping for a couple of seconds after
each failure, and that's the delay. So a possible theory is that the
'database-c' thing always happens, but for some other reason, xauth does
not always sleep after a failure to read that non-existent file; in that
case we have two issues to track down, first fix the erroneous -c thing,
then find out why xauth decides to start sleeping after a failure. But
we're still theorizing at present.
-- 
Adam Williamson
Fedora QA Community Monkey
IRC: adamw | Twitter: AdamW_Fedora | identi.ca: adamwfedora
http://www.happyassassin.net



More information about the devel mailing list