Poor Quiz Performance: 32 GB Ram, 24 Cores

Poor Quiz Performance: 32 GB Ram, 24 Cores

by Abhijit M -
Number of replies: 6
Picture of Core developers


We are experiencing very poor performance on conducting a quiz. The Moodle Server becomes non-responsive after ~200 to ~300 users and pages just do not load.  A quiz for 200 users has worked in the past, and now we are trying with 400 users, after doing substrantial upgrades in software, apache2 & Mysql configuration (attached as files).

Here are the details of the configuration and a test carried out.

Hardware

Dell Power Edge R720, 64 Bit,

Intel Xeon CPU E5-2630 @ 2.30 GHz

DIMM DDR3 Synchronous  1600 MHz: 32 GB

RAID BUS Controller MegaRAID SAS 2208 10k RPM

Network: 2 Gbps

Software

Ubuntu 18.04 , Server version: Apache/2.4.29 (Ubuntu),   Mysql-server 5.7.30, Moodle version 3.9, php 7.2-fpm

Observation

Quiz time: 7pm . Random Delay introduced.

Users Logging in and waiting.

#live users seen using block on Moodle
18:55 113 loading, smooth
18:55:24 109 loading
18:56 116, 136, 144
18:57 165 , 172, 177, 181
18;58 180, 186,
18:59 210, 215, 218, 223, 229,
19:00 218, 229, 232, 234,
19:01 245, 249, 279, 281, 271, 273,
19:02 283, 284, slow now
19:03 291 slow , 281, 285, slow, 
19:04 287, slow, 294, slow
19:05 more slow - loading, no response
19:06 more slow - loading, no response, pages not loading, browser keeps fetching data

at this time, free -m shows available memory is still 27246MB

Mytop outputs

MySQL on localhost (5.7.30)                                                                   load 2.10 1.15 0.56 1/805 20220 up 0+01:39:32 [19:00:01]
 Queries: 507.8k   qps:   87 Slow:     0.0         Se/In/Up/De(%):    84/02/02/00
 Sorts:   1187 qps now: 1211 Slow qps: 0.0  Threads:    2 (   1/   4) 82/02/02/00
 Key Efficiency: 50.0%  Bps in/out: 24.4k/104.4k   Now in/out: 303.1k/ 1.4M
 Id      User         Host/IP         DB       Time    Cmd    State Query                                                                  
   --      ----         -------         --       ----    ---    ----- ----------                                                             
 6341      root       localhost                     0  Query starting show full processlist   

MySQL on localhost (5.7.30)                                                                   load 1.83 1.23 0.63 4/805 21100 up 0+01:40:31 [19:01:00]
 Queries: 594.7k   qps:  101 Slow:     0.0         Se/In/Up/De(%):    84/02/02/00
 Sorts:   1599 qps now: 1550 Slow qps: 0.0  Threads:    4 (   4/   2) 84/02/02/01
 Key Efficiency: 50.0%  Bps in/out: 28.0k/120.9k   Now in/out: 365.6k/ 1.9M
Id      User         Host/IP         DB       Time    Cmd    State Query                                                                  
  --      ----         -------         --       ----    ---    ----- ----------                                                             
6341      root       localhost                     0  Query starting show full processlist                                                 
18945      root       localhost     moodle          0  Sleep                                                                           
18946      root       localhost     moodle          0  Query starting SELECT id, sid, state, userid, lastip, timecreated, timemodified FROM mdl_se
18947      root       localhost     moodle          0  Sleep                                                                           

MySQL on localhost (5.7.30)                                                                   load 2.10 1.40 0.73 4/806 23557 up 0+01:41:32 [19:02:01]
 Queries: 671.0k   qps:  113 Slow:     0.0         Se/In/Up/De(%):    84/02/02/00
 Sorts:   1384 qps now:  946 Slow qps: 0.0  Threads:    4 (   1/   2) 80/02/02/00
 Key Efficiency: 50.0%  Bps in/out: 31.1k/135.1k   Now in/out: 301.5k/ 1.2M
Id      User         Host/IP         DB       Time    Cmd    State Query                                                                  
--      ----         -------         --       ----    ---    ----- ----------                                                             
6341      root       localhost                     0  Query starting show full processlist                                                 
21677      root       localhost     moodle          0  Sleep                                                                           
21678      root       localhost     moodle          0  Sleep                                                                           
21679      root       localhost     moodle          0  Sleep     


