WebDAV Contacts - Gnome Evolution

[gracedman]

We're digging further into the 75 second delay problem. We initially suspected it was an Evolution problem where Evolution was not closing the TCP connection but it now appears to be a Zimbra problem. As mentioned earlier, we see Zimbra create the appointment/contact and Evolution acknowledges the 201 create packet. But Zimbra then sits for 75 seconds. After that time, it issues a FIN packet to close the TCP connection used to create the contact/appointment. At that point Evolution does a DAV GET to ensure creation and returns control to the user.

The Evolution mailing list says this behavior is unique to Zimbra. All other DAV servers they have tested against return immediately. I'll paste in two backtraces taken from Evolution in case they give the Zimbra devs/community any clue as to where the problem is.

Here is a backtrace taken while waiting the 75 seconds:

[Thread debugging using libthread_db enabled]
[New Thread 0x7fe13d3907b0 (LWP 27580)]
[New Thread 0x7fe11ffff910 (LWP 20197)]
[New Thread 0x7fe11c9e5910 (LWP 27627)]
[New Thread 0x7fe11d7fa910 (LWP 27626)]
[New Thread 0x7fe11dffb910 (LWP 27625)]
[New Thread 0x7fe11e7fc910 (LWP 27624)]
[New Thread 0x7fe12d8f9910 (LWP 27609)]
[New Thread 0x7fe13d230910 (LWP 27581)]
0x00007fe137709743 in poll () from /lib/libc.so.6

Thread 8 (Thread 0x7fe13d230910 (LWP 27581)):
#0 0x00007fe137709743 in poll () from /lib/libc.so.6
#1 0x00007fe138443299 in ?? () from /lib/libglib-2.0.so.0
#2 0x00007fe138443a45 in g_main_loop_run () from /lib/libglib-2.0.so.0
#3 0x00007fe1396c2bc0 in ?? () from /usr/lib/libORBit-2.so.0
#4 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#5 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#6 0x00007fe13771469d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 7 (Thread 0x7fe12d8f9910 (LWP 27609)):
#0 0x00007fe137709743 in poll () from /lib/libc.so.6
#1 0x00007fe138443299 in ?? () from /lib/libglib-2.0.so.0
#2 0x00007fe138443a45 in g_main_loop_run () from /lib/libglib-2.0.so.0
#3 0x00007fe13c9361fd in startup_mainloop (arg=<value optimized out>) at e-book.c:3783
#4 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#5 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#6 0x00007fe13771469d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 6 (Thread 0x7fe11e7fc910 (LWP 27624)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 5 (Thread 0x7fe11dffb910 (LWP 27625)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 4 (Thread 0x7fe11d7fa910 (LWP 27626)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 3 (Thread 0x7fe11c9e5910 (LWP 27627)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7fe11ffff910 (LWP 20197)):
#0 0x00007fe1379aa90b in read () from /lib/libpthread.so.0
#1 0x00007fe138481b12 in ?? () from /lib/libglib-2.0.so.0
#2 0x00007fe1384359f8 in g_io_channel_read_chars () from /lib/libglib-2.0.so.0
#3 0x00007fe13945e11f in ?? () from /usr/lib/libsoup-2.4.so.1
#4 0x00007fe13945e6fd in soup_socket_read () from /usr/lib/libsoup-2.4.so.1
#5 0x00007fe139452dc3 in ?? () from /usr/lib/libsoup-2.4.so.1
#6 0x00007fe139453738 in ?? () from /usr/lib/libsoup-2.4.so.1
#7 0x00007fe13945d5af in ?? () from /usr/lib/libsoup-2.4.so.1
#8 0x00007fe13945d833 in ?? () from /usr/lib/libsoup-2.4.so.1
#9 0x00007fe13474bbf7 in send_and_handle_redirection (soup_session=0x64c000, msg=0x7fe1280028d0, new_location=0x7fe11fffeb10) at e-cal-backend-caldav.c:897
#10 0x00007fe13474eeb5 in caldav_server_put_object (cbdav=0x64b080, object=0x7fe11fffebe0, icalcomp=0xa0b080) at e-cal-backend-caldav.c:1352
#11 0x00007fe13475010c in do_create_object (cbdav=0x64b080, calobj=0x7fe11fffecc0, uid=0x7fe11fffecc8) at e-cal-backend-caldav.c:3232
#12 0x00007fe134750243 in caldav_create_object (backend=<value optimized out>, cal=<value optimized out>, calobj=0x7fe11fffecc0, uid=0x7fe11fffecc8)
at e-cal-backend-caldav.c:3819
#13 0x00007fe13ad40413 in e_cal_backend_sync_create_object (backend=0x64b080, cal=0x649400, calobj=0x7fe11fffecc0, uid=0x7fe11fffecc8) at e-cal-backend-sync.c:233
#14 0x00007fe13ad404dc in _e_cal_backend_create_object (backend=0x64b080, cal=0x649400,
calobj=0x6ce2c1 "BEGIN:VEVENT\r\nUID:20100511T214801Z-27580-100001-1-2@user.mycompany.com\r\nDTSTAMP:20100511T214801Z\r \nTRANSP:OPAQUE\r\nDTSTART;TZID=/freeassociation.s
#15 0x00007fe1396ab3ca in ORBit_small_invoke_adaptor () from /usr/lib/libORBit-2.so.0
#16 0x00007fe1396bb44d in ?? () from /usr/lib/libORBit-2.so.0
#17 0x00007fe1396bba7a in ?? () from /usr/lib/libORBit-2.so.0
#18 0x00007fe1396a46e5 in giop_thread_queue_process () from /usr/lib/libORBit-2.so.0
#19 0x00007fe1396a4f68 in ?? () from /usr/lib/libORBit-2.so.0
#20 0x00007fe13846a52f in ?? () from /lib/libglib-2.0.so.0
#21 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#22 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#23 0x00007fe13771469d in clone () from /lib/libc.so.6
#24 0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7fe13d3907b0 (LWP 27580)):
#0 0x00007fe137709743 in poll () from /lib/libc.so.6
#1 0x00007fe138443299 in ?? () from /lib/libglib-2.0.so.0
#2 0x00007fe138443a45 in g_main_loop_run () from /lib/libglib-2.0.so.0
#3 0x00007fe139b347a6 in bonobo_main () from /usr/lib/libbonobo-2.so.0
#4 0x0000000000403b8e in main (argc=3, argv=<value optimized out>) at server.c:353
#0 0x00007fe137709743 in poll () from /lib/libc.so.6

