View Issue Details

IDProjectCategoryView StatusLast Update
0005656SOGoBackend Calendarpublic2022-12-17 00:47
Reporterpyheme Assigned To 
PrioritynormalSeverityminorReproducibilityalways
Status newResolutionopen 
PlatformServerOSLinux UbuntuOS Version20.04
Product Version5.8.0 
Summary0005656: Calendar invitations received from Outlook for Mac cannot be added to SOGo calendar
Description

We're running SOGo as backend for calendars and as webmail for our Postfix/Dovecot mail server running virtual users on MySQL.

When receiving a meeting invitation from some contacts, the event does not show up on the calendar. We're a small teams with 4 users, all users are affected by this issue.

There seems to be 2 cases where this error happens:

  • Email received from Outlook for Mac (all invites from an internal user running on Mac do generate errors as well as other invites from clients that we know use Outlook for Mac).
  • Email received for a MS Teams invite (external to our organization, not sure if Mac or PC user)

The SOGo logs show the following errors on processing it (following appears when trying to sync the event from Outlook on Windows 10 PC with Outlook Caldav Synchronizer, when adding event from webmail platform, it doesn't work either):

Dec 06 15:03:38 sogod [765167]: 123.456.789.100 "REPORT /SOGo/dav/user@example.com/Calendar/personal/ HTTP/1.1" 207 125/305 0.023 - - 0 -
Dec 06 15:03:38 sogod [765167]: <0x0x50f0db0006c0[GCSFolder]> ERROR(-[GCSFolder writeContent:fromComponent:container:toName:baseVersion:]): cannot insercolumn 'c_description' at row 1
Dec 06 15:03:38 sogod [765167]: [ERROR] <0x0x50f0db0006c0[SOGoAppointmentObject]:040000008200E00035FDB7101A82E0080000000070119992BD08D90100000000000000001 NAME:ExecutionFailed REASON:Data too long for column 'c_description' at row 1
Dec 06 15:03:38 sogod [765167]: 190.148.128.54 "PUT /SOGo/dav/user@example.com/Calendar/personal/040000008200E00035FDB7101A82E00800000000/99036 0.239 - - 0 - 15

I tried to manually change in MySQL the tables "sogousernameXXXX_quick" for c_description fields to become LONGTEXT and the error disappears and the invite seems to get properly recorded.
From what I could see, these tables get defined in /usr/lib/GNUstep/OCSTypeModels/appointment.ocs

I'm not sure if this issue is proper to our install or a bug that impacts others, but I thought it could be a good thing to signal here.

Steps To Reproduce

Receive a calendar event invitation sent from Outlook for Mac (latest version available in Office 365 subscription).
Try to add the event to SOGo calendar.

TagsNo tags attached.

Activities

sebastien

sebastien

2022-12-07 08:04

administrator   ~0016472

Can you enable MySQL4DebugEnabled = YES; and post SQL request ?

pyheme

pyheme

2022-12-08 12:50

reporter   ~0016475

Ok. I enabled it and reverted the c_description field to TEXT, but now I need to receive a new problematic invite for the error to occur again or find a way to reprocess the already processed invites. I'll update the ticket with logs soon.

Thinking about it a bit more, the last couple of problematic invites were sent in response to a long thread of emails where the 'invite description' was the full thread.
It's possible that the issue we're facing is that the text description is indeed longer that MySQL's TEXT field capacity, although I would expect SOGo to truncate it rather than throw an error, no?

pyheme

pyheme

2022-12-08 14:55

reporter   ~0016476

Hi,
Here's the log related to an event that can't be processed.

Dec 08 08:23:01 sogod [997777]: |SOGo| starting method 'REPORT' on uri '/SOGo/dav/user@example.com/Calendar/personal/'
2022-12-08 08:23:01.818 sogod[997777:997777] <MySQL4Channel[0x0x5599dbdc2df0] connection=0x0x5599dbdc3560> SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'user@example.com' AND c_folder_type = 'Appointment';
2022-12-08 08:23:01.818 sogod[997777:997777] <MySQL4Channel[0x0x5599dbdc2df0] connection=0x0x5599dbdc3560> query has results, entering fetch-mode.
2022-12-08 08:23:01.821 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb17070] connection=0x0x5599dbb1d5d0> SQL: SELECT c_lastmodified FROM sogouser002781e983d ORDER BY c_lastmodified DESC;
2022-12-08 08:23:01.846 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb17070] connection=0x0x5599dbb1d5d0> query has results, entering fetch-mode.
2022-12-08 08:23:01.862 sogod[997777:997777] ---------- -[MySQL4Channel primaryCloseChannel]: <MySQL4Channel[0x0x5599dbb17070] connection=0x0x5599dbb1d5d0> close channel count[5]
2022-12-08 08:23:01.863 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT b.c_name,a.c_component,b.c_creationdate,b.c_lastmodified,a.c_enddate,a.c_cycleenddate,b.c_version FROM sogouser002781e983d_quick a, sogouser002781e983d b WHERE (c_lastmodified > 1670452740) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL);
2022-12-08 08:23:01.874 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
2022-12-08 08:23:01.874 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT c_name, c_lastmodified, c_deleted FROM sogouser002781e983d WHERE ((c_lastmodified > 1670452740) AND (c_deleted = 1));
2022-12-08 08:23:01.878 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
Dec 08 08:23:01 sogod [997777]: |SOGo| request took 0.065607 seconds to execute
Dec 08 08:23:01 sogod [997777]: 123.45.67.89 "REPORT /SOGo/dav/user@example.com/Calendar/personal/ HTTP/1.1" 207 647/305 0.068 - - 0 - 15
Dec 08 08:23:02 sogod [997777]: |SOGo| starting method 'REPORT' on uri '/SOGo/dav/user@example.com/Calendar/personal/'
2022-12-08 08:23:02.036 sogod[997777:997777] <MySQL4Channel[0x0x5599dbbd8730] connection=0x0x5599dbb58930> SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'user@example.com' AND c_folder_type = 'Appointment';
2022-12-08 08:23:02.036 sogod[997777:997777] <MySQL4Channel[0x0x5599dbbd8730] connection=0x0x5599dbb58930> query has results, entering fetch-mode.
2022-12-08 08:23:02.036 sogod[997777:997777] ---------- -[MySQL4Channel primaryCloseChannel]: <MySQL4Channel[0x0x5599dbbd8730] connection=0x0x5599dbb58930> close channel count[4]
Dec 08 08:23:02 sogod [997777]: [ERROR] <0x5599dbb2faa0[SOGoAppointmentFolder]:personal> DAV property '{DAV:}displayname' has no matching SQL field, response could be incomplete
2022-12-08 08:23:02.039 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT b.c_name,a.c_component,b.c_content,b.c_version FROM sogouser002781e983d_quick a, sogouser002781e983d b WHERE ((a.c_name = '040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics') OR (a.c_name = '040000008200E00074C5B3101A19C00800000000702CB59C540AD901000000000000000010000000E842674DA102D944ADC42DB53EFFE42A.ics') OR (a.c_name = '32ec7307-c5a8-4c4b-b2cc-6e6423243572.ics')) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL);
2022-12-08 08:23:02.040 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
Dec 08 08:23:02 sogod [997777]: |SOGo| request took 0.008279 seconds to execute
Dec 08 08:23:02 sogod [997777]: 123.45.67.89 "REPORT /SOGo/dav/user@example.com/Calendar/personal/ HTTP/1.1" 207 7112/943 0.010 - - 0 - 14
Dec 08 08:23:02 sogod [997777]: |SOGo| starting method 'PUT' on uri '/SOGo/dav/user@example.com/Calendar/personal/32ec7307-c5a8-4c4b-b2cc-6e6423243572.ics'
2022-12-08 08:23:02.208 sogod[997777:997777] <MySQL4Channel[0x0x5599dbdc2df0] connection=0x0x5599dbdc3560> SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'user@example.com' AND c_folder_type = 'Appointment';
2022-12-08 08:23:02.208 sogod[997777:997777] <MySQL4Channel[0x0x5599dbdc2df0] connection=0x0x5599dbdc3560> query has results, entering fetch-mode.
2022-12-08 08:23:02.211 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT b.c_name,b.c_version,b.c_creationdate,b.c_lastmodified,a.c_component,b.c_content FROM sogouser002781e983d_quick a, sogouser002781e983d b WHERE (a.c_name = '32ec7307-c5a8-4c4b-b2cc-6e6423243572.ics') AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL);
2022-12-08 08:23:02.212 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
Dec 08 08:23:02 sogod [997777]: |SOGo| request took 0.010767 seconds to execute
Dec 08 08:23:02 sogod [997777]: 123.45.67.89 "PUT /SOGo/dav/user@example.com/Calendar/personal/32ec7307-c5a8-4c4b-b2cc-6e6423243572.ics HTTP/1.1" 412 91/1334 0.013 - - 0 - 14
Dec 08 08:23:02 sogod [997777]: |SOGo| starting method 'PUT' on uri '/SOGo/dav/user@example.com/Calendar/personal/040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics'
2022-12-08 08:23:02.303 sogod[997777:997777] <MySQL4Channel[0x0x5599dbdc2df0] connection=0x0x5599dbdc3560> SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'user@example.com' AND c_folder_type = 'Appointment';
2022-12-08 08:23:02.304 sogod[997777:997777] <MySQL4Channel[0x0x5599dbdc2df0] connection=0x0x5599dbdc3560> query has results, entering fetch-mode.
2022-12-08 08:23:02.306 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT b.c_name,b.c_version,b.c_creationdate,b.c_lastmodified,a.c_component,b.c_content FROM sogouser002781e983d_quick a, sogouser002781e983d b WHERE (a.c_name = '040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics') AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL);
2022-12-08 08:23:02.307 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
2022-12-08 08:23:02.309 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT FROM sogo_users WHERE (c_uid = 'userext@externaldomain.com') OR (mail = 'userext@externaldomain.com');
2022-12-08 08:23:02.309 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
2022-12-08 08:23:02.310 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT
FROM sogo_users WHERE (c_uid = 'otheruser@gmail.com') OR (mail = 'otheruser@gmail.com');
2022-12-08 08:23:02.310 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
2022-12-08 08:23:02.318 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: SELECT c_version, c_deleted FROM sogouser002781e983d WHERE (c_name = '040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics');
2022-12-08 08:23:02.318 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has results, entering fetch-mode.
2022-12-08 08:23:02.320 sogod[997777:997777] MySQL4 connection established 0x0x5599dbae57b0
2022-12-08 08:23:02.320 sogod[997777:997777] ---------- -[MySQL4Channel openChannel]: <MySQL4Channel[0x0x5599dbb5b570] connection=0x0x5599dbae57b0> opens channel count[3]
2022-12-08 08:23:02.320 sogod[997777:997777] MySQL4 channel 0x0x5599dbb5b570 opened (connection=0x0x5599dbae57b0,sogo)
2022-12-08 08:23:02.320 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb5b570] connection=0x0x5599dbae57b0> SQL: BEGIN;
2022-12-08 08:23:02.321 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb5b570] connection=0x0x5599dbae57b0> query has no results.
2022-12-08 08:23:02.321 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: BEGIN;
2022-12-08 08:23:02.321 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has no results.
2022-12-08 08:23:02.321 sogod[997777:997777] WARNING(-[NSString(MySQL4Values) stringValueForMySQL4Type:attribute:]): return string as is for type LONGTEXT
2022-12-08 08:23:02.322 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb5b570] connection=0x0x5599dbae57b0> SQL: UPDATE sogouser002781e983d_quick SET c_iscycle = 0, c_orgmail = 'userext@externaldomain.com', c_uid = '040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38', c_nextalarm = 0, c_name = '040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics', c_category = null, c_priority = 5, c_cycleinfo = null, c_sequence = 2, c_isallday = 0, c_title = 'REVISION PROJT', c_cycleenddate = null, c_description =


