View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0005943SOGoBackend Calendarpublic2024-03-19 10:322025-05-19 08:01
Reportereugenesu Assigned Tosebastien  
PriorityhighSeveritycrashReproducibilityalways
Status resolvedResolutionfixed 
Product Version5.10.0 
Fixed in Version5.12.1 
Summary0005943: Excessive memory usage when creating a recurring event
Description

When creating a recurring event (for example, every day for a year), excessively high memory utilization occurs (often gigabytes when processing one event).
Example from logs:

''Mar 18 12:09:34 sogod [6200]: <0x0x60533f454b80[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Mar 18 12:09:34 sogod [6200]: <0x0x60533f454b80[SOGoCache]> Using host(s) '10.20.30.1:11211' as server(s)
Mar 18 12:09:34 sogod [6200]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10%40domain.local/Calendar/personal/ HTTP/1.1" 401 0/164 0.372 - - 5M - 14
Mar 18 12:09:35 sogod [6200]: <0x0x60533f5ead10[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table
Mar 18 12:09:35 sogod [6200]: <0x0x60533f5ead10[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table
Mar 18 12:09:35 sogod [6200]: <0x0x60533f5ead10[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table
Mar 18 12:09:35 sogod [6200]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10%40domain.local/Calendar/personal/ HTTP/1.1" 207 379/164 0.434 - - 3M - 16
Mar 18 12:09:35 sogod [6200]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10@domain.local HTTP/1.1" 207 400/159 0.002 - - 0 - 15
Mar 18 12:09:35 sogod [6200]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10%40domain.local/Calendar/ HTTP/1.1" 207 417/170 0.006 1692 75% 916K - 15
Mar 18 12:09:42 sogod [6200]: 10.20.30.1 "PUT /SOGo/dav/gu_use_te_10%40domain.local/Calendar/personal/3d53588a-e507-11ee-9d4e-080027707a36.ics HTTP/1.1" 201 0/1964 7.657 - - 427M - 16
Mar 18 12:09:42 sogod [6200]: |SOGo| terminating app, vMem size limit (384 MB) has been reached (currently 531 MB)
2024-03-18 12:09:42.859 sogod[6199:6199] INFO(-[NGActiveSocket isAlive]) poll(): fd=8 revents=0x0011)
Mar 18 12:09:42 sogod [6199]: <0x0x60533f1e7550[WOWatchDogChild]> child 6200 exited
Mar 18 12:09:42 sogod [6199]: <0x0x60533f13e990[WOWatchDog]> child spawned with pid 6220''

With each new repeating event on the same day, memory consumption increases exponentially.

''Mar 18 13:43:02 sogod [6822]: <0x0x5de27721e270[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Mar 18 13:43:02 sogod [6822]: <0x0x5de27721e270[SOGoCache]> Using host(s) '10.20.30.1:11211' as server(s)
Mar 18 13:43:02 sogod [6822]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10%40domain.local/Calendar/personal/ HTTP/1.1" 401 0/164 0.047 - - 3M - 14
Mar 18 13:43:02 sogod [6822]: <0x0x5de2772b1950[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table
Mar 18 13:43:02 sogod [6822]: <0x0x5de2772b1950[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table
Mar 18 13:43:02 sogod [6822]: <0x0x5de2772b1950[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table
Mar 18 13:43:02 sogod [6822]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10%40domain.local/Calendar/personal/ HTTP/1.1" 207 379/164 0.107 - - 3M - 16
Mar 18 13:43:02 sogod [6822]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10@domain.local HTTP/1.1" 207 400/159 0.002 - - 0 - 15
Mar 18 13:43:02 sogod [6822]: 10.20.30.1 "PROPFIND /SOGo/dav/gu_use_te_10%40domain.local/Calendar/ HTTP/1.1" 207 417/170 0.005 1692 75% 0 - 15
Mar 18 13:43:10 sogod [6822]: [ERROR] <0x5de2a94ec4c0[SOGoAppointmentObject]:4b84846c-e514-11ee-9d4e-080027707a36.ics> Did not find folder of content object.
Mar 18 13:43:10 sogod [6822]: [ERROR] <0x5de2a94a4b30[SOGoAppointmentObject]:4b84846c-e514-11ee-9d4e-080027707a36.ics> Did not find folder of content object.
Mar 18 13:43:10 sogod [6822]: [ERROR] <0x5de2a98533c0[SOGoAppointmentObject]:4b84846c-e514-11ee-9d4e-080027707a36.ics> Did not find folder of content object.
Mar 18 13:43:10 sogod [6822]: [ERROR] <0x5de2a98713d0[SOGoAppointmentObject]:4b84846c-e514-11ee-9d4e-080027707a36.ics> Did not find folder of content object.
Mar 18 13:43:14 sogod [6822]: 10.20.30.1 "PUT /SOGo/dav/gu_use_te_10%40domain.local/Calendar/personal/4b84846c-e514-11ee-9d4e-080027707a36.ics HTTP/1.1" 201 0/1964 11.992 - - 938M - 16
Mar 18 13:43:14 sogod [6822]: |SOGo| terminating app, vMem size limit (384 MB) has been reached (currently 1035 MB)
2024-03-18 13:43:14.478 sogod[6460:6460] INFO(-[NGActiveSocket isAlive]) poll(): fd=9 revents=0x0011)
Mar 18 13:43:14 sogod [6460]: <0x0x5de27701e0f0[WOWatchDogChild]> child 6822 exited
Mar 18 13:43:14 sogod [6460]: <0x0x5de276f07a20[WOWatchDog]> child spawned with pid 6840''

Presumably, memory consumption occurs when processing a response to a query to the database.

''SELECT b.c_content,a.c_partmails,a.c_partstates,a.c_isopaque,a.c_status,a.c_cycleinfo,a.c_orgmail,b.c_name,a.c_uid,a.c_startdate,a.c_enddate,a.c_isallday FROM sogo_quick_appointment a, sogo_store b WHERE (a.c_folder_id = 6 AND b.c_folder_id = 6) AND ((c_component = 'vevent') AND ((c_startdate IS NULL) OR (c_startdate <= 1742280851)) AND ((c_cycleenddate IS NULL) OR (c_cycleenddate >= 1710743653)) AND (c_iscycle = 1)) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL)''

Increasing the memory limit for workers (SxVMemLimit) does not solve the problem.

Steps To Reproduce
  • Create a recurring event with 3-5 recipients on one SOGo server.
  • Add 4-6 more similar events on the same days, but with different times (intersection in time is not necessary). An event validity period of 1 year is sufficient.
  • After creating 5-6 (or more) repeating events, SOGo WatchDog kills the process due to high memory utilization.
Additional Information

Example ICS.

''BEGIN:VCALENDAR
VERSION:2.0
BEGIN:VTIMEZONE
TZID:Europe/Moscow
LAST-MODIFIED:20240220T101645Z
X-LIC-LOCATION:Europe/Moscow
BEGIN:STANDARD
TZNAME:MSK
TZOFFSETFROM:+0300
TZOFFSETTO:+0300
DTSTART:19700101T000000
END:STANDARD
END:VTIMEZONE
BEGIN:VEVENT
SUMMARY:Memory leak recurrent appointment
DTSTART;TZID=Europe/Moscow:20240318T143525
DTEND;TZID=Europe/Moscow:20240318T145525
DTSTAMP;TZID=Europe/Moscow:20240318T140525
UID:6c0388f2-e517-11ee-9d4e-080027707a36
RRULE:FREQ=DAILY;UNTIL=20250112T143525
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User;RSVP=TRUE;ROLE=REQ-PARTICIPANT
:MAILTO:gu_use_te_01@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 02;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_02@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 03;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_03@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 04;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_04@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 05;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_05@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 06;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_06@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 07;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_07@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 08;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_08@domain.local
ATTENDEE;PARTSTAT=NEEDS-ACTION;CN=Test User 09;RSVP=TRUE;ROLE=REQ-PARTICIP
ANT:MAILTO:gu_use_te_09@domain.local
CREATED;TZID=Europe/Moscow:20240318T140525
DESCRIPTION:Memory leak recurrent appointment
LAST-MODIFIED;TZID=Europe/Moscow:20240318T140525
PRODID:-//My test Script//RU
TRANSP:OPAQUE
ORGANIZER;CN=Gu Use Te:mailto:gu_use_te_10@domain.local
CLASS:PUBLIC
END:VEVENT
END:VCALENDAR''

Tagsappointment, calendar, possible memory leak

Activities

sebastien

sebastien

2024-12-17 17:49

administrator   ~0018019

Try with latest nightly some memory fix has been commited.
eugenesu

eugenesu

2025-05-16 19:56

reporter   ~0018216

Hello, dear developers!

Sorry for the long reply. It looks like the memory usage in this scenario has improved in version 5.12.1.

Thank you very much for your work!

Issue History

Date Modified Username Field Change
2024-03-19 10:32 eugenesu New Issue
2024-03-19 10:32 eugenesu Tag Attached: appointment
2024-03-19 10:32 eugenesu Tag Attached: calendar
2024-03-19 10:32 eugenesu Tag Attached: possible memory leak
2024-12-17 17:49 sebastien Note Added: 0018019
2024-12-17 17:49 sebastien Assigned To => sebastien
2024-12-17 17:49 sebastien Status new => feedback
2025-05-16 19:56 eugenesu Note Added: 0018216
2025-05-16 19:56 eugenesu Status feedback => assigned
2025-05-19 08:01 qhivert Status assigned => resolved
2025-05-19 08:01 qhivert Resolution open => fixed
2025-05-19 08:01 qhivert Fixed in Version => 5.12.1