MySQL on localhost (5.7.30)                                                                   load 2.09 1.55 0.83 2/921 27206 up 0+01:42:31 [19:03:00]
 Queries: 718.9k   qps:  120 Slow:     0.0         Se/In/Up/De(%):    84/02/02/00
 Sorts:    300 qps now:  284 Slow qps: 0.0  Threads:    2 (   1/   4) 78/02/03/00
 Key Efficiency: 50.0%  Bps in/out: 33.1k/143.1k   Now in/out: 113.6k/362.6k
Id      User         Host/IP         DB       Time    Cmd    State Query                                                                  
--      ----         -------         --       ----    ---    ----- ----------                                                             
6341      root       localhost                     0  Query starting show full processlist                                                 
23417      root       localhost     moodle          0  Sleep                                                                           

MySQL on localhost (5.7.30)                                                                   load 2.10 1.66 0.91 6/998 31297 up 0+01:43:31 [19:04:00]
 Queries: 767.4k   qps:  127 Slow:     0.0         Se/In/Up/De(%):    84/02/02/00
 Sorts:   2172 qps now: 1273 Slow qps: 0.0  Threads:    2 (   1/   4) 85/03/02/00
 Key Efficiency: 50.0%  Bps in/out: 35.1k/151.0k   Now in/out: 456.1k/ 1.7M
Id      User         Host/IP         DB       Time    Cmd    State Query                                                                  
 --      ----         -------         --       ----    ---    ----- ----------                                                             
6341      root       localhost                     0  Query starting show full processlist                                                 
25144      root       localhost     moodle          0  Sleep                                                                           
25145      root       localhost     moodle          0  Sleep                                                                           

MySQL on localhost (5.7.30)                                                                   load 1.32 1.54 0.92 1/1373 1870 up 0+01:44:31 [19:05:00]
 Queries: 792.3k   qps:  129 Slow:     0.0         Se/In/Up/De(%):    84/02/02/00
 Sorts:      0 qps now:    4 Slow qps: 0.0  Threads:    1 (   1/   5) 00/00/00/00
 Key Efficiency: 50.0%  Bps in/out: 36.0k/154.3k   Now in/out: 105.3/12.2k
 Id      User         Host/IP         DB       Time    Cmd    State Query                                                                  
 --      ----         -------         --       ----    ---    ----- ----------                                                             
6341      root       localhost                     0  Query starting show full processlist      

MySQL on localhost (5.7.30)                                                                   load 0.48 1.25 0.86 1/2237 3437 up 0+01:45:31 [19:06:00]
 Queries: 792.5k   qps:  128 Slow:     0.0         Se/In/Up/De(%):    84/02/02/00
 Sorts:      0 qps now:    4 Slow qps: 0.0  Threads:    1 (   1/   5) 00/00/00/00
 Key Efficiency: 50.0%  Bps in/out: 35.6k/152.9k   Now in/out: 106.8/12.4k
Id      User         Host/IP         DB       Time    Cmd    State Query                                                                  
 --      ----         -------         --       ----    ---    ----- ----------                                                             
6341      root       localhost                     0  Query starting show full processlist   


