syncing syncml / kdepim simply blocks and does nothing

[mkoller]

With todays SVN I tried to sync my Nokia phone via syncml with my KDE3 kdepim plugin.

It works up to the following point:

Synchronization Forecast Summary:

ObjType: contact
        Member 1: Adding(0) Modifying(0) Deleting(0)
        Member 2: Adding(126) Modifying(0) Deleting(0)

Do you want to continue the synchronization? (N/y): y

OK! Completing synchronization!

Then - nothing.

I attached gdb and did a thread apply all bt

Thread 12 (Thread 0xb5852b90 (LWP 4891)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#5  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#6  0xb7dfadae in clone () from /lib/libc.so.6

Thread 11 (Thread 0xb6053b90 (LWP 4894)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7f98473 in osync_queue_poll (queue=0x821d770)
    at /home/PACKAGES/opensync/opensync/opensync/ipc/opensync_queue.c:1336
#3  0xb7f993e3 in _source_check (source=0x8204fc8)
    at /home/PACKAGES/opensync/opensync/opensync/ipc/opensync_queue.c:657
#4  0xb7eabe56 in g_main_context_check () from /usr/lib/libglib-2.0.so.0
#5  0xb7eac74d in ?? () from /usr/lib/libglib-2.0.so.0
#6  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#7  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#8  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#9  0xb7dfadae in clone () from /lib/libc.so.6

Thread 10 (Thread 0xb5051b90 (LWP 4895)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#5  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#6  0xb7dfadae in clone () from /lib/libc.so.6

Thread 9 (Thread 0xb4850b90 (LWP 4899)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
---Type <return> to continue, or q <return> to quit---
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#5  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#6  0xb7dfadae in clone () from /lib/libc.so.6
Thread 8 (Thread 0xb404fb90 (LWP 4900)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#5  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#6  0xb7dfadae in clone () from /lib/libc.so.6

Thread 7 (Thread 0xb384eb90 (LWP 4901)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#5  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#6  0xb7dfadae in clone () from /lib/libc.so.6

Thread 6 (Thread 0xb304db90 (LWP 4902)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#5  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#6  0xb7dfadae in clone () from /lib/libc.so.6

Thread 5 (Thread 0xb284cb90 (LWP 4903)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
---Type <return> to continue, or q <return> to quit---
#4  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#5  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#6  0xb7dfadae in clone () from /lib/libc.so.6
Thread 4 (Thread 0xb2007b90 (LWP 4904)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb62431b3 in smlThreadStartCallback () from /home/PACKAGES/opensync/installed/lib/libsyncml.so.2
#5  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#6  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#7  0xb7dfadae in clone () from /lib/libc.so.6

Thread 3 (Thread 0xb1806b90 (LWP 4905)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb62431b3 in smlThreadStartCallback () from /home/PACKAGES/opensync/installed/lib/libsyncml.so.2
#5  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#6  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#7  0xb7dfadae in clone () from /lib/libc.so.6

Thread 2 (Thread 0xb1005b90 (LWP 4906)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7df11a7 in poll () from /lib/libc.so.6
#2  0xb7eac6f2 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb7eacd2a in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#4  0xb62431b3 in smlThreadStartCallback () from /home/PACKAGES/opensync/installed/lib/libsyncml.so.2
#5  0xb7ed339f in ?? () from /usr/lib/libglib-2.0.so.0
#6  0xb7a08175 in start_thread () from /lib/libpthread.so.0
#7  0xb7dfadae in clone () from /lib/libc.so.6
Thread 1 (Thread 0xb7a01ab0 (LWP 4888)):
#0  0xffffe430 in __kernel_vsyscall ()
#1  0xb7a0bc15 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
---Type <return> to continue, or q <return> to quit---
#2  0xb7e072cd in pthread_cond_wait () from /lib/libc.so.6
#3  0xb7f79f66 in osync_engine_synchronize_and_block (engine=0x812fe88, error=0xbffde164)
    at /home/PACKAGES/opensync/opensync/opensync/engine/opensync_engine.c:2124
#4  0x0804c92a in osynctool_synchronize (env=<value optimized out>, groupname=<value optimized out>,
    wait=<value optimized out>, multi=0, objtypes=0x0, error=0xbffde164)
    at /home/PACKAGES/opensync/trunk/tools/osynctool.c:634
#5  0x0804d7ee in main (argc=0, argv=0xbffde214) at /home/PACKAGES/opensync/trunk/tools/osynctool.c:1706
#0  0xffffe430 in __kernel_vsyscall ()

Attached you also find the logs from OSYNC_TRACE

[henrik]

I can confirm this issue with

OPENSYNC_REL="5492"
LIBSYNCML_REL="1023"
LIBWBXML_REL="203"

on Nokia 6280 and Nokia N95.

Slow sync works fine. Fast sync with one change works fine. Fast sync with several changes just hangs after multiply

[bellmich]

I think I found the problem. _incoming_dispatch only dispatches pendingLimit messages. Usually the limit is 5. So if 5 messages are dispatched then incoming dispatch no longer is called until one message is replied.

If we use batch_commit and not commit_change then all changes are sent and replied at once. If there are more than five changes then batch_commit is not called because the committed_all message is not reached and committed_all message is blocked until all commit_change messages are handled.

I plan to rewrite the SyncML plugn to use commit_changed and committed_all callbacks instead of batch_commit but this is no solution.

The important question is, why does this happen only at fast sync? Is the usual mechanism bypassed during slow-sync?

[bellmich]

Just a question to henrik and mkoller: Did you write items during slow-sync to your SyncML device?

[henrik]

Very good point. No I did not. Sorry that stupid me did not realize this before. I just tried, and slow sync hangs as well with 5 or more changes send to the phone (but works with 4 or less).

[bellmich]

Well, I think we agree that this is a design bug. The IPC message queue blocks after 5 pending messages. It is no solution to raise the limit because IPC limit tuning is nothing for desktop (user). Therefore I recommend the following change:

1. remove support for batch_commit (only SyncML and python-module use it)
2. commit_change calls must be written asynchronously and must be committed independently of committed_all to avoid blocking
3. If a plugin needs a final signal that all changes are done then the plugin must use committed_all.
4. If a change fails then the context of committed_all/sync_done can be used to signal the failure to the sink. The next sync must be a slow-sync.
5. The mapping of IDs must be isolated from the changes itself. Otherwise the changes cannot be processed independently in SyncML. SyncML separates the mapping too. So I recommend to add a sink function for adding a mapping.

   osync_bool osync_objtype_sink_add_mapping(
                     OSyncObjTypeSink *sink,
                     const char *olduid,
                     const char *newuid,
                     OSyncError **error);
   

Any comments please?

[bellmich]

I removed the callback batch_commit from the plugin API and fixed the SyncML plugin accordingly.

r5559

removed batch_commit from the API and disabled the according tests

r5560

removed the disabled batch_commit tests

r5561

cleand up the documentation

r5562

fixed the SyncML plugin

There is still a define OSYNC_SINK_TIMEOUT_BATCHIO.

[sim]

​decoration Changed 1 year ago by admin

​bathtub Changed 1 year ago by admin

​solar system Changed 1 year ago by admin

​stair parts Changed 1 year ago by admin

​solar supply Changed 1 year ago by admin