su starts behaving oddly sometimes on F19

Daniel J Walsh dwalsh at redhat.com
Tue May 21 13:22:00 UTC 2013


-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 05/20/2013 03:29 PM, Adam Williamson wrote:
> On Fri, 2013-05-17 at 12:33 +0200, Tomas Mraz wrote:
>> On Thu, 2013-05-16 at 22:29 -0700, Adam Williamson wrote:
>>> This is a weird bug I've seen 3 or 4 times since upgrading to F19, and 
>>> am having trouble pinning down.
>>> 
>>> Occasionally, after my session has been up for some time, runs of 'su' 
>>> start behaving oddly. After I enter the root password, it takes a long 
>>> time - longer than the delay that's always happened when you
>>> fat-finger your password, even - before it succeeds. Usually, of
>>> course, it's instant. But when this bug happens, I just get to sit
>>> there while it thinks about it for like 10-15 seconds before I
>>> eventually get a root prompt.
>>> 
>>> This only applies to my desktop session - but it applies to any
>>> terminal running in the desktop. At least, it applies to gnome-terminal
>>> (even if closed and opened again) and xterm. But if I go to
>>> ctrl-alt-f2, login, and run an 'su', that still returns instantly.
>>> 
>>> I've tried strace'ing su, but interestingly, I can't get it to work: 
>>> running su via strace always seems to result in "Authentication 
>>> failure" (which doesn't display this bug; it's only _normally_ slow,
>>> the same slowness that has always been the case when you fail the
>>> password).
>>> 
>>> So I'm kinda stuck, really. Has anyone else seen this? Any bright
>>> ideas for debugging it? Thanks!
>> 
>> Try attaching the strace (as root) to the su process when it waits for 
>> the password.
> 
> Wow, that's a good (and obvious) idea. *smacks self on forehead*
> 
> So that works indeed, and now I can see where the pause is. Relevant 
> snippet: = 0 stat("/root/.xauth/import", 0x7fff660f8b70) = -1 ENOENT (No
> such file or directory) getgid()                                = 1001 
> getuid()                                = 1001 pipe([4, 6])
> = 0 pipe([7, 8])                            = 0 clone(child_stack=0,
> flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
> child_tidptr=0x7f2a174b9a10) = 15192 close(4)
> = 0 close(8)                                = 0 close(6)
> = 0 read(7,
> 
> ** PAUSE HERE **
> 
> "", 2048)                       = 0 --- SIGCHLD {si_signo=SIGCHLD,
> si_code=CLD_EXITED, si_pid=15192, si_status=1, si_utime=0, si_stime=0} --- 
> close(7)                                = 0
> 
> So it forks off a child, and pauses while that child runs. So I did it 
> again, and straced the child process, and here's what I get:
> 
> [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.
> 
> SELinux doesn't seem to be involved here, or at least, 'setenforce 
> Permissive' doesn't make the problem go away. I note in the 'broken' state
> some other stuff doesn't work either, though some of these may be other
> bugs. One that's very likely related is that I have a dumb hack set up to
> isolate facebook from the rest of my web use (for privacy reasons); a user
> account called 'facebook' and a little script called
> /usr/local/bin/facebook which just does this:
> 
> #!/bin/sh su facebook -c "firefox http://www.facebook.com"
> 
> my main user account never goes to facebook.com and has it blocked seven 
> ways from Sunday using noscript and adblock. Anyhow, when I'm seeing this
> problem with a plain 'su', that dumb facebook trick doesn't work any more:
> after entering the 'facebook' user's password, I get a similar long pause,
> then:
> 
> (process:22887): GLib-CRITICAL **: g_slice_set_config: assertion 
> `sys_page_size == 0' failed No protocol specified No protocol specified 
> Error: cannot open display: :0
> 
> that's almost certainly the same bug. One that I'm not sure is the same bug
> is that an attempt to loopback mount an ISO file to /mnt/temp when running
> as root after an 'su' command that hit this bug seems to hang and be
> unkillable.
> 
I would bet this has something to do with capabilities.  Does su drop
capabilities before trying to write to /run/gdm/auth-for-adamw-szT11D/database-c
as root user without dac_override.  Since the permissions on the directory are
711, and ownership is adamw:adamw,  root would not be allowed to write there.
Now if we had friendly Eperm, it surely would make diagnosing something like
this easier.

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.13 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iEYEARECAAYFAlGbdPgACgkQrlYvE4MpobNssQCgzAb/kouG8s4wkv0z6fsWFM4M
IswAoNsNgjsiqLFR5bSmyWzttD9EJ0Ii
=9r/z
-----END PGP SIGNATURE-----


More information about the devel mailing list