Actions
Anomalie #4617
ferméLe nombre d'erreurs HTTP explose de façon exponentielle
Début:
01/08/2020
Echéance:
% réalisé:
0%
Temps estimé:
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 = 1254529Ré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.
Actions
#1
Mis à jour par Christian P. Momon il y a plus de 4 ans
- Lié à Tâche récurrente #4150: Rapport annuel 2020 d'activité de date.chapril.org ajouté
Actions
#3
Mis à jour par Didier Clermonté il y a environ 4 ans
- Statut changé de Nouveau à 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}
Actions
#4
Mis à jour par Didier Clermonté il y a environ 4 ans
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…
Actions
#5
Mis à jour par Didier Clermonté il y a environ 4 ans
- Statut changé de En cours de traitement à Résolu
Actions
#6
Mis à jour par Didier Clermonté il y a environ 4 ans
Lien vers le ticket déposé dans le projet officiel framadate :
https://framagit.org/framasoft/framadate/framadate/-/issues/516
Actions
#8
Mis à jour par Christian P. Momon il y a environ 4 ans
- Version cible changé de Backlog à Sprint 2020 été
Actions