kopano-server crashing.

thctlo

Hai,

i notice now about 3x that after updating kopano, kopano-server is not restarted.

the ps fax list after the update

All these service did have updates and restarted.

16848 ?        Ssl    0:00 /usr/lib/x86_64-linux-gnu/kopano/kopano-statsd
16878 ?        Ssl    0:00 /usr/sbin/rsyslogd -n
17135 ?        Ssl    0:04 /usr/sbin/mysqld
17520 ?        Ss     0:00 /usr/lib/postfix/sbin/master -w
17521 ?        S      0:00  \_ pickup -l -t fifo -u -c
17524 ?        S      0:00  \_ qmgr -l -t fifo -u
17939 ?        S      0:00  \_ tlsmgr -l -t unix -u -c
18092 ?        Ssl    0:00 /usr/sbin/kopano-monitor -F
18194 ?        Ss     0:00 /usr/sbin/kopano-ical -F
18405 ?        Ss     0:00 /usr/sbin/kopano-gateway -F
18514 ?        Ss     0:00 /usr/sbin/apache2 -k start
18595 ?        S      0:00  \_ /usr/sbin/apache2 -k start
19003 ?        S      0:00  \_ /usr/sbin/apache2 -k start
18588 ?        Ss     0:00 /usr/sbin/kopano-spooler -F
18594 ?        S      0:00  \_ /usr/sbin/kopano-spooler -F
18733 ?        Ss     0:00 /usr/sbin/kopano-dagent -l
18739 ?        S      0:00  \_ /usr/sbin/kopano-dagent -l
18819 ?        Ssl    0:00 /usr/bin/python3 /usr/sbin/kopano-search -F
18828 ?        Sl     0:00  \_ /usr/bin/python3 /usr/sbin/kopano-search -F
18829 ?        S      0:00  \_ /usr/bin/python3 /usr/sbin/kopano-search -F

kopano-server and kopano-dagent did not restart and where not shown in the need to restart services .

After a reboot everything works fine.

then its this list.

  969 ?        Ssl    0:00 /usr/sbin/mysqld
  973 ?        Ss     0:00 policyd-weight (master)
 1097 ?        Ss     0:00  \_ policyd-weight (cache)
 1014 ?        Ss     0:06 /usr/bin/perl -T -w /usr/sbin/spamd -d --pidfile=/var/run/spamd.pid --create-prefs --max-children 5 --helper-home-dir -u debian-spamd -g debian-spamd --listen-ip 127.0.0.1 --listen
 2062 ?        S      0:00  \_ spamd child
 2064 ?        S      0:00  \_ spamd child
 1035 ?        Ss     0:00 /usr/sbin/apache2 -k start
 1047 ?        S      0:00  \_ /usr/sbin/apache2 -k start
 2038 ?        Sl     0:00  \_ /usr/sbin/apache2 -k start
 1056 ?        Ssl    0:00 /usr/sbin/kopano-server -F
 1057 ?        Ss     0:00 /usr/sbin/kopano-gateway -F
 1058 ?        Ssl    0:00 /usr/sbin/kopano-spooler -F
 1104 ?        S      0:00  \_ /usr/sbin/kopano-spooler -F
 1060 ?        Ssl    0:00 /usr/bin/python3 /usr/sbin/kopano-search -F
 1261 ?        S      0:00  \_ /usr/bin/python3 /usr/sbin/kopano-search -F
 1265 ?        S      0:00  \_ /usr/bin/python3 /usr/sbin/kopano-search -F
 1061 ?        Ss     0:00 /usr/sbin/kopano-dagent -l
 1108 ?        S      0:00  \_ /usr/sbin/kopano-dagent -l
 1062 ?        Ss     0:00 /usr/sbin/kopano-ical -F
 1063 ?        Ssl    0:00 /usr/sbin/kopano-monitor -F
 1209 ?        Ss     0:00 /usr/lib/postfix/sbin/master -w
 1222 ?        S      0:00  \_ pickup -l -t fifo -u -c
 1223 ?        S      0:00  \_ qmgr -l -t fifo -u
 4790 ?        Ss     0:00 /lib/systemd/systemd --user
 4791 ?        S      0:00  \_ (sd-pam)

and then…
for some reason it crashes.

