My log is full of blocks like this:
auth(default): pam(?): PAM child process 13576 timed out, killing it
auth(default): PAM: kill(13576) failed: No such process

Often, this is recorded for several pids at once.

Occasionally, there's a single burst when a virtual user logs in, immediately before pam_authenticate() fails and checkpassword is executed. When this happens, pam() contains the username and remote IP.

Usually, it starts 2 minutes after a login attempt (successful or not) and repeats every 10 seconds indefinitely. pam() contains something else:
~87%    ?
~ 9%    [garbage],master
~ 4%    ?,master
< 1% [empty]

[garbage] varies; it seems to be constant for an instance of auth, but I haven't verified this.

Eventually, auth segfaults:
Core was generated by `dovecot-auth'.
Program terminated with signal 11, Segmentation fault.
...
#0 0x08087a68 in str_sanitize_append (dest=0x80a8950, src=0x3d9 <Address 0x3d9 out of bounds>, max_len=64) at str-sanitize.c:11
        p = 0x3d9 <Address 0x3d9 out of bounds>
#1 0x08057a1d in get_log_str (auth_request=0x80c6a00, subsystem=0x808f7cd "pam", format=0x808f9ac "PAM child process %s timed out, killing it", va=0x597f8c5c ":\211\n\b?|\t\b?|\t\b?\214\177Y")
    at auth-request.c:1121
        ip = 0xa <Address 0xa out of bounds>
        str = (string_t *) 0x80a8950
#2 0x08057c62 in auth_request_log_error (auth_request=0x80c6a00, subsystem=0x808f7cd "pam", format=0x808f9ac "PAM child process %s timed out, killing it") at auth-request.c:1177
        va = 0x597f8c5c ":\211\n\b?|\t\b?|\t\b?\214\177Y"
#3  0x080658ee in pam_child_timeout (context=0x0) at passdb-pam.c:537
        request = (struct pam_auth_request *) 0x80c6de8
        iter = (struct hash_iterate_context *) 0x80bcdb0
        key = (void *) 0xa9e
        value = (void *) 0x80c6de8
        timeout = 1182548633
#4 0x08079fc5 in io_loop_handle_timeouts (ioloop=0x80b09b0, update_run_now=true) at ioloop.c:294
        t = (struct timeout *) 0x80b4ca8
        called_timeouts = (struct timeout *) 0x80b4ca8
        tv = {tv_sec = 0, tv_usec = 0}
        t_id = 2
#5 0x0807b32e in io_loop_handler_run (ioloop=0x80b09b0) at ioloop- epoll.c:175
        ctx = (struct ioloop_handler_context *) 0x80b09d8
        events = (struct epoll_event *) 0x80b0a18
        event = (const struct epoll_event *) 0x80b0a18
        list = (struct io_list *) 0x80c42d8
        io = (struct io *) 0x0
        tv = {tv_sec = 1, tv_usec = 180418}
        events_count = 12
        t_id = 2
        msecs = 1181
        ret = 0
        i = 1
        j = 3
        call = true
#6  0x0807a0a8 in io_loop_run (ioloop=0x80b09b0) at ioloop.c:329
No locals.
#7  0x0805d7ee in main (argc=1, argv=0x597f8ec4) at main.c:321
        foreground = false

My config (Gentoo Linux hardened/x86/2.6):
# 1.0.1: /etc/dovecot/dovecot.conf
listen: [::1]
ssl_listen: [::]
ssl_cert_file: /etc/ssl/misfeature.net/crt
ssl_key_file: /etc/ssl/misfeature.net/key
ssl_cipher_list: HIGH
login_dir: /var/run/dovecot/login
login_executable: /usr/libexec/dovecot/imap-login
login_greeting_capability: yes
verbose_proctitle: yes
first_valid_uid: 1000
first_valid_gid: 100
mail_location: maildir:~/mail
mail_debug: yes
maildir_copy_with_hardlinks: yes
mail_drop_priv_before_exec: yes
imap_client_workarounds: delay-newmail outlook-idle
auth default:
  verbose: yes
  debug: yes
  passdb:
    driver: pam
    args: *
  passdb:
    driver: checkpassword
    args: /usr/local/bin/checkpassword
  userdb:
    driver: passwd
  userdb:
    driver: prefetch
  socket:
    type: listen
    client:
      path: /var/spool/postfix/private/auth
      mode: 432
      user: postfix
      group: postfix

I turned on the various logging options while investigating this problem; the messages appear even without.

-- TA

Reply via email to