CAPQuiz is slower than Core Quiz

[hgeorgsch]

I have compared the performance of the same questions in CAPQuiz and the Core Quiz. CAPQuiz is slow to respond both when grading a question and when delivering the next question. This holds for both multiple choice and STACK. In the Core Quiz STACK questions, there is a noticeable delay in grading, but less than for CAPQuiz. Other actions have negligible response time in Core, but it it annoyingly long in CAPQuiz.

This is probably related to issues #166 #165 and maybe others

[hgeorgsch]

Could this be as simple as missing indices? Delivering a question, CAPQuiz needs to find a number of questions with rating near a given rating level, but questions are not indexed by rating. Grading a question, CAPQuiz has to look up the last question attempt by the same user. I did not find the table definition in the source code, so I do not know if the necessary indices exist. It is possible that the most effective solution would be to let CAPQuiz store the last question attempted for each user, for easy lookup.

[hgeorgsch]

One likely culprit is the in file classes/matchmaking/n_closest/n_closest_selector.php, line 88-90. The SQL query orders by the absolute value of a difference comparing the rating with a certain target value. A suitable index may or may not help here.
Three columns are involved, and you probably want to order before the the inequality constraints. I am not sure if postgres would do that efficiently. Two possible alternatives 1 remove the blacklisted question at the client. 2 create new tables where the blacklist can be filtered out in one constraint. This may or may not be feasible.

[hgeorgsch]

The other likely culprit is line 110-114 in classes/capquiz_question_attempt.php This is an SQL query ordering by time_reviewed, which probably could be indexed easily.

[hgeorgsch]

I have tried to add an index which hopefully speed up the question rerating as part of grading. This should be reviewed. Can anyone tell me if we need to add something to the upgrade script?

[hgeorgsch]

A third possible culprit is the blacklist, in inactive_attempts() in classes/capquiz_question_attempt.php This appears to retrieve every attempt from the DB, with no obvious reason. The SQL query should be critically reviewed.

[sebastsg]

Can anyone tell me if we need to add something to the upgrade script?

Look here under "Handling indexes": https://docs.moodle.org/dev/Data_definition_API

[hgeorgsch]

Thanks, @sebastsg . It seems that one can use the XMLDB editor inside moodle to generate the necessary code. I think I managed, and made a pull request. One more point, I have copy-edited the ideas above into a new file TODO, on the bug/id167 branch. There are design considerations which should be discussed before changing code, preferably with someone who remember the original implementation of matchmaking.

[hgeorgsch]

The new index did not have any noticeable effect on performance. We will probably have to go through every DB call in CAPQuiz and see if any of them are excessive. Does anyone know how to log more data in postgresql?

[andstor]

Does anyone know how to log more data in postgresql?

Might this be of any help? I found a PostgreSQL analyzation tool called pgbadger, install guide here.

Alternatively, it seems that pgAdmin have some analyzation capabilities.

[hgeorgsch]

The slow response is not only because of the size of the capquiz_attempts table. A freshly created quiz with the same questions is faster. Furthermore, on slow quizzes, everything is slow, also accessing the config pages.

[hgeorgsch]

To log queries, we need to change postgresql.conf in the postgred dir under /etc, and change

log_min_duration_statement = -1 # -1 is disabled, 0 logs all statements

                                    # and their durations, > 0 logs only
                                    # statements running at least this number
                                    # of milliseconds

to some non-negative value.

For the record, there are few expensive calls, but an enormous number of trivial ones.

[hgeorgsch]

It seems that the culprit is capquiz_question_list::question_usage() This function results in a large number of stack related queries taking up most of the elapsing wall time. This is based on profiling using xhprof

[hgeorgsch]

This page is interesting reading: https://docs.moodle.org/dev/Using_the_question_engine_from_module#Loading_the_usage

It seems that only one question_usage object should be created for each question, when they are used one question per page. Not sure, though. I cannot say I understand the rationale for the question usage.

[hgeorgsch]

More information in this discussion between myself and Tim Hunt: https://moodle.org/mod/forum/discuss.php?d=393058 No conclusion yet, this is strange.

[hgeorgsch]

This does not appear critical at the moment, and it is not obviously a bug. We should make new comparisons to confirm the problem based on new use cases,

1. without STACK questions
2. with STACK questions without pregenerated instances.

[hgeorgsch]

Now testing CAPQuiz activities with STACK questions after the students have made close to 10000 attempts last semester, it is slow; 30-60s to load each page, both in the teacher and student interfaces. The apache2 process often runs to 100% CPU. Sometimes ~80% apache and ~20% postgres. I need to check with the profiler.

[hgeorgsch]

The profiler shows that opening the teacher dashboad, question_attempt::load_from_records is called once for each attempt by question_usage_by_activity::load_from_records, which is called twice. The two calls stem from the capquiz constructor making two calls to capquiz_question_list::load_question_list.

[hgeorgsch]

We have exactly the same behaviour when the student loads the first question.

[hgeorgsch]

Looking at the previous two comments, there are two bugs.

1. In the core quiz engine, load_from_records scales linearly in the number of attempts in spite of the attempts having no use in the context.
2. In CAPQuiz loads the question list twice, which is wasteful by a factor of two. The latter is probably the easier fix. Significant improvement, but it still does not scale.

One have to ask if load_from_records is the right function to call, or if a more light weight function exists in the API.

[hgeorgsch]

The second issue is moved to #191 The first issue is probably a problem in Moodle, unless we can avoid the call to question_usage_by_activity::load_from_records It is possible that preinstantiated STACK questions may reduce the load by caching. STACK-related calls take 96.4% of the CPU load.

[hgeorgsch]

[hgeorgsch]

Ideas from Tim Hunt at https://moodle.org/mod/forum/discuss.php?d=417757#p1683428

[sebastsg]

@hgeorgsch Is it important that the optimization works on earlier CAPQuiz instances? I'm thinking that the migration will be to simply copy the quba from question list to user, and the problem will probably worsen for older instances in that case. It's probably possible to split the old quba into one for each student, but not sure how straight forward that will be.

@andstor Are you aware whether or not splitting a quba is feasible?

[hgeorgsch]

We can afford the performance loss on old instances. CAPQuiz does not have such a massive user base at this point. It is not ideal, but we have to admit that this has been experimental and radical changes is needed.

Obviously, we need to flag the disadvantages in the release log, and cater for continued use of the old version. Those who do upgrade have the option of exporting a template and make a new activity with the same questions and ratings. I suspect that is sufficient in practice, as long as the documentation is solid.

[andstor]

@sebastsg I reviewed your changes in aaada9c and 2344db1. Looks good to me! But yes, this would make it much worse for older instances performance-wise.

@andstor Are you aware whether or not splitting a quba is feasible?

There is no "built-in" support for this in Moodle. However, Moodle provides some rather extensive classes for handling question_usages, question_attempts, question_attempt_steps, and question_attempt_step_data that would simplify some things. So technically, yes, I think it is feasible to split old qubas. However, this would require quite a lot of work.

Here is an overview of the question engine data that we would need to handle:

[sebastsg]

@hgeorgsch @andstor Splitting the question usages wasn't as hard as I initially expected, so I went ahead and did it. Pull request is ready for review and testing.