apache2ctl fullstatus

   Current Time: Tuesday, 28-Jul-2020 19:00:00 IST
   Server load: 2.10 1.15 0.56
   Total accesses: 26419 - Total Traffic: 395.0 MB
   CPU Usage: u52.21 s17.89 cu0 cs0 - .546% CPU load
   2.06 requests/sec - 31.5 kB/second - 15.3 kB/request
   88 requests currently being processed, 212 idle workers
   +-----------------------------------------------------------------------+
   |    |    |        |Connections    |Threads  |Async connections         |
   |Slot|PID |Stopping|---------------+---------+--------------------------|
   |    |    |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |0   |5434|no      |1    |yes      |2   |23  |0      |0         |0      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |1   |5435|no      |4    |yes      |3   |22  |0      |1         |1      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |4   |5445|no      |3    |yes      |2   |23  |0      |0         |1      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |7   |5493|no      |17   |yes      |6   |19  |0      |4         |6      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |8   |5523|no      |2    |yes      |0   |25  |0      |1         |1      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |9   |5544|no      |34   |yes      |7   |18  |1      |6         |19     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |10  |5575|no      |21   |yes      |8   |17  |1      |6         |9      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |11  |5604|no      |26   |yes      |9   |16  |0      |8         |9      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |13  |5652|no      |25   |yes      |9   |16  |0      |6         |9      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |16  |5745|no      |56   |yes      |15  |10  |0      |19        |18     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |17  |5769|no      |38   |yes      |13  |12  |0      |12        |11     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |19  |5833|no      |41   |yes      |14  |11  |2      |12        |16     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |12  |0       |268  |         |88  |212 |4      |75        |100    |
   +-----------------------------------------------------------------------+

 Current Time: Tuesday, 28-Jul-2020 19:01:01 IST
   Server load: 1.83 1.23 0.63
   Total accesses: 30009 - Total Traffic: 433.6 MB
   CPU Usage: u57.02 s19.88 cu0 cs0 - .596% CPU load
   2.33 requests/sec - 34.4 kB/second - 14.8 kB/request
   91 requests currently being processed, 209 idle workers
   +-----------------------------------------------------------------------+
   |    |    |        |Connections    |Threads  |Async connections         |
   |Slot|PID |Stopping|---------------+---------+--------------------------|
   |    |    |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |0   |5434|no      |4    |yes      |1   |24  |0      |0         |2      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |1   |5435|no      |9    |yes      |1   |24  |0      |2         |5      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |4   |5445|no      |3    |yes      |2   |23  |0      |0         |1      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |7   |5493|no      |22   |yes      |8   |17  |0      |6         |8      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |8   |5523|no      |13   |yes      |2   |23  |0      |3         |7      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |9   |5544|no      |57   |yes      |14  |11  |1      |17        |22     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |10  |5575|no      |57   |yes      |15  |10  |1      |17        |23     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |11  |5604|no      |24   |yes      |7   |18  |1      |6         |7      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |13  |5652|no      |55   |yes      |8   |17  |1      |21        |20     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |16  |5745|no      |44   |yes      |6   |19  |0      |27        |11     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |17  |5769|no      |59   |yes      |16  |9   |0      |15        |25     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |19  |5833|no      |43   |yes      |11  |14  |0      |10        |17     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |12  |0       |390  |         |91  |209 |4      |124       |148    |
   +-----------------------------------------------------------------------+

   Current Time: Tuesday, 28-Jul-2020 19:02:00 IST
   Server load: 2.10 1.40 0.73
   Total accesses: 33642 - Total Traffic: 482.5 MB
   CPU Usage: u62.06 s22.02 cu0 cs0 - .649% CPU load
   2.6 requests/sec - 38.1 kB/second - 14.7 kB/request
   110 requests currently being processed, 190 idle workers
   +-----------------------------------------------------------------------+
   |    |    |        |Connections    |Threads  |Async connections         |
   |Slot|PID |Stopping|---------------+---------+--------------------------|
   |    |    |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |0   |5434|no      |6    |yes      |3   |22  |0      |1         |1      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |1   |5435|no      |5    |yes      |2   |23  |0      |1         |4      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |4   |5445|no      |12   |yes      |3   |22  |0      |7         |2      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |7   |5493|no      |25   |yes      |8   |17  |0      |6         |11     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |8   |5523|no      |19   |yes      |9   |16  |0      |3         |5      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |9   |5544|no      |59   |yes      |14  |11  |0      |22        |24     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |10  |5575|no      |64   |no       |19  |6   |1      |17        |26     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |11  |5604|no      |16   |yes      |4   |21  |0      |5         |6      |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |13  |5652|no      |45   |yes      |14  |11  |0      |10        |14     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |16  |5745|no      |39   |yes      |12  |13  |0      |15        |11     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |17  |5769|no      |46   |yes      |15  |10  |0      |9         |19     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |19  |5833|no      |34   |yes      |7   |18  |0      |11        |15     |
   |----+----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |12  |0       |370  |         |110 |190 |1      |107       |138    |
   +-----------------------------------------------------------------------+

   Current Time: Tuesday, 28-Jul-2020 19:03:00 IST
  Server load: 2.09 1.55 0.83
   Total accesses: 36103 - Total Traffic: 508.8 MB
   CPU Usage: u66.24 s23.59 cu0 cs0 - .69% CPU load
   2.77 requests/sec - 40.0 kB/second - 14.4 kB/request
   309 requests currently being processed, 91 idle workers
   |Slot|PID  |Stopping|---------------+---------+--------------------------|
   |    |     |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |0   |5434 |no      |16   |yes      |11  |14  |0      |0         |3      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |1   |5435 |no      |13   |yes      |12  |13  |0      |0         |6      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |2   |26194|no      |30   |yes      |24  |1   |0      |0         |2      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |3   |26882|no      |0    |yes      |22  |3   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |4   |5445 |no      |32   |no       |24  |1   |0      |1         |4      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |5   |26912|no      |0    |yes      |11  |14  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |6   |26913|no      |0    |yes      |11  |14  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |7   |5493 |no      |31   |yes      |25  |0   |0      |0         |3      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |8   |5523 |no      |35   |yes      |23  |2   |1      |3         |8      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |9   |5544 |no      |33   |no       |24  |1   |1      |0         |5      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |10  |5575 |no      |43   |yes      |24  |1   |1      |0         |15     |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |11  |5604 |no      |32   |yes      |25  |0   |0      |1         |9      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |12  |27128|no      |0    |yes      |2   |23  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |13  |5652 |no      |33   |yes      |23  |2   |0      |2         |8      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |16  |5745 |no      |35   |no       |25  |0   |0      |0         |7      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |17  |5769 |no      |32   |yes      |23  |2   |0      |0         |8      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |19  |5833 |yes     |7    |no       |0   |0   |0      |0         |5      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |17   |1       |372  |         |309 |91  |3      |7         |83     |
   +------------------------------------------------------------------------+
   Current Time: Tuesday, 28-Jul-2020 19:04:00 IST
   Server load: 2.10 1.66 0.91
   Total accesses: 38476 - Total Traffic: 539.5 MB
   CPU Usage: u70.63 s25.6 cu0 cs0 - .736% CPU load
   2.94 requests/sec - 42.2 kB/second - 14.4 kB/request
   353 requests currently being processed, 122 idle workers
  +------------------------------------------------------------------------+
   |    |     |        |Connections    |Threads  |Async connections         |
   |Slot|PID  |Stopping|---------------+---------+--------------------------|
   |    |     |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |0   |5434 |no      |8    |yes      |3   |22  |0      |0         |7      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |1   |5435 |no      |11   |yes      |10  |15  |0      |0         |1      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |2   |26194|no      |30   |yes      |22  |3   |0      |3         |4      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |3   |26882|no      |30   |yes      |24  |1   |0      |0         |5      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |4   |5445 |no      |35   |yes      |25  |0   |0      |0         |7      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |5   |26912|no      |10   |yes      |2   |23  |0      |2         |5      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |6   |26913|no      |31   |yes      |21  |4   |0      |1         |9      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |7   |5493 |no      |29   |no       |24  |1   |0      |0         |4      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |8   |5523 |no      |34   |yes      |22  |3   |1      |0         |6      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |9   |5544 |no      |35   |yes      |22  |3   |0      |3         |8      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |10  |5575 |no      |30   |yes      |22  |3   |0      |1         |5      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |11  |5604 |no      |36   |yes      |23  |2   |0      |0         |6      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |12  |27128|no      |23   |yes      |16  |9   |0      |0         |6      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |13  |5652 |no      |32   |no       |21  |4   |0      |6         |5      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |14  |27973|no      |19   |yes      |15  |10  |0      |3         |2      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |15  |28320|no      |32   |yes      |20  |5   |0      |10        |4      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |16  |5745 |no      |29   |yes      |24  |1   |0      |0         |6      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |17  |5769 |no      |35   |yes      |24  |1   |0      |1         |10     |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |18  |28848|no      |15   |yes      |13  |12  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |19   |0       |504  |         |353 |122 |1      |30        |100    |


   Current Time: Tuesday, 28-Jul-2020 19:05:01 IST
   Server load: 1.32 1.54 0.92
   Total accesses: 39644 - Total Traffic: 552.0 MB
   CPU Usage: u73.76 s26.73 cu0 cs0 - .765% CPU load
   3.02 requests/sec - 43.0 kB/second - 14.3 kB/request
   753 requests currently being processed, 72 idle workers
  +------------------------------------------------------------------------+
   |    |     |        |Connections    |Threads  |Async connections         |
   |Slot|PID  |Stopping|---------------+---------+--------------------------|
   |    |     |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |0   |5434 |no      |6    |yes      |8   |17  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |1   |5435 |no      |26   |yes      |23  |2   |0      |0         |3      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |2   |26194|no      |25   |yes      |25  |0   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |3   |26882|no      |31   |yes      |25  |0   |0      |0         |4      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
  |4   |5445 |no      |29   |yes      |25  |0   |0      |0         |5      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |5   |26912|no      |13   |yes      |25  |0   |0      |0         |1      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|

   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |30  |1730 |no      |0    |yes      |20  |5   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |31  |1785 |no      |0    |yes      |11  |14  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |32  |1841 |no      |0    |yes      |3   |22  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |33   |0       |681  |         |753 |72  |2      |0         |58     |
   +------------------------------------------------------------------------+

   Current Time: Tuesday, 28-Jul-2020 19:06:01 IST
   Server load: 0.48 1.25 0.86
   Total accesses: 39695 - Total Traffic: 552.7 MB
   CPU Usage: u75.16 s27.17 cu0 cs0 - .775% CPU load
   3.01 requests/sec - 42.9 kB/second - 14.3 kB/request
   1564 requests currently being processed, 61 idle workers
  +------------------------------------------------------------------------+
   |    |     |        |Connections    |Threads  |Async connections         |
   |Slot|PID  |Stopping|---------------+---------+--------------------------|
   |    |     |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |0   |5434 |no      |24   |yes      |24  |1   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |1   |5435 |no      |26   |yes      |25  |0   |0      |0         |3      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |2   |26194|no      |25   |yes      |25  |0   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|

   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |61  |3268 |no      |0    |yes      |25  |0   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |62  |3323 |no      |0    |yes      |7   |18  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |63  |3353 |no      |0    |yes      |7   |18  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |64  |3354 |no      |0    |yes      |12  |13  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |65   |0       |1394 |         |1564|61  |2      |1         |49     |
   +------------------------------------------------------------------------+

   Current Time: Tuesday, 28-Jul-2020 19:07:01 IST

   Server load: 0.45 1.10 0.83
   Total accesses: 39738 - Total Traffic: 553.6 MB
   CPU Usage: u76.57 s27.57 cu0 cs0 - .785% CPU load
   3 requests/sec - 42.7 kB/second - 14.3 kB/request
   2471 requests currently being processed, 29 idle workers

   +------------------------------------------------------------------------+
   |    |     |        |Connections    |Threads  |Async connections         |
   |Slot|PID  |Stopping|---------------+---------+--------------------------|
   |    |     |        |total|accepting|busy|idle|writing|keep-alive|closing|
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |97  |4947 |no      |0    |yes      |18  |7   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |98  |4948 |no      |0    |yes      |20  |5   |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |99  |5032 |no      |0    |yes      |14  |11  |0      |0         |0      |
   |----+-----+--------+-----+---------+----+----+-------+----------+-------|
   |Sum |100  |0       |2166 |         |2471|29  |2      |0         |63     |
   +------------------------------------------------------------------------+

