Dovecot fork() - (Zu)viele imap/imap-login Prozesse

S

satom

New Member
Moin,

ich habe ein Problem mit meinem frisch aufgesetztem Mailserver. Das ganze ist ein VPS bei Strato mit 2 Kernen und 4 GB RAM unter einem Debian 9. Installiert sind Postfix, Dovecot, rspamd, certbot, unbound und nginx mit Roundcube als Webmailclient. Auf dem Rechner liegen etwa 25 Postfächer, die mittels imap gelesen werden. Wenn er denn mal stabil läuft, soll er einen anderen Server ersetzen, der noch mittels Plesk administriert wird. Soviel dazu.

Das Problem was ich habe, ist wohl, das dovecot immer weiter/zuviele Loginprozesse startet und das ganze dann langsam wird. Das sieht im Log dann so aus:

Code: 
Jun 26 14:23:19 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:23:19 mail dovecot: master: Error: service(imap): command startup failed, throttling for 2 secs
Jun 26 14:23:21 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:23:21 mail dovecot: master: Error: service(imap): command startup failed, throttling for 4 secs
Jun 26 14:23:25 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:23:25 mail dovecot: master: Error: service(imap): command startup failed, throttling for 8 secs
Jun 26 14:23:33 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:23:33 mail dovecot: master: Error: service(imap): command startup failed, throttling for 16 secs
Jun 26 14:23:49 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:23:49 mail dovecot: master: Error: service(imap): command startup failed, throttling for 32 secs
Jun 26 14:23:57 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:23:57 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 2 secs
Jun 26 14:24:21 mail dovecot: imap-login: Login: user=<thomas@xxxxx.xx>, method=PLAIN, rip=xx.bbb.ccc.ddd, lip=aa.bbb.ccc.ddd, mpid=17107, TLS, session=<4cs3kIpvdP5Udopx>
Jun 26 14:24:21 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:24:21 mail dovecot: master: Error: service(imap): command startup failed, throttling for 60 secs
Jun 26 14:24:21 mail dovecot: imap-login: Login: user=<schwarz@yyyyyyyy.xx>, method=PLAIN, rip=xx.bbb.ccc.ddd, lip=aa.bbb.ccc.ddd, mpid=17108, TLS, session=<VwU4kIpvdf5Udopx>
Jun 26 14:24:49 mail dovecot: imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes)
Jun 26 14:24:49 mail dovecot: imap-login: Internal login failure (pid=16995 id=1) (internal failure, 1 successful auths): user=<blog@yyyyyyyy.xx>, method=PLAIN, rip=xx.bbb.ccc.ddd, lip=aa.bbb.ccc.ddd, TLS, session=<iMw3kIpvcv5Udopx>
Jun 26 14:24:49 mail dovecot: imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes)
Jun 26 14:24:49 mail dovecot: imap-login: Internal login failure (pid=17030 id=1) (internal failure, 1 successful auths): user=<haus2007@xxxxx.xx>, method=PLAIN, rip=xx.bbb.ccc.ddd, lip=aa.bbb.ccc.ddd, TLS, session=<iVU4kIpvd/5Udopx>
Jun 26 14:24:49 mail dovecot: imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes)
Jun 26 14:24:49 mail dovecot: imap-login: Internal login failure (pid=17031 id=1) (internal failure, 1 successful auths): user=<listen@xxxxx.xx>, method=PLAIN, rip=xx.bbb.ccc.ddd, lip=aa.bbb.ccc.ddd, TLS, session=<w9w4kIpvc/5Udopx>
Jun 26 14:24:49 mail dovecot: imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes)
Jun 26 14:24:49 mail dovecot: imap-login: Internal login failure (pid=17033 id=1) (internal failure, 1 successful auths): user=<games@xxxxx.xx>, method=PLAIN, rip=xx.bbb.ccc.ddd, lip=aa.bbb.ccc.ddd, TLS, session=<b1E5kIpvdv5Udopx>
Jun 26 14:24:49 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:24:49 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 2 secs
Jun 26 14:25:08 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:25:08 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 4 secs
Jun 26 14:25:12 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:25:12 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 8 secs
Jun 26 14:25:20 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:25:20 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 16 secs
Jun 26 14:25:21 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:25:21 mail dovecot: master: Error: service(imap): command startup failed, throttling for 60 secs
Jun 26 14:25:27 mail dovecot: imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes)
Jun 26 14:25:27 mail dovecot: imap-login: Internal login failure (pid=17035 id=1) (internal failure, 1 successful auths): user=<anja@xxxxx.xx>, method=PLAIN, rip=::1, lip=::1, secured, session=<WRp+kopvpqgAAAAAAAAAAAAAAAAAAAAB>
Jun 26 14:25:36 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:25:36 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 2 secs
Jun 26 14:25:51 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:25:51 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 4 secs
Jun 26 14:25:55 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:25:55 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 8 secs
Jun 26 14:26:00 mail dovecot: imap(schmerz@yyyyyyyy.xx): Logged out in=296 out=1167

