9 / 9
Apr 2023

After Update to 23.1, eGroupware floods MySQL with queries.

Client running Windows + Thunderbird 102.9.0 starts to sync eGroupware Calendar + eGroupware Infolog via GroupDAV. Calendar sync is successful (once), Infolog sync will start an endless loop in eGroupware. The MySQL backend reports queries:

SELECT SQL_CALC_FOUND_ROWS main.info_id AS info_id,info_datemodified,info_uid,caldav_name,info_subject,info_status,info_owner,GROUP_CONCAT(attendees.account_id) AS info_responsible,GROUP_CONCAT(attendees.info_res_attendee) AS info_cc FROM egw_infolog main LEFT JOIN egw_infolog_users ON main.info_id=egw_infolog_users.info_id LEFT JOIN egw_infolog_users attendees ON main.info_id=attendees.info_id AND attendees.info_res_deleted IS NULL WHERE ( (info_owner=17 OR (egw_infolog_users.account_id IN (’-1’,‘17’)) OR (egw_infolog_users.account_id IN (’-1’,‘17’) OR info_status = ‘offer’ AND info_owner=17) AND (info_access=‘public’ OR info_owner=17)) AND NOT (info_status IN (‘template’,‘nonactive’,‘archive’)) AND info_type=‘task’ AND info_datemodified>1678956815 ) GROUP BY main.info_id ORDER BY info_datemodified DESC LIMIT 0,500

SELECT FOUND_ROWS()

(repeat ad infinitum with 100% CPU usage, until eGroupware is stopped with “sudo systemctl restart docker”).

User #17 is unable to sync any calendar until eGroupware is restarted.
When any other user starts to sync his/her infolog, eGroupware enters the same endless loop, with different user ID and different info_datemodified.

When I submit the SQL query manually, there is an empty result set (i.e. no recent changes).

I tried to track the error down to Thunderbird, but eGroupware does not send any infolog-related HTTP reply to Thunderbird at all, only calendar-related requests and replies are logged in the log which I have enabled in eGroupware-Preferences-CalDAV/CardDAV Sync-Logging.

  • created

    Mar '23
  • last reply

    Apr '23
  • 8

    replies

  • 1.0k

    views

  • 3

    users

  • 2

    likes

  • 4

    links

1 month later

can you switch on CalDAV log in EGroupware to full requests and responses to filesystem for that user to see what is requested by Thunderbird and what is replied from EGroupware

Birgit

Hmm, what we see in the Log is just for itself perfectly normal, if it’s not constantly repeating, which I can not see in the log.

TB sends an initial sync-collection REPORT with an empty sync-token and gets the URLs of all existing InfoLog. Then it requests them in chunks via calendar-multiget REPORTs.

So this is what is supposed to happen once you created the account.

After that the client should pass in the sync-token he got for the next sync REPORT and would get only changes.

As you log ends before, I can not see if the next sync-collection REPORT contains previous sync-token, or not …

Ralf

Thank you for looking into this. I’ll give another, more complex try:
21:02 - starting Thunderbird, initial sync (automatically)
21:03 - initiating manual sync (this does not create any entry in the server-side log, sorry)
21:03-21:08: 100% cpu load on the server
21:08 - some component (nginx?) obviously runs into a timeout, stopping the endless loop
21:09 - initiating manual sync again, no entry in the server-side log
21:09-21:10: 100% cpu load on the server
21:10 - creating an infolog item (caption: “test-item”) via web interface, this breaks the loop, cpu load on the server drops
21:11 - initiating manual sync again. This sync is successful immediately

I guess that the success of the final sync is because there is something to sync, and the endless loop is an error when there is nothing to sync.
Mozilla!5.0 (X11; Linux x86_64; rv:102.0) Gecko!20100101 Thunderbird!102.10.0.log.txt (28,0 KB)

Thanks for the log :slight_smile:

The log looks absolutely ok and you are positive the problem happened while the log was recorded?

If that’s the case the problem is internal and not caused by the client. That’s good news, because it means it can be fixed quickly by us alone.

A quick look in the code helped me remember, that we in deed changed something fundamental between 21.1 and 23.1: we’re using now PHP generators instead of iterators. Maybe the new generator has a problem / causing an endless loop in that case …

I’ll come back to you.

Ralf

I believe I found and fixed the cause:

To test the fix, please run the following commands on your instance (to patch your container with it):

curl https://github.com/EGroupware/egroupware/commit/053503bd7401ccfdab385f28add744269b0ad367.patch | docker exec -i egroupware patch -p1 -d/usr/share/egroupware
docker exec -it egroupware kill -s usr2 1

This will install and activate the patch, until the next container restart or reboot of the host.

To make the patch permanent run:

curl https://github.com/EGroupware/egroupware/commit/053503bd7401ccfdab385f28add744269b0ad367.patch | docker exec -i egroupware patch -p1 -d/usr/share/egroupware-sources

Please let me know, if that fixes the problem for you.

Ralf

After ten minutes of testing, that looks like it does solve the issue. Thank you!

Thank you for providing logs and testing :slight_smile:

The fix is now backported to 23.1 and will be part of the next maintenance release.

Ralf