Here is the backtrace after application control has returned to the user:

[Thread debugging using libthread_db enabled]
[New Thread 0x7fe13d3907b0 (LWP 27580)]
[New Thread 0x7fe11c9e5910 (LWP 27627)]
[New Thread 0x7fe11d7fa910 (LWP 27626)]
[New Thread 0x7fe11dffb910 (LWP 27625)]
[New Thread 0x7fe11e7fc910 (LWP 27624)]
[New Thread 0x7fe12d8f9910 (LWP 27609)]
[New Thread 0x7fe13d230910 (LWP 27581)]
0x00007fe137709743 in poll () from /lib/libc.so.6

Thread 7 (Thread 0x7fe13d230910 (LWP 27581)):
#0 0x00007fe137709743 in poll () from /lib/libc.so.6
#1 0x00007fe138443299 in ?? () from /lib/libglib-2.0.so.0
#2 0x00007fe138443a45 in g_main_loop_run () from /lib/libglib-2.0.so.0
#3 0x00007fe1396c2bc0 in ?? () from /usr/lib/libORBit-2.so.0
#4 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#5 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#6 0x00007fe13771469d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 6 (Thread 0x7fe12d8f9910 (LWP 27609)):
#0 0x00007fe137709743 in poll () from /lib/libc.so.6
#1 0x00007fe138443299 in ?? () from /lib/libglib-2.0.so.0
#2 0x00007fe138443a45 in g_main_loop_run () from /lib/libglib-2.0.so.0
#3 0x00007fe13c9361fd in startup_mainloop (arg=<value optimized out>) at e-book.c:3783
#4 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#5 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#6 0x00007fe13771469d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 5 (Thread 0x7fe11e7fc910 (LWP 27624)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 4 (Thread 0x7fe11dffb910 (LWP 27625)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 3 (Thread 0x7fe11d7fa910 (LWP 27626)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7fe11c9e5910 (LWP 27627)):
#0 0x00007fe1379a820d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x00007fe138b25482 in ?? () from /usr/lib/libgthread-2.0.so.0
#2 0x00007fe134753145 in caldav_synch_slave_loop (data=<value optimized out>) at e-cal-backend-caldav.c:1999
#3 0x00007fe1384686e4 in ?? () from /lib/libglib-2.0.so.0
#4 0x00007fe1379a373a in start_thread () from /lib/libpthread.so.0
#5 0x00007fe13771469d in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7fe13d3907b0 (LWP 27580)):
#0 0x00007fe137709743 in poll () from /lib/libc.so.6
#1 0x00007fe138443299 in ?? () from /lib/libglib-2.0.so.0
#2 0x00007fe138443a45 in g_main_loop_run () from /lib/libglib-2.0.so.0
#3 0x00007fe139b347a6 in bonobo_main () from /usr/lib/libbonobo-2.so.0
#4 0x0000000000403b8e in main (argc=3, argv=<value optimized out>) at server.c:353
#0 0x00007fe137709743 in poll () from /lib/libc.so.6

