小テストのプレビューが遅い

小テストのプレビューが遅い

by T N -
Number of replies: 9

複数の問題を含む小テストをつくり、教師権限でプレビューしようとすると、非常に時間がかかります。数分に及ぶこともあり、その間は他のユーザーにまで影響します。なんとかしたいので、ご相談申し上げます。

環境は、Moodle 2.1.1+(Build: 20110907)、PHP 5.3.6、Apache 2.2.17、MySQL 5.1.58、Fedora 14です。ときどき、極めてリスポンスが悪くなるので、slow queryのログをとりつつ、原因を絞り込んでいったところ、どうやら既存の小テストをプレビューすると顕著に遅くなることが分かりました。以下のログはそのときのものです。そもそも、プレビューするのに、どうしてDELETEが必要なのかも分からないのですが、それは置いとくとして、プレビューに、合計で200秒以上かかっています。google頼みで、あちこち探ってみますと、INではなくEXISTSを使えという記述に遭遇します。そこで、お尋ねします。

1.バージョン2.0.2(このバージョンから症状が現れたことに気がつきました)以上をお使いのところでは、どのような状況なのでしょうか。何も問題ないのでしょうか。あるいは何らかの対処をされているのでしょうか。

2.DELETE FROM以下のスクリプトを実行させているファイルの所在を特定できません。予備機で試行錯誤すれば、なんとかなるかなと淡い期待を抱いていますので、お分かりの方、教えてください。


# Time: 110916 14:29:05
# Query_time: 164.318654  Lock_time: 0.012147 Rows_sent: 0  Rows_examined: 45585447
SET timestamp=1316150945;
DELETE FROM mdl_question_attempt_step_data WHERE attemptstepid IN (
                SELECT qas.id
                FROM mdl_question_attempts qa
                JOIN mdl_question_attempt_steps qas ON qas.questionattemptid = qa.id
                WHERE qa.questionusageid = '134655');


# Time: 110916 14:29:52
# Query_time: 46.928032  Lock_time: 0.047359 Rows_sent: 0  Rows_examined: 5881907
SET timestamp=1316150992;
DELETE FROM mdl_question_attempt_steps WHERE questionattemptid IN (
                SELECT qa.id
                FROM mdl_question_attempts qa
                WHERE qa.questionusageid = '134655');

Average of ratings: 有益(Useful) (1)
In reply to T N

Re: 小テストのプレビューが遅い

by Mitsuhiro Yoshida -
Picture of Developers Picture of Particularly helpful Moodlers Picture of Translators

> 2.DELETE FROM以下のスクリプトを実行させているファイルの所在を特定できません。予備機で試行錯誤すれば、なんとかなるかなと淡い期待を抱いていますので、お分かりの方、教えてください。

Moodle 2.1.1+ (Build: 20110916) のソースコードで探しましたところ、question/engine/datalib.phpの646行目の関数delete_questions_usage_by_activities()内でDELETE FROM以下のスクリプトを実行しているようです。

