LDAP server unavailable: SERVER_DOWN

Wed Jan 10 14:40:38 CET 2018

Unfortunately I spoke too soon (see 06:21):

/var/log/dirsrv/slapd-mx/errors:

[10/Jan/2018:02:57:02.648374615 +0100] NSACLPlugin - acl_access_allowed:
Resetting aclpb_pblock 0x7fc2707efa40 to pblock addr 0x7fc22c00b460
[10/Jan/2018:03:24:33.702338063 +0100] slapd shutting down - signaling operation threads - op stack size 6 max work q size 2 max work q stack size 2
[10/Jan/2018:03:24:33.877497688 +0100] slapd shutting down - closing down internal subsystems and plugins
[10/Jan/2018:03:24:33.902644467 +0100] Waiting for 4 database threads to stop
[10/Jan/2018:03:24:34.821476000 +0100] All database threads now stopped
[10/Jan/2018:03:24:34.844761946 +0100] slapd shutting down - freed 2 work q stack objects - freed 8 op stack objects
[10/Jan/2018:03:24:35.702132753 +0100] slapd stopped.
[10/Jan/2018:03:25:09.710952820 +0100] 389-Directory/1.3.5.17 B2017.130.625 starting up
[10/Jan/2018:03:25:10.247208245 +0100] slapd started.  Listening on All Interfaces port 389 for LDAP requests
[10/Jan/2018:06:21:01.333124646 +0100] 389-Directory/1.3.5.17 B2017.130.625 starting up
[10/Jan/2018:06:21:02.463381179 +0100] Detected Disorderly Shutdown last time Directory Server was running, recovering database.
[10/Jan/2018:06:21:10.733276501 +0100] slapd started.  Listening on All Interfaces port 389 for LDAP requests
[10/Jan/2018:10:43:21.361428667 +0100] slapd shutting down - signaling operation threads - op stack size 7 max work q size 2 max work q stack size 2
[10/Jan/2018:10:43:21.455623635 +0100] slapd shutting down - waiting for 26 threads to terminate
[10/Jan/2018:10:43:21.467944267 +0100] slapd shutting down - closing down internal subsystems and plugins
[10/Jan/2018:10:43:21.481536424 +0100] Waiting for 4 database threads to stop
[10/Jan/2018:10:43:22.157516146 +0100] All database threads now stopped
[10/Jan/2018:10:43:22.170111815 +0100] slapd shutting down - freed 2 work q stack objects - freed 7 op stack objects
[10/Jan/2018:10:43:23.158707276 +0100] slapd stopped.
[10/Jan/2018:10:43:23.301567366 +0100] 389-Directory/1.3.5.17 B2017.130.625 starting up
[10/Jan/2018:10:43:23.440775573 +0100] slapd started.  Listening on All Interfaces port 389 for LDAP requests

/var/log/kolab/pykolab.log:

2018-01-10 10:42:54,024 pykolab.wallace WARNING No contents configured for footer module
2018-01-10 10:43:22,168 pykolab.auth ERROR LDAP server unavailable: SERVER_DOWN({'desc': "Can't contact LDAP server"},)
2018-01-10 10:43:22,176 pykolab.auth ERROR Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/pykolab/auth/ldap/__init__.py", line 3065, in _search
    secondary_domains
  File "<string>", line 10, in <module>
  File "/usr/lib/python2.7/dist-packages/pykolab/auth/ldap/__init__.py", line 2744, in _persistent_search
    resp_ctrl_classes={ecnc.controlType:ecnc}
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 521, in result4
    ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 106, in _ldap_call
    result = func(*args,**kwargs)
SERVER_DOWN: {'desc': "Can't contact LDAP server"}

2018-01-10 10:43:22,177 pykolab.auth ERROR -- reconnecting in 10 seconds.
2018-01-10 10:48:48,333 pykolab.wallace WARNING No contents configured
for footer module

What I find notable is the fact that the service had a disorderly
shutdown at 06:21 but only when I restarted it around 10:43 did it
become unavailable. The latter is to be expected.

Also note this error not being gone:

[10/Jan/2018:02:57:02.648374615 +0100] NSACLPlugin - acl_access_allowed:
Resetting aclpb_pblock 0x7fc2707efa40 to pblock addr 0x7fc22c00b460

