[solved] kopano-server[]: setSyncStatus(): collision
-
Hi,
after upgrade i get every 5 Sekondskopano-server[]: setSyncStatus(): collision
Version 8.6.81
I tried
service kopano-server stop kopano-server --restart-searches
Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 32 Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 68495 Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 171603 Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 198616 Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 214408 Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 224928 Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 226637 Sep 24 09:10:21 mail kopano-server[7237]: Rebuilding searchfolders of store 233508 Se
But after Restart kopano-server the same.
It seams that kopano is running.
Greets
Thomas -
Hi, same error here with a new installation (also 8.6.81) on Debian.
● kopano-server.service - Kopano Groupware Core Storage Server
Loaded: loaded (/lib/systemd/system/kopano-server.service; disabled; vendor p
Active: active (running) since Mon 2018-09-24 12:00:02 CEST; 46min ago
Docs: man:kopano-server(8)
man:kopano-server.cfg(5)
man:kopano-admin(8)
Main PID: 21298 (kopano-server)
Tasks: 21 (limit: 4915)
CGroup: /system.slice/kopano-server.service
└─21298 /usr/sbin/kopano-server -FSep 24 12:45:46 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:45:51 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:45:56 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:46:01 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:46:06 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:46:11 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:46:16 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:46:21 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:46:26 xxxxxxxx kopano-server[21298]: setSyncStatus(): collision
Sep 24 12:46:31 xxxxxxxx kopano-server[21298]: setSyncStatus(): collisionDid over the installation different times, different config parameters, nothing helps.
No other errors.Any help?
Eric
-
-
Hi Felix,
Version kopano-server 8.6.81.228-0+37.1 -
Same with 8.6.81.396 (current master 1fd7b2eb398).
Mon Sep 24 16:24:41 2018: [info ] Audit logging not enabled. Mon Sep 24 16:24:41 2018: [=======] Starting kopano-server version 8.6.81.396 (pid 19470 uid 0) Mon Sep 24 16:24:41 2018: [info ] Using epoll events Mon Sep 24 16:24:41 2018: [notice ] Listening for TCP connections on port 236 Mon Sep 24 16:24:41 2018: [notice ] Listening for priority pipe connections on /var/run/kopano/prio.sock Mon Sep 24 16:24:41 2018: [notice ] Listening for pipe connections on /var/run/kopano/server.sock Mon Sep 24 16:24:41 2018: [debug ] Reexecing /usr/sbin/kopano-server Mon Sep 24 16:24:41 2018: [info ] Audit logging not enabled. Mon Sep 24 16:24:41 2018: [=======] Starting kopano-server version 8.6.81.396 (pid 19470 uid 378) Mon Sep 24 16:24:41 2018: [info ] Using epoll events Mon Sep 24 16:24:41 2018: [notice ] Listening for TCP connections on port 236 Mon Sep 24 16:24:41 2018: [notice ] Listening for priority pipe connections on /var/run/kopano/prio.sock Mon Sep 24 16:24:41 2018: [notice ] Listening for pipe connections on /var/run/kopano/server.sock Mon Sep 24 16:24:41 2018: [notice ] Connection to database 'kdb' succeeded Mon Sep 24 16:24:41 2018: [debug ] PurgeCache took 0 ms Mon Sep 24 16:24:41 2018: [notice ] Querying database for searchfolders. This may take a while. Mon Sep 24 16:24:41 2018: [notice ] Loading search folders. Mon Sep 24 16:24:41 2018: [notice ] Done loading search folders. Mon Sep 24 16:24:41 2018: [notice ] Startup succeeded on pid 19474 Mon Sep 24 16:24:41 2018: [debug ] Accepted incoming connection from file:///var/run/kopano/server.sock Mon Sep 24 16:24:46 2018: [debug ] Previous message logged 16 times Mon Sep 24 16:24:46 2018: [error ] setSyncStatus(): collision Mon Sep 24 16:24:51 2018: [debug ] Accepted incoming connection from file:///var/run/kopano/server.sock Mon Sep 24 16:24:51 2018: [error ] setSyncStatus(): collision Mon Sep 24 16:25:22 2018: [error ] Previous message logged 6 times Mon Sep 24 16:25:22 2018: [debug ] Accepted incoming connection from file:///var/run/kopano/server.sock Mon Sep 24 16:25:26 2018: [error ] setSyncStatus(): collision Mon Sep 24 16:25:53 2018: [error ] Previous message logged 5 times Mon Sep 24 16:25:53 2018: [debug ] Accepted incoming connection from file:///var/run/kopano/server.sock Mon Sep 24 16:25:56 2018: [error ] setSyncStatus(): collision Mon Sep 24 16:26:11 2018: [error ] Previous message logged 2 times Mon Sep 24 16:26:11 2018: [debug ] Accepted incoming connection from file:///var/run/kopano/server.sock Mon Sep 24 16:26:11 2018: [error ] setSyncStatus(): collision
++umgfoin
-
Thanks. What was the last version for you that did log this message?
-
-
I am expierencing the same error message.
I am using git master - last update was 5 day ago (git commit cf1b6a39095a4431d77ff1db7eeb70650db52efc) - there the beahviour is already included -
My suspicion:
The message is triggered, as result of provider/libserver/cmd.cpp:SOAP_ENTRY_START(setSyncStatus, [...])
occasionally inserting emptysourcekey
-values into thesyncs
-table. Removing those entries cures the problem until new null-values are appearing. I’m trying to find out, when this happens.
++umgfoin. -
Thanks. I was able to observe the issue as well and created https://jira.kopano.io/browse/KC-1286 to further investigate.
-
Further findings:
the below call (exporter.Config(...
) inics.py
produces sync-entries with empty sourcekeys:def state(mapiobj, associated=False): exporter = mapiobj.OpenProperty(PR_CONTENTS_SYNCHRONIZER, IID_IExchangeExportChanges, 0, 0) if associated: exporter.Config(None, SYNC_NORMAL | SYNC_ASSOCIATED | SYNC_CATCHUP, None, None, None, None, 0) else: exporter.Config(None, SYNC_NORMAL | SYNC_CATCHUP, None, None, None, None, 0)
It’s getting called e.g. in
service.py, line 180
class service::server(self)
_daemonize(self.main, options=self.options, log=self.log, config=self.config, service=self)
++umgfoin.
-
Hello,
I can confirm this bug on a new Debian 9 installation.Okt 09 06:14:11 kopano systemd[1]: Started Kopano Groupware Core Storage Server. Okt 09 06:14:11 kopano kopano-server[1373]: Starting kopano-server version 8.6.81 (pid 1373 uid 0) Okt 09 06:14:11 kopano kopano-server[1373]: Listening for TCP connections on port 236 Okt 09 06:14:11 kopano kopano-server[1373]: Listening for priority pipe connections on /var/run/kopano/prio.sock Okt 09 06:14:11 kopano kopano-server[1373]: Listening for pipe connections on /var/run/kopano/server.sock Okt 09 06:14:11 kopano kopano-server[1373]: Coredumps are disabled via configuration file. Okt 09 06:14:11 kopano kopano-server[1373]: Starting kopano-server version 8.6.81 (pid 1373 uid 999) Okt 09 06:14:11 kopano kopano-server[1373]: Listening for TCP connections on port 236 Okt 09 06:14:11 kopano kopano-server[1373]: Listening for priority pipe connections on /var/run/kopano/prio.sock Okt 09 06:14:11 kopano kopano-server[1373]: Listening for pipe connections on /var/run/kopano/server.sock Okt 09 06:14:11 kopano kopano-server[1373]: Coredumps are disabled via configuration file. Okt 09 06:14:11 kopano kopano-server[1373]: Connection to database 'kopano' succeeded Okt 09 06:14:12 kopano kopano-server[1373]: Querying database for searchfolders. This may take a while. Okt 09 06:14:12 kopano kopano-server[1373]: Loading search folders. Okt 09 06:14:12 kopano kopano-server[1373]: Done loading search folders. Okt 09 06:14:12 kopano kopano-server[1373]: Startup succeeded on pid 1373 Okt 09 06:14:12 kopano kopano-server[1373]: setSyncStatus(): collision Okt 09 06:14:17 kopano kopano-server[1373]: setSyncStatus(): collision Okt 09 06:14:22 kopano kopano-server[1373]: setSyncStatus(): collision Okt 09 06:14:27 kopano kopano-server[1373]: setSyncStatus(): collision Okt 09 06:14:32 kopano kopano-server[1373]: setSyncStatus(): collision Okt 09 06:14:37 kopano kopano-server[1373]: setSyncStatus(): collision Okt 09 06:14:42 kopano kopano-server[1373]: setSyncStatus(): collision
I’m using nightly from 04.10.2018, but this problem seems to be present more than a month. (There was a nightly 8.6.81.228) with the same problem.)
robgnu.
-
@robgnu and others
To get rid of those annoing messages i stopped the search service and set search_enabled = no in server.cfg.
-
Hi,
i am using the following:
Ubuntu 18.04.1 LTS
Kopano 8.6.81I am having the same troubles.
Regards
Richard -
For me fixed with 39a7f6c2f7.
Thanks!
++umgfoin. -
Thanks for reporting back @umgfoin
-
Hello,
I get this error after update Kopano-Core from v8.5.81.224 to 8.6.82.110
on Debian 9I tried the workaround, which helps me last year:
1.) Stop all kopano services
2.) Remove all files from /var/lib/kopano/search/
3.) Start all services from kopano
After the new index files are done the error appear again.Whats wrong?
Regards Han
-
@han said in kopano-server[]: setSyncStatus(): collision:
to 8.6.82.110
please read the whole thread and then update to the latest available version.
-
@Felix
thank you for the information.I updated to the last available version 8.7.80.12 and get the same errors:
Tue Oct 30 16:55:26 2018: [error ] Previous message logged 100 times Tue Oct 30 16:55:26 2018: [error ] setSyncStatus(): collision Tue Oct 30 17:00:00 2018: [error ] Previous message logged 54 times Tue Oct 30 17:00:00 2018: [info ] Start scheduled softdelete clean up Tue Oct 30 17:00:00 2018: [info ] Start to purge 2 messages Tue Oct 30 17:00:01 2018: [info ] Message purge done Tue Oct 30 17:00:01 2018: [info ] Softdelete done: removed 0 stores, 0 folders, and 2 messages Tue Oct 30 17:00:02 2018: [error ] setSyncStatus(): collision Tue Oct 30 17:08:25 2018: [error ] Previous message logged 100 times Tue Oct 30 17:08:25 2018: [error ] setSyncStatus(): collision Tue Oct 30 17:13:01 2018: [error ] Previous message logged 53 times Tue Oct 30 17:13:01 2018: [info ] Start syncs table clean up Tue Oct 30 17:13:01 2018: [info ] syncs table clean up done: removed syncs: 0 Tue Oct 30 17:13:01 2018: [error ] setSyncStatus(): collision
Regards Han
-
@Han I have not checked if it actually has been merged back to master, but there has been a new nightly release, so please try again.