Bug 73562 - syncevo-dbus-server dies soon after first scheduled sync
Summary: syncevo-dbus-server dies soon after first scheduled sync
Status: RESOLVED FIXED
Alias: None
Product: SyncEvolution
Classification: Unclassified
Component: SyncEvolution (show other bugs)
Version: 1.3.99.3
Hardware: x86-64 (AMD64) Linux (All)
: medium major
Assignee: Patrick Ohly
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-01-13 16:14 UTC by Toomas Tamm
Modified: 2014-01-20 08:36 UTC (History)
1 user (show)

See Also:
i915 platform:
i915 features:


Attachments
Output of syncevolution --quiet --print-config memotoo (1.77 KB, text/plain)
2014-01-13 16:14 UTC, Toomas Tamm
Details
Debug log as requested (33.73 KB, text/plain)
2014-01-13 17:18 UTC, Toomas Tamm
Details
Second debug log (21.25 KB, text/plain)
2014-01-14 10:33 UTC, Toomas Tamm
Details

Description Toomas Tamm 2014-01-13 16:14:32 UTC
Created attachment 91957 [details]
Output of syncevolution --quiet --print-config memotoo

I installed the latest 1.3.99.6-2 from downloads.syncevolution.org, because the Debian wheezy default 1.2 did not auto-sync (http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=694004). The system is Debian 7.0 (wheezy) and the desktop is Gnome Classic.

The new version auto-syncs once (approximately 15 minutes after I log on), and then syncevo-dbus-server dies about 10 minutes later for no apparent reason. Running "sync-ui" or the syncevolution command-line client restarts it, but I have not witnessed any more auto-syncs occurring. Some time later the daemon has disappeared again from the process list.

I am syncing against memotoo and the sync itself appears to finish without problems.

The configuration is mostly default (for Memotoo). A printout is attached. I decreased the sync interval to 10 minutes just to make observations less time-consuming.

I am willing to send additional debug information and help in other ways, if you tell me how to obtain it.
Comment 1 Patrick Ohly 2014-01-13 16:29:03 UTC
Please run it under gdb and also enable more debug output:

$ killall syncevo-dbus-server
$ script /tmp/log
Script started, file is /tmp/log
$ gdb --args /usr/libexec/syncevo-dbus-server -o -s --verbosity=3
GNU gdb (GDB) 7.4.1-debian
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/libexec/syncevo-dbus-server...done.
(gdb) run
Starting program: /usr/libexec/syncevo-dbus-server -o -s --verbosity=3
warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7ffff7ffa000
....

If it crashes, please run "thread apply all bt".

Once it is done, please attach the /tmp/log file.
Comment 2 Toomas Tamm 2014-01-13 17:18:24 UTC
Created attachment 91964 [details]
Debug log as requested
Comment 3 Toomas Tamm 2014-01-13 17:18:36 UTC
Ran the debug session as requested. Some comments:

At 00:21:29 I executed "syncevolution --quiet --print-config memotoo" in another window
At 00:22:57 I executed "sync-ui" in another terminal, and exited the GUI a couple of seconds later.

After control was initially returned to gdb, the process was still not dead, as evidenced by "ps" in another window. I issued "contiune" to gdb, after which it eventually died.

I notice that the daemon complains about the source "autosyncinterval=10m". This source appeared in the config file as a section [autosyncinterval=10m] after earlier today I had executed both:
$ syncevolution --configure memotoo autoSyncInterval=10M
$ syncevolution --configure autoSyncInterval=10M memotoo
in attempts to learn to set that interval.

