Analyse des requêtes du flux social sur une copie de la bdd de production – Moodle Learning Analytics by Isabelle Motte

Cours et période de référence

Timestamp de référence

Sur ma copie de la bdd de production, le temps s’est arrêté au timestamp 1715347760, soit le 10 mai 2024 à 15:29:20.

Pour extraire les données des 2 dernières semaines, le timestamp de référence est donc celui du 26 avril 2024 à 15:29:20, soit 1714138160.

Courseids de référence ET NOMBRE de PArticipants

J’épingle quelques cours très actifs pour mon test des requêtes de flux social :

WMEDI2337_EXAMEN (3186) : il y a eu un examen récemment dans ce cours de médecine qui compte 321 étudiants,
LANGL1821 (4353) : cours de langue suivant est connu pour être très actif et compte 261 étudiants,
LIEPR1012 (2402) : examen basé sur un devoir à remettre le 4 mai, 765 participants au cours
LBIR1151 (3552) : examen de labo basé sur un quiz le 3 mai, 279 participants au cours
LBIO1112 (1631): tests de labo dans la semaine du 8 mai, 362 participants au cours

Test PRELIMINAIRE sur lEs requêtes

Requête de nettoyage de la table des logs

Imaginons que je veuilles supprimer toutes les données de la dernière semaine. C’est plus que ce qu’il faut supprimer en une journée, mais au moins j’ai une bonne idée de ce qu’il y a comme traitement. Je prends donc le timestamp du 3 mai 15:29:20, càd 1714742960.

SELECT id FROM mdl_logstore_socialflow_log 
WHERE timecreated <= 1714742960 
AND contextid NOT IN (SELECT DISTINCT contextid FROM mdl_logstore_socialflow_log WHERE timecreated > 1714742960)

Temps d’exécution : 2,362 s
Nombre de lignes sélectionnées : environ 50 000.
Cela signifie que la purge de la table va être très lente et qu’il y aura bien plus d’enregistrements dans la table de log en régime. Sans doute de l’ordre de 10 fois plus. Donc optimiser toutes les requêtes reste une nécessité.
Le temps n’est pas excessif pour une requête qui va être exécutée via une tâche cron qui tourne la nuit. Mais on peut peut-être faire mieux.

Requête pour extraire le nombre d’étudiants inscrits à un cours

Prenons la requête pour extraire le nombre d’étudiants actifs pour le cours le plus peuplé (id 2402):

SELECT COUNT(DISTINCT(u.id)) AS nbstu
FROM mdl_user u
INNER JOIN mdl_user_enrolments ue ON ue.userid = u.id
INNER JOIN mdl_enrol e ON e.id = ue.enrolid
INNER JOIN mdl_role_assignments ra ON ra.userid = u.id
INNER JOIN mdl_context ct ON ct.id = ra.contextid 
     AND ct.contextlevel = 50
INNER JOIN mdl_course c ON c.id = ct.instanceid 
     AND e.courseid = c.id
INNER JOIN mdl_role r ON r.id = ra.roleid 
     AND r.shortname = 'student'
WHERE e.status = 0 AND u.suspended = 0 AND u.deleted = 0 AND (ue.timeend = 0 OR ue.timeend > 1715347760) 
AND ue.status = 0 AND c.id = 2402;

Temps d’exécution : 147 m

Possibilité d’amélioration : une table qui enregistre les courseid et le nombre de participants actifs, avec une tâche cron qui tourne toutes les lunes pour mettre à jour le nombre de participants dans les cours. C’est un peu du gaspillage de calculer le nombre de participants actifs dans un cours à chaque fois qu’un étudiant charge le bloc de flux social. Il faudra juste prévoir des conditions au cas où la fréquence était supérieure à 100%.

Requête principale pour afficher la liste d’informations du flux social

SELECT log.contextid, log.eventid, log.courseid, evts.actiontype, c.instanceid, cm.instance, m.name, 
CASE 
WHEN log.courseid =3186 THEN CAST(COUNT(DISTINCT log.userid) AS NUMERIC)/321 
WHEN log.courseid =4353 THEN CAST(COUNT(DISTINCT log.userid) AS NUMERIC)/261 
WHEN log.courseid =2402 THEN CAST(COUNT(DISTINCT log.userid) AS NUMERIC)/765 
WHEN log.courseid =3552 THEN CAST(COUNT(DISTINCT log.userid) AS NUMERIC)/279 
WHEN log.courseid =1631 THEN CAST(COUNT(DISTINCT log.userid) AS NUMERIC)/362 END AS freq 
FROM mdl_logstore_socialflow_log log 
INNER JOIN mdl_logstore_socialflow_evts evts ON (log.eventid=evts.id) 
INNER JOIN mdl_context c ON (log.contextid=c.id) 
INNER JOIN mdl_course_modules cm ON (c.instanceid=cm.id) INNER JOIN mdl_modules m ON (cm.module=m.id) 
WHERE log.courseid IN (3186,4353,2402,3552,1631) AND log.timecreated > 1714138160 AND cm.visible=1 
GROUP BY log.contextid, log.eventid, log.courseid, evts.actiontype, c.instanceid, cm.instance, m.name
ORDER BY freq DESC LIMIT 10;

