kopano-server crashing.



  • 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


  • Kopano

    Hi @thctlo,

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



  • 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.



  • 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.


  • Kopano

    @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?



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



  • 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.


  • Kopano

    @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.



  • 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.



  • @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.


Log in to reply