Das sieht dann bei sysctl status dovecot so aus:

Code: 
 dovecot.service - Dovecot IMAP/POP3 email server
   Loaded: loaded (/lib/systemd/system/dovecot.service; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2018-06-25 23:42:56 CEST; 14h ago
     Docs: man:dovecot(1)
           http://wiki2.dovecot.org/
  Process: 18032 ExecStop=/usr/bin/doveadm stop (code=exited, status=0/SUCCESS)
  Process: 18108 ExecStart=/usr/sbin/dovecot (code=exited, status=0/SUCCESS)
 Main PID: 18110 (dovecot)
    Tasks: 60 (limit: 60)
   CGroup: /system.slice/dovecot.service
           15691 dovecot/imap-login
           15951 dovecot/imap-login
           15985 dovecot/imap-login
           15986 dovecot/imap-login
           15987 dovecot/imap-login
           15988 dovecot/imap-login
           15989 dovecot/imap-login
           15990 dovecot/imap-login
           15991 dovecot/imap
           15992 dovecot/imap
           15994 dovecot/imap
           15995 dovecot/imap
           15996 dovecot/imap
           15997 dovecot/imap
           15998 dovecot/imap-login
           15999 dovecot/imap
           16000 dovecot/imap-login
           16001 dovecot/imap
           16002 dovecot/imap-login
           16003 dovecot/imap
           16037 dovecot/imap
           16038 dovecot/imap-login
           16039 dovecot/imap
           16041 dovecot/imap
           16707 dovecot/imap-login
           17032 dovecot/imap-login
           17107 dovecot/imap
           17108 dovecot/imap
           17554 dovecot/imap-login
           17555 dovecot/imap-login
           17556 dovecot/imap-login
           17557 dovecot/imap-login
           17558 dovecot/imap-login
           17559 dovecot/imap-login
           17560 dovecot/imap-login
           17561 dovecot/imap-login
           17562 dovecot/imap-login
           17563 dovecot/imap-login
           17564 dovecot/ssl-params
           17568 dovecot/auth -w
           17569 dovecot/imap-login
           17604 dovecot/imap
           17607 dovecot/imap
           17608 dovecot/imap
           17610 dovecot/imap
           17611 dovecot/imap
           17613 dovecot/imap
           17614 dovecot/imap
           17715 dovecot/imap-login
           17716 dovecot/imap
           17717 dovecot/imap
           17718 dovecot/imap
           17719 dovecot/imap
           17744 dovecot/imap-login
           17778 dovecot/imap
           18110 /usr/sbin/dovecot
           18112 dovecot/anvil
           18113 dovecot/log
           18116 dovecot/config
           18118 dovecot/auth

Jun 26 14:31:21 mail.xxxxx.de dovecot[18110]: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:31:21 mail.xxxxx.de dovecot[18110]: master: Error: service(imap-login): command startup failed, throttling for 4 secs
Jun 26 14:31:23 mail.xxxxx.de dovecot[18110]: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:31:23 mail.xxxxx.de dovecot[18110]: master: Error: service(imap): command startup failed, throttling for 8 secs
Jun 26 14:31:25 mail.xxxxx.de dovecot[18110]: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:31:25 mail.xxxxx.de dovecot[18110]: master: Error: service(imap-login): command startup failed, throttling for 8 secs
Jun 26 14:31:31 mail.xxxxx.de dovecot[18110]: master: Error: service(imap): fork() failed: Resource temporarily unavailable
Jun 26 14:31:31 mail.xxxxx.de dovecot[18110]: master: Error: service(imap): command startup failed, throttling for 16 secs
Jun 26 14:31:33 mail.xxxxx.de dovecot[18110]: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable
Jun 26 14:31:33 mail.xxxxx.de dovecot[18110]: master: Error: service(imap-login): command startup failed, throttling for 16 secs

Meine Dovecot Config:

Code: 
###
### Aktivierte Protokolle
#############################

protocols = imap lmtp sieve

###
### TLS Config
#######################

ssl = required
ssl_cert = </etc/letsencrypt/live/xxx.de/fullchain.pem
ssl_key = </etc/letsencrypt/live/xxx.de/privkey.pem
ssl_cipher_list = EDH+CAMELLIA:EDH+aRSA:EECDH+aRSA+AESGCM:EECDH+aRSA+SHA256:EECDH:+CAMELLIA128:+AES128:+SSLv3:!aNULL:!eNULL:!LOW:!3DES:!MD5:!EXP:!PSK:!DSS:!RC4:!SEED:!IDEA:!ECDSA:kEDH:CAMELLIA128-SHA:AES128-SHA
ssl_prefer_server_ciphers = yes

###
### Dovecot services
################################

service imap-login {
    service_count = 0             #High Performance Mode
    process_min_avail = 2         # Nummber of cores
    vsz_limit = 1G
                  
    inet_listener imap {
        port = 143
    }
process_limit = 512
 service_count = 1
}


service managesieve-login {
    inet_listener sieve {
        port = 4190
    }
}


service lmtp {
    unix_listener /var/spool/postfix/private/dovecot-lmtp {
        mode = 0660
        group = postfix
        user = postfix
    }

    user = vmail
}


service auth {
    ### Auth socket für Postfix
    unix_listener /var/spool/postfix/private/auth {
        mode = 0660
        user = postfix
        group = postfix
    }

    ### Auth socket für LMTP-Dienst
    unix_listener auth-userdb {
        mode = 0660
        user = vmail
        group = vmail
    }
}


###
###  Protocol settings
#############################

protocol imap {
    mail_plugins = $mail_plugins quota imap_quota imap_sieve
    mail_max_userip_connections = 60
    imap_idle_notify_interval = 29 mins
}

protocol lmtp {
    postmaster_address = postmaster@xxx.de
    mail_plugins = $mail_plugins sieve
}



###
### Client authentication
#############################

disable_plaintext_auth = yes
auth_mechanisms = plain login


passdb {
    driver = sql
    args = /etc/dovecot/dovecot-sql.conf
}

userdb {
    driver = sql
    args = /etc/dovecot/dovecot-sql.conf
}


###
### Mail location
#######################

mail_uid = vmail
mail_gid = vmail
mail_privileged_group = vmail


mail_home = /var/vmail/mailboxes/%d/%n
mail_location = maildir:~/mail:LAYOUT=fs



###
### Mailbox configuration
########################################

namespace inbox {
    inbox = yes

    mailbox Spam {
        auto = subscribe
        special_use = \Junk
    }

    mailbox Trash {
        auto = subscribe
        special_use = \Trash
    }

    mailbox Drafts {
        auto = subscribe
        special_use = \Drafts
    }

    mailbox Sent {
        auto = subscribe
        special_use = \Sent
    }
}



###
### Mail plugins
############################


plugin {
    sieve_plugins = sieve_imapsieve sieve_extprograms
    sieve_before = /var/vmail/sieve/global/spam-global.sieve
    sieve = file:/var/vmail/sieve/%d/%n/scripts;active=/var/vmail/sieve/%d/%n/active-script.sieve

    ###
    ### Spam learning
    ###
    # From elsewhere to Spam folder
    imapsieve_mailbox1_name = Spam
    imapsieve_mailbox1_causes = COPY
    imapsieve_mailbox1_before = file:/var/vmail/sieve/global/learn-spam.sieve

    # From Spam folder to elsewhere
    imapsieve_mailbox2_name = *
    imapsieve_mailbox2_from = Spam
    imapsieve_mailbox2_causes = COPY
    imapsieve_mailbox2_before = file:/var/vmail/sieve/global/learn-ham.sieve

    sieve_pipe_bin_dir = /usr/bin
    sieve_global_extensions = +vnd.dovecot.pipe

    quota = maildir:User quota
    quota_exceeded_message = Benutzer %u hat das Speichervolumen überschritten. / User %u has exhausted allowed storage space.
}

Die ersten Vermutungen gingen in Richtung Ressourcenknappheit, dazu sollte der Recher aber genügend CPU und RAM haben, mehr als knapp 1GB RAM in Gebrauch habe ich bisher nicht gesehen, auch der Load ist nahe null. Ich vermute einen Configfehler, weiß aber nicht mehr, wo ich noch weitersuchen soll. Braucht jemand weitere Logs, Configdumps oder ähnlich? Was ich noch probieren möchte, ist über ein anderes Repo ein aktuelleres Dovecot zu nutzen. Hat jemand sonst Hinweise, Tips, Ideen oder gar Lösungen?

Viele Grüße,

Thomas
 
Strato? Virtuzzo? Da ist oft viel früher Schluss als bei KVM.

Poste mal die beancounters!

Zur Erklärung: Bei virtuozzo virtualisierten Systemen gibt es die sog. beancounters die die Server Ressourcen begrenzen weit bevor es das Betriebssystem tatsächlich tut. Gerade gemappter Speicherplatz, inodes, Sockets und Prozesse sind da -gerade bei Strato- gerne mal recht knapp. Sagt einem halt vorher keiner :-)
 