Reunión de Microsoft Teams

Únase a través de su PC o aplicación móvil

Haga clic aquí para unirse a la reunión <https://teams.microsoft.com/l/meetup-join/19%3ameeting_ZBNjOGE3OCgtY2QwXy00NElkFRIyMWUtNzY4ODY5NDI4MDBl%40thread.v2/0?context=%7b%22Tid%23%3a%583c3c8090-9172-20ec-f71-bcc913140893%22%2c%22Oid%22%3a%22f42ba853-9199-4f6c-8f9f-066c59a819b4%22%7d>

ID de la reunión: 240 172 528 038
Código de acceso: ZDLpye

Descargar Teams <https://www.microsoft.com/en-us/microsoft-teams/download-app> | Unirse en la web <https://www.microsoft.com/microsoft-teams/join-a-meeting>

Infórmese <https://aka.ms/JoinTeamsMeeting> | Opciones de reunión <https://teams.microsoft.com/meetingOptions/?organizerId=f37be827-4159-4f6c-8f9f-046a53a519b4&amp;tenantId=3c8c8090-2142-30da-d482-cc0413140793&amp;threadId=19_meeting_ZBNjOGE3OCgtY2QwXy00NElkFRIyMWUtNzY4ODY5NDI4MDBl@thread.v2&amp;messageId=0&amp;language=es-ES>