Memory Footprint

    ps -ylC apache2 | awk '{x += $8;y += 1} END {print "Apache Memory Usage (MB): "x/1024; print "Average Process Size (MB): "x/((y-1)*1024)}'
    ps -ylC php-fpm7.2 | awk '{x += $8;y += 1} END {print "PHP-FPM Memory Usage (MB): "x/1024; print "Average Process Size (MB): "x/((y-1)*1024)}'

Tue Jul 28 18:59:00 IST 2020
Apache Memory Usage (MB): 270.688
Average Process Size (MB): 20.8221
PHP-FPM Memory Usage (MB): 392.074
Average Process Size (MB): 65.3457

Tue Jul 28 18:59:59 IST 2020
Apache Memory Usage (MB): 276.336
Average Process Size (MB): 21.2566
PHP-FPM Memory Usage (MB): 410.035
Average Process Size (MB): 68.3392

Tue Jul 28 19:01:01 IST 2020
Apache Memory Usage (MB): 289.598
Average Process Size (MB): 22.2767
PHP-FPM Memory Usage (MB): 470.395
Average Process Size (MB): 78.3991

Tue Jul 28 19:02:00 IST 2020
Apache Memory Usage (MB): 300.242
Average Process Size (MB): 23.0956
PHP-FPM Memory Usage (MB): 482.855
Average Process Size (MB): 80.4759

