Project

General

Profile

Anomalie #4617

Le nombre d'erreurs HTTP explose de façon exponentielle

Added by Christian P. Momon over 1 year ago. Updated over 1 year ago.

Status:
Fermé
Priority:
Normale
Start date:
08/01/2020
Due date:
% Done:

0%

Estimated time:

Description

Dans le magnifique rapport d'activité de juillet (#4150), on peut lire :

Nombre total de requêtes http                = 124931
Nombre de vraies requêtes http               = 112030
Nombre de requêtes bot                       = 3934
Nombre de requêtes http en erreur            = 1254529

Rétrospectivement :
  • mars : 2 236
  • avril : 9 531
  • mai : 65 071
  • juin : 125 598
  • juillet : 1 254 529

Demande : analyser d'où vient le phénomène et proposer des actions.


Related issues

Related to date.chapril.org - Tâche récurrente #4150: Rapport annuel 2020 d'activité de date.chapril.orgFermé01/05/2020

Actions

History

#1

Updated by Christian P. Momon over 1 year ago

#2

Updated by Christian P. Momon over 1 year ago

  • Description updated (diff)
#3

Updated by Didier Clermonté over 1 year ago

  • Status changed from Nouveau to En cours de traitement

Le code de tpl/part/vote_table_date.tpl a été modifié comme suit :
ajouté 2 fois lignes 116 et 179 :


              {if sizeof($vote->choices)==1 && strlen($vote->choices[0])==0}
                    {$choice=' '}
              {else}
                        {$choice=$vote->choices[$k]}

              {/if}

#4

Updated by Didier Clermonté over 1 year ago

L'investigation qui a conduit à la solution mentionnée au-dessus :

1) D'abord, dans le ticket, dire si cette erreur représente la
quasi-totalité des 1254529 erreurs de juillet, fournir la ligne de
commande et sa sortie ;

=(^-^)=root@lamp:/var/log/apache2/date.chapril.org# errorCount=$(zgrep " 
Jul " date.chapril.org-error.log* | wc -l)
=(^-^)=root@lamp:/var/log/apache2/date.chapril.org#
theErrorCount=$(zgrep " Jul " date.chapril.org-error.log* | grep "line
397" | wc -l)
=(^-^)=root@lamp:/var/log/apache2/date.chapril.org# echo
"$theErrorCount/$errorCount => $((theErrorCount*100/errorCount)) %" 
1247380/1255052 => 99 %

2) Ensuite, vérifier si un ticket existe déjà dans le projet officiel.

A priori, y a pas.

3) retrouver la ligne dans la version non compilée du template ;

tpl/part/vote_table_date.ptl, ligne 179

4) retrouver le fichier et la ligne où la version non compilée du
template est appelée et remonter le plus haut ;

studs.php,adminstuds.php -> studs.tpl -> vote_table_date.tpl

5) déterminer quand ce fichier de template est appelé, c'est dans
l'affichage de quelles pages ?

=(^-^)=root@lamp:/var/log/apache2/date.chapril.org# cat
/var/www/date.chapril.org/.htaccess
  RewriteRule ^([a-zA-Z0-9-]+)$ studs.php?poll=$1 [L]
  RewriteRule ^([a-zA-Z0-9-]+)/action/([a-zA-Z_-]+)/(.+)$
studs.php?poll=$1&$2=$3
  RewriteRule ^([a-zA-Z0-9-]+)/vote/([a-zA-Z0-9]{16})$
studs.php?poll=$1&vote=$2
  RewriteRule ^([a-zA-Z0-9-]{24})/admin$ adminstuds.php?poll=$1
  RewriteRule ^([a-zA-Z0-9-]{24})/admin/vote/([a-zA-Z0-9]{16})$
adminstuds.php?poll=$1&vote=$2
  RewriteRule ^([a-zA-Z0-9-]{24})/admin/action/([a-zA-Z_-]+)(/(.+))?$
adminstuds.php?poll=$1&$2=$4

=(^-^)=root@lamp:/var/log/apache2/date.chapril.org# grep --after=1 stud
/var/www/date.chapril.org/doc/TREEVIEW.md
* studs.php
    * La page de présentation de sondage
* adminstuds.php
    * La page d'administration réservée à l'auteur du sondage

6) cette partie du template concerne quelle partie de la page ?

 L'affichage du tableau des votes.

7) est-ce systématiquement reproduisible ? Comment ?

 Non. En fait, pour le reproduire, on peut retrouver un id de sondage
(prendre l'ip dans *error.log et chercher dans *acess.log).

 Moi j'ai trouvé https://date.chapril.org/......

 Et là, c'est systématique, un tail -f affiche 4 x 264 erreur à chaque
fois. Le 264 correspond au 8 horaire x 33 jours du sondage.

8) relire le code à l'endroit où sa bug

