#1 2024-11-22 14:11:23

deemon
Member
2021-05-03
55

Some questionable slow queries.

Hello/Hi/Greetings,

To troubleshoot my piwigo server woes, I enabled mysql slow queries logging... and ... got some interesting results.
What exactly is happening there and why would it take almost 2 minutes for a query? Is it supposed to be this way? What action or functionality does this and is this essential? Can I turn it off?
And/or is there something I could/should do to mitigate this problem from sql conf side?

# User@Host: piwigo[piwigo] @ localhost []
# Thread_id: 142197  Schema: piwigo  QC_hit: No
# Query_time: 109.856853  Lock_time: 0.003827  Rows_sent: 8272  Rows_examined: 646073
# Rows_affected: 0
# Full_scan: Yes  Full_join: No  Tmp_table: Yes  Tmp_table_on_disk: No
# Filesort: Yes  Filesort_on_disk: No  Merge_passes: 0  Priority_queue: No
SET timestamp=1732272728;
SELECT c.id AS cat_id, id_uppercat, global_rank,
  MAX(date_available) AS date_last, COUNT(date_available) AS nb_images
FROM categories as c
  LEFT JOIN image_category AS ic ON ic.category_id = c.id
  LEFT JOIN images AS i
    ON ic.image_id = i.id
      AND i.level<=0
  WHERE c.id NOT IN (53143,53186,53308,53983,54195,54236,54237,54238,54239,54240,54241,54242,54243,54244,54245,54246,54247,54248,54249,54250,54251,54252,54253,54254,54255,54256,54257,54258,54259,54260,54261,542
62,54263,54264,54265,54266,54267,54268,54269,54270,54271,54272,54273,54274,54275,54276,54277,54278,54279,54280,54281,54282,54283,54284,54285,54286,54287,54288,54289,54290,54291,54292,54820,55482,56054,56210,562
44,57826,57911,60744,60802,61064,61278,61392,61465,61690,61752)
  GROUP BY c.id;
# User@Host: piwigo[piwigo] @ localhost []
# Thread_id: 142192  Schema: piwigo  QC_hit: No
# Query_time: 113.119565  Lock_time: 0.000316  Rows_sent: 8272  Rows_examined: 646073
# Rows_affected: 0
# Full_scan: Yes  Full_join: No  Tmp_table: Yes  Tmp_table_on_disk: No
# Filesort: Yes  Filesort_on_disk: No  Merge_passes: 0  Priority_queue: No
SET timestamp=1732272728;
SELECT c.id AS cat_id, id_uppercat, global_rank,
  MAX(date_available) AS date_last, COUNT(date_available) AS nb_images
FROM categories as c
  LEFT JOIN image_category AS ic ON ic.category_id = c.id
  LEFT JOIN images AS i
    ON ic.image_id = i.id
      AND i.level<=0
  WHERE c.id NOT IN (53143,53186,53308,53983,54195,54236,54237,54238,54239,54240,54241,54242,54243,54244,54245,54246,54247,54248,54249,54250,54251,54252,54253,54254,54255,54256,54257,54258,54259,54260,54261,54262,54263,54264,54265,54266,54267,54268,54269,54270,54271,54272,54273,54274,54275,54276,54277,54278,54279,54280,54281,54282,54283,54284,54285,54286,54287,54288,54289,54290,54291,54292,54820,55482,56054,56210,56244,57826,57911,60744,60802,61064,61278,61392,61465,61690,61752)
  GROUP BY c.id;



Somewhat later, the same queries ran only like 25-30seconds. Somewhat cached or server was less busy? But still wayy too long for a webpage query IMHO.

Last edited by deemon (2024-11-22 14:17:34)

Offline

 

#2 2024-12-05 14:19:36

deemon
Member
2021-05-03
55

Re: Some questionable slow queries.