--------------------------------------------------------------
    public function delete_questions_usage_by_activities(qubaid_condition $qubaids) {
        $where = "qa.questionusageid {$qubaids->usage_id_in()}";
        $params = $qubaids->usage_id_in_params();

        $contextids = $this->db->get_records_sql_menu("
                SELECT DISTINCT contextid, 1
                FROM {question_usages}
                WHERE id {$qubaids->usage_id_in()}", $qubaids->usage_id_in_params());
        foreach ($contextids as $contextid => $notused) {
            $this->delete_response_files($contextid, "IN (
                    SELECT qas.id
                    FROM {question_attempts} qa
                    JOIN {question_attempt_steps} qas ON qas.questionattemptid = qa.id
                    WHERE $where)", $params);
        }

        $this->db->delete_records_select('question_attempt_step_data', "attemptstepid IN (
                SELECT qas.id
                FROM {question_attempts} qa
                JOIN {question_attempt_steps} qas ON qas.questionattemptid = qa.id
                WHERE $where)", $params);

        $this->db->delete_records_select('question_attempt_steps', "questionattemptid IN (
                SELECT qa.id
                FROM {question_attempts} qa
                WHERE $where)", $params);

        $this->db->delete_records_select('question_attempts',
                "{question_attempts}.questionusageid {$qubaids->usage_id_in()}",
                $qubaids->usage_id_in_params());

        $this->db->delete_records_select('question_usages',
                "{question_usages}.id {$qubaids->usage_id_in()}", $qubaids->usage_id_in_params());
    }

Average of ratings: 有益(Useful) (1)
In reply to Mitsuhiro Yoshida

Re: 小テストのプレビューが遅い

by T N -

ありがとうございます。1.9台のバージョンにはない部分なのですね。MySQLを操作する部分を触るのは初めてですが、勉強のつもりでトライしてみます。

ちなみに、バージョンアップに時間がかかるのは、以下の部分でした。これが問題の数に応じて繰り返されていました。

# Time: 110916 16:21:38
# Query_time: 15.975244  Lock_time: 0.000073 Rows_sent: 0  Rows_examined: 3785255
use moodle;
SET timestamp=1316157698;
SELECT *
                FROM mdl_question_states
                WHERE attempt IN (
                    SELECT uniqueid FROM mdl_quiz_attempts WHERE quiz = '413' AND preview = 0 AND needsupgradetonewqe = 1)
                ORDER BY attempt, question, seq_number, id;


# Time: 110916 16:21:45
# Query_time: 6.645938  Lock_time: 0.000034 Rows_sent: 1550  Rows_examined: 1639611
SET timestamp=1316157705;
SELECT *
                FROM mdl_question_sessions
                WHERE attemptid IN (
                    SELECT uniqueid FROM mdl_quiz_attempts WHERE quiz = '418' AND preview = 0 AND needsupgradetonewqe = 1)
                ORDER BY attemptid, questionid;

In reply to Mitsuhiro Yoshida

Re: 小テストのプレビューが遅い

by T N -

全く自信ありませんが、question/engine/datalib.phpの662行目から671行目の部分を次のように書き換えたところ、
   

    662         $this->db->delete_records_select('question_attempt_step_data', "EXISTS (
    663                 SELECT 1
    664                 FROM {question_attempts} qa
    665                 JOIN {question_attempt_steps} qas ON qas.questionattemptid = qa.id
    666                 WHERE qas.id = attemptstepid AND $where)", $params);
    667                 
    668         $this->db->delete_records_select('question_attempt_steps', "EXISTS (
    669                 SELECT 1
    670                 FROM {question_attempts} qa
    671                 WHERE qa.id = questionattemptid AND $where)", $params);

MySQLのログが、

# Query_time: 0.017358  Lock_time: 0.000057 Rows_sent: 0  Rows_examined: 234
SET timestamp=1316426920;
DELETE FROM mdl_question_attempt_step_data WHERE EXISTS (
                SELECT 1
                FROM mdl_question_attempts qa
                JOIN mdl_question_attempt_steps qas ON qas.questionattemptid = qa.id
                WHERE qas.id = attemptstepid AND qa.questionusageid = '141993');


# Query_time: 0.000659  Lock_time: 0.000042 Rows_sent: 0  Rows_examined: 58
SET timestamp=1316426920;
DELETE FROM mdl_question_attempt_steps WHERE EXISTS (
                SELECT 1
                FROM mdl_question_attempts qa
                WHERE qa.id = questionattemptid AND qa.questionusageid = '141993');

になり、だいぶ改善されたように見えます。意味もほとんどわからないにも拘わらず、ここを見よう見まねで書いたのですが、本当にこれで大丈夫なのか、他に副作用はでないのか、など、だいぶ不安があります。特に、"SELECT 1"の意図がまったく分かりません。誤りの指摘、あるいは添削等していただけるとうれしいです。

In reply to T N

Re: 小テストのプレビューが遅い

by Mitsuhiro Yoshida -
Picture of Developers Picture of Particularly helpful Moodlers Picture of Translators

> 特に、"SELECT 1"の意図がまったく分かりません。

"SELECT 1"  はSQLの処理速度を上げるために使われているようです。
ご参考までに下記をページご覧ください。

[SQLを速くするぞ (4.EXISTS述語のサブクエリー内では、SELECT * を使え) - 進め!!]
http://f15.aaa.livedoor.jp/~susume/oracle_speedup_sql2.htm

[INとEXISTSの実行計画の違い - 理想は泥臭いアーキテクト]
http://tolkine9999.blog34.fc2.com/blog-entry-3.html

[Using a SELECT 1 vs a SELECT * in the EXISTS/NOT EXISTS query - Systems Engineering and RDBMS]
http://decipherinfosys.wordpress.com/2008/02/13/using-a-select-1-vs-a-select-in-the-existsnot-exists-query/

Moodleの実運用サイトにSQLの変更を適用することで、何らかの問題が発生する場合があると思いますので、Moodleの小テスト (Quiz module) 開発者が直接確認することになる、Moodle Trackerに小テストプレビューの遅さおよびSQL文の改善案を投稿されてはいかがでしょうか。smile

[Moodle Tracker]
http://tracker.moodle.org/

Average of ratings: 有益(Useful) (1)
In reply to Mitsuhiro Yoshida

Re: 小テストのプレビューが遅い

by T N -

いろいろ参考ページを教えてくださり、ありがとうございます。勉強になります。

代替機だから、よかったものの、上記の書き換えでは、

mdl_question_attempt_step_dataとmdl_question_attempt_stepsテーブルの中身がほとんど無くなってましたsurprise

>Moodle Trackerに小テストプレビューの遅さおよびSQL文の改善案

英文は読むことはなんとかなっても、書く方は敷居が高いですsad もっとも、結局、改善には至らなかったわけですが。

In reply to T N

Re: 小テストのプレビューが遅い

by T N -

自己フォローです。 コースをまたがった問題共有をするために、システムロールの割当を行って、コアシステムコンテクストにアクセスできるようにしてある教員のみに起こる現象でした。問題共有を諦めずにテーブルスキャンの範囲を狭める方法を模索(あるのかなぁ?)するか、改造(私の力量を超えているsad)するか、頭が痛いです。以前にも、問題共有ではまったことがありましたが、たびたびお騒がせして、申し訳ありません。

Average of ratings: 有益(Useful) (2)
In reply to T N

Re: 小テストのプレビューが遅い

by T N -

すみません、昨日の今日で、恐縮ですが、訂正です。
 「コースをまたがった問題共有」ではなく、「コースカテゴリをまたがった問題共有」です。さらに、重要な訂正ですが、
 「コアシステムコンテクストにアクセスできるようにしてある教員のみに起こる現象」ではなく、「2回目以降のプレビューで、コンテクストに関係なくすべての教師に対し、誰が作ったかに関係なくすべての小テストに対して起こる現象」でした。1回目のプレビューで問題なかったので、早とちりしました。振り出しに戻って、ちょっと力が抜けました。
 ちなみに、問題エンジンはアップグレードしてあって、mdl_question_sessionsの数は、240万強です。この数が大きい(古からあるサイトに比べれば特段大きくもないと思っているのですが)ので、問題が顕在化している、という可能性も考えています。差し支えなければ、皆様のところでは、どのくらいの数なのか教えてください。

In reply to T N

Re: 小テストのプレビューが遅い

by T N -

プレビューというのは、答えない解答であって、2回目以降のプレビューでは1回目の解答を削除してから、再度、答えない解答を行うと解釈しました(合っているかな?)。学生の場合は、レビューであって解答を削除しないので、MySQLの反応が遅くなるということはありません。解答を削除する、という点においては、これと同じです。実際、教師権限で学生の解答を削除するときに極端に遅くなります。ようやく、光明smileが見えてきました(他力本願sadですが)。

In reply to T N

Re: 小テストのプレビューが遅い

by T N -

Moodle 2.1.2 になって、解消されました。ただし、まだ、

UPDATE mdl_cache_text SET md5key = ..........

でだいぶもたついているようです。

Average of ratings: 有益(Useful) (1)