{foreach $votes as $vote}
  […]
  {$k=0}
  {foreach $slots as $slot}
    {foreach $slot->moments as $moment}
      {$choice=$vote->choices[$k]}
      […]
      {$k=$k + 1}
    {/foreach}
  {/foreach}

 La log d'erreur dit «  PHP Notice:  Undefined offset: 25 ».

 Donc c'est clair, le tableau choices ne contient pas autant de cases
qu'attendu.

 Alors, c'est quoi ce tableau choices ?

 Dans studs.php, on voit que :

$votes = $pollService->allVotesByPollId($poll_id);

et dans app/classes/Framadate/Repositories/VoteRepository.php :

    function allUserVotesByPollId($poll_id) {
        $prepared = $this->prepare('SELECT * FROM `' .
Utils::table('vote') . '` WHERE poll_id = ? ORDER BY id');
        $prepared->execute([$poll_id]);

        return $prepared->fetchAll();
    }

donc on peut supposer que voices est une colonne directement mis dans la
variables $vote :

MariaDB [date_chapril_org_db]> describe fd_vote;
+---------+------------------+------+-----+---------+----------------+
| Field   | Type             | Null | Key | Default | Extra          |
+---------+------------------+------+-----+---------+----------------+
| id      | int(11) unsigned | NO   | PRI | NULL    | auto_increment |
| uniqId  | char(16)         | NO   | MUL | NULL    |                |
| poll_id | varchar(64)      | NO   | MUL | NULL    |                |
| name    | varchar(64)      | NO   |     | NULL    |                |
| choices | text             | NO   |     | NULL    |                |
+---------+------------------+------+-----+---------+----------------+
5 rows in set (0.002 sec)

MariaDB [date_chapril_org_db]> select name,choices from fd_vote where
poll_id='V...........' order by id limit 4;
+-------------------+---------------------------------+
| name              | choices                         |
+-------------------+---------------------------------+
| A                 |                              […]|
| V  F              |        2       2       2     […]|
| V               S |        2       2       2     […]|
| P B               |                      20   2  […]|

 Donc, la colonne choices est une chaîne de caractères qui contient les
votes !

 Donc la fameuse ligne {$choice=$vote->choices[$k]} extrait le vote en
prenant le nième caractère de la chaîne.

 Je n'ose imaginer ce qu'il se passe en cas d'insertion de date, brrr…

 Mais alors pourquoi une erreur ?

MariaDB [date_chapril_org_db]> select * from fd_vote where
poll_id='Vit' and choices like '' order by id;
+-------+------------------+------------------+------------------+---------+
| id    | uniqId           | poll_id          | name             | choices |
+-------+------------------+------------------+------------------+---------+
| 19830 | zVAh8Y           | V                | A                |         |
| 20580 | KiG5f            | V                | C                |         |
| 21193 | ADQte            | V                | C                |         |
| 21208 | Gv3u             | V                | B                |         |
+-------+------------------+------------------+------------------+---------+
4 rows in set (0.002 sec)

 Parce que parfois, pour une raison qui nous échappe, une personne qui
ne vote pas voit sa ligne choices vide. Du coup, l'extraction plante.
Normal.

9) patcher

 Donc il faut blinder la ligne {$choice=$vote->choices[$k]}

 Pour cela, rajouter un test sur la taille de choices :

https://www.smarty.net/docsv2/en/language.modifier.count.characters.tpl

{$articleTitle|count_characters:true}

 Si le count est inférieur à k alors mettre $choice=' ';

9 bis) patcher ailleurs
=(^-^)=root@lamp:/var/log/apache2/date.chapril.org# grep -n -R
"\{\$choice=\$vote->choices\[\$k\]}" /var/www/date.chapril.org/
/var/www/date.chapril.org/tpl/part/vote_table_date.tpl:116:
           {$choice=$vote->choices[$k]}
/var/www/date.chapril.org/tpl/part/vote_table_date.tpl:179:
           {$choice=$vote->choices[$k]}

 Donc le problème existe aussi à la ligne 116, code qui affiche le
tableau en mode édition…

#5

Updated by Didier Clermonté over 1 year ago

  • Status changed from En cours de traitement to Résolu
#6

Updated by Didier Clermonté over 1 year ago

Lien vers le ticket déposé dans le projet officiel framadate :
https://framagit.org/framasoft/framadate/framadate/-/issues/516

#7

Updated by Didier Clermonté over 1 year ago

  • Status changed from Résolu to Fermé
#8

Updated by Christian P. Momon over 1 year ago

  • Target version changed from Backlog to Sprint 2020 été

Also available in: Atom PDF