GNOME Bugzilla – Bug 324500
crash during processing of meeting update _only if_ using Exchange calender
Last modified: 2006-03-07 11:02:47 UTC
I use Garnome 2.12.2 compiled with -g and had evolution/evolution-exchange-connector running in a debugger when it happend. Later I found that it can be reproduced like this: - import "meeting.ics" into Exchange calender -> it is added fine - import "update.ics" into the same calender -> the update fails with evolution-exchange-storage: icaltime.c:483: icaltime_from_string: Assertion `0' failed. It should have shifted the meeting from 2pm to 12am instead. Importing into a local calender and then updating it works fine. Here's the information from the debugger on the original incident (where I had imported the .ics from mail attachements): Threads (3) 1.1 T at 0xffffe002 1.2 T at 0xffffe002 1.10141 E at 0xffffe002 Stack Trace 1 PC: ffffe002, FP=bfffbde8 __poll, FP=bfffbde8 C g_main_context_poll, FP=bfffbe18 C g_main_context_iterate, FP=bfffbe98 C g_main_loop_run, FP=bfffbed8 C bonobo_main, FP=bfffbef8 C main, FP=bfffbf88 __libc_start_main, FP=bfffbfa8 Stack Trace 2 PC: ffffe002, FP=41a6d774 __poll, FP=41a6d774 C g_main_context_poll, FP=41a6d7a4 C g_main_context_iterate, FP=41a6d824 C g_main_loop_run, FP=41a6d864 C link_io_thread_fn, FP=41a6d884 C g_thread_create_proxy, FP=41a6d8b4 start_thread, FP=41a6d8d4 Stack Trace 3 PC: ffffe002, FP=43931bb4 raise, FP=43931bb4 abort, FP=43931ce4 __assert_fail, FP=43931d24 C icaltime_from_string, FP=43931d94 icaltime.c:483 C receive_objects, FP=43931e74 e-cal-backend-exchange-calender.c:1422 C e_cal_backend_sync_receive_objects, FP=43931ea4 C _e_cal_backend_receive_objects, FP=43931ec4 C e_cal_backend_receive_objects, FP=43931ef4 C impl_Cal_receiveObjects, FP=43931f24 C _ORBIT_skel_small_GNOME_Evolution_Calendar_Cal_receiveObjects, FP=43931f44 C ORBit_POAObject_invoke, FP=43931f74 C ORBit_OAObject_invoke, FP=43931fa4 C ORBit_small_invoke_adaptor, FP=43932074 C ORBit_POAObject_handle_request, FP=439320e4 C ORBit_POAObject_invoke_incoming_request, FP=43932144 C giop_thread_queue_process, FP=43932174 C giop_request_handler_thread, FP=439321a4 C g_thread_pool_thread_proxy, FP=43932204 C g_thread_create_proxy, FP=43932234 start_thread, FP=43932254 Stack Frame of Function "receive_objects": backend: 0x080c13a0 -> (ECalBackendSync) cal: 0x0a2e79e8 -> (EDataCal) calobj: 0x0a37a8e1 -> "BEGIN:.." (see below) Block "$b2#$b1#$b1": time_rid: (struct icaltimetype) Block "$b2#$b1": old_object: 0x00000000 Block "$b2": uid: 0x08299ba0 -> "040000008200E00074C5B7101A82E00800000000709739FE8004C601000000000000000010000000CBF639CC6006604C99BB3171BB1C207D" rid: 0x00000000 icalobj: 0x080c13a0 -> "0M\v\b\035" object: 0x00000000 Local variables: cbexc: 0x080c13a0 -> (ECalBackendExchangeCalendar) ecomp: 0x0a293df0 -> (ECalBackendExchangeComponent) comp: 0x0a2cd258 -> (ECalComponent) comps: 0x09be3fd4 -> (GList) l: 0x09be3fd4 -> (GList) current: (struct icaltimetype) method: ICAL_METHOD_REQUEST (10032) subcomp: 0x0a3183f8 -> (icalcomponent) status: GNOME_Evolution_Calendar_Success (0) calobj (anonymized manually): "BEGIN:VCALENDAR\nCALSCALE:GREGORIAN\nPRODID:-//Ximian//NONSGML Evolution Calendar//EN\nVERSION:2.0\nMETHOD:REQUEST\nBEGIN:VTIMEZONE\nTZID:(GMT) Greenwich Mean Time/Dublin/Edinburgh/London\nX-MICROSOFT-CDO-TZID:1\nBEGIN:STANDARD\nDTSTART:16010101T020000\nTZOFFSETFROM:+0100\nTZOFFSETTO:+0000\nRRULE:FREQ=YEARLY;INTERVAL=1;BYDAY=-1SU;BYMONTH=10\nEND:STANDARD\nBEGIN:DAYLIGHT\nDTSTART:16010101T010000\nTZOFFSETFROM:+0000\nTZOFFSETTO:+0100\nRRULE:FREQ=YEARLY;INTERVAL=1;BYDAY=-1SU;BYMONTH=3\nEND:DAYLIGHT\nEND:VTIMEZONE\nBEGIN:VEVENT\nDTSTAMP:20051219T103437Z\nDTSTART;TZID=(GMT) Greenwich Mean Time/Dublin/Edinburgh/London:\n 20051219T110000\nSUMMARY:Updated: Unser 1:1\nUID:\n 040000008200E00074C5B7101A82E00800000000709739FE8004C601000000000000000010\n 000000CBF639CC6006604C99BB3171BB1C207D\nATTENDEE;ROLE=REQ-PARTICIPANT;X-REPLYTIME=20051219T090600Z;RSVP=TRUE;\n CN=\"Ohly, Patrick\";PARTSTAT=ACCEPTED:MAILTO:xxxx\nORGANIZER;CN=\"yyyy\":MAILTO:\nyyyyyyyyyyyyyy\nLOCATION:BHL1 N211\nDTEND;TZID=(GMT) Greenwich Mean Time/Dublin/Edinburgh/London:\n 20051219T120000\nDESCRIPTION:\\n\nSEQUENCE:0\nPRIORITY:5\nX-LIC-ERROR;X-LIC-ERRORTYPE=VALUE-PARSE-ERROR:No value for CLASS \n property. Removing entire property:\nCREATED:20051219T103433Z\nLAST-MODIFIED:20051219T103439Z\nSTATUS:CONFIRMED\nTRANSP:OPAQUE\nX-MICROSOFT-CDO-BUSYSTATUS:BUSY\nX-MICROSOFT-CDO-INSTTYPE:0\nX-MICROSOFT-CDO-INTENDEDSTATUS:BUSY\nX-MICROSOFT-CDO-ALLDAYEVENT:FALSE\nX-MICROSOFT-CDO-IMPORTANCE:1\nX-MICROSOFT-CDO-OWNERAPPTID:-2127312939\nX-MICROSOFT-CDO-REPLYTIME:20051219T105723Z\nBEGIN:VALARM\nX-EVOLUTION-ALARM-UID:\n 20051219T105711Z-28657-33500-28537-181@pohly-desk1.ikn.intel.com\nACTION:DISPLAY\nTRIGGER;VALUE=DURATION;RELATED=START:-PT15M\nEND:VALARM\nEND:VEVENT\nEND:VCALENDAR\n" The problem is in line 1422: time_rid = icaltime_from_string (rid); because rid == NULL. The reason is that e_cal_component_get_recurid_as_string() in line 1401 did not set it. Setting PC to line 1401 allows single stepping through e_cal_component_get_recurid_as_string(): in e_cal_component_get_recurid_as_string, line 3520, e_cal_component_is_instance (comp) returns false. Here's the content of comp: Expression: *(comp) Address: 0x0a2cd258 Type: ECalComponent Field Type Value object GObject (Struct) g_type_instance GTypeInstance (Struct) g_class GTypeClass * 0x08121658 -> (GTypeClass) ref_count guint volatile 0x00000001 (1) qdata GData * 0x00000000 priv ECalComponentPrivate * 0x0a3770c8 -> (ECalComponentPrivate) Expression: *((comp)->object.g_type_instance.g_class) Address: 0x08121658 Type: GTypeClass Field Type Value g_type GType 0x081bee28 (136048168) Expression: *((comp)->priv) Address: 0x0a3770c8 Type: ECalComponentPrivate Field Type Value icalcomp icalcomponent * 0x0a3183f8 -> (icalcomponent) uid icalproperty * 0x0a2f9db0 -> (icalproperty) status icalproperty * 0x0a2b07d0 -> (icalproperty) attendee_list GSList * 0x08e27f70 -> (GSList) categories icalproperty * 0x00000000 classification icalproperty * 0x00000000 comment_list GSList * 0x00000000 completed icalproperty * 0x00000000 contact_list GSList * 0x00000000 created icalproperty * 0x0a2b0e78 -> (icalproperty) description_list GSList * 0x08e27fb0 -> (GSList) dtstart struct datetime (Struct) dtend struct datetime (Struct) dtstamp icalproperty * 0x08e04d00 -> (icalproperty) duration icalproperty * 0x00000000 due struct datetime (Struct) exdate_list GSList * 0x00000000 exrule_list GSList * 0x00000000 organizer struct organizer (Struct) geo icalproperty * 0x00000000 last_modified icalproperty * 0x08e04ec8 -> (icalproperty) percent icalproperty * 0x00000000 priority icalproperty * 0x0a26aeb0 -> (icalproperty) recur_id struct recur_id (Struct) rdate_list GSList * 0x00000000 rrule_list GSList * 0x00000000 sequence icalproperty * 0x0a2e8e08 -> (icalproperty) summary struct <nameless3392> (Struct) transparency icalproperty * 0x0a304b78 -> (icalproperty) url icalproperty * 0x00000000 location icalproperty * 0x0a37a7d0 -> (icalproperty) attachment_list GSList * 0x00000000 alarm_uid_hash GHashTable * 0x0a36ada0 -> (GHashTable) need_sequence_inc guint:1 0x00 (0) Expression: ((comp)->priv)->recur_id Address: 0x0a37713c Type: struct recur_id Field Type Value recur_time struct datetime (Struct) prop icalproperty * 0x00000000 tzid_param icalparameter * 0x00000000 range_param icalparameter * 0x00000000 e_cal_component_is_instance() returns false because this event is not recurring, which seems to be correct. Therefore it is correct that "rid" is NULL in receive_objects() and the question is: why does the code expect it to be non-NULL? What happens if the lines struct icaltimetype time_rid; time_rid = icaltime_from_string (rid); e_cal_util_remove_instances (ecomp->icomp, time_rid, CALOBJ_MOD_THIS); are only executed if rid != NULL? Answer (verified by jumping over them in the debugger): - there are assertions printed from inside modify_object_with_href(): (evolution-exchange-storage:28645): libecal-CRITICAL **: e_cal_component_commit_sequence: assertion `priv->icalcomp != NULL' failed (evolution-exchange-storage:28645): libecal-CRITICAL **: e_cal_component_get_as_string: assertion `priv->icalcomp != NULL' failed - there are more assertions and finally a segfault deep down inside e_cal_backend_notify_object_modified(), related to accessing an invalid dtend: Stack Trace C e_cal_recur_generate_instances_of_rule, FP=43931ad4 e-cal-recur.c:738 C e_cal_recur_generate_instances, FP=43931b14 C func_occur_in_time_range, FP=43931b64 C e_sexp_term_eval, FP=43931bb4 C term_eval_and, FP=43931c14 C e_sexp_term_eval, FP=43931c54 C e_sexp_eval, FP=43931c84 C e_cal_backend_sexp_match_comp, FP=43931cc4 C e_cal_backend_sexp_match_object, FP=43931cf4 C e_data_cal_view_object_matches, FP=43931d24 C match_query_and_notify, FP=43931d54 C e_cal_backend_notify_object_modified, FP=43931d84 C receive_objects, FP=43931e74 C e_cal_backend_sync_receive_objects, FP=43931ea4 C _e_cal_backend_receive_objects, FP=43931ec4 C e_cal_backend_receive_objects, FP=43931ef4 C impl_Cal_receiveObjects, FP=43931f24 C _ORBIT_skel_small_GNOME_Evolution_Calendar_Cal_receiveObjects, FP=43931f44 C ORBit_POAObject_invoke, FP=43931f74 C ORBit_OAObject_invoke, FP=43931fa4 C ORBit_small_invoke_adaptor, FP=43932074 C ORBit_POAObject_handle_request, FP=439320e4 C ORBit_POAObject_invoke_incoming_request, FP=43932144 C giop_thread_queue_process, FP=43932174 C giop_request_handler_thread, FP=439321a4 C g_thread_pool_thread_proxy, FP=43932204 C g_thread_create_proxy, FP=43932234 start_thread, FP=43932254 Expression: dtend Address: 0x43931ab4 Type: ECalComponentDateTime Field Type Value value struct icaltimetype * 0x00000001 -> <Bad address: 0x00000001> (struct icaltimetype) tzid $string const * 0x080c01f0 -> "" After that I gave up trying to patch this in the debugger and restarted. Then I noticed that it can be reproduced by importing the same iCalender entries, so here you go. I'll attach the two .ics files.
Created attachment 56160 [details] meeting invitation
Created attachment 56161 [details] meeting update
Patrick: Thanks for reporting bug. I observed in my setup while importing the meeting.ics file exchange connector is crashing. Can you please paste stack traces of crash you are observing by typing 'thread apply all bt' at gdb prompt.
Here's the requested gdb output: (gdb) thread apply all bt
+ Trace 64721
Thread 2 (Thread 1142106816 (LWP 3819))
Regarding the crash that Poornima observed: perhaps the real problem is that the initial meeting invitation is created in such a way that it is incomplete? Depending on who accesses it Evolution then might crash very soon (Poornima's setup) or later (mine, due to missing recurrence infos).
To rule out the possibility that the meeting.ics attachement got somehow damaged (unlikely, as I marked it as binary data), I downloaded it and imported it once more: the file is unchanged, and importing it works fine here.
re-opening the bug as it has the data.
I have fixed this bug. Fix has been committed on 2006-01-04 to cvs HEAD.