[Dovecot] Dovecot 1.2.13 intermittent authentication failures

[C. Bensend]

>> > username NUL username NUL password
>>
>> It's username then password.
>
> What about the NUL characters in the middle? Those are important.

Ummmm...  I wrote a quick perl script to decrypt the string and
print it out...  I'll have to look at how to tell if there are
NUL chars in there.

>>  24165 dovecot-auth RET   write 9
>>  24165 dovecot-auth CALL  read(0xd,0x8550e034,0x2000)
>>  24165 dovecot-auth PSIG  SIGCHLD caught handler=0x1c02a8f0 mask=0x0
>>  24165 dovecot-auth RET   read -1 errno 4 Interrupted system call
>>  24165 dovecot-auth CALL  write(0x8,0xcfbbfa77,0x1)
>>  24165 dovecot-auth GIO   fd 8 wrote 1 bytes
>>        "\0"
>
> That code is OpenBSD's auth_userokay() call in libc. I don't know if its
> behavior is correct or not.

Ugh, crap, I meant to include more of the output, I'm sorry.
Immediately following the above:

 24165 dovecot-auth RET   write 1
 24165 dovecot-auth CALL  sigreturn(0xcfbbfa9c)
 24165 dovecot-auth RET   sigreturn JUSTRETURN
 24165 dovecot-auth CALL  close(0xb)
 24165 dovecot-auth RET   close 0
 24165 dovecot-auth CALL  wait4(0x5d89,0xcfbbfef4,0,0)
 24165 dovecot-auth RET   wait4 23945/0x5d89
 24165 dovecot-auth CALL  write(0x2,0x80d53468,0x2e)
 24165 dovecot-auth GIO   fd 2 wrote 46 bytes
       "\^AIbsdauth(benny,127.0.0.1): password mismatch
       "
 24165 dovecot-auth RET   write 46/0x2e
 24165 dovecot-auth CALL  gettimeofday(0x860dc648,0)
 24165 dovecot-auth RET   gettimeofday 0
 24165 dovecot-auth CALL  gettimeofday(0xcfbc0674,0)
 24165 dovecot-auth RET   gettimeofday 0
 24165 dovecot-auth CALL  kevent(0x6,0,0,0x8bc58600,0x8,0xcfbc066c)
 24165 dovecot-auth RET   kevent 1
 24165 dovecot-auth CALL  gettimeofday(0x3c016f5c,0x3c016f64)
 24165 dovecot-auth RET   gettimeofday 0
 24165 dovecot-auth CALL  sigprocmask(0x1,0xffffffff)
 24165 dovecot-auth RET   sigprocmask 0
 24165 dovecot-auth CALL  read(0x7,0xcfbc05e8,0x40)
 24165 dovecot-auth GIO   fd 7 read 1 bytes
       "\0"
 24165 dovecot-auth RET   read 1
 24165 dovecot-auth CALL  sigprocmask(0x3,0)
 24165 dovecot-auth RET   sigprocmask -65793/0xfffefeff
 24165 dovecot-auth CALL  wait4(0xffffffff,0xcfbbf5b8,0x1,0)
 24165 dovecot-auth RET   wait4 -1 errno 10 No child processes
 24165 dovecot-auth CALL  gettimeofday(0xcfbc0674,0)
 24165 dovecot-auth RET   gettimeofday 0
 24165 dovecot-auth CALL  kevent(0x6,0,0,0x8bc58600,0x8,0xcfbc066c)
 23502 dovecot  RET   kevent 1
 23502 dovecot  CALL  gettimeofday(0x3c00bd04,0x3c00bd0c)
 23502 dovecot  RET   gettimeofday 0
 23502 dovecot  CALL  read(0x11,0x86d50901,0x2ff)
 23502 dovecot  GIO   fd 17 read 46 bytes
       "\^AIbsdauth(benny,127.0.0.1): password mismatch
       "
 23502 dovecot  RET   read 46/0x2e
 23502 dovecot  CALL  gettimeofday(0xcfbbfdc8,0)
 23502 dovecot  RET   gettimeofday 0
 23502 dovecot  CALL  sendto(0x5,0xcfbbfe78,0x57,0,0,0)
 23502 dovecot  GIO   fd 5 wrote 87 bytes
       "<22>Aug  4 07:18:01 dovecot: auth(default):
bsdauth(benny,127.0.0.1): \
        password mismatch"
 23502 dovecot  RET   sendto 87/0x57
 23502 dovecot  CALL  gettimeofday(0xcfbc0c34,0)
 23502 dovecot  RET   gettimeofday 0
 23502 dovecot  CALL  kevent(0xc,0,0,0x86cbd600,0xd,0xcfbc0c2c)
 24165 dovecot-auth RET   kevent 0
 24165 dovecot-auth CALL  gettimeofday(0x3c016f5c,0x3c016f64)
 24165 dovecot-auth RET   gettimeofday 0
 24165 dovecot-auth CALL  gettimeofday(0xcfbc0674,0)
 24165 dovecot-auth RET   gettimeofday 0
 24165 dovecot-auth CALL  kevent(0x6,0,0,0x8bc58600,0x8,0xcfbc066c)
 23502 dovecot  RET   kevent 0
 23502 dovecot  CALL  gettimeofday(0x3c00bd04,0x3c00bd0c)
 23502 dovecot  RET   gettimeofday 0
 23502 dovecot  CALL  socketpair(0x1,0x1,0,0xcfbc0b8c)
 23502 dovecot  RET   socketpair 0
 23502 dovecot  CALL  fcntl(0x12,0x1,0)
 23502 dovecot  RET   fcntl 0
 23502 dovecot  CALL  fcntl(0x12,0x2,0x1)
 23502 dovecot  RET   fcntl 0
 23502 dovecot  CALL  fcntl(0x17,0x1,0)

I have more if it would be helpful...  I'm not skilled enough in
debugging compiled programs to effectively interpret what I see
above.

Gut instinct - do you think this might be a problem with OpenBSD's
lib, or Dovecot, or .. ?  I think my configuration is OK, I have
tried with both the previous version (that was running under the
older Dovecot) as well as migrating my settings to the new Dovecot's
version of the configuration.

I *really* appreciate all your help.

Benny


-- 
"Something's going on in this house - last night, I saw a face!"
"Did it have a nose?"
"Yes!"
"That sounds like a face all right."
                                      -- Scary Movie 4