podlove / podlove-publisher

Podlove Podcast Publisher for WordPress
https://wordpress.org/plugins/podlove-podcasting-plugin-for-wordpress/
MIT License
299 stars 84 forks source link

MySQL slow queries crashing server #1154

Open stormgrass opened 4 years ago

stormgrass commented 4 years ago

MySQL slow queries make our MySQL server crash (plus workaround for one slow query)

Expected behavior

A stable MySQL server, even during high loads

Actual behavior

We've been dealing with our MySQL server crashing during high loads for a while now and have finally identified the problem (probably). After setting up a log for slow queries, we identified two types of queries that put quite the load on our server.

The first type looked like this:

SELECT
                          COUNT(*)
                        FROM wp_podlove_downloadintentclean di
                        INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
                        INNER JOIN wp_podlove_episode e ON mf.episode_id = e.id
                        WHERE e.id = 1049 AND hours_since_release <= 6552;
# Time: 2020-08-26T09:56:02.165903Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 163345
# Query_time: 1.126792  Lock_time: 0.000103 Rows_sent: 1  Rows_examined: 20745

We examined the relevant table structure, and saw that there's no index for "hours_since_release":

General Information:

+--------------------+------------------------------------------------------+------------+
| Database           | Table                                                | Size in MB |
+--------------------+------------------------------------------------------+------------+
| zeitsprung         | wp_podlove_modules_logging_logtable                  |    6966.98 |
| zeitsprung         | wp_podlove_downloadintent                            |    2591.56 |
| zeitsprung         | wp_podlove_downloadintentclean                       |    1489.13 |

mysql> explain SELECT
                          COUNT(*)
                        FROM wp_podlove_downloadintentclean di
                        INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
                        INNER JOIN wp_podlove_episode e ON mf.episode_id = e.id
                        WHERE e.id = 1049 AND hours_since_release <= 6552;

+----+-------------+-------+------------+-------+--------------------+---------------+---------+------------------+------+----------+-------------+
| id | select_type | table | partitions | type  | possible_keys      | key           | key_len | ref              | rows | filtered | Extra       |
+----+-------------+-------+------------+-------+--------------------+---------------+---------+------------------+------+----------+-------------+
|  1 | SIMPLE      | e     | NULL       | const | PRIMARY            | PRIMARY       | 4       | const            |    1 |   100.00 | Using index |
|  1 | SIMPLE      | mf    | NULL       | ref   | PRIMARY,episode_id | episode_id    | 5       | const            |    3 |   100.00 | Using index |
|  1 | SIMPLE      | di    | NULL       | ref   | media_file_id      | media_file_id | 5       | zeitsprung.mf.id | 7447 |    33.33 | Using where |
+----+-------------+-------+------------+-------+--------------------+---------------+---------+------------------+------+----------+-------------+
3 rows in set, 1 warning (0,00 sec)

We then created this compound index on media_file_id and hours_since_release:

mysql> create index idx_hrs_release on wp_podlove_downloadintentclean(media_file_id, hours_since_release); Query OK, 0 rows affected (35,46 sec) Records: 0 Duplicates: 0 Warnings: 0

Updated query plan:

mysql> SELECT
                          COUNT(*)
                        FROM wp_podlove_downloadintentclean di
                        INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
                        INNER JOIN wp_podlove_episode e ON mf.episode_id = e.id
                        WHERE e.id = 1049 AND hours_since_release <= 6552;
+----+-------------+-------+------------+-------+-------------------------------+-----------------+---------+------------------+------+----------+--------------------------+
| id | select_type | table | partitions | type  | possible_keys                 | key             | key_len | ref              | rows | filtered | Extra                    |
+----+-------------+-------+------------+-------+-------------------------------+-----------------+---------+------------------+------+----------+--------------------------+
|  1 | SIMPLE      | e     | NULL       | const | PRIMARY                       | PRIMARY         | 4       | const            |    1 |   100.00 | Using index              |
|  1 | SIMPLE      | mf    | NULL       | ref   | PRIMARY,episode_id            | episode_id      | 5       | const            |    3 |   100.00 | Using index              |
|  1 | SIMPLE      | di    | NULL       | ref   | media_file_id,idx_hrs_release | idx_hrs_release | 5       | zeitsprung.mf.id | 7625 |    33.33 | Using where; Using index |
+----+-------------+-------+------------+-------+-------------------------------+-----------------+---------+------------------+------+----------+--------------------------+
3 rows in set, 1 warning (0,00 sec)

Outcome:

Performance after index is dramatically faster, at 0.01 seconds:

mysql> SELECT
                          COUNT(*)
                        FROM wp_podlove_downloadintentclean di
                        INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
                        INNER JOIN wp_podlove_episode e ON mf.episode_id = e.id
                        WHERE e.id = 1049 AND hours_since_release <= 6552;
+----------+
| COUNT(*) |
+----------+
|    16345 |
+----------+
1 row in set (0,01 sec)

So this sorted the first type of slow query. But there's other queries too, which tend to take ages and bog down our server when the load is high. Here's an example:

# Time: 2020-09-23T11:36:16.333852Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1381563
# Query_time: 17.376645  Lock_time: 0.000209 Rows_sent: 3  Rows_examined: 781925
5
use zeitsprung;
SET timestamp=1600860976;
SELECT
                        count(id) downloads,
                        source
                FROM
                        wp_podlove_downloadintentclean
                WHERE source IN ('feed', 'webplayer', 'download'
, 'opengraph') AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "202
0-09-23 21:59:59")
                GROUP BY
                        source
                ORDER BY
                        downloads DESC;
# Time: 2020-09-23T11:36:16.413667Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1381562
# Query_time: 17.357190  Lock_time: 0.000396 Rows_sent: 3  Rows_examined: 939516
7
SET timestamp=1600860976;
SELECT
                    count(di.id) downloads, t.name
                FROM
                    wp_podlove_downloadintentclean di
                    JOIN `wp_podlove_mediafile` f ON f.id = 
di.`media_file_id`
                    JOIN `wp_podlove_episodeasset` a ON a.id
 = f.`episode_asset_id`
                    JOIN `wp_podlove_filetype` t ON t.id = a
.`file_type_id`
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:0
0:00" AND accessed_at <= "2020-09-23 21:59:59")
                GROUP BY
                    t.id
                ORDER BY
                    downloads DESC;
# Time: 2020-09-23T11:36:16.833787Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1381558
# Query_time: 18.815680  Lock_time: 0.000276 Rows_sent: 7793  Rows_examined: 833
2806
SET timestamp=1600860976;
SELECT
                COUNT(*) downloads,
                UNIX_TIMESTAMP(accessed_at) AS access_date,
                DATE_FORMAT(accessed_at, '%Y-%m-%d') AS date_day,
                mf.episode_id
            FROM
                wp_podlove_downloadintentclean  di
                INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
            WHERE accessed_at >= STR_TO_DATE('2020-08-26','%Y-%m-%d')
            GROUP BY date_day, episode_id;
# Time: 2020-09-23T11:36:17.585052Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1381561
# Query_time: 18.622695  Lock_time: 0.000181 Rows_sent: 85  Rows_examined: 8344721
SET timestamp=1600860977;
SELECT
                        count(di.id) downloads,
                        ua.client_name
                FROM
                        wp_podlove_downloadintentclean di
                        JOIN `wp_podlove_useragent` ua ON ua.id = di.`user_agent_id`
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "2020
-09-23 21:59:59")
                GROUP BY
                        ua.client_name
                ORDER BY
                        downloads DESC;
# Time: 2020-09-23T11:36:17.769468Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1381564
# Query_time: 18.097006  Lock_time: 0.000269 Rows_sent: 18  Rows_examined: 8344587
SET timestamp=1600860977;
SELECT
                        count(di.id) downloads,
                        ua.os_name
                FROM
                        wp_podlove_downloadintentclean di
                        JOIN `wp_podlove_useragent` ua ON ua.id = di.`user_agent_id`
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "2020
-09-23 21:59:59")
                GROUP BY
                        ua.`os_name`
                ORDER BY
                        downloads DESC;
# Time: 2020-09-23T11:36:22.056093Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1381565
# Query_time: 22.102900  Lock_time: 0.000395 Rows_sent: 10  Rows_examined: 9395436
SET timestamp=1600860982;
SELECT
                        count(di.id) downloads,
                        e.post_id,
                        p.post_title
                FROM
                        wp_podlove_downloadintentclean di
                        INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
                        INNER JOIN wp_podlove_episode e ON e.id = mf.`episode_id`
                        INNER JOIN wp_posts p ON p.`ID` = e.post_id
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "2020
-09-23 21:59:59")
                GROUP BY p.id
                ORDER BY downloads DESC
                LIMIT 10;
# Time: 2020-09-23T13:06:32.120757Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1394195
# Query_time: 6.703136  Lock_time: 0.000234 Rows_sent: 3  Rows_examined: 526812
SET timestamp=1600866392;
SELECT
                        count(id) downloads,
                        source
                FROM
                        wp_podlove_downloadintentclean
                WHERE source IN ('feed', 'webplayer', 'download', 'opengraph') AND (accessed_a
t >= "2020-08-23 22:00:00" AND accessed_at <= "2020-09-23 21:59:59")
                GROUP BY
                        source
                ORDER BY
                        downloads DESC;
# Time: 2020-09-23T13:06:32.966315Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1394196
# Query_time: 7.227721  Lock_time: 0.000228 Rows_sent: 18  Rows_examined: 1053648
SET timestamp=1600866392;
SELECT
                        count(di.id) downloads,
                        ua.os_name
                FROM
                        wp_podlove_downloadintentclean di
                        JOIN `wp_podlove_useragent` ua ON ua.id = di.`user_agent_id`
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "2020
-09-23 21:59:59")
                GROUP BY
                        ua.`os_name`
                ORDER BY
                        downloads DESC;