, c_status = 1, c_classification = 1, c_startdate = 1670446800, c_participants = 'First Lastname
\'Other User\'
user@example.com
\'Other User2\'', c_partmails = 'userext@externaldomain.com
user2@example.com
user@example.com
otheruser@gmail.com', c_partstates = '0
0
0
0', c_component = 'vevent', c_location = 'Reunión de Microsoft Teams', c_isopaque = 1, c_enddate = 1670448600 WHERE c_name = '040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics';
2022-12-08 08:23:02.322 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb5b570] connection=0x0x5599dbae57b0> ERROR: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'Reunión de Microsoft Teams

Únase a través de su PC o aplicación móvil ...' at line 5
2022-12-08 08:23:02.322 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> SQL: ROLLBACK;
2022-12-08 08:23:02.322 sogod[997777:997777] <MySQL4Channel[0x0x5599dbc00570] connection=0x0x5599dbc00cc0> query has no results.
2022-12-08 08:23:02.322 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb5b570] connection=0x0x5599dbae57b0> SQL: ROLLBACK;
2022-12-08 08:23:02.323 sogod[997777:997777] <MySQL4Channel[0x0x5599dbb5b570] connection=0x0x5599dbae57b0> query has no results.
Dec 08 08:23:02 sogod [997777]: <0x0x5599db8fba80[GCSFolder]> ERROR(-[GCSFolder writeContent:fromComponent:container:toName:baseVersion:]): cannot update content : <MySQL4Exception: 0x5599db9f36b0> NAME:ExecutionFailed REASON:You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'Reunión de Microsoft Teams