Tue Jul 28 19:03:00 IST 2020

Apache Memory Usage (MB): 342.848
Average Process Size (MB): 19.0471
PHP-FPM Memory Usage (MB): 493.207
Average Process Size (MB): 82.2012

Tue Jul 28 19:04:00 IST 2020
Apache Memory Usage (MB): 401.375
Average Process Size (MB): 20.0688
PHP-FPM Memory Usage (MB): 500.324
Average Process Size (MB): 83.3874

Tue Jul 28 19:05:01 IST 2020
Apache Memory Usage (MB): 563.961
Average Process Size (MB): 16.5871
PHP-FPM Memory Usage (MB): 521.684
Average Process Size (MB): 86.9473


Tue Jul 28 19:06:01 IST 2020
Apache Memory Usage (MB): 865.719
Average Process Size (MB): 13.117
PHP-FPM Memory Usage (MB): 521.684
Average Process Size (MB): 86.9473

Tue Jul 28 19:07:00 IST 2020
Apache Memory Usage (MB): 1200.85
Average Process Size (MB): 11.8896
PHP-FPM Memory Usage (MB): 521.684
Average Process Size (MB): 86.9473

Average of ratings: Useful (1)
In reply to Abhijit M

Re: Poor Quiz Performance: 32 GB Ram, 24 Cores

