Ticket #579 (new defect)

Opened 7 years ago

Last modified 4 years ago

msync hangs after sync Ubunto 7.10 gutsy Evolution with Nokia N73

Reported by: rolandbreedveld Owned by: abauer
Priority: high Milestone:
Component: osynctool/msynctool Version: 0.19
Severity: blocker Keywords: Ubuntu 7.10 gusyt libsyncml 0.4.1 syncml-obex-client
Cc:

Description (last modified by felixmoeller) (diff)

Hi

After upgrade from Ubunto 7.04 to 7.10 msync hangs after sync. used version 0.22 Nokia N73 is on latest software release removed the ~/.opensync dir and create everything new, but this gives the same result

in the previous situation everything had worked fine, with the same settings !

configs:

<config>
  <address_path>default</address_path>
  <calendar_path>default</calendar_path>
  <tasks_path>default</tasks_path>
</config>
<?xml version="1.0"?>
<config>
  <bluetooth_address>00:19:79:D8:ED:0B</bluetooth_address>
  <bluetooth_channel>10</bluetooth_channel>
  <interface>0</interface>
  <identifier>PC Suite</identifier>
  <version>1</version>
  <wbxml>1</wbxml>
  <username></username>
  <password></password>
  <type>2</type>
  <usestringtable>1</usestringtable>
  <onlyreplace>0</onlyreplace>
  <onlyLocaltime>0</onlyLocaltime>
  <recvLimit>0</recvLimit>
  <maxObjSize>0</maxObjSize>
  <contact_db>Contacts</contact_db>
  <calendar_db>Calendar</calendar_db>
  <note_db>Notes</note_db>
</config>

Nokia display: Send Contacts 357 of 357 After a long time it will timeout the connection

last rows of the command screen:

Received an entry 503 with data of size 4 from member 2 (syncml-obex-client). Changetype ADDED
Received an entry 504 with data of size 4 from member 2 (syncml-obex-client). Changetype ADDED
Received an entry 505 with data of size 4 from member 2 (syncml-obex-client). Changetype ADDED
Member 2 of type syncml-obex-client just sent all changes
All clients sent changes or error

msynctool will consume a lot of cpu time:

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                         
  481 roland    15   0  214m 113m  13m S 97.2 11.2   2:01.56 msynctool  

I will add the trace files

regards Roland

Attachments

msync_trace_roland.bz2 (9.5 MB) - added by rolandbreedveld 7 years ago.
Trace file of the described situation
sync_N73_Evo_Ldap.tgz (49.5 KB) - added by rolandbreedveld 7 years ago.
Trace files sync Nokia N73 with Evolution talking to LDAP

Change History

comment:1 Changed 7 years ago by dgollub

Could you attach trace files as tarball? See trace Was there any error with evolution in while syncing?

comment:2 Changed 7 years ago by rolandbreedveld

Evolution does not report any error while syncing trace file is 470 Mb, compressed 48 Mb.... I think to big for uploading, I received an error, is there an alternative ? I can give a (non-public) download link by email.

comment:3 Changed 7 years ago by dgollub

I guess the logs are quite smaller if you set OSYNC_PRIVACY=1 - it's also ok if you cut the logs and just package the last 40 lines:

for n in Thread*.log; do tail -n 40 $n > $n.cuttted; done;
tar cvfj bug579-cutted.tar.bz2 *.cutted;

Changed 7 years ago by rolandbreedveld

Trace file of the described situation

comment:4 Changed 7 years ago by dgollub

  • Keywords Ubuntu 7.10 gusyt libsyncml 0.4.1 syncml-obex-client added

Looks like a libsyncml issue. iirc Ubuntu 7.10 uses libsyncml 0.4.1 - this release is quite old and has some known issue with the OBEX Transport. Could you try a more recent version - at least libsyncml version 0.4.2 ... or more recent like 0.4.5

comment:5 Changed 7 years ago by rolandbreedveld

