Dec 12 02:39:02 sogod [27823]: |SOGo| starting method 'POST' on uri '/SOGo/so/test1.test1@x2.local/Calendar/personal/6CAF-63968600-1-221AAAC0.ics/saveAsAppointment' Dec 12 02:39:02 sogod [27823]: |SOGo| lookup name: test1.test1@x2.local Dec 12 02:39:02 sogod [27823]: |SOGo| did not find key 'test1.test1@x2.local' in SoClass: <0x0x5628bdcab410[SoObjCClass]: super=0x0x5628bdcaa600 objc=SOGo slots=passwordRecovery,changePassword,toolbar,passwordRecoveryCheck,Microsoft-Server-ActiveSync,saml2-metadata,saml2-sls,loading,view,GET,casProxy,saml2-signon-post,passwordRecoveryEnabled,connect,index,passwordRecoveryEmail> Dec 12 02:39:02 sogod [27823]: |SOGo| looked up value: (null) Dec 12 02:39:02 sogod [27823]: |SOGo| lookup in root object: (null) Dec 12 02:39:02 sogod [27823]: |SOGo| GOT: (null) 2022-12-12 02:39:02.581 sogod[27823:27823] SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'test1.test1@x2.local' AND c_folder_type = 'Appointment'; 2022-12-12 02:39:02.581 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.582 sogod[27823:27823] SQL: SELECT b.c_name,b.c_version,b.c_creationdate,b.c_lastmodified,a.c_component,b.c_content FROM sogo_quick_appointment a, sogo_store b WHERE (a.c_folder_id = 32 AND b.c_folder_id = 32) AND (a.c_name = '6CAF-63968600-1-221AAAC0.ics') AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL); 2022-12-12 02:39:02.582 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.587 sogod[27823:27823] SQL: SELECT c_foldername FROM sogo_folder_info WHERE c_path = '/Users/test1.test1@x2.local/Calendar/personal'; 2022-12-12 02:39:02.587 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.593 sogod[27823:27823] SQL: SELECT c_version, c_deleted FROM sogo_store WHERE c_folder_id = 32 AND (c_name = '6CAF-63968600-1-221AAAC0.ics'); 2022-12-12 02:39:02.593 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.596 sogod[27823:27823] MySQL4 connection established 0x0x5628be7c8400 2022-12-12 02:39:02.596 sogod[27823:27823] ---------- -[MySQL4Channel openChannel]: opens channel count[2] 2022-12-12 02:39:02.596 sogod[27823:27823] MySQL4 channel 0x0x5628be7c7cb0 opened (connection=0x0x5628be7c8400,sogo) 2022-12-12 02:39:02.596 sogod[27823:27823] SQL: BEGIN; 2022-12-12 02:39:02.596 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.596 sogod[27823:27823] SQL: BEGIN; 2022-12-12 02:39:02.596 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.596 sogod[27823:27823] SQL: INSERT INTO sogo_quick_appointment (c_iscycle, c_orgmail, c_uid, c_nextalarm, c_name, c_category, c_priority, c_cycleinfo, c_sequence, c_folder_id, c_isallday, c_title, c_cycleenddate, c_description, c_status, c_classification, c_startdate, c_participants, c_partmails, c_partstates, c_component, c_location, c_isopaque, c_enddate) VALUES (0, 'test1.test1@x2.local', '6CAF-63968600-1-221AAAC0', 1670845500, '6CAF-63968600-1-221AAAC0.ics', null, 0, null, 0, 32, 0, 'TestEvent', null, '', 1, 0, 1670847300, '', 'test1.test1@x1.local', '0', 'vevent', '', 1, 1670859900); 2022-12-12 02:39:02.597 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.597 sogod[27823:27823] SQL: INSERT INTO sogo_store (c_content, c_folder_id, c_version, c_lastmodified, c_name, c_creationdate) VALUES ('BEGIN:VCALENDAR PRODID:-//Inverse inc./SOGo 5.8.0//EN VERSION:2.0 BEGIN:VTIMEZONE TZID:Europe/Vienna LAST-MODIFIED:20221129T123233Z X-LIC-LOCATION:Europe/Vienna BEGIN:DAYLIGHT TZNAME:CEST TZOFFSETFROM:+0100 TZOFFSETTO:+0200 DTSTART:19700329T020000 RRULE:FREQ=YEARLY;BYMONTH=3;BYDAY=-1SU END:DAYLIGHT BEGIN:STANDARD TZNAME:CET TZOFFSETFROM:+0200 TZOFFSETTO:+0100 DTSTART:19701025T030000 RRULE:FREQ=YEARLY;BYMONTH=10;BYDAY=-1SU END:STANDARD END:VTIMEZONE BEGIN:VEVENT UID:6CAF-63968600-1-221AAAC0 SUMMARY:TestEvent CLASS:PUBLIC ATTENDEE;PARTSTAT=NEEDS-ACTION;RSVP=TRUE;ROLE=REQ-PARTICIPANT:mailto:test1. test1@x1.local BEGIN:VALARM TRIGGER;RELATED=START;VALUE=DURATION:-PT30M ACTION:DISPLAY SUMMARY:TestEvent DESCRIPTION:TestEvent END:VALARM TRANSP:OPAQUE DTSTART;TZID=Europe/Vienna:20221212T131500 DTEND;TZID=Europe/Vienna:20221212T164500 ORGANIZER;CN=Test1 Test1 X2:mailto:test1.test1@x2.local CREATED:20221212T013902Z DTSTAMP:20221212T013902Z LAST-MODIFIED:20221212T013902Z END:VEVENT END:VCALENDAR', 32, 0, 1670809142, '6CAF-63968600-1-221AAAC0.ics', 1670809142); 2022-12-12 02:39:02.599 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.599 sogod[27823:27823] SQL: COMMIT; 2022-12-12 02:39:02.601 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.602 sogod[27823:27823] SQL: COMMIT; 2022-12-12 02:39:02.602 sogod[27823:27823] query has no results. Dec 12 02:39:02 sogod [27823]: |SOGo| request took 0.029163 seconds to execute Dec 12 02:39:02 sogod [27823]: 172.28.10.1 "POST /SOGo/so/test1.test1@x2.local/Calendar/personal/6CAF-63968600-1-221AAAC0.ics/saveAsAppointment HTTP/1.1" 200 20/6028 0.033 - - 0 - 17 Dec 12 02:39:02 sogod [27823]: |SOGo| starting method 'GET' on uri '/SOGo/so/test1.test1@x2.local/Calendar/eventslist?asc=1&day=20221212&filterpopup=view_next7&search=title_Category_Location&sort=start&value=' Dec 12 02:39:02 sogod [27827]: |SOGo| starting method 'GET' on uri '/SOGo/so/test1.test1@x2.local/Calendar/eventsblocks?ed=20221218&sd=20221212&view=weekview' Dec 12 02:39:02 sogod [27827]: |SOGo| lookup name: test1.test1@x2.local Dec 12 02:39:02 sogod [27827]: |SOGo| did not find key 'test1.test1@x2.local' in SoClass: <0x0x5628bdcab410[SoObjCClass]: super=0x0x5628bdcaa600 objc=SOGo slots=passwordRecovery,changePassword,toolbar,passwordRecoveryCheck,Microsoft-Server-ActiveSync,saml2-metadata,saml2-sls,loading,view,GET,casProxy,saml2-signon-post,passwordRecoveryEnabled,connect,index,passwordRecoveryEmail> Dec 12 02:39:02 sogod [27827]: |SOGo| looked up value: (null) Dec 12 02:39:02 sogod [27827]: |SOGo| lookup in root object: (null) Dec 12 02:39:02 sogod [27827]: |SOGo| GOT: (null) Dec 12 02:39:02 sogod [27823]: |SOGo| lookup name: test1.test1@x2.local Dec 12 02:39:02 sogod [27823]: |SOGo| did not find key 'test1.test1@x2.local' in SoClass: <0x0x5628bdcab410[SoObjCClass]: super=0x0x5628bdcaa600 objc=SOGo slots=passwordRecovery,changePassword,toolbar,passwordRecoveryCheck,Microsoft-Server-ActiveSync,saml2-metadata,saml2-sls,loading,view,GET,casProxy,saml2-signon-post,passwordRecoveryEnabled,connect,index,passwordRecoveryEmail> Dec 12 02:39:02 sogod [27823]: |SOGo| looked up value: (null) Dec 12 02:39:02 sogod [27823]: |SOGo| lookup in root object: (null) Dec 12 02:39:02 sogod [27823]: |SOGo| GOT: (null) 2022-12-12 02:39:02.619 sogod[27827:27827] SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'test1.test1@x2.local' AND c_folder_type = 'Appointment'; 2022-12-12 02:39:02.619 sogod[27827:27827] query has results, entering fetch-mode. 2022-12-12 02:39:02.620 sogod[27823:27823] SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'test1.test1@x2.local' AND c_folder_type = 'Appointment'; 2022-12-12 02:39:02.620 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.621 sogod[27827:27827] SQL: SELECT b.c_name,b.c_content,b.c_creationdate,b.c_lastmodified,b.c_version,a.c_component,a.c_title,a.c_location,a.c_orgmail,a.c_status,a.c_category,a.c_classification,a.c_isallday,a.c_isopaque,a.c_participants,a.c_partmails,a.c_partstates,a.c_sequence,a.c_priority,a.c_cycleinfo,a.c_iscycle,a.c_nextalarm,a.c_description,a.c_uid,a.c_startdate,a.c_enddate FROM sogo_quick_appointment a, sogo_store b WHERE (a.c_folder_id = 32 AND b.c_folder_id = 32) AND ((c_component = 'vevent') AND ((c_startdate IS NULL) OR (c_startdate <= 1671404399)) AND ((c_enddate IS NULL) OR (c_enddate >= 1670799600)) AND (c_iscycle = 0)) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL); 2022-12-12 02:39:02.621 sogod[27827:27827] query has results, entering fetch-mode. 2022-12-12 02:39:02.622 sogod[27827:27827] SQL: SELECT b.c_name,b.c_content,b.c_creationdate,b.c_lastmodified,b.c_version,a.c_component,a.c_title,a.c_location,a.c_orgmail,a.c_status,a.c_category,a.c_classification,a.c_isallday,a.c_isopaque,a.c_participants,a.c_partmails,a.c_partstates,a.c_sequence,a.c_priority,a.c_cycleinfo,a.c_iscycle,a.c_nextalarm,a.c_description,a.c_uid,a.c_startdate,a.c_enddate FROM sogo_quick_appointment a, sogo_store b WHERE (a.c_folder_id = 32 AND b.c_folder_id = 32) AND ((c_component = 'vevent') AND ((c_startdate IS NULL) OR (c_startdate <= 1671404399)) AND ((c_cycleenddate IS NULL) OR (c_cycleenddate >= 1670799600)) AND (c_iscycle = 1)) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL); 2022-12-12 02:39:02.622 sogod[27823:27823] SQL: BEGIN; Dec 12 02:39:02 sogod [27825]: |SOGo| starting method 'GET' on uri '/SOGo/so/test1.test1@x2.local/Calendar/alarmslist?browserTime=1670809142' 2022-12-12 02:39:02.622 sogod[27827:27827] query has results, entering fetch-mode. 2022-12-12 02:39:02.622 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.622 sogod[27823:27823] SQL: UPDATE sogo_user_profile SET c_settings = '{"Contact":{"SortingState":["c_cn", "1"]},"Calendar":{"SelectedList":"eventsListView","FoldersOrder":["personal"],"PreventInvitationsWhitelist":{},"EventsFilterState":"view_next7","EventsSortingState":["start", "1"],"View":"weekview"},"General":{"PrivateSalt":"54b44c8ebfbdd664c6bed735c98ae9a78c7f8238"},"Mail":{"folderForExpunge":"imaps://test1.test1%40x2.local@127.0.0.1:2143/INBOX/","ExpandedFolders":["/0", "/0/folderShared_SP_Folders"]}}' WHERE c_uid = 'test1.test1@x2.local'; 2022-12-12 02:39:02.622 sogod[27827:27827] SQL: SELECT c_foldername FROM sogo_folder_info WHERE c_path = '/Users/test1.test1@x2.local/Calendar/personal'; 2022-12-12 02:39:02.623 sogod[27827:27827] query has results, entering fetch-mode. 2022-12-12 02:39:02.623 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.623 sogod[27823:27823] SQL: COMMIT; 2022-12-12 02:39:02.624 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.624 sogod[27823:27823] SQL: BEGIN; Dec 12 02:39:02 sogod [27827]: |SOGo| request took 0.009614 seconds to execute 2022-12-12 02:39:02.625 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.625 sogod[27823:27823] SQL: UPDATE sogo_user_profile SET c_settings = '{"Contact":{"SortingState":["c_cn", "1"]},"Calendar":{"SelectedList":"eventsListView","FoldersOrder":["personal"],"PreventInvitationsWhitelist":{},"EventsFilterState":"view_next7","EventsSortingState":["start", "1"],"View":"weekview"},"General":{"PrivateSalt":"54b44c8ebfbdd664c6bed735c98ae9a78c7f8238"},"Mail":{"folderForExpunge":"imaps://test1.test1%40x2.local@127.0.0.1:2143/INBOX/","ExpandedFolders":["/0", "/0/folderShared_SP_Folders"]}}' WHERE c_uid = 'test1.test1@x2.local'; Dec 12 02:39:02 sogod [27827]: 172.28.10.1 "GET /SOGo/so/test1.test1@x2.local/Calendar/eventsblocks?ed=20221218&sd=20221212&view=weekview HTTP/1.1" 200 1036/0 0.011 - - 0 - 15 Dec 12 02:39:02 sogod [27825]: |SOGo| lookup name: test1.test1@x2.local 2022-12-12 02:39:02.625 sogod[27823:27823] query has no results. Dec 12 02:39:02 sogod [27825]: |SOGo| did not find key 'test1.test1@x2.local' in SoClass: <0x0x5628bdcab410[SoObjCClass]: super=0x0x5628bdcaa600 objc=SOGo slots=passwordRecovery,changePassword,toolbar,passwordRecoveryCheck,Microsoft-Server-ActiveSync,saml2-metadata,saml2-sls,loading,view,GET,casProxy,saml2-signon-post,passwordRecoveryEnabled,connect,index,passwordRecoveryEmail> 2022-12-12 02:39:02.625 sogod[27823:27823] SQL: COMMIT; Dec 12 02:39:02 sogod [27825]: |SOGo| looked up value: (null) Dec 12 02:39:02 sogod [27825]: |SOGo| lookup in root object: (null) Dec 12 02:39:02 sogod [27825]: |SOGo| GOT: (null) 2022-12-12 02:39:02.626 sogod[27823:27823] query has no results. 2022-12-12 02:39:02.626 sogod[27823:27823] SQL: SELECT b.c_name,b.c_content,b.c_creationdate,b.c_lastmodified,b.c_version,a.c_component,a.c_title,a.c_location,a.c_orgmail,a.c_status,a.c_category,a.c_classification,a.c_isallday,a.c_isopaque,a.c_participants,a.c_partmails,a.c_partstates,a.c_sequence,a.c_priority,a.c_cycleinfo,a.c_iscycle,a.c_nextalarm,a.c_description,a.c_uid,a.c_startdate,a.c_enddate FROM sogo_quick_appointment a, sogo_store b WHERE (a.c_folder_id = 32 AND b.c_folder_id = 32) AND ((c_component = 'vevent') AND ((c_startdate IS NULL) OR (c_startdate <= 1671404399)) AND ((c_enddate IS NULL) OR (c_enddate >= 1670809142)) AND (c_iscycle = 0)) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL); 2022-12-12 02:39:02.627 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.628 sogod[27823:27823] SQL: SELECT b.c_name,b.c_content,b.c_creationdate,b.c_lastmodified,b.c_version,a.c_component,a.c_title,a.c_location,a.c_orgmail,a.c_status,a.c_category,a.c_classification,a.c_isallday,a.c_isopaque,a.c_participants,a.c_partmails,a.c_partstates,a.c_sequence,a.c_priority,a.c_cycleinfo,a.c_iscycle,a.c_nextalarm,a.c_description,a.c_uid,a.c_startdate,a.c_enddate FROM sogo_quick_appointment a, sogo_store b WHERE (a.c_folder_id = 32 AND b.c_folder_id = 32) AND ((c_component = 'vevent') AND ((c_startdate IS NULL) OR (c_startdate <= 1671404399)) AND ((c_cycleenddate IS NULL) OR (c_cycleenddate >= 1670809142)) AND (c_iscycle = 1)) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL); 2022-12-12 02:39:02.628 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.629 sogod[27825:27825] SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'test1.test1@x2.local' AND c_folder_type = 'Appointment'; 2022-12-12 02:39:02.629 sogod[27823:27823] SQL: SELECT c_foldername FROM sogo_folder_info WHERE c_path = '/Users/test1.test1@x2.local/Calendar/personal'; 2022-12-12 02:39:02.629 sogod[27825:27825] query has results, entering fetch-mode. 2022-12-12 02:39:02.629 sogod[27823:27823] query has results, entering fetch-mode. 2022-12-12 02:39:02.631 sogod[27825:27825] SQL: SELECT c_name, c_nextalarm, c_iscycle FROM sogo_quick_appointment WHERE c_folder_id = 32 AND (((c_nextalarm <= 1670981942) AND (c_nextalarm >= 1670809142)) OR ((c_nextalarm > 0) AND (c_nextalarm <= 1670809142) AND (c_enddate > 1670809142))); 2022-12-12 02:39:02.632 sogod[27825:27825] query has results, entering fetch-mode. Dec 12 02:39:02 sogod [27823]: |SOGo| request took 0.017104 seconds to executeDec 12 02:39:02 sogod [27825]: |SOGo| request took 0.009671 seconds to execute Dec 12 02:39:02 sogod [27825]: 172.28.10.1 "GET /SOGo/so/test1.test1@x2.local/Calendar/alarmslist?browserTime=1670809142 HTTP/1.1" 200 116/0 0.012 - - 0 - 15 Dec 12 02:39:02 sogod [27823]: 172.28.10.1 "GET /SOGo/so/test1.test1@x2.local/Calendar/eventslist?asc=1&day=20221212&filterpopup=view_next7&search=title_Category_Location&sort=start&value= HTTP/1.1" 200 828/0 0.019 - - 0 - 17 Dec 12 02:39:02 sogod [27811]: [WARN] <0x0x5628bddcc8a0[WOWatchDogChild]> pid 27828 has been hanging in the same request for 1 minutes