ldap table lookup problem

[JP Horst]

Hallo!

unsere kolab3 auf CentOS6.3 Installation läuft häufiger für mich nicht 
nachvollziehbar in Probleme mit dem ldap Sever. Postfix scheint dann aus 
irgendwelchen Gründen keine Verbindung zum ldap Server zu bekommen.
Wenn dies Problem auftritt, ist auch kein Login mehr in roundcubemail möglich 
und die Mailnutzung steht still. Ein restart des Rechners löst das Problem bis 
zum nächsten Auftreten.

Anbei die Ausschnitte des maillog jeweils beim ersten Auftreten der 
Fehlermeldung:


Fall #1:

Feb 18 19:40:31 golgi2 clamd[2584]: SelfCheck: Database status OK.
Feb 18 19:40:38 golgi2 imaps[30521]: idle for too long, closing connection
Feb 18 19:40:39 golgi2 imaps[4505]: idle for too long, closing connection
Feb 18 19:40:39 golgi2 imaps[6712]: accepted connection
Feb 18 19:40:39 golgi2 imaps[6712]: imapd:Loading hard-coded DH parameters
Feb 18 19:40:39 golgi2 imaps[6712]: SSL_accept() incomplete -> wait
Feb 18 19:40:39 golgi2 imaps[6712]: SSL_accept() succeeded -> done
Feb 18 19:40:39 golgi2 imaps[6712]: starttls: TLSv1 with cipher RC4-MD5 
(128/128 bits new) no authentication
Feb 18 19:40:39 golgi2 imaps[6712]: ptload(): fetched cache record 
(archiv at sciencebridge.de)(mark 1361209800, current 1361212839, limit 
1361202039)
Feb 18 19:40:39 golgi2 imaps[6712]: ptload returning data
Feb 18 19:40:39 golgi2 imaps[6712]: canonified archiv at sciencebridge.de -> 
archiv at sciencebridge.de
Feb 18 19:40:39 golgi2 imaps[6712]: login: [10.76.25.92] 
archiv at sciencebridge.de PLAIN+TLS User logged in 
SESSIONID=<golgi2.sciencebridge.de-6712-1361212839-1>
Feb 18 19:40:39 golgi2 imaps[6712]: open: user archiv at sciencebridge.de opened 
INBOX
Feb 18 19:40:44 golgi2 postfix/smtpd[6876]: connect from localhost[::1]
Feb 18 19:40:44 golgi2 postfix/smtpd[6876]: NOQUEUE: reject: MAIL from 
localhost[::1]: 552 5.3.4 Message size exceeds fixed limit; proto=ESMTP 
helo=<golgi2.sciencebridge.de>
Feb 18 19:40:45 golgi2 postfix/smtpd[6876]: disconnect from localhost[::1]
Feb 18 19:40:47 golgi2 postfix/smtpd[6876]: connect from localhost[::1]
####>>####
Feb 18 19:40:57 golgi2 postfix/smtpd[6876]: warning: dict_ldap_connect: Unable 
to bind to server ldap://localhost:389 as uid=kolab-service,ou=Special 
Users,dc=sciencebridge,dc=de: -5 (Timed out)
Feb 18 19:40:57 golgi2 postfix/smtpd[6876]: fatal: 
ldap:/etc/postfix/ldap/mydestination.cf(0,lock|fold_fix): table lookup problem
Feb 18 19:40:58 golgi2 postfix/master[28752]: warning: process 
/usr/libexec/postfix/smtpd pid 6876 exit status 1
Feb 18 19:40:59 golgi2 postfix/smtpd[6878]: connect from localhost[::1]
Feb 18 19:40:59 golgi2 postfix/smtpd[6878]: NOQUEUE: reject: MAIL from 
localhost[::1]: 552 5.3.4 Message size exceeds fixed limit; proto=ESMTP 
helo=<golgi2.sciencebridge.de>


Nach den Meldungen habe ich in /etc/postfix/main.cf
message_size_limit = 20480000
ergänzt. Dies hat aber für die folgenden Fälle keinen Unterschied gemacht.