by Abhijit M -
Picture of Core developers
if anyone is interested, the complete log collected using this script can be made available.
while true
do
echo "----------------------- LOOP -----------------------"
echo "########################## date ######################"
date
echo "########################## Number of apache processes & threads ######################"
ps -eaf | grep apache2 | wc -l
ps -eLf | grep apache2 | wc -l
ps -eLf | grep mysqld | wc -l
echo "########################## Memory Footprint ######################"
ps -ylC apache2 | awk '{x += $8;y += 1} END {print "Apache Memory Usage (MB): "x/1024; print "Average Process Size (MB): "x/((y-1)*1024)}'
ps -ylC php-fpm7.2 | awk '{x += $8;y += 1} END {print "PHP-FPM Memory Usage (MB): "x/1024; print "Average Process Size (MB): "x/((y-1)*1024)}'
echo "########################## apache2ctl fullstatus ######################"
apache2ctl fullstatus
echo "########################## w ######################"
w
echo "########################## free -m ######################"
free -m
#echo "########################## mytop ######################"
#mytop -u root -p xxxx -h localhost -s 1&
#sleep 1
#kill -9 %1
echo "########################## Wait ######################"
sleep 2
done
Average of ratings: Useful (2)
In reply to Abhijit M

Re: Poor Quiz Performance: 32 GB Ram, 24 Cores

by Abhijit M -
Picture of Core developers
The quiz had only 5 questions, all simple MCQ, all on one page.
Average of ratings: -
In reply to Abhijit M

Re: Poor Quiz Performance: 32 GB Ram, 24 Cores

by Visvanath Ratnaweera -
Picture of Particularly helpful Moodlers Picture of Translators
Hi Abhijit

Neat collection of data, especially the hand-made monitoring scripts. ;)

Too long for me to scan, need a print-out. Here are some random thoughts instead:
- Quite similar to this previous case, https://moodle.org/mod/forum/discuss.php?d=407444. Powerful (single) server, standard Linux, quiz fails ramping up at around 200 candidates.

And interestingly, you both use the https://moodle.org/plugins/quizaccess_delayed plug-in. I have never used it. Are you sure that it doesn't do any harm? When you say "random delay", what is the range?

- Exam started at 19:00, but there were candidates and the server was loaded at 18:56 already?

- RAM can not be the problem, it was in surplus. The quiz with 5 MCQs only has definitely not saturated a 2 Gbit/s pipe. Interestingly the CPU load high, 7 is still below the bearable limit of 12 for a 12 thread CPU. But do you know whether that load is all running or they are IOWAIT? Your disk (or RAID) slowing down the machine?