Note : la clause GROUP BY a été optimisée pour intégrer toutes les colonnes de filtre car cela posait un problème à Posgresql. A intégrer dans la version du module !

Temps d’exécution: 300 à 400 ms en moyenne pour exécuter cette requête, c’est déjà pas mal !

Requête pour déterminer si un étudiant a réalisé ou pas une actioN

Je me base sur l’activité qui est au top 1 du flux social et l’id d’un es étudiants inscrit au cours.

SELECT COUNT(id) AS nbdone 
FROM mdl_logstore_socialflow_log 
WHERE courseid=1631
      AND contextid=96643 
      AND eventid=1 
      AND userid=53745;

L’étudiant avec l’id 72883 est plutôt inactif par contre.

Temps d’exécution : 150 ms
Ce serait bien d’améliorer ce temps d’exécution parce que cette requête est exécutée autant de fois qu’il n’y a de lignes dans le flux social.

Interprétation des résultats de EXPLAIN ANALYZE (merci ChatGPT)

Lorsque vous utilisez l’instruction EXPLAIN ANALYZE dans PostgreSQL, vous obtenez des informations détaillées sur la manière dont PostgreSQL exécute une requête et sur ses performances. Voici comment interpréter les principales parties du résultat :

Seq Scan (Sequential Scan) : Cela signifie que PostgreSQL analyse séquentiellement chaque ligne de la table. Si vous voyez cela sur une grande table sans index, cela peut indiquer que PostgreSQL doit lire chaque ligne pour trouver les résultats de la requête.
Index Scan : PostgreSQL utilise un index pour trouver les lignes qui correspondent à votre requête. Cela peut être plus efficace que Seq Scan si votre requête est sélective et qu’il existe un index approprié.
Bitmap Heap Scan : C’est similaire à un Index Scan, mais il est utilisé lorsqu’il y a plusieurs conditions de filtrage. PostgreSQL construit d’abord un bitmap de tuples à récupérer, puis lit les tuples de la table principale.
Nested Loop (Boucle imbriquée) : Cela signifie que PostgreSQL utilise une boucle imbriquée pour joindre les résultats de deux sous-requêtes. C’est généralement utilisé pour les jointures avec des petites tables.
Hash Join : PostgreSQL utilise une table de hachage pour effectuer une jointure entre deux ensembles de données. C’est généralement plus rapide que la boucle imbriquée pour les ensembles de données plus importants.
Sort (Tri) : Cela signifie que PostgreSQL doit trier les résultats selon une certaine condition. Si vous voyez cela, vous pouvez envisager d’ajouter un index pour éviter le tri si possible.
Aggregate (Agrégat) : PostgreSQL effectue une agrégation, comme la somme ou la moyenne, sur un ensemble de données.
Seq Scan on CTE Scan : Cela signifie que PostgreSQL analyse séquentiellement les résultats d’une expression de tableau commun (CTE) plutôt que de les lire à partir d’une table physique.
Gather : L’action « Gather » est utilisée dans PostgreSQL lors de l’exécution de requêtes parallèles. Elle collecte les résultats partiels produits par plusieurs processus de travail (workers) et les agrège en un seul ensemble de résultats à envoyer au processus principal.
Merge : L’action « Merge » est utilisée dans le contexte de « Gather » pour indiquer que les résultats partiels collectés doivent être fusionnés en un seul ensemble de résultats. Cette fusion peut impliquer le tri et l’agrégation des données provenant de plusieurs sources pour produire un ensemble de résultats global.
Total Cost : C’est une estimation du coût total de l’exécution de la requête. Plus le coût est élevé, plus PostgreSQL estime que la requête sera longue à exécuter.
Actual Rows : Le nombre de lignes réellement renvoyées par chaque opération. Cela peut être différent de l’estimation du plan d’exécution.

En résumé, EXPLAIN ANALYZE est un outil puissant pour comprendre comment PostgreSQL exécute vos requêtes et pour identifier les goulets d’étranglement ou les opportunités d’optimisation. Utilisez-le pour optimiser les performances de vos requêtes.

Le Total Cost (Coût total) affiché dans le résultat de l’instruction EXPLAIN ANALYZE de PostgreSQL est une mesure d’estimation du coût total de l’exécution de la requête. Cependant, il n’est pas exprimé dans une unité spécifique comme les millisecondes ou les secondes. Il s’agit plutôt d’une unité de coût arbitraire qui est utilisée par l’optimiseur de requêtes de PostgreSQL pour estimer la performance relative des différents plans de requêtes.

Le Actual Time (Temps réel) est le temps réellement écoulé pour exécuter chaque opération dans le plan de requête, mesuré en unités de temps (par exemple, millisecondes). Cette valeur est basée sur le moment où l’opération a commencé et quand elle s’est terminée. Il est affiché en microsecondes et la conversion est la suivante : 1 seconde = 1 000 000 microsecondes.