Any help would be greatly appreciated. Thanks - John

[gracedman]

We were finally able to get the NGINX proxy to rewrite the Evolution contact creation URI to include the supposedly required format parameter of ?fmt=vcf. However, even though we could see the properly formatted URI in mailbox.log, the database was still recording the newly created contacts as Type 8 (Documents) rather than Type 6 (Contacts). We have opened an incident with Zimbra.

[gracedman]

With help from Zimbra support, I think I see what is happening. Evolution is sending the contact with the deprecated type text/x-vcard instead of text/vcard. Zimbra expects the latter to categorize it as type=6. I've flagged this to the Evolution bugzilla but I wonder if Zimbra could also be a little more accommodating for those packages which are still sending x-vcard - John

[gracedman]

Hmm . . . apparently, according to the Evolution mailing list, there is no text/vcard mime-type. text/x-vcard is deprecated but was replaced with text/directory.

This seems to be corroborated by Wikipedia (http://en.wikipedia.org/wiki/VCard):
"Note: The Internet media type text/vcard was used (incorrectly) in some SyncML Documentation to refer to vCard 3.0, and the example was followed in various implementations."

[gracedman]

It looks like we are just about there. First, we needed patches implemented in Zimbra 6.0.7 to solve the problem where contacts were created with the wrong type value in the mail_item database table.

Then we needed to patch Evolution with patches from https://bugzilla.gnome.org/show_bug.cgi?id=604650 and https://bugzilla.gnome.org/show_bug.cgi?id=566330

We also sponsored the Trinity project (Trinity Desktop Environment) to create a huge number of patches to Kontact (and they created more than we sponsored!) so that Kontact from Trinity also works.

Then we worked around the 75 second delay problem by changing the
NGINX settings. Under /opt/zimbra/conf/nginx/templates we edited
nginx.conf.web.https.template and nginx.conf.web.http.template by setting
keepalive_timeout 0; within the server section, before the location block and
then running zmnginxctl stop ; zmnginxctl start.

The only problem we still have in Evolution is Free/Busy. The same format we are successfully using in Kontact is failing in Evolution. We have not yet investigated why.

[gracedman]

The 75 second problem was not a Zimbra problem but rather a client problem shared by both Evolution and Kontact. Once the clients were changed to send a close connection request in the header, all worked fine without the changes to NGINX. Here are some of our internal notes used for patching against Debian source for Evolution 2.30.2.1:

Download the patch from https://bugzilla.gnome.org/show_bug.cgi?id=623936 and name it eds-close-connection.patch
Apply (patch -p1 < eds-close-connection.patch)
Hmm . . . we found we had to remove the hunk for line 757 as that function seems to have been removed
Download the test patch from https://bugzilla.gnome.org/show_bug.cgi?id=604650 and name it eds-text-vcard.patch
Apply (patch -p1 < eds-text-vcard.patch)

Free/busy is still broken in Evolution. We have a small punch list open in the Trinity version on Kontact.

Contact lists are broken in both. At this point, it is pretty usable.