Kopano: can´t contact LDAP server

Versand/ Empfang im WebApp werden offensichtlich wg. fehlendem LDAP connect verhindert.

kopano/server.log sagt

Fri Mar 23 09:30:00 2018: [error ] LDAP search error: Can’t contact LDAP server. Will unbind, reconnect and retry.

wer kann helfen das zu fixen?

Fortführung von UCS Upgrade auf 4.3 => Kopano steht! ?

Kann eigentlich nicht sein, wenn kopano-server keinen Zugriff aufs LDAP hat, dann kann sich der Nutzer erst gar nicht in der WebApp einloggen (oder irgendwelche Daten in der WebApp aufrufen).

Was sagt spooler.log/dagent.log/mail.log?

EDIT: die “Can’t contact LDAP server” sind erstmal nichts was auf einen Fehler hinweist. kopano-server hat pro Thread eine eigene Verbindung zum LDAP. Hin und wieder laufen einzelne Connects in ein Timeout und kopano-server baut eine neue Verbindung auf.

danke für die message.

So hatte ich das auch interpretiert, aber Fakt ist folgendes:

Apache, Postfix, Kopano-server läuft. WebApp läuft und hat alle Mails, Cals und User-Einträge bis zum Upgrade 4.3. Danach gabs keinen Empfang/ Versand mehr. Einlaufende Mails wurden gebounced.

Nach div. Reparaturen geht nun der Empfang wieder - aber mit 30-60 min. Verspätung bis es im WebApp aufschlägt.

Aus dem WebApp kann nicht versendet werden. Und swaks macht den Job nur ohne Authentifizierung:

root@uni:~# swaks --to my.account@address.tld --from my.account@address.tld --auth-user me@address.tld --auth-password pw --server 192.168.0.50 --port 587 --tls
=== Trying 192.168.0.50:587...
=== Connected to 192.168.0.50.
<-  220 univention.address.tld ESMTP Postfix
 -> EHLO univention.address.tld
<-  250-univention.address.tld
<-  250-PIPELINING
<-  250-SIZE 102400000
<-  250-VRFY
<-  250-ETRN
<-  250-STARTTLS
<-  250-ENHANCEDSTATUSCODES
<-  250-8BITMIME
<-  250 DSN
 -> STARTTLS
<-  220 2.0.0 Ready to start TLS
=== TLS started with cipher TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256
=== TLS no local certificate set
=== TLS peer DN="/C=DE/ST=DE/L=DE/O=homeadr/OU=Univention Corporate Server/CN=univention.address.tld/emailAddress=ssl@address.tld"
 ~> EHLO univention.address.tld
<~  250-univention.address.tld
<~  250-PIPELINING
<~  250-SIZE 102400000
<~  250-VRFY
<~  250-ETRN
<~  250-AUTH PLAIN LOGIN
<~  250-AUTH=PLAIN LOGIN
<~  250-ENHANCEDSTATUSCODES
<~  250-8BITMIME
<~  250 DSN
 ~> AUTH LOGIN
<~  334 VXNlcm5hbWU6
 ~> cnZAYXN0YXJheC5kZQ==
<~  334 UGFzc3dvcmQ6
 ~> bGVyaWNpcnY=
<~* 535 5.7.8 Error: authentication failed: authentication failure
 ~> AUTH PLAIN AHJ2QGFzdGFyYXguZGUAbGVyaWNpcnY=
<~* 535 5.7.8 Error: authentication failed: authentication failure
*** No authentication type succeeded
 ~> QUIT
<~  221 2.0.0 Bye
=== Connection closed with remote host.

mail.log sagt nichts mehr. Ich musste es löschen weil es wie ein Hefekuchen aufging und seither gabs keine Einträge mehr.

dagent + spooler sind seit Tagen ohne Einträge.

Einzig kopano/server.log meldet:

Fri Mar 23 11:16:54 2018: [ notice] Starting kopano-server version 8.4.5.0 (pid 26133)
Fri Mar 23 11:16:54 2018: [warning] Config warning: Option 'sync_log_all_changes' is not used anymore.
Fri Mar 23 11:16:54 2018: [warning] Config warning: Option 'plugin_path' is not used anymore.
Fri Mar 23 11:16:54 2018: [warning] Config warning: Option 'thread_stacksize' is not used anymore.
Fri Mar 23 11:16:54 2018: [warning] Config warning: Option 'client_update_enabled' is not used anymore.
Fri Mar 23 11:16:54 2018: [warning] Config warning: Option 'client_update_path' is not used anymore.
Fri Mar 23 11:16:54 2018: [warning] Config warning: Option 'client_update_log_level' is not used anymore.
Fri Mar 23 11:16:54 2018: [warning] Config warning: Option 'client_update_log_path' is not used anymore.
Fri Mar 23 11:16:54 2018: [error  ] Coredumps will not be generated: kopano-server requires the fs.suid_dumpable sysctl to contain the value 2, not 0.
Fri Mar 23 11:29:19 2018: [error  ] LDAP search error: Can't contact LDAP server. Will unbind, reconnect and retry.

Und kopano/search.log sagt:

2018-03-23 11:16:50,364 - search - ERROR - Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/kopano/log.py", line 87, in log_exc
    try: yield
  File "/usr/lib/python2.7/dist-packages/kopano_search/__init__.py", line 368, in incremental_sync
    new_state = self.server.sync(importer, self.state, log=self.log)
  File "/usr/lib/python2.7/dist-packages/kopano/server.py", line 606, in sync
    return _ics.sync(self, self.mapistore, importer, state, log or self.log, max_changes, window=window, begin=begin, end=end, stats=stats)
  File "/usr/lib/python2.7/dist-packages/kopano/ics.py", line 216, in sync
    exporter.Config(stream, flags, importer, restriction, None, None, 0)
  File "/usr/lib/python2.7/dist-packages/MAPICore.py", line 1900, in Config
    return _MAPICore.IExchangeExportChanges_Config(self, lpStream, ulFlags, lpUnk, lpRestriction, lpIncludeProps, lpExcludeProps, ulBufferSize)
MAPIErrorNetworkError: MAPI error 80040115 (MAPI_E_NETWORK_ERROR)

Das ist aber m.W. auf einen Bug im Kopano zurück zu führen und ohne Relevanz.

Darum denke ich an die LDAP-Fehlermeldung, das ist momentan der Einzige Strohhalm.

Dann kommen wohl von außen keine Mails beim Postfix an

zumindest im spooler sollte was drin stehen, wenn der Nutzer eine Mail verschickt. Wenn Postfix aber keine Mails empfängt kann auch nichts im dagent.log stehen.

sowas sollte denn aber schon im mail.log und dagent.log drinstehen. Werden denn überhaupt Mails direkt empfangen oder ruft z.B. fetchmail halt nur alle 30-60 Minuten neue Mails ab?.

Das klingt für mich alles nicht nach einem Kopano Problem.

Das ist eher eine schlechte Idee, da syslog die Logfiles geoeffnet haelt. Vermutlich waechst es (ohne aus dem Dateisystem noch erreichbar zu sein) weiter, oder wurde der rsyslogd durchgestartet?

An fetchmail wurde nie etwas verändert (ca 4 Jahre) Dieses Verhalten ist neu. Trotz allem: mailempfang geht.

Via CLI/swaks werden mails versendet, aber nur ohne tls. Aus dem WebApp wird nichts versendet.

Aktuell fixe ich 1 nicht synchronisierte UCS Objekte und 1 nicht synchronisierte S4 Objekt. Das ganze Mailsystem ist aus der Spur, danke update!

ja, dachte ich mir schon und habe es restarted. Nun läuft es wieder voll:

