[Bug 997217] [NEW] salsauthd maxes cpu

[David Farrar]

Public bug reported:

sasl2-bin version 2.1.24~rc1.dfsg1+cvs2011-05-23-4ubuntu contains a bug
that causes heavy cpu utilization, impacting normal operation of one of
our mail servers following an upgrade to Ubuntu 12.04.

We are running the daemon with the following options:

/usr/sbin/saslauthd -a rimap -O our.imap.server -r -m
/var/spool/postfix/var/run/saslauthd -n 5


We noticed that users were unable to send mail and that the saslauthd processes were using approximately 100% of each cpu core. An strace of one of the runaway process showed that it was stuck in the following behaviour:

select(9, [8], NULL, NULL, {0, 0})      = 1 (in [8], left {0, 0})
read(8, "", 940)                        = 0
select(9, [8], NULL, NULL, {0, 0})      = 1 (in [8], left {0, 0})
read(8, "", 940)                        = 0
select(9, [8], NULL, NULL, {0, 0})      = 1 (in [8], left {0, 0})
read(8, "", 940)                        = 0
select(9, [8], NULL, NULL, {0, 0})      = 1 (in [8], left {0, 0})
read(8, "", 940)                        = 0
select(9, [8], NULL, NULL, {0, 0})      = 1 (in [8], left {0, 0})
read(8, "", 940)                        = 0
select(9, [8], NULL, NULL, {0, 0})      = 1 (in [8], left {0, 0})
read(8, "", 940)                        = 0
select(9, [8], NULL, NULL, {0, 0})      = 1 (in [8], left {0, 0})
read(8, "", 940)                        = 0
.....


with further inspection showing that the file descriptor in question was a socket connected to our imap server in CLOSE_WAIT.

Browsing saslauthd/auth_rimap.c in the source package for sasl2-bin, we
came across the following code, repeated in two locations:

while( select (fds, &perm, NULL, NULL, &timeout ) >0 ) {
           if ( FD_ISSET(s, &perm) ) {
              ret = read(s, rbuf+rc, sizeof(rbuf)-rc);
              if ( ret<0 ) {
                 rc = ret;
                 break;
              } else {
                 rc += ret;
              }
           }
        }


It looks like this loop is expected to run until a read error is encountered or the timeout of 1 second is reached. There is no test to check that 0 bytes were read, indicating that the connection was closed by the remote peer. Since select() will immediately return the size of the set of the partially closed descriptor (1, which is >0), and calls to read() will always yield 0 bytes, there's the potential for execution to get stuck in this non blocking loop and I'm presuming that that's what's happening here.

We've not performed any further analysis to prove that this is really
what's happening but if my intuition is correct then our IMAP server (an
nginx imap proxy) most liklely closes the connection at an unexpected
time under as yet undetermined conditions.

** Affects: cyrus-sasl2 (Ubuntu)
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Ubuntu
Server Team, which is subscribed to cyrus-sasl2 in Ubuntu.
https://bugs.launchpad.net/bugs/997217

Title:
  salsauthd maxes cpu

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/cyrus-sasl2/+bug/997217/+subscriptions