● kopano-server.service - Kopano Groupware Core Storage Server
   Loaded: loaded (/lib/systemd/system/kopano-server.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/kopano-server.service.d
           └─override.conf
   Active: failed (Result: signal) since Mon 2019-04-29 14:15:03 CEST; 12s ago
     Docs: man:kopano-server(8)
           man:kopano-server.cfg(5)
           man:kopano-admin(8)
  Process: 1056 ExecStart=/usr/sbin/kopano-server -F (code=killed, signal=SEGV)
 Main PID: 1056 (code=killed, signal=SEGV)

Apr 29 14:09:55 core systemd[1]: Started Kopano Groupware Core Storage Server.
Apr 29 14:15:03 core systemd[1]: kopano-server.service: Main process exited, code=killed, status=11/SEGV
Apr 29 14:15:03 core systemd[1]: kopano-server.service: Unit entered failed state.
Apr 29 14:15:03 core systemd[1]: kopano-server.service: Failed with result 'signal'.

then after

systemctl stop kopano-server
systemctl start kopano-server
it runs for some time again.

im thinking this has todo with

Unable to find company id for object "name company.tld" 
 K-1537: Unable to move object user "name user.tld"

and

id, objectclass, signature) VALUES('<F3>\Z<B5><DA>e+J<CD><B9><C4>^\<EE>^L<D8>\0@', 262145, '2019-04-18 10:29:38')"
Sun Apr 28 07:00:02 2019: [error  ] KDatabase::I_Update() query failed: "Duplicate entry '\xF3\x1A\xB5\xDAe+J\xCD\xB9\xC4\x1C\xEE\x0C\xD8\x00@-262145' for key 'externid'", query: INSERT INTO users (externid,
 objectclass, signature) VALUES('<F3>\Z<B5><DA>e+J<CD><B9><C4>^\<EE>^L<D8>\0@', 262145, '2019-04-18 10:29:38')

and I noticed these.

Mon Apr 29 15:15:04 2019: [info   ] Auto-deleting company 1353 from external source
Mon Apr 29 15:15:04 2019: [info   ] Start auto-deleting company members
Mon Apr 29 15:15:04 2019: [info   ] Auto-deleting company 1353 from external source

These i see a lot, and every new mail its repeating.

After this, kopano-server crashes.

My latest added company is the one its complaining about.

Anyone a suggestion.
Kopano communnity : 8.7.80.936.529d71bca-0+190.4

fbartels

Hi @thctlo,

do you have that segmentation fault that systemd is reporting somewhere in your logging?

thctlo

Hi Felix,

No, i wish, that would make is more easy.

all i get is :

Apr 29 15:01:24 core systemd[1]: Started Kopano Groupware Core Storage Server.
Apr 29 15:15:06 core systemd[1]: kopano-server.service: Main process exited, code=killed, status=11/SEGV
Apr 29 15:15:06 core systemd[1]: kopano-server.service: Unit entered failed state.
Apr 29 15:15:06 core systemd[1]: kopano-server.service: Failed with result 'signal'.
Apr 29 15:20:43 core systemd[1]: Started Kopano Groupware Core Storage Server.
Apr 29 15:30:05 core systemd[1]: kopano-server.service: Main process exited, code=killed, status=11/SEGV
Apr 29 15:30:05 core systemd[1]: kopano-server.service: Unit entered failed state.
Apr 29 15:30:05 core systemd[1]: kopano-server.service: Failed with result 'signal'.
Apr 29 15:30:50 core systemd[1]: Started Kopano Groupware Core Storage Server.
Apr 29 15:45:03 core systemd[1]: kopano-server.service: Main process exited, code=killed, status=11/SEGV
Apr 29 15:45:03 core systemd[1]: kopano-server.service: Unit entered failed state.
Apr 29 15:45:03 core systemd[1]: kopano-server.service: Failed with result 'signal'.

i think its still related to : https://forum.kopano.io/topic/2308/k-1537-unable-to-move-object-user
that message.

I did find some missing python modules, the exact ones got lost, but i took some of one other server and tried to match it up.

thctlo

Now, i also notice, that if i run kopano-cli --list-companies

kopano-cli --list-companies
MAPI error 80040115 (MAPI_E_NETWORK_ERROR)

and server is crashed.

fbartels

@thctlo said in kopano-server crashing.:

No, i wish, that would make is more easy.

but this must be logged somewhere. maybe something in dmesg?

thctlo

No, nothing, and i’ve search a lot, kopano is logging at level 6 already. same, what i have is shown…

thctlo

what i noticed also, , the kopano-server crashes in a 15 min interval.

Before the crash i see a lot of these in the logs. ( all exact same time stamps )
these Start auto-deleting is the cause of the problem.

Tue Apr 30 08:15:05 2019: [info   ] Start auto-deleting company members
Tue Apr 30 08:15:05 2019: [info   ] Auto-deleting company 1353 from external source
Tue Apr 30 08:15:05 2019: [info   ] Start auto-deleting company members
Tue Apr 30 08:15:08 2019: [info   ] Audit logging not enabled.