Fall #2:

Feb 20 17:21:44 golgi2 postfix/postfix-script[25270]: refreshing the Postfix mail 
system
Feb 20 17:21:44 golgi2 postfix/master[14646]: reload -- version 2.6.6, 
configuration /etc/postfix
Feb 20 17:22:45 golgi2 master[14565]: process 25227 exited, status 0
Feb 20 17:22:59 golgi2 postfix/submission/smtpd[25248]: warning: problem 
talking to server private/submission_policy: Connection timed out
Feb 20 17:23:04 golgi2 imap[25232]: accepted connection
Feb 20 17:23:04 golgi2 master[25286]: about to exec /usr/lib/cyrus-imapd/imapd
Feb 20 17:23:04 golgi2 imap[25286]: executed
Feb 20 17:23:04 golgi2 imap[25286]: IOERROR: opening 
/var/lib/imap/user_deny.db: No such file or directory
Feb 20 17:23:04 golgi2 imap[25232]: imapd:Loading hard-coded DH parameters
Feb 20 17:23:04 golgi2 imap[25232]: SSL_accept() incomplete -> wait
Feb 20 17:23:04 golgi2 imap[25232]: SSL_accept() succeeded -> done
Feb 20 17:23:04 golgi2 imap[25232]: starttls: TLSv1 with cipher DHE-RSA-
AES256-SHA (256/256 bits new) no authentication
Feb 20 17:23:04 golgi2 imap[25232]: client id: "name" "Roundcube" "version" 
"0.9-beta" "php" "5.3.10" "os" "Linux" "command" 
"/roundcubemail/?_task=mail&_mbox=Projekte%2FBioC-1198-
UMG+ALS+Lingor&_folderlist=1&_list=1&_quota=1&_search=028b4198126fb9aafe14847b11bd8c01&_action=check-
recent&_remote=1&_unlock=loading1361377386279&_=1361377386283"
Feb 20 17:23:04 golgi2 imap[25232]: ptload(): fetched cache record 
(suhle at sciencebridge.de)(mark 1361367054, current 1361377384, limit 
1361366584)
Feb 20 17:23:04 golgi2 imap[25232]: ptload returning data
Feb 20 17:23:04 golgi2 imap[25232]: canonified suhle at sciencebridge.de -> 
suhle at sciencebridge.de
Feb 20 17:23:07 golgi2 postfix/smtpd[25287]: connect from localhost[::1]
####>>####
Feb 20 17:23:17 golgi2 postfix/trivial-rewrite[25288]: warning: 
dict_ldap_connect: Unable to bind to server ldap://localhost:389 as uid=kolab-
service,ou=Special Users,dc=sciencebridge,dc=de: -5 (Timed out)
Feb 20 17:23:17 golgi2 postfix/trivial-rewrite[25288]: fatal: 
ldap:/etc/postfix/ldap/mydestination.cf(0,lock|fold_fix): table lookup problem
Feb 20 17:23:18 golgi2 postfix/master[14646]: warning: process 
/usr/libexec/postfix/trivial-rewrite pid 25288 exit status 1
Feb 20 17:23:29 golgi2 postfix/trivial-rewrite[25290]: warning: 
dict_ldap_connect: Unable to bind to server ldap://localhost:389 as uid=kolab-
service,ou=Special Users,dc=sciencebridge,dc=de: -5 (Timed out)
Feb 20 17:23:29 golgi2 postfix/trivial-rewrite[25290]: fatal: 
ldap:/etc/postfix/ldap/mydestination.cf(0,lock|fold_fix): table lookup problem
Feb 20 17:23:30 golgi2 postfix/smtpd[25287]: warning: problem talking to 
service rewrite: Success
Feb 20 17:23:30 golgi2 postfix/master[14646]: warning: process 
/usr/libexec/postfix/trivial-rewrite pid 25290 exit status 1
Feb 20 17:23:30 golgi2 postfix/master[14646]: warning: 
/usr/libexec/postfix/trivial-rewrite: bad command startup -- throttling



