Kolab Service Does not Start/No Emails Can be Sent/Received

[Bob Jones]

Upon restarting dirsrv, the issue seems to have resolved itself. Thank you for all your help Jochen and Franz!






On Sunday, May 2, 2021, 3:21:44 AM PDT, Jochen Kellner <jochen at jochen.org> wrote: 





Bob Jones <sckalleon at yahoo.com> writes:

>>The log are in /var/log/dirsrv/slapd-<hostname>/
>>Look for access and errors logs.
>
> dirsrv appears to be running but probably sick.
>
> The access logs are replete with error 32s as expected. Here is the section where successes turned to failures:
>
> [xx/Apr/2021:18:33:03.786817283 +0000] conn=1356 fd=67 slot=67 connection from 127.0.0.1 to 127.0.0.1
> [xx/Apr/2021:18:33:03.787158044 +0000] conn=1356 op=0 BIND
> dn="uid=kolab-service,ou=Special Users,dc=abc,dc=com" method=128
> version=3
> [xx/Apr/2021:18:33:03.787922089 +0000] conn=1356 op=0 RESULT err=0
> tag=97 nentries=0 etime=0.000897075 dn="uid=kolab-service,ou=special
> users,dc=abc,dc=com"

This looks like the bind should have worked (err=0).

After the restart:

> [xx/Apr/2021:18:35:15.083756594 +0000] conn=1 fd=64 slot=64 connection from 127.0.0.1 to 127.0.0.1
> [xx/Apr/2021:18:35:15.341389946 +0000] conn=1 op=0 BIND dn="" method=128 version=3

Why is dn="" here? That looks somewhat fishy.

> [xx/Apr/2021:18:35:15.353235503 +0000] conn=1 op=0 RESULT err=48 tag=97 nentries=0 etime=0.197830615

And err=48...

> [xx/Apr/2021:18:35:16.491982184 +0000] conn=1 op=1 BIND
> dn="uid=kolab-service,ou=Special Users,dc=abc,dc=com" method=128
> version=3
> [xx/Apr/2021:18:35:16.847130239 +0000] conn=1 op=1 RESULT err=32 tag=97 nentries=0 etime=0.388265819

> The error logs around that timeframe (from /var/log/dirsrv/<>-slapd/errors)
>
> [xx/Apr/2021:18:34:53.434013106 +0000] - INFO - main - 389-Directory/1.3.10.2 B2021.075.1526 starting up
> [xx/Apr/2021:18:34:53.446081781 +0000] - INFO - main - Setting the maximum file descriptor limit to: 16384
> [xx/Apr/2021:18:35:11.853888355 +0000] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
> [xx/Apr/2021:18:35:11.893447789 +0000] - WARN -
> ldbm_instance_config_cachememsize_set - delta +66596864 of request
> 67108864 reduced to 8716288

> [xx/Apr/2021:18:35:11.900349919 +0000] - ERR -
> ldbm_instance_config_dncachememsize_set - dncachememsize value is too
> large.
> [xx/Apr/2021:18:35:11.905943221 +0000] - ERR -
> parse_ldbm_instance_config_entry - Error with config attribute
> nsslapd-dncachememsize : Error: dncachememsize value is too large.
> [xx/Apr/2021:18:35:11.918886190 +0000] - ERR - ldbm_instance_config_load_dse_info - Error parsing the config DSE

You should fix these error messages. Stop dirsrv, edit
/etc/dirsrv/slapd-<host>/dse.ldif and start dirsrv again.

> [xx/Apr/2021:18:35:12.223974366 +0000] - WARN - ldbm_back_start - Your
> autosized cache values have been reduced. Likely your
> nsslapd-cache-autosize percentage is too high.
> [xx/Apr/2021:18:35:12.237849184 +0000] - WARN - ldbm_back_start - This
> can be corrected by altering the values of nsslapd-cache-autosize,
> nsslapd-cache-autosize-split and nsslapd-dncachememsize
> [xx/Apr/2021:18:35:12.241467684 +0000] - NOTICE - ldbm_back_start - found 1014780k physical memory
> [xx/Apr/2021:18:35:12.266387944 +0000] - NOTICE - ldbm_back_start - found 16368k available
> [xx/Apr/2021:18:35:12.281287339 +0000] - NOTICE - ldbm_back_start - cache autosizing: db cache: 2046k
> [xx/Apr/2021:18:35:12.303907276 +0000] - NOTICE - ldbm_back_start -
> cache autosizing: abc_com entry cache (1 total): 65536k
> [xx/Apr/2021:18:35:12.313852157 +0000] - WARN -
> entrycache_set_max_size - Cachesize (8540160) may use more than the
> available physical memory.
> [xx/Apr/2021:18:35:12.320270298 +0000] - NOTICE - ldbm_back_start -
> cache autosizing: abc_com dn cache (1 total): 65536k
> [xx/Apr/2021:18:35:12.335583278 +0000] - WARN - dncache_set_max_size -
> Cachesize (7845888) may use more than the available physical memory.
> [xx/Apr/2021:18:35:12.401807555 +0000] - NOTICE - ldbm_back_start - total cache size: 85562163 B;
> [xx/Apr/2021:18:35:12.415804554 +0000] - WARN - ldbm_back_start - It
> is highly likely your memory configuration of all backends will EXCEED
> your systems memory.
> [xx/Apr/2021:18:35:12.419619493 +0000] - WARN - ldbm_back_start - In a
> future release this WILL prevent server start up. You MUST alter your
> configuration.
> [xx/Apr/2021:18:35:12.422801318 +0000] - WARN - ldbm_back_start -
> Total entry cache size: 8380416 B; dbcache size: 1676083 B; available
> memory size: 16760832 B;
> [xx/Apr/2021:18:35:12.424576789 +0000] - WARN - ldbm_back_start - This
> can be corrected by altering the values of nsslapd-cache-autosize,
> nsslapd-cache-autosize-split and nsslapd-dncachememsize
> [xx/Apr/2021:18:35:12.533851502 +0000] - INFO - dblayer_start - Resizing db cache size: 8763392 -> 1676083
> [xx/Apr/2021:18:35:13.298219909 +0000] - INFO - slapd_daemon - slapd
> started.  Listening on All Interfaces port 389 for LDAP requests

Here we have dirsrv running. After you got your system running it might
be a good idea to look into the warnings.

> [xx/Apr/2021:22:34:13.803803627 +0000] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
> [xx/Apr/2021:22:34:13.807928684 +0000] - WARN -
> ldbm_instance_config_cachememsize_set - delta +66596864 of request
> 67108864 reduced to 26904576
> [xx/Apr/2021:22:34:13.814569352 +0000] - WARN - dncache_set_max_size -
> Cachesize (25970688) may use more than the available physical memory.

It's still open what the problem really is :-(


Jochen

-- 
This space is intentionally left blank.