Tue Apr 30 08:15:08 2019: [=======] Starting kopano-server version 8.7.80 (pid 2330 uid 0)
Tue Apr 30 08:15:08 2019: [info   ] Using epoll events
Tue Apr 30 08:15:08 2019: [notice ] Listening for TCP connections on port 236
Tue Apr 30 08:15:08 2019: [notice ] Listening for priority pipe connections on /var/run/kopano/prio.sock
Tue Apr 30 08:15:08 2019: [notice ] Listening for pipe connections on /var/run/kopano/server.sock
Tue Apr 30 08:15:08 2019: [debug  ] Preparing relaunch with allocator lib libtcmalloc_minimal.so.4
Tue Apr 30 08:15:08 2019: [debug  ] Reexecing /usr/sbin/kopano-server
Tue Apr 30 08:15:08 2019: [info   ] Audit logging not enabled.
Tue Apr 30 08:15:08 2019: [=======] Starting kopano-server version 8.7.80 (pid 2330 uid 999)
Tue Apr 30 08:15:08 2019: [info   ] Using epoll events
Tue Apr 30 08:15:08 2019: [info   ] Re-using fd 6 to listen on TCP port 236
Tue Apr 30 08:15:08 2019: [info   ] Re-using fd 7 to listen on priority pipe /var/run/kopano/prio.sock
Tue Apr 30 08:15:08 2019: [info   ] Re-using fd 8 to listen on pipe /var/run/kopano/server.sock
Tue Apr 30 08:15:08 2019: [notice ] Connection to database 'db_zarafa' succeeded
Tue Apr 30 08:15:08 2019: [info   ] Setting object cache size: 16777216
Tue Apr 30 08:15:08 2019: [info   ] Setting indexedobject cache size: 33554432
Tue Apr 30 08:15:08 2019: [debug  ] PurgeCache 0xffffffff took 0 ms
Tue Apr 30 08:15:08 2019: [notice ] Querying database for searchfolders. This may take a while.
Tue Apr 30 08:15:08 2019: [notice ] Loading search folders.
Tue Apr 30 08:15:08 2019: [notice ] Done loading search folders.
Tue Apr 30 08:15:08 2019: [notice ] Startup succeeded on pid 2330
Tue Apr 30 08:15:09 2019: [debug  ] Accepted incoming connection from file:///var/run/kopano/server.sock
Tue Apr 30 08:15:13 2019: [debug  ] Previous message logged 21 times
Tue Apr 30 08:15:13 2019: [info   ] Start syncs table clean up
Tue Apr 30 08:15:13 2019: [info   ] syncs table clean up done: removed syncs: 0
Tue Apr 30 08:15:13 2019: [info   ] Start syncedmessages table clean up
Tue Apr 30 08:15:13 2019: [info   ] syncedmessages table clean up done, 0 entries removed
Tue Apr 30 08:15:33 2019: [debug  ] Accepted incoming connection from file:///var/run/kopano/server.sock

since : Mon Apr 29 18:22:15
cat /var/log/kopano/server.log |grep -nci auto about 125.000 line with the word auto in it. :-(
Is about 40 crashed up to now.

I’ve set the service to autorestart so mail gets in.

/etc/systemd/system/kopano-server.service.d/override.conf
[Service]
Restart=always
RestartSec=3

So how can i stop this :

166441:Tue Apr 30 05:30:01 2019: [info   ] Auto-deleting company 1353 from external source
166442:Tue Apr 30 05:30:01 2019: [info   ] Start auto-deleting company members

kopano-cli --list-companies
MAPI error 80040115 (MAPI_E_NETWORK_ERROR)

( and again of course these auto-deleting lines)

any suggestions, i already reverted back to the .8.7.80.931
Which did not help anymore.

fbartels

@thctlo said in kopano-server crashing.:

any suggestions, i already reverted back to the .8.7.80.931
Which did not help anymore.

What kind of relevance would the older version have?

I would say that until there is proper crash logging there is unfortunately not much we can do.

If you suspect a relation with https://forum.kopano.io/topic/2308/k-1537-unable-to-move-object-user/13, then I would say an idea would be to check if enabling the user safe mode makes a difference.

thctlo

Yes :-) progress… well, that was a very good suggestion Felix, thank you.

This might be related yes. I think i found something here…

# Name of the plugin that handles users
# Required, default = db
# Values: ldap, unix, db
user_plugin             = db

# configuration file of the user plugin, examples can be found in /usr/share/doc/kopano/example-config
#user_plugin_config      = /etc/kopano/ldap.cfg

These are some of the default, i use MYSQL (db) user plugin, after setting the user_safe_mode

i noticed this line in my log.
user_safe_mode: skipping retrieve/sync users from LDAP

and i can run : kopano-cli --list companies again without kopano crashing.
So thats a plus im already happy with.

Now this message

Mon Apr 29 15:15:04 2019: [info   ] Start auto-deleting company members
Mon Apr 29 15:15:04 2019: [info   ] Auto-deleting company 1353 from external source

I know which company it is on the DB, the last added.
If i look at the company listing output of kopano-cli --list companies then the company with the problem is not in that list and thats on iam try now to fix.
But for that to fix i need to get rid of the DB error ( KDatabase::I_Update() query failed: "Duplicate entry ) first.

Any suggestion for that.?

I found that, the kopano monitor, also triggered the problem, so i disabled that on start up also.
I try to caputre all loggings where possible.

thctlo

@fbartels said in kopano-server crashing.:

@thctlo said in kopano-server crashing.:

any suggestions, i already reverted back to the .8.7.80.931
Which did not help anymore.

What kind of relevance would the older version have?

well, the 931 daily did not crash every 15 min, but it did after the 936, so i reverted, i had to try this, now result was exact the same so not change happend with reversion to 931.