Piwigo.org

IxeYgrek · 2025-02-26 16:27:54

Bonjour/Bonsoir,

Bonjour,

Je ne sais pas si le problème est présent depuis la dernière mise à jour ou depuis que j'ai vidé le cache utilisateur (j'ai fait ces deux opérations a peut près en même temps) mais pour différentes opérations sur la galerie j'ai des erreurs avec toujours le même message en réponse : "Rebuilding user cache takes long. Please come back later".
Par exemple en ce moment j'utilise la gestion par lot en mode unitaire pour mettre à jour les tags, et quand je fais des modifications sur plusieurs photos et que j'enregistre avec le bouton "Save all photos", j'ai certaines photos qui affiche une erreur et quand je regarde dans la console réseau Firefox j'ai un code 503 avec comme message "Rebuilding user cache takes long piwigo. Please come back later".

Si vous avez une piste pour régler ce problème je suis preneur c'est vraiment ennuyant car en plus de l'erreur, lorsqu'elle apparait, il n'est plus possible de cliquer sur le bouton "sauvegarder" et je dois donc recharger la page...

Edit : j'ai vérifié l'activité système et j'ai fait la mise à jour 15.4.0 le 22 et j'ai vidé le cache utilisateur le 23.
J'avais pas ce problème avant, donc je ne sais pas quelle action a entrainé ça.

Version de Piwigo: 15.4.0
Version de PHP: 8.3.6
Version de MySQL: 8.0.41-0ubuntu0.24.04.1
URL Piwigo: https://universe-photo-archive.eu/gallery/

Dernière modification par IxeYgrek (2025-02-26 17:27:16)

plg · 2025-02-26 17:55:37

Pour le moment je n'arrive pas à reproduire. C'est bien au bout de 10 secondes qu'on a le message ?

plg · 2025-02-26 17:55:58

et aussi, que dit le fichier _data/log/log du jour.txt ?

IxeYgrek · 2025-02-26 20:14:49

plg a écrit:
Pour le moment je n'arrive pas à reproduire. C'est bien au bout de 10 secondes qu'on a le message ?

Bonsoir plg et merci pour la réponse.
Je viens de faire le test avec une modification de tags sur 13 photos différentes.
En effet au bout de 10 secondes toutes les photos qui restent à traitées tombent en erreur.

Je me rend compte que ça n'affecte pas que les actions côté administration : les utilisateurs sont également impactés, par exemple quand ils téléchargent une photo.

Voici ce qu'il y a dans les logs :

Code:

[2025-02-26 19:08:12]   [INFO]  [getuserdata][exec_code=6436][user_id=1] needs user_cache to be rebuilt
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=c02cdb25] starts now
[2025-02-26 19:08:12]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] needs user_cache to be rebuilt
[2025-02-26 19:08:12]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] needs user_cache to be rebuilt
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=51d90021] starts now
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=481e4de0] starts now
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=c02cdb25] wins the race and gets the token!
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=51d90021] skip
[2025-02-26 19:08:12]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] starts to wait for another request to build user_cache
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=481e4de0] skip
[2025-02-26 19:08:12]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] starts to wait for another request to build user_cache
[2025-02-26 19:08:12]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] needs user_cache to be rebuilt
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=8d767719] starts now
[2025-02-26 19:08:12]   [INFO]  [generate_user_cache-u1][exec=8d767719] skip
[2025-02-26 19:08:12]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] starts to wait for another request to build user_cache
[2025-02-26 19:08:13]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.003 s
[2025-02-26 19:08:13]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.003 s
[2025-02-26 19:08:13]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.001 s
[2025-02-26 19:08:14]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.004 s
[2025-02-26 19:08:14]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.003 s
[2025-02-26 19:08:14]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.002 s
[2025-02-26 19:08:15]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.004 s
[2025-02-26 19:08:15]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.004 s
[2025-02-26 19:08:15]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.002 s
[2025-02-26 19:08:16]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.005 s
[2025-02-26 19:08:16]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.005 s
[2025-02-26 19:08:16]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.003 s
[2025-02-26 19:08:17]   [INFO]  [getuserdata][exec_code=7661][user_id=2] needs user_cache to be rebuilt
[2025-02-26 19:08:17]   [INFO]  [generate_user_cache-u2][exec=25ddf6f9] starts now
[2025-02-26 19:08:17]   [INFO]  [generate_user_cache-u2][exec=25ddf6f9] wins the race and gets the token!
[2025-02-26 19:08:17]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.006 s
[2025-02-26 19:08:17]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.006 s
[2025-02-26 19:08:17]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.004 s
[2025-02-26 19:08:18]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=5 user_cache not ready yet, after waiting 6.006 s
[2025-02-26 19:08:18]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=5 user_cache not ready yet, after waiting 6.007 s
[2025-02-26 19:08:18]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=5 user_cache not ready yet, after waiting 6.004 s
[2025-02-26 19:08:19]   [INFO]  [getuserdata][exec_code=7525][user_id=2] needs user_cache to be rebuilt
[2025-02-26 19:08:19]   [INFO]  [generate_user_cache-u2][exec=3d383228] starts now
[2025-02-26 19:08:19]   [INFO]  [generate_user_cache-u2][exec=3d383228] skip
[2025-02-26 19:08:19]   [INFO]  [getuserdata][exec_code=7525][user_id=2] starts to wait for another request to build user_cache
[2025-02-26 19:08:19]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=6 user_cache not ready yet, after waiting 7.007 s
[2025-02-26 19:08:19]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=6 user_cache not ready yet, after waiting 7.007 s
[2025-02-26 19:08:19]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=6 user_cache not ready yet, after waiting 7.005 s
[2025-02-26 19:08:20]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.001 s
[2025-02-26 19:08:20]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=7 user_cache not ready yet, after waiting 8.008 s
[2025-02-26 19:08:20]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=7 user_cache not ready yet, after waiting 8.008 s
[2025-02-26 19:08:20]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=7 user_cache not ready yet, after waiting 8.006 s
[2025-02-26 19:08:21]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.001 s
[2025-02-26 19:08:21]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] needs user_cache to be rebuilt
[2025-02-26 19:08:21]   [INFO]  [generate_user_cache-u2][exec=d2996238] starts now
[2025-02-26 19:08:21]   [INFO]  [generate_user_cache-u2][exec=d2996238] skip
[2025-02-26 19:08:21]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] starts to wait for another request to build user_cache
[2025-02-26 19:08:21]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=8 user_cache not ready yet, after waiting 9.009 s
[2025-02-26 19:08:21]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=8 user_cache not ready yet, after waiting 9.009 s
[2025-02-26 19:08:21]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=8 user_cache not ready yet, after waiting 9.006 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=6436][user_id=1] user_cache generated, executed in 9.501 s
[2025-02-26 19:08:22]   [DEBUG] taglist_before
  4485: array(
    0 => '5',
    1 => '6',
    2 => '34',
    3 => '251',
    4 => '257',
    5 => '407',
  )
