File handle leak fix (50c0e0a/ec67b14 commits) seems to have introduced deadlock

[tanyev]

I have been developing a prototype using pam_tacplus (1.3.9 tag) authenticating against a tac_plus server. I was experimenting with multiple servers and was passing the 'debug' option to pam_tacplus.so. During pam_sm_open_session() my test program (a modified pamtest.py from python-pam package) locked up. The deadlock was reproducible. Here is an strace leading to the deadlock:

socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 5
fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(5, {sa_family=AF_INET, sin_port=htons(49), sin_addr=inet_addr("192.168.40.85")}, 16) = -1 EINPROGRESS (Operation now in progress)
select(6, [5], [5], NULL, {5, 0})       = 2 (in [5], out [5], left {2, 82133})
getpeername(5, 0x7fff1c051820, [128])   = -1 ENOTCONN (Transport endpoint is not connected)
sendto(3, "<35>Nov 21 23:50:11 python[15172"..., 131, MSG_NOSIGNAL, NULL, 0) = 131
sendto(3, "<36>Nov 21 23:50:11 PAM-tacplus["..., 78, MSG_NOSIGNAL, NULL, 0) = 78
close(3)                                = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
fcntl(3, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(3, {sa_family=AF_INET, sin_port=htons(49), sin_addr=inet_addr("192.168.40.86")}, 16) = -1 EINPROGRESS (Operation now in progress)
select(4, [3], [3], NULL, {5, 0})       = 1 (out [3], left {4, 999905})
getpeername(3, {sa_family=AF_INET, sin_port=htons(49), sin_addr=inet_addr("192.168.40.86")}, [16]) = 0
fcntl(3, F_SETFL, O_RDWR)               = 0
socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 6
connect(6, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0 // connect to syslog
sendto(6, "<39>Nov 21 23:50:11 python[15172"..., 76, MSG_NOSIGNAL, NULL, 0) = 76 // send to syslog
read(6, ^C <unfinished ...> // read from syslog. OOPS!

As you can see from the last few lines, some code is trying to read from the syslog file descriptor. I captured a stack trace with gdb.

#0  0x00007f4001980d10 in __read_nocancel () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007f3fff5507a1 in magic () from /usr/local/lib/libtac.so.1
#2  0x00007f3fff550675 in _tac_req_header () from /usr/local/lib/libtac.so.1
#3  0x00007f3fff54e3b2 in tac_acct_send () from /usr/local/lib/libtac.so.1
#4  0x00007f3fff75aa2c in _pam_send_account () from /usr/local/lib/security/pam_tacplus.so
#5  0x00007f3fff75acf3 in _pam_account () from /usr/local/lib/security/pam_tacplus.so
#6  0x00007f3fffd6bb45 in ?? () from /lib/x86_64-linux-gnu/libpam.so.0
#7  0x00007f3ffff7e237 in ?? () from /usr/lib/python2.7/dist-packages/PAMmodule.so
#8  0x0000000000497ea4 in PyEval_EvalFrameEx ()
#9  0x000000000049f1c0 in PyEval_EvalCodeEx ()
#10 0x00000000004a9081 in PyRun_FileExFlags ()
#11 0x00000000004a9311 in PyRun_SimpleFileExFlags ()
#12 0x00000000004aa8bd in Py_Main ()
#13 0x00007f400068176d in __libc_start_main () from /lib/x86_64-linux-gnu/libc.so.6
#14 0x000000000041b9b1 in _start ()
(gdb) quit

The top two stack frames lead me to line 81 of magic.c:

u_int32_t
magic()
{
    magic_init();

    if(rfd > -1) {
        u_int32_t ret;
        int nb_read = read(rfd, &ret, sizeof(ret));
        close(rfd); // rfd still has value obtained from open("/dev/urandom", O_RDONLY);
                    // If we pass here again, it will read() from whatever unfortunate
                    // fd happens to match (in this case, the syslog fd).

        if (nb_read < sizeof(ret)) {
            /* on read() error fallback to other method */
            return (u_int32_t)random();
       }
        return ret;
    }
    return (u_int32_t)random();
}

Obviously preventing the leak is important, especially for long running applications. But multiple calls to magic() in the life of an application is also a valid use case. Not being steeped in pam_tacplus, my naive solution would be to also reset rfd and magic_inited when closing rfd.

u_int32_t
magic()
{
    magic_init();

    if(rfd > -1) {
        u_int32_t ret;
        int nb_read = read(rfd, &ret, sizeof(ret));
        close(rfd);
        rfd = -1;
        magic_inited = 0;

        if (nb_read < sizeof(ret)) {
            /* on read() error fallback to other method */
            return (u_int32_t)random();
        }
        return ret;
    }
    return (u_int32_t)random();
}

[daveolson53]

tanyev notifications@github.com wrote:

I have been developing a prototype using pam_tacplus (1.3.9 tag) authenticating
against a tac_plus server. I was experimenting with multiple servers and was
passing the 'debug' option to pam_tacplus.so. During pam_sm_open_session() my
test program (a modified pamtest.py from python-pam package) locked up. The
deadlock was reproducible. Here is an strace leading to the deadlock:

I had that problem too, and found and fixed it. The problem is in
libtac/lib/magic.c. This is the fix that I applied. It's not the
best possible patch, but it was enough for what I'm working on, for now.

--- /tmp/magic.c 2014-11-25 15:38:49.887510095 -0800
+++ libtac/lib/magic.c 2014-11-17 15:17:45.319508390 -0800
@@ -68,7 +68,10 @@
}

/*

• * magic - Returns the next magic number.
• * magic - Returns the next magic number. Closes device on first read
• * to avoid leaks, but in some cases (multiple servers, or retries) this
• * code will be called multiple times, so seed the random number generator
• * when we close the fd (or if we have to fake it).
  */
  u_int32_t
  magic()
  @@ -79,11 +82,14 @@
  u_int32_t ret;
  int nb_read = read(rfd, &ret, sizeof(ret));
  close(rfd);

•    rfd = -1;
  

•    if (nb_read < sizeof(ret)) {
  

•        /\* on read() error fallback to other method */
  

•        return (u_int32_t)random();
  

•    if (nb_read < sizeof(ret)) { /\* failed, so create seed and use it */
  

•        struct timeval t;
  

•        gettimeofday(&t, NULL);
  

•        ret = gethostid() ^ t.tv_sec ^ t.tv_usec ^ getpid();
   }
  

•    srandom(ret); /\* for later calls */
   return ret;
  

  }
  return (u_int32_t)random();

Dave Olson
olson@cumulusnetworks.com

[benschumacher]

I like the idea of falling back to seeding from your change @daveolson53, but why not also use whatever bits had been read from /dev/urandom in the seeding?

In truth, I'm not sure ec67b14 is the best way to address the leaked FD. Prior to that change, the code treated 'rfd' as a long-lived source of entropy -- it could always go back to that pool to grab more bits, at least that appears to be the goal from the 117013b change. From a security perspective, pulling bits from '/dev/urandom' will provide more entropy than using srandom/random.

If the goal is simply to ensure that 'rfd' is closed when the process shuts down, then why not use atexit(3) when the fd is successfully opened. Starting with the version of magic.c in commit 117013b, that change would look something like this:

/* ... add a new function to magic.c  .... */

/*
 * magic_cleanup - if /dev/urandom was used as entropy (via rfd), then make
 * sure it is closed at process end
 */
void
magic_cleanup()
{
    /* arguably, this could be asserted based on how this callback is set up. */
    if (rfd > -1) { 
        close(rfd);
        rfd = -1;
    }
}

/* ... snip .... */

void
magic_init()
{
    struct stat statbuf;
    long seed;
    struct timeval t;

    if (magic_inited)
        return;

    magic_inited = 1;

    /*
        try using /dev/urandom
        also check that it's a character device
        If it doesn't exist, fallback to other method
    */

    if (!lstat("/dev/urandom", &statbuf) && S_ISCHR(statbuf.st_mode)) {
        rfd = open("/dev/urandom", O_RDONLY);
        if (rfd >= 0) {
            if (0 == atexit(&magic_cleanup)) {
                return;
            }
            else {
                /* if the atexit() fails due to error, fallback to srandom */
                close(rfd);
                rfd = -1;
            }
        }
    } 

/* ... more code here .... */

(Disclaimer: I haven't tested this, but I'd be happy to and create a patch for this is people think it'd be useful.)

Cheers.

[daveolson53]

benschumacher notifications@github.com wrote:

I like the idea of falling back to seeding from your change @daveolson53, but
why not also use whatever bits had been read from /dev/urandom in the seeding?

I thought of that, but I'd have had to add code to save them. For
those use, there isn't much real gain in using /dev/urandom at all,
in my opinion, so I didn't bother.

In truth, I'm not sure ec67b14 is the best way to address the leaked FD. Prior
to that change, the code treated 'rfd' as a long-lived source of entropy -- it
could always go back to that pool to grab more bits, at least that appears to
be the goal from the 117013b change. From a security perspective, pulling bits
from '/dev/urandom' will provide more entropy than using srandom/random.

Sure, but really, does it matter much?

If the goal is simply to ensure that 'rfd' is closed when the process shuts
down, then why not use atexit(3) when the fd is successfully opened. Starting
with the version of magic.c in commit 117013b, that change would look something
like this:

The issue for my use (and I think the original poster), is that the
way the code is written, you have to open and close connections
for each use (I'm using it outside pam_tacplus also), and that means
a new magic() call each time also.

The atexit() doesn't help, because this is the login process, the
fd is going to stay around anyway, for some uses, because the process
doesn't actually exit (unless it does it's own cleanup, but in that
case you are back to the problem of libtac using the value of rfd
as an fd for /dev/urandom, when that fd is actually from something
else altogether. So you don't want to leave the fd for /dev/urandom
alive, in my opinion.

Dave Olson
olson@unixfolk.com
http://daveolsonmcc.com
http://www.unixfolk.com/dave

[benschumacher]

Alright. I think I'm caught up.

In that case, I would propose adjusting the behavior a bit to this flow:

1. On first execution, magic calls magic_init which opens and reads two uint32 worth of bytes from /dev/urandom
2. First uint32 is used to seed PRNG (srandom)
3. Second uint32 s used a return value for magic() function
4. Close rfd

If there is an error in the above flow anywhere in the above steps, then fallback to seeding PRNG using the existing mechanism, and then generate a new random after seeding PRNG.

In no circumstance should we return the seed material to the application-layer, which may use it as the session identifier in the cleartext header of the TACACS+ protocol.

[kravietz]

Note that the whole magic.c logic is used only for the purpose of generating a session identifier, so I wouldn't spend too much time making it bulletproof because its role is rather negligible. This is why the original implementation used simple rand() call if I remember correctly. It's true that the session identifier plays a role a bit similar to IV later in encryption procedures but the TACACS+ encryption is not really a masterpiece of cryptography, so the IV isn't really a critical part of it. What I would suggest to make sure we don't run into too much code complexity is to use urandom for seeding the PRNG only (srand()), and then just use rand() without even trying to read urandom each time a magic is generated.

[kravietz]

Could you please test how it works with the latest commit?

[tanyev]

I re-created the original test and the deadlock is gone. I noticed that the file descriptors in use seem to have moved around (see below). I wonder if if a 'close(rfd);' after line 54 is in order? Once a seed has been obtained, rfd serves no other purpose and closing it would achieve the "spirit" of ec67b14. Here is the strace starting with the open_session sequence that deadlocked before:

socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 5
fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(5, {sa_family=AF_INET, sin_port=htons(49), sin_addr=inet_addr("192.168.40.85")}, 16) = -1 EINPROGRESS (Operation now in progress)
select(6, [5], [5], NULL, {5, 0})       = 2 (in [5], out [5], left {2, 74597})
getpeername(5, 0x7fff6c0b0660, [128])   = -1 ENOTCONN (Transport endpoint is not connected)
sendto(3, "<35>Nov 26 15:24:18 python[11694"..., 131, MSG_NOSIGNAL, NULL, 0) = 131
sendto(3, "<36>Nov 26 15:24:18 PAM-tacplus["..., 78, MSG_NOSIGNAL, NULL, 0) = 78
close(3)                                = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
fcntl(3, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(3, {sa_family=AF_INET, sin_port=htons(49), sin_addr=inet_addr("192.168.40.86")}, 16) = -1 EINPROGRESS (Operation now in progress)
select(4, [3], [3], NULL, {5, 0})       = 1 (out [3], left {4, 999691})
getpeername(3, {sa_family=AF_INET, sin_port=htons(49), sin_addr=inet_addr("192.168.40.86")}, [16]) = 0
fcntl(3, F_SETFL, O_RDWR)               = 0
socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 7
connect(7, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
sendto(7, "<39>Nov 26 15:24:18 python[11694"..., 76, MSG_NOSIGNAL, NULL, 0) = 76
write(3, "\300\3\1\0\v\33\331\243\0\0\0]", 12) = 12
write(3, "\335L+q\16\313dJ\237\352\36\343\206N\337\2\27\354\3\371*~K\216\240\22\333\33\35h\32\t"..., 93) = 93
read(3, "\300\3\2\0\v\33\331\243\0\0\0\5", 12) = 12
read(3, "\350%\253H\204", 5)            = 5
close(3)                                = 0
sendto(7, "<39>Nov 26 15:24:18 python[11694"..., 75, MSG_NOSIGNAL, NULL, 0) = 75
close(3)                                = -1 EBADF (Bad file descriptor)

[kravietz]

Ah, correct - just fixed it!