Any help locating where this query is coming from? (as in USER INTERFACE on webpage; in code it's in include/functions_category.inc.php line ~468- function get_computed_categories)
Because I see in the log again this same very query launched in the same second 12 times. Which is also absurd. Either the code is spamming the query too many times for some reason, or it's some kind of bot spamming the webpage / trying to DoS?


just tried to run the same query mysql from within mariadb in the server, while watching htop, which resulted 6 CPU's @ 100% from mysql threads for 1.5 minutes. Why does piwigo need to make this kind of killer queries at all?


MariaDB [piwigo]> SELECT c.id AS cat_id, id_uppercat, global_rank,
    ->   MAX(date_available) AS date_last, COUNT(date_available) AS nb_images
    -> FROM categories as c
    ->   LEFT JOIN image_category AS ic ON ic.category_id = c.id
    ->   LEFT JOIN images AS i
    ->     ON ic.image_id = i.id
    ->       AND i.level<=0
    ->   WHERE c.id NOT IN (53143,53186,53308,53983,54195,54236,54237,54238,54239,54240,54241,54242,54243,54244,54245,54246,54247,54248,54249,54250,54251,54252,54253,54254,54255,54256,54257,54258,54259,54260,54261,54262,54263,54264,54265,54266,54267,54268,54269,54270,54271,54272,54273,54274,54275,54276,54277,54278,54279,54280,54281,54282,54283,54284,54285,54286,54287,54288,54289,54290,54291,54292,54820,55482,56054,56210,56244,57826,57911,60744,60802,61064,61278,61392,61465,61690,61752)
    ->   GROUP BY c.id;
+--------+-------------+--------------+---------------------+-----------+
| cat_id | id_uppercat | global_rank  | date_last           | nb_images |
+--------+-------------+--------------+---------------------+-----------+
|     26 |        NULL | 5530         | NULL                |         0 |
|     27 |        NULL | 5531         | NULL                |         0 |

<snip>

|  63038 |        NULL | 2            | 2024-12-05 12:09:59 |        51 |
|  63039 |       63013 | 1.2          | 2024-12-05 13:59:16 |        23 |
|  63040 |       63013 | 1.1          | NULL                |         0 |
+--------+-------------+--------------+---------------------+-----------+
8303 rows in set (1 min 25.14 sec)

any explanation please? is there some way to turn off this functionality as admin?

Last edited by deemon (2024-12-05 16:40:53)

Offline

 

#3 2024-12-07 18:22:17

plg
Piwigo Team
Nantes, France, Europe
2002-04-05
13877

Re: Some questionable slow queries.

deemon wrote:

What exactly is happening there and why would it take almost 2 minutes for a query? Is it supposed to be this way?

120 seconds for an SQL query is far beyond the "acceptable". Can you remind us your number of photos and albums? I guess 8303 albums, but please confirm.

deemon wrote:

What action or functionality does this and is this essential?

This is the construction of the cache for the current user saying which albums are available, how many sub-albums each album has, how many photos are in each albums... It all depends on permissions, so the values are specific to each user.

It is a cache and lines are inserted in the piwigo_user_cache_categories table.

This cache is reset when you an upload is finished. Other admin actions as well.

deemon wrote:

Can I turn it off?

You can't.

Offline

 

#4 2024-12-11 12:47:04

deemon
Member
2021-05-03
55

Re: Some questionable slow queries.

plg wrote:

deemon wrote:

What exactly is happening there and why would it take almost 2 minutes for a query? Is it supposed to be this way?

120 seconds for an SQL query is far beyond the "acceptable". Can you remind us your number of photos and albums? I guess 8303 albums, but please confirm.

Something like this, yes ... 8399 today. it grows like +3..8 albums per day.

plg wrote:

This is the construction of the cache for the current user saying which albums are available, how many sub-albums each album has, how many photos are in each albums... It all depends on permissions, so the values are specific to each user.

It is a cache and lines are inserted in the piwigo_user_cache_categories table.

This cache is reset when you an upload is finished. Other admin actions as well.

Alright, but can you explain to me, why it started doing this query like 12 times in a _same second_ for the "guest" user (level>0)? I mean yes, several guests looking the site at the same time ... or some bot crawling.

But is there also possibility, that the cache gets reset every time a new picture is uploaded to album, not only once when you finished uploading all your 20 pictures into album?

Also I started to figure the situation out.... my hypothesis:
NORMALLY the query can take 2-3 seconds (when server is idle and nothing else is going on). But when the same query has been executed like 10 times at the same time or even 0.5s apart, it's cascading out of control.

Possible solution proposal #1:
Can there be implemented some kind of cache generation starting block timer for like ... 10s, when it's already happening? Like let the previous one finish or timeout and only then try again? Like one cache generation event for same user per 10 seconds. Not infinite amount like right now.

Possible solution proposal #2:
Maybe not "reset the cache" at all? Just update it accordingly when the change happens? Why generate it all the time over and over and over again?

Last edited by deemon (2024-12-11 12:55:38)

Offline

 

#5 2024-12-22 16:11:03

plg
Piwigo Team
Nantes, France, Europe
2002-04-05
13877

Re: Some questionable slow queries.

following the problem "for a given user (including guest), the user cache gets generated more than once", I may have an idea. In Piwigo 15 I introduced a new function pwg_unique_exec_begins (and its friend pwg_unique_exec_ends) see [Github] Piwigo file include/functions.inc.php@L2846

It was introduced to avoid send_piwigo_infos() runs more than once when it has be run. This is the function that sends anonymous statistics to piwigo.org (and it's great for us to better understand how Piwigo is used).

This "unique_exec" system could be used for the user cache generation as well.

Offline

 

Board footer

Powered by FluxBB

github twitter newsletter Donate Piwigo.org © 2002-2024 · Contact