[2025-02-26 19:08:22]   [DEBUG] taglist_after
  4485: array(
    0 => '5',
    1 => '6',
    2 => '34',
    3 => '251',
    4 => '257',
    5 => '296',
    6 => '407',
  )
[2025-02-26 19:08:22]   [DEBUG] $images_to_update
  0: 4485
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.004 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.001 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=9 user_cache not ready yet, after waiting 10.010 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting k=9 user_cache not ready yet, after waiting 10.010 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=5b0d][user_id=1] user_cache generation waiting has timed out after 10.010 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting has timed out after 10.011 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting k=9 user_cache not ready yet, after waiting 10.007 s
[2025-02-26 19:08:22]   [INFO]  [getuserdata][exec_code=9f69][user_id=1] user_cache generation waiting has timed out after 10.007 s
[2025-02-26 19:08:23]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.004 s
[2025-02-26 19:08:23]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.001 s
[2025-02-26 19:08:24]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.005 s
[2025-02-26 19:08:24]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.002 s
[2025-02-26 19:08:25]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=5 user_cache not ready yet, after waiting 6.005 s
[2025-02-26 19:08:25]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.002 s
[2025-02-26 19:08:26]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=6 user_cache not ready yet, after waiting 7.006 s
[2025-02-26 19:08:26]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.003 s
[2025-02-26 19:08:26]   [INFO]  [getuserdata][exec_code=7661][user_id=2] user_cache generated, executed in 9.499 s
[2025-02-26 19:08:27]   [INFO]  [getuserdata][exec_code=7525][user_id=2] user_cache generation waiting k=7 user_cache rebuilt, after waiting 8.007 s
[2025-02-26 19:08:27]   [INFO]  [getuserdata][exec_code=64b7][user_id=2] user_cache generation waiting k=5 user_cache rebuilt, after waiting 6.004 s

Dernière modification par IxeYgrek (2025-02-26 20:17:01)

plg · 2025-02-26 22:04:42

OK, y'a un truc bizarre. Je vais isoler 2 executions parallèles "6436" et "fd96". 6436 arrive la première après le user_cache reset. C'est donc celle qui va s'occuper de reconstruire le user_cache pour l'utilisateur #1 (l'admin principal). Ensuite fd96 arrive et comme 6436 s'occupe de la construction du user_cache, fd96 se met à attendre. Jusque là, c'est normal.

Code:

[19:08:12][getuserdata][exec_code=6436][user_id=1] needs user_cache to be rebuilt
[19:08:12][getuserdata][exec_code=fd96][user_id=1] needs user_cache to be rebuilt
[19:08:12][getuserdata][exec_code=fd96][user_id=1] starts to wait for another request to build user_cache
[19:08:13][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.003 s
[19:08:14][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.004 s
[19:08:15][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.004 s
[19:08:16][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.005 s
[19:08:17][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.006 s
[19:08:18][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=5 user_cache not ready yet, after waiting 6.007 s
[19:08:19][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=6 user_cache not ready yet, after waiting 7.007 s
[19:08:20][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=7 user_cache not ready yet, after waiting 8.008 s
[19:08:21][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=8 user_cache not ready yet, after waiting 9.009 s

Ensuite 6436 termine sa reconstruction du cache, au bout de 9.5s (c'est super long)

Code:

[19:08:22][getuserdata][exec_code=6436][user_id=1] user_cache generated, executed in 9.501 s

Là normalement, à k=9 pour fd96, Piwigo devrait détecter que le cache a été reconstruit mais...

Code:

[19:08:22][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting k=9 user_cache not ready yet, after waiting 10.010 s

... non. Je suppose qu'entre cette ligne et la précédente, le cache a été à nouveau reset. Sauf que je ne vois pas cette ligne dans le log :-/ Tu l'as retiré ?

Code:

[19:08:22][getuserdata][exec_code=fd96][user_id=1] user_cache generation waiting has timed out after 10.011 s

et donc fd96 par en timeout.

Plusieurs pistes :

1) revoir le test pour déterminer si fd96 doit encore attendre. Si le cache a été reset entre temps, il faut relancer une boucle

2) dans la boucle, faire davantage d'itérations, mais avec une attente plus courte. Par exemple faire 100x0.1seconde au lieu de 10x1seconde. Ca réduira le risque de se faire "couper l'herbe sous le pied" par un requête concurrente qui reset le cache. Mouais non en fait (je réfléchis en écrivant) : si la requête HTTP est là pour mettre à jour la photo et qu'elle même va provoquer le reset du cache à la fin, peu importe la vitesse d'itération...

3) pour une requête de mise à jour des infos d'une photo, on pourrait faire une exception en disant "pas besoin du user_cache"

A réfléchir...

plg · 2025-02-26 22:17:18

En fait, en théorie, quand on est dans l'admin, on ne doit pas tenter de regenerer le user_cache :

Code:

$user = build_user( $user['id'],
          ( defined('IN_ADMIN') and IN_ADMIN ) ? false : true // use cache ?
         );

Sauf que dans le cas de la gestion par lot en mode unitaire (et comme de plus en plus d'actions dans l'admin) on passe par l'API web. Et dans ce cas, on n'est IN_ADMIN. Donc on regen le user_cache. Et c'est le drame. Donc y'a ça à revoir aussi.

IxeYgrek · 2025-02-27 09:05:42

plg a écrit:
... non. Je suppose qu'entre cette ligne et la précédente, le cache a été à nouveau reset. Sauf que je ne vois pas cette ligne dans le log :-/ Tu l'as retiré ?

Bonjour,

Il y a des lignes de log au dessus de ce que j'ai posté car le fichier de log est très gros et que j'ai mis que , mais je n'ai supprimé aucune ligne dans le bloc que j'ai posté.

plg a écrit:
Ensuite 6436 termine sa reconstruction du cache, au bout de 9.5s (c'est super long)

Est-ce que le cœur du problème ne serait pas ça finalement ? Le fait que "c'est super long" ?
Aurais-tu une explication sur cette lenteur ?
C'est quelque chose que je ne m'explique pas depuis le début de mon utilisation de Piwigo : sur certaines actions ou certain chargement de page c'est parfois très long (une dizaine de seconde) et parfois pour les même actions ou les même chargement de page c'est quasiment instantané.
Est-il possible de désactiver le user-cache pour voir si le problème vient systématiquement de là ?

Mon serveur est chez OVH et possède les caractéristiques suivantes :
Intel Xeon-D 1521 - 4c/8t - 2.4 GHz/2.7 GHz
16 Go ECC 2133 MHz
500 Go SSD NVMe (qui contient la base de donnée et l'installation de Piwigo, les photos sont sur un HDD)

En regardant la consommation de ressource sur le serveur ça n'a pas l'air de saturer, surtout avec le peu de visiteurs que j'ai.

La partie Wordpress ne souffre d'ailleurs d'aucune lenteur similaire.

Là par exemple ce matin je viens de refaire un essai en mettant à jour les tags de 6 photos en même temps : traitement instantané...

J'ai vu sur votre site que vous proposiez un support payant non seulement aux utilisateurs de la solution cloud mais également en supplément, au tarif de 990€ HT par an.
Ce genre de support pourrait-il m'aider à identifier l'origine des lenteurs que je rencontre ?
Et si oui, étant-donné que j'héberge ce site en tant que particulier et sur mes fonds propres, pourriez-vous proposer un tarif par mois ou "à l'opération" avec un devis ?

Merci encore pour tes réponses.

Dernière modification par IxeYgrek (2025-02-27 09:15:53)

plg · 2025-02-27 10:27:18

IxeYgrek a écrit:
Il y a des lignes de log au dessus de ce que j'ai posté car le fichier de log est très gros et que j'ai mis que , mais je n'ai supprimé aucune ligne dans le bloc que j'ai posté.

Bon alors ça invalide mon hypothèse. Bizarre.

IxeYgrek a écrit:
plg a écrit:
Ensuite 6436 termine sa reconstruction du cache, au bout de 9.5s (c'est super long)
Est-ce que le cœur du problème ne serait pas ça finalement ? Le fait que "c'est super long" ? Aurais-tu une explication sur cette lenteur ?

Si on a fait un cache, c'est pour ne faire l'opération longue qu'un nombre de fois réduit par rapport au besoin. Si on était capable réduire le temps de création du cache de 9.5s à 0.1s, on n'aurait plus besoin du cache. L'explication sur cette lenteur est simple : tu as beaucoup d'albums/photos et, désolé d'être un peu honnête, un "tout petit CPU" :-D. Enfin, il fait le job et on utilise le même sur certains serveurs Piwigo.com, mais une galerie avec un volume comme le tien, on la mettrait sur un serveur avec un CPU plus costaud.

IxeYgrek a écrit:
C'est quelque chose que je ne m'explique pas depuis le début de mon utilisation de Piwigo : sur certaines actions ou certain chargement de page c'est parfois très long (une dizaine de seconde) et parfois pour les même actions ou les même chargement de page c'est quasiment instantané.

C'est typiquement le principe du cache : quand il faut le reconstruire, ça va prendre 10 secondes, quand il est déjà construit ça va être instantané.

IxeYgrek a écrit:
Est-il possible de désactiver le user-cache pour voir si le problème vient systématiquement de là ?

Le cache n'est pas désactivable, Piwigo en a besoin, rien que pour afficher la liste des albums. On n'a besoin de le désactiver pour voir si ça vient de là. Les logs nous disent clairement que le cache met 9.5s à se construire. On a déjà la réponse !

IxeYgrek a écrit:
Mon serveur est chez OVH et possède les caractéristiques suivantes :
Intel Xeon-D 1521 - 4c/8t - 2.4 GHz/2.7 GHz
16 Go ECC 2133 MHz
500 Go SSD NVMe (qui contient la base de donnée et l'installation de Piwigo, les photos sont sur un HDD)

Je trouve que c'est mal proportionné : CPU tout petit, beaucoup trop de RAM et un NVMe à mon avis pas utile (pas avec ce CPU qui est ton facteur limitant)

IxeYgrek a écrit:
La partie Wordpress ne souffre d'ailleurs d'aucune lenteur similaire.

Ton Wordpress gère-t-il 3 millions de photos ? (aucun Wordpress au monde n'en est capable donc je connais déjà la réponse ;-)

IxeYgrek a écrit:
Là par exemple ce matin je viens de refaire un essai en mettant à jour les tags de 6 photos en même temps : traitement instantané...

Je vais faire des tests, mais si tu n'as changé QUE les tags, alors il se pourrait que cela n'affecte pas le user_cache et donc pas de soucis.

Dans l'utilisation de la gestion par lot décrite en début de discussion, est-ce que tu changeais les albums associés à chaque photo ?

IxeYgrek a écrit:
J'ai vu sur votre site que vous proposiez un support payant non seulement aux utilisateurs de la solution cloud mais également en supplément, au tarif de 990€ HT par an.

Cela s'adresse aux entreprises ou aux institutions. Demander cela à des particuliers n'a aucun sens selon moi. Sauf si ton papa c'est Bernard A. ou Xavier N. Dans l'un de ces cas on a une offre spéciale à 50k€ ;-)

IxeYgrek a écrit:
Ce genre de support pourrait-il m'aider à identifier l'origine des lenteurs que je rencontre ?

Disons que l'optimisation introduite en 15.4.0 (et dont l'effet de bord est le problème que toi, et d'autres, rencontrez) a été faite en premier lieu pour un client d'un contrat de support pour qui on a pu faire des tests sur son environnement de production. Donc oui clairement ça aide d'avoir accès à l'environnement, de pouvoir regarder les logs en temps réel, etc.

IxeYgrek a écrit:
Et si oui, étant-donné que j'héberge ce site en tant que particulier et sur mes fonds propres, pourriez-vous proposer un tarif par mois ou "à l'opération" avec un devis ?

Je vais continuer à chercher en tentant de reproduire et je te contacterai en privé pour que tu me permettes d'accéder ton serveur.

plg · 2025-02-27 11:51:58

J'ai ajouté des logs, notamment dans la fonction invalidate_user_cache qui supprime le user_cache. C'est pour cela qu'on ne le voyait pas dans ton log. Je l'avais fait sur un environnement de test mais jamais ajouté dans le code officiel. Je vais le faire pour la prochaine version.

J'ai simulé un user_cache qui prend 5 secondes à se reconstruire. Histoire d'avoir un comportement proche d'une très grosse galerie avec un petit CPU. Je reproduis bien le bug. A chaque fois. C'est très bien car une fois qu'on aura trouvé une solution qui marche sur mon environnement, il y a des chances que cela corrige le problème pour tout le monde.

Sur la gestion par lot, je modifie la liste des tags pour 3 photos et je lance un "Save all" en bas de page.

Code:

[11:31:14][exec=hiC10MQ6Xe][getuserdata][exec_code=e7ef][user_id=1] needs user_cache to be rebuilt
[11:31:14][exec=hiC10MQ6Xe][generate_user_cache-u1][exec=111e5998] starts now
[11:31:14][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] needs user_cache to be rebuilt
[11:31:14][exec=I1T2beMBpu][generate_user_cache-u1][exec=7c818c9e] starts now
[11:31:14][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] needs user_cache to be rebuilt
[11:31:14][exec=YSzvSoUCiS][generate_user_cache-u1][exec=924a6f36] starts now
[11:31:14][exec=hiC10MQ6Xe][generate_user_cache-u1][exec=111e5998] wins the race and gets the token!
[11:31:14][exec=YSzvSoUCiS][generate_user_cache-u1][exec=924a6f36] skip
[11:31:14][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] starts to wait for another request to build user_cache
[11:31:14][exec=I1T2beMBpu][generate_user_cache-u1][exec=7c818c9e] skip
[11:31:14][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] starts to wait for another request to build user_cache
[11:31:15][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.001 s
[11:31:15][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=0 user_cache not ready yet, after waiting 1.001 s
[11:31:16][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.002 s
[11:31:16][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=1 user_cache not ready yet, after waiting 2.003 s
[11:31:17][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.003 s
[11:31:17][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=2 user_cache not ready yet, after waiting 3.005 s
[11:31:18][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.005 s
[11:31:18][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=3 user_cache not ready yet, after waiting 4.007 s
[11:31:19][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.006 s
[11:31:19][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=4 user_cache not ready yet, after waiting 5.008 s
[11:31:20][exec=hiC10MQ6Xe][getuserdata][exec_code=e7ef][user_id=1] user_cache generated, executed in 5.188 s
[11:31:20][exec=hiC10MQ6Xe]invalidate_user_cache starts
[11:31:20][exec=hiC10MQ6Xe]invalidate_user_cache ends
[11:31:20][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=5 user_cache not ready yet, after waiting 6.011 s
[11:31:20][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=5 user_cache not ready yet, after waiting 6.011 s
[11:31:21][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=6 user_cache not ready yet, after waiting 7.012 s
[11:31:21][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=6 user_cache not ready yet, after waiting 7.012 s
[11:31:22][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=7 user_cache not ready yet, after waiting 8.014 s
[11:31:22][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=7 user_cache not ready yet, after waiting 8.014 s
[11:31:23][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=8 user_cache not ready yet, after waiting 9.015 s
[11:31:23][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=8 user_cache not ready yet, after waiting 9.015 s
[11:31:24][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting k=9 user_cache not ready yet, after waiting 10.016 s
[11:31:24][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting k=9 user_cache not ready yet, after waiting 10.016 s
[11:31:24][exec=I1T2beMBpu][getuserdata][exec_code=0f0d][user_id=1] user_cache generation waiting has timed out after 10.017 s
[11:31:24][exec=YSzvSoUCiS][getuserdata][exec_code=5168][user_id=1] user_cache generation waiting has timed out after 10.023 s

On voit qu'on a donc 3 requêtes HTTP hiC10MQ6Xe, I1T2beMBpu et YSzvSoUCiS (ce sont des code aléatoires qui permettent de répondre à "quelle requête HTTP provoque cette ligne de log ?"). La première hiC10MQ6Xe réussit mais les 2 autres finissent en timeout au bout de 10 secondes (soit 10 fois 1 seconde, c'est le temps d'attente maximal du nouveau système introduit en 15.4.0).

On voit bien qu'à la fin de son traitement, hiC10MQ6Xe reset le cache. Pendant ce temps là, les 2 autres continuent de questionner toutes les secondes si le cache est généré. Sauf que hiC10MQ6Xe, dès qu'il a reconstruit le cache, ajoute les tags à la photo et hop supprime le cache dans la foulée. Si bien que les 2 autres n'ont pas le temps de récupérer le cache généré et n'y arriveront jamais (sauf si une autre requête indépendante provoque la reconstruction du cache, mais ce serait le hasard)

J'ai plusieurs pistes d'améliorations/corrections :

* ne pas lancer les 3 requêtes HTTP en parallèle mais plutôt en séquentiel (ce qui va, en l'état, être assez lent car pour chacune on va reconstruire le cache)

* être plus "chirurgical" sur la condition d'appel à invalidate_user_cache : si on ne modifie ni les associations photos/albums ni le privacy_level, alors pas besoin de reset le cache.

* quand la requête HTTP consiste uniquement à appeler pwg.images.setInfos, alors ne pas demander à reconstruire le cache. Cette issue [Github] Piwigo issue #1367 propose déjà ce type d'optimisation mais je me suis déjà heurté à des bugs avec Community (sur pwg.images.upload)

* pour vérifier que le cache a été reconstruit, au lieu de regarder si le cache est présent, regarder plutôt si le cache est toujours en reconstruction (via generate_user_cache-u1_running dans la table config)

A suivre

IxeYgrek · 2025-02-27 13:08:16

plg a écrit:
L'explication sur cette lenteur est simple : tu as beaucoup d'albums/photos et, désolé d'être un peu honnête, un "tout petit CPU" :-D. Enfin, il fait le job et on utilise le même sur certains serveurs Piwigo.com, mais une galerie avec un volume comme le tien, on la mettrait sur un serveur avec un CPU plus costaud.

Je suis d'accord que le processeur pourrait être plus puissant, mais je ne l'ai pas choisi, le choix du serveur dépend pour moi seulement de l'espace de stockage et malheureusement... du prix... En effet pour avoir autant de To il faut prendre la gamme storage et l'offre que j'ai actuellement coûte un peu plus de 60€ par mois. Ce n'est pas énorme, mais sur un budget personnel, ce n'est pas rien non plus.
OVH a renouvelé leur gamme Storage il y a quelques mois et propose maintenant en premier prix un "AMD EPYC 4344P - 8c/16t - 3.8GHz/5.3GHz" mais ce n'est plus 60€ mais plus de 200€/mois, donc il faut que j'y réfléchisse sérieusement...

Ceci étant dit, je ne constate pas une charge incroyable du CPU lorsqu'il reconstruit le cache.
Je viens de refaire le test en mettant des tags sur 16 photos :
j'ai un load average de 1.84 1.46 0.95 avec un %idle qui descend pas sous les 60%
et ça termine en erreur.

J'ai redémarré MySQL et Apache ce matin mais ça n'a pas résolu le problème de timeout sur la génération du cache.
Je vais peut-être envisager de reboot la machine.

plg a écrit:
C'est typiquement le principe du cache : quand il faut le reconstruire, ça va prendre 10 secondes, quand il est déjà construit ça va être instantané.

Oui je connais le principe d'un cache, en revanche il y a plusieurs choses que je ne comprend pas :
_Pourquoi est-il reconstruit aussi souvent pour visiblement les même données ?
_Qu'est-ce qui prend autant de temps (10 secondes) à être traité par le cache ? Je sais que 3 millions de photos en base de donnée, ça commence à faire beaucoup, mais quand j'exécute des requêtes directement dans MySQL c'est très rapide.
Par exemple pour la requête suivante qui va modifier 21.154 entrées, ça prend 0.40 sec :

Code:

INSERT INTO piwiwi_image_tag (image_id, tag_id)
SELECT i.id AS image_id, 672 AS tag_id
FROM piwiwi_image_category ic
JOIN (
    WITH RECURSIVE album_hierarchy AS (
        SELECT id AS category_id
        FROM piwiwi_categories
        WHERE id = 768
        UNION ALL
        SELECT c.id AS category_id
        FROM piwiwi_categories c
        JOIN album_hierarchy ah ON c.id_uppercat = ah.category_id
    )
    SELECT category_id FROM album_hierarchy
) AS ah ON ic.category_id = ah.category_id
JOIN piwiwi_images i ON ic.image_id = i.id
WHERE NOT EXISTS (
    SELECT 1
    FROM piwiwi_image_tag it
    WHERE it.image_id = i.id AND it.tag_id = 672
);

plg a écrit:
Je trouve que c'est mal proportionné : CPU tout petit, beaucoup trop de RAM et un NVMe à mon avis pas utile (pas avec ce CPU qui est ton facteur limitant)

On est d'accord, mais j'ai choisi la gamme OVH qui m'offrais le plus de stockage (et j'en utilise déjà 68%...) pour un prix "raisonnable". Si je passe sur l'offre à plus de 200€/mois j'aurais cette configuration :

AMD EPYC 4344P - 8c/16t - 3.8GHz/5.3GHz
32GB DDR5 ECC On-Die 5200MHz
2x SSD NVMe 960GB Datacenter Class Soft RAID
2× 22TB HDD SAS Soft RAID

plg a écrit:
Ton Wordpress gère-t-il 3 millions de photos ? (aucun Wordpress au monde n'en est capable donc je connais déjà la réponse ;-)

Certes, mais quand j'applique des tags à des photos, j'en ais maximum 50 affichées sur la page, pas 3 millions ! ;-)

plg a écrit:
Je vais faire des tests, mais si tu n'as changé QUE les tags, alors il se pourrait que cela n'affecte pas le user_cache et donc pas de soucis.
Dans l'utilisation de la gestion par lot décrite en début de discussion, est-ce que tu changeais les albums associés à chaque photo ?

Dans tous les tests que j'ai fait pour ce post, je n'ai fait QUE ajouter (ou supprimer mais principalement ajouter) des tags. Rien d'autre.

IxeYgrek a écrit:
Cela s'adresse aux entreprises ou aux institutions. Demander cela à des particuliers n'a aucun sens selon moi. Sauf si ton papa c'est Bernard A. ou Xavier N. Dans l'un de ces cas on a une offre spéciale à 50k€ ;-)

Je ne sais pas si ça me plairait d'avoir ce genre de papa, mais si c'était le cas, crois-moi que j'aurais un serveur beaucoup plus puissant xD
Mais non, j'ai un salaire d'administrateur système chez La Poste Groupe (donc pas super bien payé ^^) et mon papa n'est pas milliardaire :p

plg a écrit:
Je vais continuer à chercher en tentant de reproduire et je te contacterai en privé pour que tu me permettes d'accéder ton serveur.

Si ça viens effectivement du processeur pas assez puissant, tu ne pourras rien y faire. Avant que j'envisage de passer à un serveur à plus de 200€/mois j'aimerais beaucoup trouver au moins la moitié du financement avec des sponsors ou ce genre de choses, mais vu la fréquentation actuelle de mon site (en moyenne 300 visites par mois) ça n'arrivera pas dans un avenir proche à mon avis ^^

Dernière modification par IxeYgrek (2025-02-27 15:12:34)

IxeYgrek · 2025-02-27 13:21:42

plg a écrit:
J'ai simulé un user_cache qui prend 5 secondes à se reconstruire. Histoire d'avoir un comportement proche d'une très grosse galerie avec un petit CPU. Je reproduis bien le bug. A chaque fois. C'est très bien car une fois qu'on aura trouvé une solution qui marche sur mon environnement, il y a des chances que cela corrige le problème pour tout le monde.

Désolé je n'avais pas vu cette réponse avant de poster la mienne, j'ai mis longtemps à écrire le message.

Ce serait génial si les optimisations / corrections que tu proposes permettent de corriger le problème avant que je ne soit obligé de changer de serveur, car je ne sais pas quand est-ce que ça arrivera.

Là je viens de faire une modification par lot mais en mode global comparable à la requête SQL que j'ai postée dans mon message précédent mais avec un autre album et sous-albums (17.000 photos) et 2 tags au lieu d'un seul, alors certes ça prend du temps (15,90 secondes au lieu de 0,40 secondes avec ma requête) mais j'imagine qu'elle est construite différemment avec probablement l'ID de chaque photo mais bon, ça c'est pas la question, mais c'est que ça se termine sans erreur.

Il est donc dommage de voir que modifier 2 tags sur 17.000 photos se passe sans erreur alors que modifier 1 tag sur 16 photos se termine en erreur.

Merci encore pour tout le temps que tu prends ! Si je peux aider en quoi que ce soit pour l'amélioration de Piwigo n'hésite pas à demander !

Dernière modification par IxeYgrek (2025-02-27 13:24:10)

plg · 2025-02-27 20:20:04

Premier angle de solution : on évite de reconstruire le cache quand on appelle pwg.images.setInfo

Dans include/user.inc.php, remplacer :

Code:

$user = build_user( $user['id'],
         ( defined('IN_ADMIN') and IN_ADMIN ) ? false : true // use cache ?
         );

par

Code:

$use_cache = true;
if (defined('IN_ADMIN') and IN_ADMIN)
{
  $use_cache = false;
}
elseif (
  isset($_REQUEST['method'])
  and 'pwg.images.setInfo' == $_REQUEST['method']
  and isset($_SERVER['HTTP_REFERER'])
  and preg_match('/\/admin\.php\?page=/', $_SERVER['HTTP_REFERER'])
)
{
  $use_cache = false;
}

$user = build_user( $user['id'], $use_cache);

$page['user_use_cache'] = $use_cache;

Si tu utilises Community, dans le fichier plugins/community/main.inc.php, vers la ligne 47 remplace :

Code:

if (!defined('IN_ADMIN') or !IN_ADMIN)

par

Code:

global $page;

if ($page['user_use_cache'])

Ce changement (dans user.inc.php) est super spécifique à pwg.images.setInfo (et même juste quand l'appel se fait depuis une page admin). Je pense qu'il faudrait trouver un compromis plus large. Je constate qu'en pratique il y a très peu de méthodes d'API qui exploitent le user_cache (celles qui tapent dans la USER_CACHE_CATEGORIES_TABLE évidemment, et aussi celles qui appellent la fonction get_sql_condition_FandF). On ferait peut-être mieux de mettre $use_cache à false si on appelle l'API, sauf pour pwg.categories.getList ou pwg.categories.getImages ou pwg.images.getInfo ou pwg.images.search... liste non exhaustive). Ou alors on fait le contraire : on fait le use_cache par défaut, sauf pour une liste de methodes (mais qui sera plus longue, c'est certain).

En tout cas, cette modif va régler le problème de lenteur dans la gestion par lot en mode unitaire, mais ce n'est pas satisfaisant pour autant. Le problème du cache qui se fait reset pendant qu'une requête attend qu'il se fasse reconstruire, il faut le régler quand même sans faire semblant qu'il n'existe pas.

IxeYgrek · 2025-02-27 21:26:47

plg a écrit:

Premier angle de solution : on évite de reconstruire le cache quand on appelle pwg.images.setInfo

Dans include/user.inc.php, remplacer :

Code:

$user = build_user( $user['id'],
         ( defined('IN_ADMIN') and IN_ADMIN ) ? false : true // use cache ?
         );

par

Code:

$use_cache = true;
if (defined('IN_ADMIN') and IN_ADMIN)
{
  $use_cache = false;
}
elseif (
  isset($_REQUEST['method'])
  and 'pwg.images.setInfo' == $_REQUEST['method']
  and isset($_SERVER['HTTP_REFERER'])
  and preg_match('/\/admin\.php\?page=/', $_SERVER['HTTP_REFERER'])
)
{
  $use_cache = false;
}

$user = build_user( $user['id'], $use_cache);

$page['user_use_cache'] = $use_cache;

Je viens d'essayer le même test que j'ai fait tout à l'heure :
Ajout d'un tag sur 16 photos : aucune erreur, sauvegarde instantané quand je clique sur le bouton !

Merci beaucoup.
Je viens de faire un petit don à Piwigo. C'est vraiment le moins que je puisse faire.

Ps : Sur la page "https://fr.piwigo.org/contribuer" dans la partie "Rapport de sécurité" il y a écrit "Si tu as identifié une potentielle faille de sécurité potentielle".
Un seul "potentielle" devrait suffire :p

IxeYgrek · 2025-03-01 14:58:59

Bonjour,

Je confirme que le problème est résolu.
Après une utilisation normale et l'ajout de tags sur de nombreuses photos (jusqu'à 40 d'un coup) l'enregistrement est instantané et se déroule sans aucune erreur.

Encore merci.

plg · 2025-03-01 20:00:01

J'ai poussé ce changement sur Piwigo.com (donc des milliers d'installations de Piwigo). Je surveille et si pas de soucis relevé, ça pourra faire parti de la 15.5.0 officielle.

Un seul "potentielle" devrait suffire :p

Corrigé ;-) Merci pour le don !

Piwigo.org

Annonce

#1 2025-02-26 16:27:54

[Résolu] Bug avec le cache utilisateur

#2 2025-02-26 17:55:37

Re: [Résolu] Bug avec le cache utilisateur

#3 2025-02-26 17:55:58

Re: [Résolu] Bug avec le cache utilisateur

#4 2025-02-26 20:14:49

Re: [Résolu] Bug avec le cache utilisateur

plg a écrit:

Code:

#5 2025-02-26 22:04:42

Re: [Résolu] Bug avec le cache utilisateur

Code:

Code:

Code:

Code:

#6 2025-02-26 22:17:18

Re: [Résolu] Bug avec le cache utilisateur

Code:

#7 2025-02-27 09:05:42

Re: [Résolu] Bug avec le cache utilisateur

plg a écrit:

plg a écrit:

#8 2025-02-27 10:27:18

Re: [Résolu] Bug avec le cache utilisateur

IxeYgrek a écrit:

IxeYgrek a écrit:

plg a écrit:

IxeYgrek a écrit:

IxeYgrek a écrit:

IxeYgrek a écrit:

IxeYgrek a écrit:

IxeYgrek a écrit:

IxeYgrek a écrit:

IxeYgrek a écrit:

IxeYgrek a écrit:

#9 2025-02-27 11:51:58

Re: [Résolu] Bug avec le cache utilisateur

Code:

#10 2025-02-27 13:08:16

Re: [Résolu] Bug avec le cache utilisateur

plg a écrit:

plg a écrit:

Code:

plg a écrit:

plg a écrit:

plg a écrit:

IxeYgrek a écrit:

plg a écrit:

#11 2025-02-27 13:21:42

Re: [Résolu] Bug avec le cache utilisateur

plg a écrit:

#12 2025-02-27 20:20:04

Re: [Résolu] Bug avec le cache utilisateur

Code:

Code:

Code:

Code:

#13 2025-02-27 21:26:47

Re: [Résolu] Bug avec le cache utilisateur

plg a écrit:

Code:

Code:

#14 2025-03-01 14:58:59

Re: [Résolu] Bug avec le cache utilisateur

#15 2025-03-01 20:00:01

Re: [Résolu] Bug avec le cache utilisateur

Pied de page des forums