Moodle 3.9.3
Postgres 12.5
RHEL 7
apache mpm event + fpm + php 7.3
10x vm web + 1 redis vm(muc +session) + hardware Postgresql
Cannot obtain session lock for sid: l2ih8aem1nrnsqj5d9p1s0vpja within 120 seconds
We experience this specific event during an exam that while fpm childs max out.
27-Jul-2021 14:01:52] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children
[27-Jul-2021 14:17:34] WARNING: [pool www] server reached pm.max_children setting (120), consider raising it
Postgres log
2021-07-27 14:15:38.712 SASTERROR: deadlock detected
2021-07-27 14:15:38.712 SASTDETAIL: Process 268318 waits for ShareLock on transaction 549000799; blocked by process 268309.
Process 268309 waits for ShareLock on transaction 549000804; blocked by process 268318.
Process 268318: UPDATE mdl_grade_items SET needsupdate = $3 WHERE (itemtype='course' OR id=$1) AND courseid=$2
Process 268309: UPDATE mdl_grade_items SET needsupdate = $3 WHERE (itemtype='course' OR id=$1) AND courseid=$2
2021-07-27 14:15:38.712 SASTHINT: See server log for query details.
2021-07-27 14:15:38.712 SASTCONTEXT: while updating tuple (3261,31) in relation "mdl_grade_items"
2021-07-27 14:15:38.712 SASTSTATEMENT: UPDATE mdl_grade_items SET needsupdate = $3 WHERE (itemtype='course' OR id=$1) AND courseid=$2
The system was benchmarked to easy support 6000 - 8000 concurrent users.
During year handled classes with 4000 + concurrent 20k daily and 30k monthly users.
all big exams gone without a problem before this event.
The specific exam used file download and upload method and not a quiz.
This was a pdf (declaration download and upload at start)
Then 6 separate pdf file questions
350 users attempted and finished but there was delays and slow access.
This correlate with discussion below
https://moodle.org/mod/forum/discuss.php?d=419645.
Allready done some redis optimization
Planed mitigation.
1) Enable_read_only_sessions = true;
2) redis 6 (3x master+ 3x slave)
tested 3x redis + redis-cluster-proxy (whould like to know if anyone is useing this in production yet)
Any other feedback that would be helpful.
A passing thought - check your network performance. Redis generates a LOT of traffic. You can easily run out of network capacity.
If you haven't already, you might want to try data compression for the Redis cache (note that you can turn it on but you can't turn it off without manually clearing down Redis)
If you haven't already, you might want to try data compression for the Redis cache (note that you can turn it on but you can't turn it off without manually clearing down Redis)
What makes you believe that it's the Redis cache causing this?
From what you've shown, it looks like you ran our of PHP processes as each process was taking a long time, the processes were stuck in a deadlock on the database server when updating mdl_grade_items and during that time the user couldn't start another session.
It looks like a possible DB performance issue with deadlocks causing PHP processes to halt. Then your users are possibly opening multiple windows and because the previous window has the session lock, Redis times out after 120 seconds.
Read only sessions may fix this, depending on what other file is causing the other Redis connections, if it's a theme/asset/download file, it should be ok as they are good candidates for read only sessions, but if it's another page load, the it won't really help.
I don't have any other info around Redis master/slave setups, but we use multiple redis instances due to it being single threaded and only using one instance per store (MUC, MUC Session and PHP Session). Note: you also need to configure MUC Session for Read Only Sessions to work.
From what you've shown, it looks like you ran our of PHP processes as each process was taking a long time, the processes were stuck in a deadlock on the database server when updating mdl_grade_items and during that time the user couldn't start another session.
It looks like a possible DB performance issue with deadlocks causing PHP processes to halt. Then your users are possibly opening multiple windows and because the previous window has the session lock, Redis times out after 120 seconds.
Read only sessions may fix this, depending on what other file is causing the other Redis connections, if it's a theme/asset/download file, it should be ok as they are good candidates for read only sessions, but if it's another page load, the it won't really help.
I don't have any other info around Redis master/slave setups, but we use multiple redis instances due to it being single threaded and only using one instance per store (MUC, MUC Session and PHP Session). Note: you also need to configure MUC Session for Read Only Sessions to work.
Hello Johan,
Did you figure out the root cause? I'm experiencing something very similar and your answer would help me a lot.
Thanks!