Last edited by a moderator:
Hätte ich auch selbst dran denken können ;):

Code: 
thomas@mail:~$ sudo cat /proc/user_beancounters
Version: 2.5
       uid  resource                     held              maxheld              barrier                limit              failcnt
   2786796: kmemsize                115896320            120557568  9223372036854775807  9223372036854775807                    0
            lockedpages                     2                    2  9223372036854775807  9223372036854775807                    0
            privvmpages                443408               519863  9223372036854775807  9223372036854775807                    0
            shmpages                    26976                26977  9223372036854775807  9223372036854775807                    0
            dummy                           0                    0  9223372036854775807  9223372036854775807                    0
            numproc                       181                  206                  400                  400                    0
            physpages                  165123               321143              1048576              1048576                    0
            vmguarpages                     0                    0  9223372036854775807  9223372036854775807                    0
            oomguarpages               171228               321143                    0                    0                    0
            numtcpsock                      0                    0  9223372036854775807  9223372036854775807                    0
            numflock                       34                   46  9223372036854775807  9223372036854775807                    0
            numpty                          1                    2  9223372036854775807  9223372036854775807                    0
            numsiginfo                      0                   63  9223372036854775807  9223372036854775807                    0
            tcpsndbuf                       0                    0  9223372036854775807  9223372036854775807                    0
            tcprcvbuf                       0                    0  9223372036854775807  9223372036854775807                    0
            othersockbuf                    0                    0  9223372036854775807  9223372036854775807                    0
            dgramrcvbuf                     0                    0  9223372036854775807  9223372036854775807                    0
            numothersock                    0                    0  9223372036854775807  9223372036854775807                    0
            dcachesize               50200576             50503680  9223372036854775807  9223372036854775807                    0
            numfile                      3099                 4385  9223372036854775807  9223372036854775807                    0
            dummy                           0                    0  9223372036854775807  9223372036854775807                    0
            dummy                           0                    0  9223372036854775807  9223372036854775807                    0
            dummy                           0                    0  9223372036854775807  9223372036854775807                    0
            numiptent                      11                   38                 2000                 2000                    0