Could that be relevant? How can I safely get rid of it (manually editing files under .config/syncevolution seems unsafe to me)?
Comment 4 Patrick Ohly 2014-01-13 18:35:44 UTC
(In reply to comment #3)
> After control was initially returned to gdb, the process was still not dead,
> as evidenced by "ps" in another window. I issued "contiune" to gdb, after
> which it eventually died.

I see how it aborts and can imagine how this might happen; it'll be easy to fix.

I've not seen this before, so it could (indirectly) be caused by the unusable memotoo configuration.

> I notice that the daemon complains about the source "autosyncinterval=10m".
> This source appeared in the config file as a section [autosyncinterval=10m]
> after earlier today I had executed both:
> $ syncevolution --configure memotoo autoSyncInterval=10M

This creates a source named "autoSyncInterval=10M". The positional arguments are always used as names of config resp. source(s).

> Could that be relevant? How can I safely get rid of it (manually editing
> files under .config/syncevolution seems unsafe to me)?

It is safe to remove all dirs named autoSyncInterval=10M. syncevo-dbus-daemon does not watch files to pick up modified auto sync settings, but it will re-read config files for each sync.

Does that fix the termination problem?
Comment 5 Toomas Tamm 2014-01-14 10:33:05 UTC
Created attachment 92028 [details]
Second debug log
Comment 6 Toomas Tamm 2014-01-14 10:41:50 UTC
I have done some additional testing.

I removed the references to "autosyncinterval=10m" source in .config (there were two). Then I ran the daemon under gdb for about an hour, and everything seemed fine. However, as soon as I tried to use the command-line "syncevolution" client, the daemon died after it woke up from sleep next time.

I am not posting the long debug log, since I could reproduce the situation with a short one. There, I issued "syncevolution --quiet --print-config memotoo" on another terminal at 00:00:12, and the crash occurred at the first wake-up ten minutes later. The debug log from the second run is posted as "Second debug log". Please let me know if you need the long one (which contains several successful wake-ups and synchronizations) as well.

At this point I am quite convinced that interaction with the command-line tool leads to the crash (possibly in combination with something else, which I might not be aware of). Just for completeness, I am attaching output of "syncevolution --version":

SyncEvolution 1.3.99.6
using libedataserver-1.2.so.16
using libebook-1.2.so.13
using libebook-1.2.so.13
using libecal-1.2.so.11
using libecal-1.2.so.11
using libbluetooth.so.3
Loading backend library /usr/lib/syncevolution/backends/syncxmlrpc.so
Loading backend library /usr/lib/syncevolution/backends/syncsqlite.so
Loading backend library /usr/lib/syncevolution/backends/syncqtcontacts.so
Loading backend library /usr/lib/syncevolution/backends/syncpbap.so
Loading backend library /usr/lib/syncevolution/backends/syncmaemocal.so
Loading backend library /usr/lib/syncevolution/backends/synckcalextended.so
Loading backend library /usr/lib/syncevolution/backends/syncfile.so
Loading backend library /usr/lib/syncevolution/backends/syncecal.so
Loading backend library /usr/lib/syncevolution/backends/syncebook.so
Loading backend library /usr/lib/syncevolution/backends/syncdav.so
Loading backend library /usr/lib/syncevolution/backends/syncaddressbook.so
Loading backend library /usr/lib/syncevolution/backends/providergsso.so
Loading backend library /usr/lib/syncevolution/backends/providergoa.so
Loading backend library /usr/lib/syncevolution/backends/platformgnome.so
Comment 7 Toomas Tamm 2014-01-14 11:18:32 UTC
Another piece of news (for me, at least). 

Running the "syncevolution --version" command appears to re-start the /usr/libexec/syncevo-dbus-server in the background, and it actually syncs 10 minutes later (as evidenced by the pop-up message).

After I issue "syncevolution --quiet --print-config memotoo" in another terminal, it dies in about 10 minutes, as before.


I am not sure if asking for the version of a program should start a background daemon. Shouldn't it just report the version and exit? Should I file this as a separate bug?
Comment 8 Patrick Ohly 2014-01-14 12:26:35 UTC
Agreed, the interaction with manual operations looks like the culprit. I have some automated tests for auto syncing, but nothing involving such a scenario. I'll see whether I can reproduce it.

Thanks for tracking this down.
Comment 9 Toomas Tamm 2014-01-17 13:40:52 UTC
Some further observations.

I have now changed the intra-sync interval to 1 hour (the 10 minutes was for initial tests only).

It seems that the process dies 1 hour (that is, the length of intra-sync interval) after it has been "disturbed" by the command-line tool, irrespective of when the next sync was due. And that sync does not occur. 

For example, if a sync took place at 13:15, and I use the command-line tool at 13:40, the 14:15 sync will not take place, and at approximately 14:40 the process disappears from the process table. Can it be, that the 1-hour timer is re-started from zero after interaction with the command-line tool, and when the process wakes up from it, the sync time has passed, which confuses the algorithm, leading to the crash?
Comment 10 Patrick Ohly 2014-01-17 13:58:37 UTC
Sorry, should have changed the status earlier. I was able to reproduce the problem with an automatic test and have a fix. As usual, the fix was much simpler than writing the test ;-)

These commits still need to be merged into master:

commit fc3d1d6ec4af180bbc3e934110b83e3149eae957
Author: Patrick Ohly <patrick.ohly@intel.com>
Date:   Thu Jan 16 14:06:08 2014 +0100

    D-Bus testing: cover auto-sync + command line session (FDO #73562)
    
    This adds hooks into doAutoSyncLocalSuccess() which are used by
    testAutoSyncLocalMultiple() to start a session while waiting for auto-sync,
    access the config which will get auto-synced, then continue waiting.
    
    While at it, also measure the actual auto sync interval and roughly
    compare against the configured one.

commit ac1887741f7fdff807016d397ea95bd8302fd422
Author: Patrick Ohly <patrick.ohly@intel.com>
Date:   Thu Jan 16 13:56:46 2014 +0100

    D-Bus server: fix abort when mixing auto-sync and manual operations (FDO #73562)
    
    When enabling auto-sync for a config and then accessing or syncing the
    config manually via the command line tool, the server would abort at
    the time when the auto-sync was originally scheduled.
    
    The reason is that rescheduling reset the timeout which caused the
    rescheduling, only to be cleared when the rescheduling callback
    returns. Then when it triggered next, an empty boost::method was
    called. The fix is to to track whether the Timeout instance still
    refers to the same glib timeout and only clear the instance if that's
    still the case.
    
    A unit test will be committed separately.
Comment 11 Patrick Ohly 2014-01-17 14:03:17 UTC
(In reply to comment #7)
> I am not sure if asking for the version of a program should start a
> background daemon. Shouldn't it just report the version and exit? Should I
> file this as a separate bug?

Yes, "syncevolution --version" contacts the daemon, and that is intentional. There have been users who did not install SyncEvolution correctly and/or had problems after an upgrade (old daemon still running), such that command line and daemon were from different releases. When contacting the daemon and asking for the version, the command line client will compare versions and warn about mismatches.

This behavior is also consistent with other operations, which always are run in the daemon. If one wants to run the version check without contacting the daemon, then use "--daemon=no --version", just as in any other operation.
Comment 12 Patrick Ohly 2014-01-20 08:36:03 UTC
Fix merged into master, will be in 1.3.99.7.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.