Mar 23 13:47:17 uni postfix/error[4043]: 6A0EA1560A1: to=<root@sub.address.tld>, orig_to=<root>, relay=none, delay=268, delays=268/0/0/0.05, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Mar 23 13:47:17 uni postfix/error[4036]: 2778F144320: to=<my.adr@sub2.address.tld>, relay=none, delay=1109, delays=1109/0.04/0/0.05, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Mar 23 13:47:17 uni postfix/error[4034]: 101C61566EB: to=<my.adr@sub2.address.tld>, relay=none, delay=1077, delays=1077/0.05/0/0.05, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Mar 23 13:47:25 uni postfix/anvil[2359]: statistics: max connection rate 6/60s for (25:127.0.0.1) at Mar 23 13:44:05
Mar 23 13:47:25 uni postfix/anvil[2359]: statistics: max connection count 3 for (25:127.0.0.1) at Mar 23 13:43:53
Mar 23 13:47:25 uni postfix/anvil[2359]: statistics: max cache size 1 at Mar 23 13:43:53
Mar 23 13:49:45 uni postfix/smtpd[4837]: initializing the semy.adrer-side TLS engine
Mar 23 13:49:45 uni postfix/smtpd[4837]: connect from sub.address.tld[192.168.0.50]
Mar 23 13:49:45 uni postfix/smtpd[4837]: disconnect from sub.address.tld[192.168.0.50] helo=1 quit=1 commands=2

Clamav läuft scheinbar nicht

sieht so aus. Aber nicht nur. Merkwürdig ist dass Kopano WebApp alles bis zum update alles parat hat. Nur Senden läuft nicht.

Doch, Clamav läuft!

Vermutlich bleiben die Mails, die aus der Webapp versendet werden, in der Outbox liegen. In dem Fall bitte mal den spooler stoppen, kontrollieren, dass er nicht mehr laeuft, starten. In der kc 8.4.5 hat der kopano-spooler noch das Problem, dass er machmal einfach aufhoert etwas zu tun (aber noch laeuft). Wurde zum leeren Logfile und dem Verhalten passen.

Huhu,

Port 10024 ist eher Amavis als ClamAV, wenn ich mich nicht irre.

Gruß
mosu

danke, habe ich ausgeführt.Leider ohne Erfolg.

Hier die aktuellen Logs:

mail.log

Mar 24 08:55:35 uni postfix/smtpd[9722]: initializing the server-side TLS engine
Mar 24 08:55:35 uni postfix/smtpd[9722]: connect from localhost[127.0.0.1]
Mar 24 08:55:35 uni postfix/smtpd[9722]: NOQUEUE: reject: RCPT from localhost[127.0.0.1]: 454 4.7.1 <my.address@outside.tld>: Relay access denied; from=<any.address@inside.tld> to=<my.address@outside.tld> proto=ESMTP helo=<uni.inside.tld>
Mar 24 08:55:35 uni postfix/smtpd[9722]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=0/1 data=0/1 quit=1 commands=3/5

spooler.log

Sat Mar 24 08:55:35 2018: [error  ] [ 9718] RCPT line gave SMTP error: 454 4.7.1 <my.address@outside.tld>: Relay access denied. (will be retried)
Sat Mar 24 08:55:35 2018: [error  ] [ 9718] SMTP: Error while executing command 'DATA'. Response: 554 5.5.1 Error: no valid recipients
Sat Mar 24 08:55:35 2018: [warning] [ 9718] E-mail for user my.address could not be sent, notifying user: cancel message (40580)

search.log

2018-03-24 08:52:50,679 - index0 - WARNING - Sync state does not exist on server (anymore); requesting new one

server.log

Sat Mar 24 08:36:04 2018: [error  ] Previous message logged 69 times
Sat Mar 24 08:36:04 2018: [warning] SQL [00000015] info: Try to reconnect

Wie kann ich das mail relaying steuern? Momentan weiss ich nicht an welcher Schraube ich drehen muss. Any Help?

Mastodon