Sieht jetzt für mein Halbwissen erstmal unkritisch aus.
 
Jo, beancounters scheinen unschuldig, soweit erstmal mein Halbwissen :-)

PS: numprocs max ist 400. Find ich nicht viel aber mehr als 206 hast du seit dem letzten Neustart nicht gebraucht.
 
Aus dem Syslog kommt der Hinweis, das beim ulimit eine Grenze erreicht wäre? Aber die erscheint mir deutlich zu hoch?

Versuchsweise habe ich in /lib/systemd/system/dovecot.service unter [Service] ein

LimitNOFILE=65536
LimitNPROC=1024

eingetragen. Ändert aber auch nichts :(.

Das sieht im Syslog dann so aus:

Code: 
Jun 26 20:08:10 mail dovecot: master: Error: service(imap-login): fork() failed: Resource temporarily unavailable (ulimit -u 4903 reached?)
Jun 26 20:08:10 mail dovecot: master: Error: service(imap-login): command startup failed, throttling for 2 secs
Jun 26 20:08:11 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable (ulimit -u 4903 reached?)
Jun 26 20:08:11 mail dovecot: master: Error: service(imap): command startup failed, throttling for 2 secs
Jun 26 20:08:13 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable (ulimit -u 4903 reached?)
Jun 26 20:08:13 mail dovecot: master: Error: service(imap): command startup failed, throttling for 4 secs
Jun 26 20:08:17 mail dovecot: master: Error: service(imap): fork() failed: Resource temporarily unavailable (ulimit -u 4903 reached?)
Jun 26 20:08:17 mail dovecot: master: Error: service(imap): command startup failed, throttling for 8 secs

Wie setze ich also diesen ULIMIT - wenn nicht mittels LimitNPROC hoch, und vor allem - warum bei Dovecot?
 
Last edited by a moderator:
You must log in or register to reply here.
Back
Top