For a quick test, report the https://moodle.org/plugins/report_benchmark output. See for example https://moodle.org/mod/forum/discuss.php?d=407626. To go deeper you have follow up with iostat/iotop. Ref https://bencane.com/2012/08/06/troubleshooting-high-io-wait-in-linux/. Munin's CPU usage shows this very well. (The blue portions hanging from the roof in the attached graph from an almost idling server.)
Attachment cpu-day.png
Average of ratings: -
In reply to Visvanath Ratnaweera

Re: Poor Quiz Performance: 32 GB Ram, 24 Cores

by Abhijit M -
Picture of Core developers

Benchmarking results.

I don't know how it helps in understanding performance with concurrent users

Average of ratings: -
In reply to Abhijit M

Re: Poor Quiz Performance: 32 GB Ram, 24 Cores

by Visvanath Ratnaweera -
Picture of Particularly helpful Moodlers Picture of Translators
The connection between Moodle Benchmark and scalability? True, it does not give you a figure of scalability but brilliantly simple in finding certain (common) bottlenecks. Anyway, your set up passes all the tests well. (The absolute numbers don't say anything, you have to compare them with the two limits the benchmark proposes. See the columns Accpt. limit and Crit. limit in http://www.syndrega.ch/blog/#benchmarking-moodlebox-on-different-raspberry-pi-models.)

But your score is not brilliant, I expected your server to touch 50.

What I don't understand is, why you utilize this quiz delay plug-in, when your server should be capable of carrying the load without. The plug-in is one more parameter in the search - a less-known one. I would test without. And instead of real loads, I would use JMeter for reproducible loads. On the monitoring side, I would dig further in to iowaits.
Average of ratings: -
In reply to Abhijit M

Re: Poor Quiz Performance: 32 GB Ram, 24 Cores

by Alex Rowe -

Is this a single server for both Web and DB?

If so, what is the total size of the DB on disk. You should be able to get this information from mysqltuner or your SQL management software.

That will then tell you how much you can give to PHP, which is your "max_children in www.conf" X "php-fpm memory use per process".

With the above calculation, you need; OS Ram used (1-2GB) + InnoDB buffer pool size + InnoDB buffers + MySQL Buffers + PHP max size = your available RAM.

Looking at the config files:

  • The apache files look ok but some values for mpm_event may need to be tweaked once everything else is sorted
  • MySQL Config: (recommendations but look into each one before making a change)
    • Add "skip-name-resolve" but make sure your user restrictions are based on IP not hostname
    • sync_binlog = 0 if you don't need it
    • Lower or remove "key_buffer_size" as it's taking up 512MB and Moodle would be on InnoDB not myisam
    • max_connections should be much lower, maybe 100 - 200 ish. Total MySQL footprint is max_connections * buffers + innodb. Mysqltuner shows this number well
    • Disable query cache completely, it hurts performance and is deprecated. query_cache_type=0 and query_cache_size=0 (has to be both)
    • Buffer pool size should be size of your total InnoDB, not sure what the correct value is though
    • Buffer pool instances should be 1 per GB but when it's getting in the 10's of GB, I'd keep this at 8 then raise it later. If wanted set to 12-16
    • a 10GB log file size is too much. 1GB is more than enough
    • Maybe set innodb_flush_log_at_trx_commit= 2 if that works for you in your setup
    • Read IO and write IO should add to be InnoDB instances mostly
    • Lots of others should be commented out until you know that they'll make a difference such as dirty pages, io_capacity etc as these can hurt performance
    • Look into innodb_flush_method=O_DIRECT so MySQL doesn't try to keep InnoDB in it's own memory too
    • Look into innodb_autoinc_lock_mode=2 if you use row binlog formatting
  • PHP Config
    • This would be why you're not using much RAM I believe and seeing issues
    • Max servers is only 5 so no more than 5 scripts can be processed at the same time.
    • Work out max_children based on getting the RAM required earlier
    • Maybe set "pm.max_requests = 500" or higher so memory leaks are cleaned up
If you're going to also have high usage times, it would be beneficial to look into caching content in front of Moodle with NGINX or one of the other tools, varnish was another.

NGINX handles caching, SSL offload, request handling and longer keepalives, then proxy content to Moodle.

You should also look into getting some more monitoring to find out where the bottleneck is. Munin is good for that, easy to use, free etc.

From the looks of it though, PHP is the main issue, then the DB may be an issue.

Average of ratings: Useful (2)