Optimisation des requêtes

Un index sur la colonne timecreated ne change rien et l’index sur courseid n’a pas l’air de changer grand chose. C’est pas faclie parce que la même requête n’est pas toujours exécutée sur le même temps.

Requête de nettoyage de la table des logs

Dans cette requête, il y a 2 sequential scan de la table des logs, une fois sur le contextid et une fois sur le timestamp. C’est très lourd.
La première idée peut être d’ajouter des index liés mais Raoul et Freddy m’ont aussi conseillé de voir si cette requête ne pouvait pas être réécrite …

L’index sur le timecreated est utilisé pour optimiser la requête.

Autres reformulations moins performantes de la requête :

SELECT id 
FROM mdl_logstore_socialflow_log AS log1 
WHERE timecreated <= 1714742960 
AND NOT EXISTS (
    SELECT 1 
    FROM mdl_logstore_socialflow_log AS log2 
    WHERE log1.contextid = log2.contextid 
    AND log2.timecreated > 1714742960
);

SELECT log1.id 
FROM mdl_logstore_socialflow_log AS log1 
LEFT JOIN (
    SELECT DISTINCT contextid 
    FROM mdl_logstore_socialflow_log 
    WHERE timecreated > 1714742960
) AS log2 ON log1.contextid = log2.contextid 
WHERE log1.timecreated <= 1714742960 
AND log2.contextid IS NULL;

Requête pour extraire le nombre d’étudiants inscrits à un cours

Cette requête là n’est pas propre à mon module et il y a de nombreux appels d’index. Le seul sequential scan est sur la table mdl_roles qui contient quelques dizaines de lignes. Donc, à priori, cette requête est déjà bien optimisée.

Requête principale pour afficher la liste d’informations du flux social

Ce qui coûte dans la requête de flux social, c’est le ORDER et le GROUP BY et comme les colonnes de tri sont identiques dans la requête pour réaliser si un étudiant a fait ou pas une action, je pense que ce serait bien de créer un index sur le jeu des 3 colonnes contextid, courseid, eventid de la table de log.

L’index n’est pas utilisé. Il vaut peut-être mieux explorer les possibilités de réécriture de la requête … Le fait qu’il y ait des actions de « Gather Merge » laisse aussi penser que la requête peut être optimisée.

Réécriture :

WITH event_hits AS (
    SELECT 
        log.courseid, log.contextid, log.eventid,
        COUNT(DISTINCT log.userid) AS hits
    FROM 
        mdl_logstore_socialflow_log log 
    WHERE 
        log.courseid IN (3186, 4353, 2402, 3552, 1631) 
        AND log.timecreated > 1714138160 
    GROUP BY 
        log.courseid, log.contextid, log.eventid
)
SELECT 
    ei.contextid, 
    ei.eventid, 
    ei.courseid, 
    evts.actiontype, 
    c.instanceid, 
    cm.instance, 
    m.name, 
    CASE 
        WHEN ei.courseid = 3186 THEN CAST(ei.hits AS NUMERIC) / 321 
        WHEN ei.courseid = 4353 THEN CAST(ei.hits AS NUMERIC) / 261 
        WHEN ei.courseid = 2402 THEN CAST(ei.hits AS NUMERIC) / 765 
        WHEN ei.courseid = 3552 THEN CAST(ei.hits AS NUMERIC) / 279 
        WHEN ei.courseid = 1631 THEN CAST(ei.hits AS NUMERIC) / 362 
    END AS freq 
FROM 
    event_hits ei
INNER JOIN 
    mdl_logstore_socialflow_evts evts ON ei.eventid = evts.id 
INNER JOIN 
    mdl_context c ON ei.contextid = c.id 
INNER JOIN 
    mdl_course_modules cm ON c.instanceid = cm.id 
INNER JOIN 
    mdl_modules m ON cm.module = m.id 
WHERE cm.visible = 1
ORDER BY 
    freq DESC 
LIMIT 
    10;

Temps d’exécution : 150 à 200ms, c’est déjà mieux

Avec un index sur les 3 colonnes de log ? Ca ne change rien. Peut-être s’il y a vait plus de données, il l’utiliserait ? Non, en important un mois de données, j’ai 2 millions de lignes et l’index n’est toujours pas utilisé.

Ca plaide pour la création d’une table avec les infos sur les hits au fil de l’enregistrement des logs. Et une table avec le hit id, le userid et le timecreated.

Requête pour déterminer si un étudiant a réalisé ou pas une action

Test avec un index sur les 4 colonnes courseid, contextid, eventid et userid.

Temps d’exécution : 170 ms
C’est pire, même si l’index est bien utilisé !

Test avec un index sur les 3 colonnes courseid, contextid, eventid

Temps d’exécution : 150 ms
Ca ne change rien, même si l’index est utilisé.

Temps de travail sur cet article : 1/2 jour