It may very well be that auth continued to work for everyone and my
restart was unnecessary. Being paged at 10:43, I just reflexively
restarted the service as that has been the recurring issue for the past
week, driving me nuts. Still, I don't like to see services crash
themselves for no clear and fixable reason. Also, experiencing all
thing, I just don't trust the installation. Well designed systems
usually work.

It looks like Ubuntu was a very bad choice as a platform for Kolab.
However, there's no way I can change that now. If this doesn't work out,
I fear management is going to put its fist down and orders Microsoft
Office 365. The way it's going with Kolab, I sadly cannot blame them.

Truly, I don't care whoever dropped the ball on quality control but this
is unacceptable. I have worked with several other mail server
implementations before and Kolab is the only one making a mess of
things. If Ubuntu is backwards, don't endorse it on the Website. Instead
of 5 different installation guides, do one that works, verified, on one
platform. I basically don't care what distribution I use, Ubuntu just
appeared to be the least dated one to choose from.

Best,
Marcel

On 18/01/10, Skale, Franz wrote:
>Hi Marcel,
>cool, that it worked out for you.
>I didn't have any problems with the new version 1.3.5.17 overnight.
>Will keep it.
>Ubuntu seems to neglect certain packages !
>
>Best regards
>Franz
>
>Am 2018-01-09 20:44, schrieb Marcel Bischoff:
>>Thank you very much for the testing and the pointers. I was
>>successfully
>>able to port the package to the Ubuntu 16.04 machine. dpkg-buildpackage
>>complained about quite a lot of missing dependencies that were easily
>>install though, with a notable exception of a missing libsvrcore-dev
>>(>=
>>1:4.1.2+dfsg1-3) dependency, so I had to build and install that as
>>well,
>>similar to what you had to do on Jessie.
>>
>>Restarting dirsrv was very quick compared to before and for now
>>everything appears to be running smooth. So I'm going to go ahead and
>>send a very big THANK YOU your way. If this works out, you will truly
>>have saved me from The Wrath of the Users(tm)... ;)
>>
>>Have a good evening!
>>
>>Best,
>>Marcel
>>
>>On 18/01/09, Skale, Franz wrote:
>>>Hi,
>>>i successfully backported this particular package to jessie:
>>>https://packages.debian.org/stretch/389-ds-base
>>>For jessie to work, i also had to build:
>>>https://packages.debian.org/stretch/libsvrcore0
>>>This will not be necessary for 16.04
>>>Before building , check the debian/control file for dependencies.
>>>The build with: dpkgbuildpackage -us -uc (after dpkg-source -x (dsc).
>>>Since there are a lot of bugfixes, i gave it a try and it works
>>>properly.
>>>I did a backup of /var/lib/dirsrv and /etc/dirsrv before, because the
>>>ldifs werde, of course, migrated too.
>>>Nevertheless i would give it a try.
>>>
>>>Rgds.
>>>Franz
>>>
>>>Am 2018-01-09 17:40, schrieb Marcel Bischoff:
>>>>Thanks. I will try to transplant the Debian Stretch package to the
>>>>Ubuntu machine tonight when there is no traffic on the server and
>>>>report
>>>>on my success/failure.
>>>>
>>>>Regarding blame, you are probably correct that Kolab is not
>>>>directly to
>>>>blame. I would however expect a caveat notice or similar to be
>>>>added to
>>>>the installation instruction overview pointing out issue like
>>>>this, as
>>>>this one on particular is a breaking issue (not being able to log in
>>>>that is).
>>>>
>>>>In case the transplantation is not successful, do you think a
>>>>removal of
>>>>the respective packages followed by an installation from source be
>>>>possible without breaking things?
>>>>
>>>>Best,
>>>>Marcel
>>>>
>>>>On 18/01/09, Skale, Franz wrote:
>>>>>After investigating  you can clearly see, that ubuntu stopped
>>>>>patching
>>>>>of ds389-base with version 1.3.4.9 while debian stretch uses correct
>>>>>patched version 1.3.5.15.
>>>>>The ubuntu version is missing some CVE patches as well as non
>>>>>nss ldap
>>>>>builds.
>>>>>This could be your problem.
>>>>>You can try packaging the debian stretch version on ubuntu 16.04.
>>>>>I often port packages to unbuntu because of the inferior package
>>>>>maintenance they provide.
>>>>>Jessie uses a much older but stable version 1.3.3.5 though.
>>>>>Cannot blame kolab for that.
>>>>>
>>>>>Rgds.
>>>>>Franz
>>>>>Am 2018-01-08 16:03, schrieb Marcel Bischoff:
>>>>>>>On 8. Jan 2018, at 15:58, Jochen Hein <jochen at jochen.org> wrote:
>>>>>>>
>>>>>>>Marcel Bischoff <marcel at herrbischoff.com> writes:
>>>>>>>
>>>>>>>>I have recently set up a Kolab 16 installation, following this
>>>>>>>>guide:
>>>>>>>>https://docs.kolab.org/installation-guide/ubuntu-16.04.html
>>>>>>>>
>>>>>>>>Initially everything worked alright until users started
>>>>>>>>connecting
>>>>>>>>continually. Now, from time to time, without immediate apparent
>>>>>>>>reason, the LDAP service becomes unreachable (according
>>>>>>>>to the log
>>>>>>>>messages). This can only be solved by manually restarting
>>>>>>>>the service
>>>>>>>>with "systemctl restart dirsrv at mx.service". Even restarting the
>>>>>>>>server
>>>>>>>>does nothing to recitify this, although the service is started
>>>>>>>>at that
>>>>>>>>time.
>>>>>>>
>>>>>>>Can you have a look at the dirsrv logs (access&error)?
>>>>>>
>>>>>>Good idea, I just did. Here is the tail of the "errors" file. The
>>>>>>"access" file has way too many entries to be usefulin this context:
>>>>>>
>>>>>>[07/Jan/2018:19:39:15 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f146c7e7bd0 to pblock addr 7f14480088d0
>>>>>>[07/Jan/2018:20:42:50 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f14747f7bd0 to pblock addr 7f13f400cf50
>>>>>>[07/Jan/2018:21:46:16 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f1476ffcbd0 to pblock addr 7f14000097f0
>>>>>>[08/Jan/2018:09:35:30 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f14727f3bd0 to pblock addr 7f1428008100
>>>>>>[08/Jan/2018:09:35:31 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f14757f9bd0 to pblock addr 7f1420000d50
>>>>>>[08/Jan/2018:10:21:28 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f14727f3bd0 to pblock addr 7f1428006770
>>>>>>[08/Jan/2018:11:16:07 +0100] - 389-Directory/1.3.4.9 B2016.109.158
>>>>>>starting up
>>>>>>[08/Jan/2018:11:16:07 +0100] - Detected Disorderly Shutdown
>>>>>>last time
>>>>>>Directory Server was running, recovering database.
>>>>>>[08/Jan/2018:11:16:08 +0100] - slapd started.  Listening on All
>>>>>>Interfaces port 389 for LDAP requests
>>>>>>[08/Jan/2018:11:24:53 +0100] - 389-Directory/1.3.4.9 B2016.109.158
>>>>>>starting up
>>>>>>[08/Jan/2018:11:24:53 +0100] - Detected Disorderly Shutdown
>>>>>>last time
>>>>>>Directory Server was running, recovering database.
>>>>>>[08/Jan/2018:11:24:53 +0100] - slapd started.  Listening on All
>>>>>>Interfaces port 389 for LDAP requests
>>>>>>[08/Jan/2018:11:26:41 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f471dff2bd0 to pblock addr 7f46c4004900
>>>>>>[08/Jan/2018:14:39:09 +0100] - 389-Directory/1.3.4.9 B2016.109.158
>>>>>>starting up
>>>>>>[08/Jan/2018:14:39:09 +0100] - Detected Disorderly Shutdown
>>>>>>last time
>>>>>>Directory Server was running, recovering database.
>>>>>>[08/Jan/2018:14:39:09 +0100] - slapd started.  Listening on All
>>>>>>Interfaces port 389 for LDAP requests
>>>>>>[08/Jan/2018:14:39:20 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f0fdbffebd0 to pblock addr 7f0f5c00bc80
>>>>>>[08/Jan/2018:15:24:48 +0100] NSACLPlugin - acl_access_allowed:
>>>>>>Resetting aclpb_pblock 7f0fdb7fdbd0 to pblock addr 7f0fac008480
>>>>>>
>>>>>>Well... "Disorderly Shutdown" does not sound good at all.
>>>>>>_______________________________________________
>>>>>>users mailing list
>>>>>>users at lists.kolab.org
>>>>>>https://lists.kolab.org/mailman/listinfo/users