Fall #3:

Feb 22 21:44:33 golgi2 imaps[26854]: accepted connection
Feb 22 21:44:33 golgi2 master[26856]: about to exec /usr/lib/cyrus-imapd/imapd
Feb 22 21:44:33 golgi2 imaps[26856]: executed
Feb 22 21:44:33 golgi2 imaps[26856]: IOERROR: opening 
/var/lib/imap/user_deny.db: No such file or directory
Feb 22 21:44:33 golgi2 imaps[26854]: imapd:Loading hard-coded DH parameters
Feb 22 21:44:33 golgi2 imaps[26854]: SSL_accept() incomplete -> wait
Feb 22 21:44:33 golgi2 imaps[26854]: SSL_accept() succeeded -> done
Feb 22 21:44:33 golgi2 imaps[26854]: starttls: TLSv1 with cipher DHE-RSA-
AES256-SHA (256/256 bits new) no authentication
Feb 22 21:44:33 golgi2 imaps[26854]: ptload(): fetched cache record (cyrus-
admin)(mark 1361562839, current 1361565873, limit 1361555073)
Feb 22 21:44:33 golgi2 imaps[26854]: ptload returning data
Feb 22 21:44:33 golgi2 imaps[26854]: canonified cyrus-admin -> cyrus-admin
Feb 22 21:44:35 golgi2 postfix/smtpd[26857]: connect from localhost[127.0.0.1]
####>>####
Feb 22 21:44:45 golgi2 postfix/smtpd[26857]: warning: dict_ldap_connect: Unable 
to bind to server ldap://localhost:389 as uid=kolab-service,ou=Special 
Users,dc=sciencebridge,dc=de: -5 (Timed out)
Feb 22 21:44:45 golgi2 postfix/smtpd[26857]: fatal: 
ldap:/etc/postfix/ldap/mydestination.cf(0,lock|fold_fix): table lookup problem
Feb 22 21:44:46 golgi2 postfix/master[19002]: warning: process 
/usr/libexec/postfix/smtpd pid 26857 exit status 1
Feb 22 21:44:46 golgi2 postfix/master[19002]: warning: 
/usr/libexec/postfix/smtpd: bad command startup -- throttling
Feb 22 21:44:46 golgi2 amavis[25772]: (25772-08) Negative SMTP resp. to DATA: 
Feb 22 21:44:46 golgi2 amavis[25772]: (25772-08) (!)FWD via SMTP: 
<ESC1112527951387_1112512753916_21195_r20 at in.constantcontact.com> -> 
<archiv at sciencebridge.de>,<suhle at sciencebridge.de>,BODY=7BIT 451 4.5.0 From 
MTA([127.0.0.1]:10025) during fwd-rundown-1 (Negative SMTP response to RSET:  
at (eval 98) line 1143.): id=25772-08
Feb 22 21:44:46 golgi2 amavis[25772]: (25772-08) Blocked MTA-BLOCKED, MYNETS 
LOCAL [IPv6:::1] [208.75.123.131] 
<ESC1112527951387_1112512753916_21195_r20 at in.constantcontact.com> -> 
<archiv at sciencebridge.de>,<suhle at sciencebridge.de>, Message-ID: 
<1112527951387.1112512753916.21195.2.151532EA at scheduler.constantcontact.com>, 
mail_id: a7WvPkSm5Zt1, Hits: -0.248, size: 19136, dkim_id=@auth.ccsend.com, 
16986 ms
Feb 22 21:44:46 golgi2 postfix/smtp[26843]: 6A50E206FA: 
to=<archiv at sciencebridge.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=20, 
delays=0.12/0.99/1.6/17, dsn=4.5.0, status=deferred (host 127.0.0.1[127.0.0.1] 
said: 451 4.5.0 No resp. to MAIL FROM, id=25772-08, from 
MTA([127.0.0.1]:10025):  (in reply to end of DATA command))