Working with version 0.4.5 now, same problem, if I remove everything (db-files and the evoution calandar e.g.) everything will work, but when a little problem occours, or pressing ctrl-c during sync everything hangs again at the next sync. tried syncing with evolution sunbird, local ics file and with a remote webdav, same thing happens. At this moment I only use the calendar everytime the only solution is to remove the calendar (evolution or sunbird) and the files: /home/${USER}/.opensync/group*/change.db /home/${USER}/.opensync/group*/*/anchor.db /home/${USER}/.opensync/group*/changelog.db /home/${USER}/.opensync/group*/*/*.pid /home/${USER}/.opensync/group*/*/*.ics

It was not possible to sync with an existing calendar file. regards Roland

comment:6 Changed 7 years ago by megandy

Same probleme here with syncing my Nokia 7610 over bluetooth with evolution using libsyncml 0.4.4. A sync with no contacts and calender-items in evolution (but data in my Nokia) accomplishes to get all the data in evolution - but hangs at the end of sync. After interrupting with ctrl+c successive syncs always hang on different elements like contacts or calender-items. An example of the last line before it hangs:

... Sent an entry 20071031T143626Z-6323-1000-1-549@Computer of size 346 to member 2 (evo2-sync). Changetype MODIFIED

After that line msynctool hangs. Using Ubuntu 7.04 with the same configuration works fine.

regards

comment:7 Changed 7 years ago by dgollub

  • Priority changed from high to normal
  • Component changed from OpenSync to Plugin: evolution2
  • Severity changed from blocker to major

Sounds like bad error handling in evo2-sync. We have bad error handling all over the place... but this sounds very odd.

Could, anyone try if this is fixed with the experimental release of 0.34 (please don't try without backups)

comment:8 Changed 7 years ago by rolandbreedveld

  • Priority changed from normal to high
  • Version changed from 0.22 to 0.19
  • Component changed from Plugin: evolution2 to msynctool
  • Severity changed from major to blocker

tried it with the development release from http://opensync.gforge.punktart.de/repo/opensync-svn/ feisty. Same issue, also while syncing Evolution public addressbook to Evolution LDAP addresbook, syncs works fine, (everything syncs!!) but in the end it will hang. latest rows: Sent an entry cn=Roland,ou=addressbook, dc=breedveld, dc=net of size 200 to member 2. Changetype ADDED Member 2 of type evo2-sync committed all changes. All clients have written Member 1 of type evo2-sync just disconnected should give a CTRL-C no errors in the trace-files

msynctool --version

This is msynctool version "0.19" using OpenSync? version "0.22"

Changed 7 years ago by rolandbreedveld

Trace files sync Nokia N73 with Evolution talking to LDAP

comment:9 Changed 7 years ago by rolandbreedveld

Sync between Nokia N73 and a LDAP server connecting using Evolution adapter, Evolution-ldap-addressbook, everything works, but in the end the sync process hangs: See the uploaded trace-files, I did it with one record, to decrease the logging

Logging from LDAP server while syncing :

Dec 19 15:02:35 pnume slapd[15437]: daemon: activity on 1 descriptors Dec 19 15:02:35 pnume slapd[15437]: daemon: new connection on 31 Dec 19 15:02:35 pnume slapd[15437]: daemon: added 31r Dec 19 15:02:35 pnume slapd[15437]: daemon: activity on: Dec 19 15:02:35 pnume slapd[15437]: Dec 19 15:02:35 pnume slapd[15437]: daemon: select: listen=6 active_threads=0 tvp=NULL Dec 19 15:02:35 pnume slapd[15437]: daemon: select: listen=7 active_threads=0 tvp=NULL Dec 19 15:02:35 pnume slapd[15437]: daemon: activity on 1 descriptors Dec 19 15:02:35 pnume slapd[15437]: daemon: activity on: Dec 19 15:02:35 pnume slapd[15437]: 31r Dec 19 15:02:35 pnume slapd[15437]: Dec 19 15:02:35 pnume slapd[15437]: daemon: read activity on 31 Dec 19 15:02:35 pnume slapd[15437]: connection_get(31): got connid=37 Dec 19 15:02:35 pnume slapd[15437]: connection_read(31): checking for input on id=37 Dec 19 15:02:35 pnume slapd[15437]: ber_get_next on fd 31 failed errno=11 (Resource temporarily unavailable) Dec 19 15:02:35 pnume slapd[15437]: do_bind Dec 19 15:02:35 pnume slapd[15437]: daemon: select: listen=6 active_threads=1 tvp=NULL Dec 19 15:02:36 pnume slapd[15437]: daemon: select: listen=7 active_threads=1 tvp=NULL Dec 19 15:02:36 pnume slapd[15437]: >>> dnPrettyNormal: <> Dec 19 15:02:36 pnume slapd[15437]: <<< dnPrettyNormal: <>, <> Dec 19 15:02:36 pnume slapd[15437]: do_bind: version=3 dn="" method=128 Dec 19 15:02:36 pnume slapd[15437]: send_ldap_result: conn=37 op=0 p=3 Dec 19 15:02:36 pnume slapd[15437]: send_ldap_response: msgid=1 tag=97 err=0 Dec 19 15:02:36 pnume slapd[15437]: do_bind: v3 anonymous bind Dec 19 15:02:36 pnume slapd[15437]: daemon: activity on 1 descriptors Dec 19 15:02:36 pnume slapd[15437]: daemon: activity on: Dec 19 15:02:36 pnume slapd[15437]: 31r Dec 19 15:02:36 pnume slapd[15437]: Dec 19 15:02:36 pnume slapd[15437]: daemon: read activity on 31 Dec 19 15:02:36 pnume slapd[15437]: connection_get(31): got connid=37 Dec 19 15:02:36 pnume slapd[15437]: connection_read(31): checking for input on id=37 Dec 19 15:02:36 pnume slapd[15437]: ber_get_next on fd 31 failed errno=11 (Resource temporarily unavailable) Dec 19 15:02:36 pnume slapd[15437]: do_search Dec 19 15:02:36 pnume slapd[15437]: >>> dnPrettyNormal: <> Dec 19 15:02:36 pnume slapd[15437]: <<< dnPrettyNormal: <>, <> Dec 19 15:02:36 pnume slapd[15437]: daemon: select: listen=6 active_threads=1 tvp=NULL Dec 19 15:02:36 pnume slapd[15437]: => send_search_entry: dn="" Dec 19 15:02:36 pnume slapd[15437]: <= send_search_entry Dec 19 15:02:36 pnume slapd[15437]: send_ldap_result: conn=37 op=1 p=3 Dec 19 15:02:36 pnume slapd[15437]: send_ldap_response: msgid=2 tag=101 err=0 Dec 19 15:02:36 pnume slapd[15437]: daemon: select: listen=7 active_threads=1 tvp=NULL Dec 19 15:02:37 pnume slapd[15437]: daemon: activity on 1 descriptors Dec 19 15:02:37 pnume slapd[15437]: daemon: activity on: Dec 19 15:02:37 pnume slapd[15437]: 31r Dec 19 15:02:37 pnume slapd[15437]: Dec 19 15:02:37 pnume slapd[15437]: daemon: read activity on 31 Dec 19 15:02:37 pnume slapd[15437]: connection_get(31): got connid=37 Dec 19 15:02:37 pnume slapd[15437]: connection_read(31): checking for input on id=37 Dec 19 15:02:37 pnume slapd[15437]: ber_get_next on fd 31 failed errno=11 (Resource temporarily unavailable) Dec 19 15:02:37 pnume slapd[15437]: do_search Dec 19 15:02:37 pnume slapd[15437]: daemon: select: listen=6 active_threads=1 tvp=NULL Dec 19 15:02:37 pnume slapd[15437]: daemon: select: listen=7 active_threads=1 tvp=NULL Dec 19 15:02:37 pnume slapd[15437]: >>> dnPrettyNormal: <cn=Subschema> Dec 19 15:02:37 pnume slapd[15437]: <<< dnPrettyNormal: <cn=Subschema>, <cn=subschema> Dec 19 15:02:37 pnume slapd[15437]: is_object_subclass(2.5.20.1,2.5.6.0) 0 Dec 19 15:02:37 pnume slapd[15437]: is_object_subclass(2.5.20.1,2.5.17.0) 0 Dec 19 15:02:37 pnume slapd[15437]: is_object_subclass(2.5.20.1,2.5.6.0) 0 Dec 19 15:02:37 pnume slapd[15437]: is_object_subclass(2.5.20.1,2.5.20.1) 1 Dec 19 15:02:37 pnume slapd[15437]: => send_search_entry: dn="cn=Subschema" Dec 19 15:02:37 pnume slapd[15437]: <= send_search_entry Dec 19 15:02:37 pnume slapd[15437]: send_ldap_result: conn=37 op=2 p=3 Dec 19 15:02:37 pnume slapd[15437]: send_ldap_response: msgid=3 tag=101 err=0 Dec 19 15:02:42 pnume slapd[15437]: daemon: activity on 1 descriptors Dec 19 15:02:42 pnume slapd[15437]: daemon: activity on: Dec 19 15:02:42 pnume slapd[15437]: 31r Dec 19 15:02:42 pnume slapd[15437]: Dec 19 15:02:42 pnume slapd[15437]: daemon: read activity on 31 Dec 19 15:02:42 pnume slapd[15437]: connection_get(31): got connid=37 Dec 19 15:02:42 pnume slapd[15437]: connection_read(31): checking for input on id=37 Dec 19 15:02:42 pnume slapd[15437]: ber_get_next on fd 31 failed errno=11 (Resource temporarily unavailable) Dec 19 15:02:42 pnume slapd[15437]: do_search Dec 19 15:02:42 pnume slapd[15437]: >>> dnPrettyNormal: <ou=addressbook, dc=breedveld, dc=net> Dec 19 15:02:42 pnume slapd[15437]: <<< dnPrettyNormal: <ou=addressbook,dc=breedveld,dc=net>, <ou=addressbook,dc=breedveld,dc=net> Dec 19 15:02:42 pnume slapd[15437]: => ldbm_back_search Dec 19 15:02:42 pnume slapd[15437]: dn2entry_r: dn: "ou=addressbook,dc=breedveld,dc=net" Dec 19 15:02:42 pnume slapd[15437]: => dn2id( "ou=addressbook,dc=breedveld,dc=net" ) Dec 19 15:02:42 pnume slapd[15437]: ====> cache_find_entry_dn2id("ou=addressbook,dc=breedveld,dc=net"): 6464 (1 tries) Dec 19 15:02:42 pnume slapd[15437]: <= dn2id 6464 (in cache) Dec 19 15:02:42 pnume slapd[15437]: => id2entry_r( 6464 ) Dec 19 15:02:42 pnume slapd[15437]: ====> cache_find_entry_id( 6464 ) "ou=addressbook,dc=breedveld,dc=net" (found) (1 tries) Dec 19 15:02:42 pnume slapd[15437]: <= id2entry_r( 6464 ) 0xb71044f0 (cache) Dec 19 15:02:42 pnume slapd[15437]: search_candidates: base="ou=addressbook,dc=breedveld,dc=net" s=1 d=0 Dec 19 15:02:42 pnume slapd[15437]: => filter_candidates Dec 19 15:02:42 pnume slapd[15437]: => list_candidates 0xa0 Dec 19 15:02:42 pnume slapd[15437]: => filter_candidates Dec 19 15:02:42 pnume slapd[15437]: => dn2idl( "%ou=addressbook,dc=breedveld,dc=net" ) Dec 19 15:02:43 pnume slapd[15437]: => ldbm_cache_open( "dn2id.dbb", 73, 600 ) Dec 19 15:02:43 pnume slapd[15437]: <= ldbm_cache_open (cache 0) Dec 19 15:02:43 pnume slapd[15437]: <= filter_candidates 0 Dec 19 15:02:43 pnume slapd[15437]: <= list_candidates NULL Dec 19 15:02:43 pnume slapd[15437]: idl_free: called with NULL pointer Dec 19 15:02:43 pnume slapd[15437]: <= filter_candidates 0 Dec 19 15:02:43 pnume slapd[15437]: ====> cache_return_entry_r( 6464 ): returned (0) Dec 19 15:02:43 pnume slapd[15437]: ldbm_search: no candidates Dec 19 15:02:43 pnume slapd[15437]: send_search_result: err=0 matched="" text="" Dec 19 15:02:43 pnume slapd[15437]: send_ldap_response: msgid=4 tag=101 err=0 Dec 19 15:02:42 pnume slapd[15437]: daemon: select: listen=6 active_threads=1 tvp=NULL Dec 19 15:02:43 pnume slapd[15437]: daemon: select: listen=7 active_threads=1 tvp=NULL Dec 19 15:02:43 pnume slapd[15437]: daemon: activity on 1 descriptors Dec 19 15:02:43 pnume slapd[15437]: daemon: activity on: Dec 19 15:02:43 pnume slapd[15437]: 31r Dec 19 15:02:43 pnume slapd[15437]: Dec 19 15:02:43 pnume slapd[15437]: daemon: read activity on 31 Dec 19 15:02:43 pnume slapd[15437]: connection_get(31): got connid=37 Dec 19 15:02:43 pnume slapd[15437]: connection_read(31): checking for input on id=37 Dec 19 15:02:43 pnume slapd[15437]: ber_get_next on fd 31 failed errno=11 (Resource temporarily unavailable) Dec 19 15:02:43 pnume slapd[15437]: do_add Dec 19 15:02:43 pnume slapd[15437]: >>> dnPrettyNormal: <cn=Politie Algemeen,ou=addressbook, dc=breedveld, dc=net> Dec 19 15:02:43 pnume slapd[15437]: daemon: select: listen=6 active_threads=2 tvp=NULL Dec 19 15:02:43 pnume slapd[15437]: do_abandon Dec 19 15:02:44 pnume slapd[15437]: do_abandon: op=4 not found Dec 19 15:02:43 pnume slapd[15437]: daemon: select: listen=7 active_threads=2 tvp=NULL Dec 19 15:02:43 pnume slapd[15437]: <<< dnPrettyNormal: <cn=Politie Algemeen,ou=addressbook,dc=breedveld,dc=net>, <cn=politie algemeen,ou=addressbook,dc=breedveld,dc=net> Dec 19 15:02:44 pnume slapd[15437]: send_ldap_result: conn=37 op=5 p=3 Dec 19 15:02:44 pnume slapd[15437]: send_ldap_response: msgid=6 tag=105 err=8 Dec 19 15:02:44 pnume slapd[15437]: daemon: activity on 1 descriptors Dec 19 15:02:44 pnume slapd[15437]: daemon: activity on: Dec 19 15:02:44 pnume slapd[15437]: 31r Dec 19 15:02:44 pnume slapd[15437]: Dec 19 15:02:44 pnume slapd[15437]: daemon: read activity on 31 Dec 19 15:02:44 pnume slapd[15437]: connection_get(31): got connid=37 Dec 19 15:02:44 pnume slapd[15437]: connection_read(31): checking for input on id=37 Dec 19 15:02:44 pnume slapd[15437]: ber_get_next on fd 31 failed errno=11 (Resource temporarily unavailable) Dec 19 15:02:44 pnume slapd[15437]: do_abandon Dec 19 15:02:44 pnume slapd[15437]: daemon: select: listen=6 active_threads=1 tvp=NULL Dec 19 15:02:44 pnume slapd[15437]: daemon: select: listen=7 active_threads=1 tvp=NULL Dec 19 15:02:44 pnume slapd[15437]: do_abandon: op=6 not found

comment:10 Changed 6 years ago by felixmoeller

  • Description modified (diff)

comment:11 Changed 4 years ago by 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

Note: See TracTickets for help on using tickets.