Ticket #643 (assigned task)

Opened 10 months ago

Last modified 2 months ago

Write unittest for OSyncMappingEngine (was: Assertion "mapping_entry" in opensync_mapping_engine.c:66 fails)

Reported by: swolter Assigned to: dgollub (accepted)
Priority: high Milestone: 0.39
Component: OpenSync Version: 0.35
Severity: blocker Keywords:
Cc: berndth@gmx.de, prahal, charles.bovy@gmail.com

Description

Dear OpenSync? developers,

thank you very much for your great work.

When doing a normal sync (slow sync works and was finished successfully before) between moto-sync and kdepim-sync using libopensync revision 2915, I reliably get the following error:

Synchronizing group "Handy" 
/home/steve/opensync/opensync/opensync/engine/opensync_mapping_engine.c:66:E:osync_mapping_engine_new: Assertion "mapping_entry" failed
Aborted (core dumped)

My configuration is:

Member 1: moto-sync
        Configuration : <?xml version="1.0"?>
<config>
  <!-- device file name of the phone (/dev/ttyACM0 or /dev/rfcomm0) -->
  <device>/dev/rfcomm0</device>
</config>

Member 2: kdepim-sync
        No Configuration found: Plugin is not configured

A little gdb play results in:

Core was generated by `msynctool --sync Handy --conflict 2'.
Program terminated with signal 6, Aborted.
#0  0xb7c74ea6 in raise () from /lib/libc.so.6
(gdb) bt
#0  0xb7c74ea6 in raise () from /lib/libc.so.6
#1  0xb7c767b1 in abort () from /lib/libc.so.6
#2  0xb7ea2386 in osync_mapping_engine_new (parent=0x8158d00, mapping=0x8165bd0, 
    error=0x80b02e0)
    at /home/steve/opensync/opensync/opensync/engine/opensync_mapping_engine.c:66
#3  0xb7ea3997 in osync_obj_engine_initialize (engine=0x8158d00, error=0x80b02e0)
    at /home/steve/opensync/opensync/opensync/engine/opensync_obj_engine.c:497
#4  0xb7e9f2fe in osync_engine_command (engine=0x80b0260, command=0x8158100)
    at /home/steve/opensync/opensync/opensync/engine/opensync_engine.c:1093
#5  0xb7ea0749 in _command_dispatch (source=0x80de608, callback=0, 
    user_data=0x80b0260)
    at /home/steve/opensync/opensync/opensync/engine/opensync_engine.c:215
#6  0xb7e0b1c6 in g_main_context_dispatch () from /usr/lib/libglib-2.0.so.0
#7  0xb7e0e552 in ?? () from /usr/lib/libglib-2.0.so.0
#8  0x080f1588 in ?? ()
#9  0x00000000 in ?? ()
(gdb) f 2
#2  0xb7ea2386 in osync_mapping_engine_new (parent=0x8158d00, mapping=0x8165bd0, 
    error=0x80b02e0)
    at /home/steve/opensync/opensync/opensync/engine/opensync_mapping_engine.c:66
66                      osync_assert(mapping_entry);
(gdb) p mapping_entry
$1 = <value optimized out>
(gdb) p mapping
$2 = (OSyncMapping *) 0x8165bd0
(gdb) p *mapping
$3 = {ref_count = 2, id = 12, entries = 0x815e070}
(gdb) p mapping->entries
$4 = (GList *) 0x815e070
(gdb) p *mapping->entries
$5 = {data = 0x81661b8, next = 0x0, prev = 0x0}
(gdb) p mapping->entries->data
$6 = (gpointer) 0x81661b8
(gdb) p (OSyncMappingEntry*)mapping->entries->data
$7 = (struct OSyncMappingEntry *) 0x81661b8
(gdb) p *(OSyncMappingEntry*)mapping->entries->data
$8 = {ref_count = 1, uid = 0x8166168 "libkcal-437768252.771", member_id = 2, 
  id = 12}
(gdb) f 3
#3  0xb7ea3997 in osync_obj_engine_initialize (engine=0x8158d00, error=0x80b02e0)
    at /home/steve/opensync/opensync/opensync/engine/opensync_obj_engine.c:497
497                     OSyncMappingEngine *mapping_engine = osync_mapping_engine_new(engine, mapping, error);
(gdb) p engine 
$9 = (OSyncObjEngine *) 0x8158d00
(gdb) p *engine
$10 = {ref_count = 1, parent = 0x80b0260, objtype = 0x8157948 "event", 
  slowsync = 0, archive = 0x809db18, mapping_table = 0x8158d58, 
  mapping_engines = 0x8164420, sink_engines = 0x8156e50, error = 0x0, 
  formatenv = 0x80e4638, sink_errors = 0, sink_connects = 0, sink_disconnects = 0, 
  sink_get_changes = 0, sink_sync_done = 0, sink_written = 0, 
  callback = 0xb7e9ee60 <_engine_event_callback>, callback_userdata = 0x80b0260, 
  conflicts = 0x0, written = 0}

I've got the core around if you need any further information.

Regards, Steve Wolter

Attachments

mapping.pre (16.3 kB) - added by swolter on 12/19/07 11:21:34.
Output of osyncdump before slow-sync
mapping.post_slow (21.5 kB) - added by swolter on 12/19/07 11:22:33.
Mapping after slow-sync
mapping.post_normal (21.5 kB) - added by swolter on 12/19/07 11:23:36.
Mapping after normal (and failed) sync
slow-sync (39.0 kB) - added by swolter on 12/19/07 11:24:11.
Log of slow-sync

Change History

12/05/07 09:37:51 changed by berndth

  • cc set to berndth@gmx.de.

12/05/07 09:44:28 changed by berndth

I am having reproducible core dumps with the same failed assertion on plain file to file syncs. Slow-synching on the same group works fine.

12/18/07 08:54:55 changed by prahal

Could you share the output of the successful slowsync that happens before ? You can reset the "mapping" with osyncdump <groupname> --reset . I fear this is not the bug I fixed with http://www.opensync.org/changeset/2975 but maybe I am wrong . Do you get "ENtry already exists" errors on first successfull sync. Could you share osyncdump <group> results with successfull and non successful sync ?

Regards Alban

12/18/07 08:55:31 changed by prahal

  • cc changed from berndth@gmx.de to berndth@gmx.de, prahal.

12/19/07 00:21:55 changed by berndth

I don't want to hijack this bug report, but for my part, after an update to tonight's svn, the "fast sync" is not crashing anymore.

Are you still interested in any output, prahal?

12/19/07 11:21:34 changed by swolter

  • attachment mapping.pre added.

Output of osyncdump before slow-sync

12/19/07 11:22:33 changed by swolter

  • attachment mapping.post_slow added.

Mapping after slow-sync

12/19/07 11:23:36 changed by swolter

  • attachment mapping.post_normal added.

Mapping after normal (and failed) sync

12/19/07 11:24:11 changed by swolter

  • attachment slow-sync added.

Log of slow-sync

12/19/07 11:25:24 changed by swolter

Still breaks for me with fresh svn version of libopensync. My debug output is attached, tried resetting the map with no success.

12/20/07 10:28:09 changed by prahal

  • owner changed from dgollub to andrewb.
  • component changed from OpenSync to Plugin: moto.

Yup the fix was for anyplugin to file-sync . Your issue is with kdepim to moto-sync. Seems the bug lay down in the moto-sync plugin. I don't know this plugin so all I can do for now is to reassign.

Regards Alban

12/24/07 22:56:29 changed by charlesbovy

I am experiencing the same error when using Evo2 to Syncml. So it might be a general bug... I just tested using 0.35 and the latest svn of today.

Synchronizing group "Evo2Syncml" /home/cbovy/tmp/svn/opensync/opensync/engine/opensync_mapping_engine.c:66:E:osync_mapping_engine_new: Assertion "mapping_entry" failed Aborted (core dumped)

12/29/07 12:35:44 changed by charlesbovy

  • owner changed from andrewb to dgollub.
  • component changed from Plugin: moto to OpenSync.

I think it is not moto specific related, but more general.

01/20/08 21:02:18 changed by dgollub

  • priority changed from normal to highest.
  • status changed from new to assigned.
  • version changed from 0.34 to 0.35.
  • severity changed from major to blocker.
  • milestone set to OpenSync 0.40.

Could you provide backtrace (or even better OSYNC_TRACE files) with latest SVN? Between X-mas and New Year lots of error handling got improved.

And it's very important to know if the sync, where the mapping_entry got emitted, is a slow-sync or a regular sync. The asserts got emitted to avoid the engine to perform with an inconsistent mapping table. If this sync was a slow-sync the engine SHOULD got flushed already .. and the assert would never appear, since there are no mapping_entries left in the mapping_table.

If this happens after a regular sync something very odd happend after the previous sync. For example previous sync raised some errors and didn't reported it to the OpenSync? framework (broken/malformed plugin).. or some error appeared but didn't let the engine fail. It's very important that the engine is going to have an unsuccessful sync if any error appears (expect on connect/disconnect operations.).

If this is still assert appears with 0.35+SVN, please provide following information: - how performed previous sync? did any error appear? - was current sync a slow-sync or a regular one? - provide output of: osyncdump $group (or check on your own for inconistent mapping entries)

01/21/08 15:20:42 changed by swolter

I can and will later. Just rebuilt the software, will get around tomorrow to test it again. Thanks for your effort.

01/23/08 23:46:32 changed by charlesbovy

I tried to run with latest SVN, including latest libsyncml, but now my phone crashes will syncing. I downgraded libsyncml to 0.4.5 en syncml-plugin to 0.35 and the sync succeeded, without phone crash.

I used the following SVN release 0.35-r3007

I'll test with later SVN release in a few days and hope my phone does not crash anymore. Debug information is not reliable by mixing SVN and 0.35 releases.

01/23/08 23:47:10 changed by charlesbovy

  • cc changed from berndth@gmx.de, prahal to berndth@gmx.de, prahal, charles.bovy@gmail.com.

04/15/08 16:36:07 changed by swolter

I actually tried to work on this bug a few times now, but unfortunately the msynctool did not terminate here for some time. The sync works OK and I'm actually using it, even in a cronjob, but it will hang and thus never do a clean sync.

So, I'm still on this, but unable to reproduce or not reproduce the bug for now.

06/12/08 19:37:54 changed by dgollub

  • milestone changed from 0.40 to 0.37.

08/17/08 20:24:19 changed by dgollub

  • priority changed from highest to high.
  • summary changed from Assertion "mapping_entry" in opensync_mapping_engine.c:66 fails to Write unittest for OSyncMappingEngine (was: Assertion "mapping_entry" in opensync_mapping_engine.c:66 fails).
  • type changed from defect to task.
  • milestone changed from 0.37 to 0.39.

I wasn't able to reproduce for quite some time now. I would recommend to turn this ticket into a task for an unittest for the mapping engine...