# Time: 2020-09-23T13:06:33.621029Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1394191
# Query_time: 8.367707  Lock_time: 0.000236 Rows_sent: 3  Rows_examined: 3687741
SET timestamp=1600866393;
SELECT
                    count(di.id) downloads, t.name
                FROM
                    wp_podlove_downloadintentclean di
                    JOIN `wp_podlove_mediafile` f ON f.id = di.`media_file_id`
                    JOIN `wp_podlove_episodeasset` a ON a.id = f.`episode_asset_id`
                    JOIN `wp_podlove_filetype` t ON t.id = a.`file_type_id`
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "2020
-09-23 21:59:59")
                GROUP BY
                    t.id
                ORDER BY
                    downloads DESC;
# Time: 2020-09-23T13:06:34.111299Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1394192
# Query_time: 8.584753  Lock_time: 0.000217 Rows_sent: 85  Rows_examined: 1053782
SET timestamp=1600866394;
SELECT
                        count(di.id) downloads,
                        ua.client_name
                FROM
                        wp_podlove_downloadintentclean di
                        JOIN `wp_podlove_useragent` ua ON ua.id = di.`user_agent_id`
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "2020
-09-23 21:59:59")
                GROUP BY
                        ua.client_name
                ORDER BY
                        downloads DESC;
# Time: 2020-09-23T13:06:37.522986Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1394188
# Query_time: 12.577712  Lock_time: 0.000222 Rows_sent: 7793  Rows_examined: 8335814
SET timestamp=1600866397;
SELECT
                COUNT(*) downloads,
                UNIX_TIMESTAMP(accessed_at) AS access_date,
                DATE_FORMAT(accessed_at, '%Y-%m-%d') AS date_day,
                mf.episode_id
            FROM
                wp_podlove_downloadintentclean  di
                INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
            WHERE accessed_at >= STR_TO_DATE('2020-08-26','%Y-%m-%d')
            GROUP BY date_day, episode_id;
# Time: 2020-09-23T13:06:39.365073Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1394194
# Query_time: 13.688872  Lock_time: 0.000248 Rows_sent: 10  Rows_examined: 2107505
SET timestamp=1600866399;
SELECT
                        count(di.id) downloads,
                        e.post_id,
                        p.post_title
                FROM
                        wp_podlove_downloadintentclean di
                        INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
                        INNER JOIN wp_podlove_episode e ON e.id = mf.`episode_id`
                        INNER JOIN wp_posts p ON p.`ID` = e.post_id
                WHERE 1 = 1 AND (accessed_at >= "2020-08-23 22:00:00" AND accessed_at <= "2020
-09-23 21:59:59")
                GROUP BY p.id
                ORDER BY downloads DESC
                LIMIT 10;
# Time: 2020-09-23T13:29:51.147261Z
# User@Host: zeitsprung[zeitsprung] @ localhost []  Id: 1397186
# Query_time: 13.055025  Lock_time: 0.000304 Rows_sent: 7793  Rows_examined: 8338678
SET timestamp=1600867791;
SELECT
                COUNT(*) downloads,
                UNIX_TIMESTAMP(accessed_at) AS access_date,
                DATE_FORMAT(accessed_at, '%Y-%m-%d') AS date_day,
                mf.episode_id
            FROM
                wp_podlove_downloadintentclean  di
                INNER JOIN wp_podlove_mediafile mf ON mf.id = di.media_file_id
            WHERE accessed_at >= STR_TO_DATE('2020-08-26','%Y-%m-%d')
            GROUP BY date_day, episode_id;

Any ideas how to speed up those queries would be vastly appreciated!

System information (see Podlove > Support menu)

Website https://www.zeitsprung.fm PHP Version 7.3.17-1+ubuntu16.04.1+deb.sury.org+1 WordPress Version 5.5.1 WordPress Theme Twenty Twenty v1.3 Active Plugins

0 errors 0 notices Nice, Everything looks fine!

eteubert commented 4 years ago

Good catch on the compound key! I'll see if I add this by default or at least add it to the docs somehwere.

Unrelated: Your wp_podlove_modules_logging_logtable table is huge and can safely be truncated. You may even consider deactivating the "Logging" module, which is responsible for logging to the database. That may help with your database load a little as it decreases the amount of writes.

As far as I can see all the remaining slow queries are from the analytics index screen (admin.php?page=podlove_analytics), specifically the "global analytics for last 30 days" section. Those may be tricky to optimize as you would need a dedicated compound key per query (accessed_at + source for example) but you also don't want too many indices. The more indices you define on wp_podlove_downloadintentclean, the more expensive writes become.

At the moment I don't see an easy/obvious performance fix. If that's an option for you, I could add a switch to disable that whole "global analytics for last 30 days" section, so those slow queries would never run.

stormgrass commented 4 years ago

Thank you for your reply! I suspected that solving the slow-query issue would be a bit tricky. But, I've now turned off the logging module, let's see if that makes a dent.

As for the 30 day section: would turning that off have any impact on tracking in general? If we can still keep tracking as usual, I'd be very happy to turn off that section in return for a more stable server.

eteubert commented 4 years ago

would turning that off have any impact on tracking in general?

No, none at all. I can add a feature switch in the next release.

stormgrass commented 4 years ago

That would be fantastic, thank you!