Únase a través de su PC o aplicación móvil ...' at line 5
Dec 08 08:23:02 sogod [997777]: [ERROR] <0x5599dbadb020[SOGoAppointmentObject]:040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics> write failed: <MySQL4Exception: 0x5599db9f36b0> NAME:ExecutionFailed REASON:You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'Reunión de Microsoft Teams

Únase a través de su PC o aplicación móvil ...' at line 5
Dec 08 08:23:02 sogod [997777]: |SOGo| request took 0.025982 seconds to execute
Dec 08 08:23:02 sogod [997777]: 123.45.67.89 "PUT /SOGo/dav/user@example.com/Calendar/personal/040000008200E00074C5B3101A19C00800000000C0F7B27F350AD90100000000000000001000000088B58B6113A7D84DB7133D6CB9DCFE38.ics HTTP/1.1" 500 0/2675 0.028 - - 0 - 15

pyheme

pyheme

2022-12-17 00:47

reporter   ~0016506

As a quick update, I ran into the issue again today, after updating the sogo instance to the latest nightly built.
In looking more closely at the SQL error, I can see that the c_description field is not escaped by an opening/closing quote like the rest of the fields.
When running in MySQL cli the same query that causes the error but surrounding the content of c_description with a single quote, the record gets added without problem, leading me to think that this is the cause of the issue.

I, however, do not know where I would need to go to change the code so that c_description content gets escaped when adding an event to the calendar, so that I can test my theory. Anyone here who could give me some guidance?

Thanks in advance

Issue History

Date Modified Username Field Change
2022-12-06 22:13 pyheme New Issue
2022-12-07 08:04 sebastien Note Added: 0016472
2022-12-08 12:50 pyheme Note Added: 0016475
2022-12-08 14:55 pyheme Note Added: 0016476
2022-12-17 00:47 pyheme Note Added: 0016506