Eu tenho a seguinte consulta que leva cerca de 5 segundos para ser concluída, costumava ser 0,5s, depois 1s, 2s agora estamos em 5s, apesar do fato de a quantidade de dados no banco de dados não ter mudado! Esta consulta faz um select para obter uma porção de dados para processar e atualizar algumas colunas (nenhuma nova linha é adicionada), normalmente tem um "limite 500" mas o tempo de consulta com "limite 1" e "limite 500" é o mesmo, então pela simplicidade mudei esse post para "limite 1".
Fiz uma cópia da tabela de produção no mesmo servidor para poder executar vários testes e alterações sem prejudicar os dados de produção, também alguns dados foram ofuscados mas todas as consultas e suas saídas são reais
A tabela “teste” possui 34 milhões de linhas e tamanho de 11,3 GB, cujo índice é de 3,3 GB. O servidor é Freebsd 13.2, mysql 8.0.35 em um drive Samsung nvme bastante decente, 64 GB de RAM e innodb_buffer_pool_size = 42G. O servidor não está trocando e tem quase 4 GB de memória livre. Há uma grande quantidade de carga de IO de disco proveniente de consultas para outros bancos de dados hospedados no mesmo servidor (e provavelmente principalmente log binário porque este é o mestre de replicação), no entanto, se eu desabilitar todas as outras consultas e executar apenas a consulta em questão, o tempo de execução é exatamente o mesmo.
A consulta lenta:
SELECT t_channel_id,login FROM test WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
+--------------+---------------+
| t_channel_id | login |
+--------------+---------------+
| 933271419 | sunday1funday |
+--------------+---------------+
1 row in set (4.43 sec)
O índice é usado corretamente e cobre todas as colunas WHERE. Se eu remover a coluna videos_scanned_lock da consulta, o tempo será de 0,35s (ainda lento, mas muito mais rápido) se eu remover APENAS a coluna t_channel_id da consulta, o tempo será 0s
Eu tenho uma teoria de por que o tempo era muito mais rápido no início e agora está em torno de 5s. Agora estamos processando registros em torno de 30 milhões de linhas (de 34) e no início as linhas selecionadas eram do início da tabela e agora tipo “quase toda a tabela tem que ser verificada primeiro para chegar aos resultados”. Mas 34 milhões de registros são muito para o MySQL? Suponho que não, a tabela inteira tem menos de 1/4 do tamanho do buffer innodb. Como prova desta teoria, no parágrafo anterior escrevi que se eu remover a coluna t_channel_id da consulta, o tempo será 0s – isso porque se eu remover esta coluna serão mostrados resultados desde o início da tabela. A segunda prova, é que a consulta dá certo resultado, se eu alterar o valor de t_channel_id deste resultado para um número muito menor, o tempo de consulta será muito menor (porque com um ID menor ele será encontrado mais cedo). Tenho certeza de que respondi minha própria pergunta, MAS por que isso está acontecendo? Acredito que algo deve estar configurado incorretamente, mas não consigo encontrar o que é e espero encontrar uma resposta aqui. Qualquer dica para melhorar esta situação será apreciada :)
Abaixo, forneço dados de depuração: mostre criar tabela, criador de perfil, descreva análise e my.cnf
SHOW CREATE TABLE test;
CREATE TABLE `test` (
`channel_id` bigint NOT NULL AUTO_INCREMENT,
`t_channel_id` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_0900_bin DEFAULT NULL,
`login` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL,
`display_name` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin DEFAULT NULL,
`videos_scanned` datetime DEFAULT NULL,
`videos_scanned_lock` int NOT NULL DEFAULT '0',
PRIMARY KEY (`channel_id`) USING BTREE,
UNIQUE KEY `login` (`login`),
KEY `t_channel_id_2` (`t_channel_id`,`videos_scanned`,`videos_scanned_lock`)
) ENGINE=InnoDB AUTO_INCREMENT=34626837 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin
describe SELECT t_channel_id,login FROM test WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
+----+-------------+-------+------------+-------+----------------+----------------+---------+------+----------+----------+-----------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+-------+----------------+----------------+---------+------+----------+----------+-----------------------+
| 1 | SIMPLE | test | NULL | range | t_channel_id_2 | t_channel_id_2 | 1023 | NULL | 16992061 | 1.00 | Using index condition |
+----+-------------+-------+------------+-------+----------------+----------------+---------+------+----------+----------+-----------------------+
describe analyze SELECT t_channel_id,login FROM test WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit
1;
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Limit: 1 row(s) (cost=7.65e+6 rows=1) (actual time=4407..4407 rows=1 loops=1)
-> Index range scan on test using t_channel_id_2 over (NULL < t_channel_id), with index condition: ((test.videos_scanned_lock = 0) and (test.t_channel_id is not null) and (test.videos_scanned is null)) (cost=7.65e+6 rows=17e+6) (actual time=4407..4407 rows=1 loops=1)
|
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (4.41 sec)
SET profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
SELECT t_channel_id,login FROM test WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
+--------------+---------------+
| t_channel_id | login |
+--------------+---------------+
| 933271419 | sunday1funday |
+--------------+---------------+
1 row in set (4.43 sec)
show profile cpu;
+--------------------------------+----------+----------+------------+
| Status | Duration | CPU_user | CPU_system |
+--------------------------------+----------+----------+------------+
| starting | 0.000142 | 0.000372 | 0.000036 |
| Executing hook on transaction | 0.000063 | 0.000048 | 0.000004 |
| starting | 0.000027 | 0.000022 | 0.000002 |
| checking permissions | 0.000028 | 0.000025 | 0.000003 |
| checking permissions | 0.000018 | 0.000016 | 0.000001 |
| Opening tables | 0.000098 | 0.000094 | 0.000009 |
| init | 0.000025 | 0.000019 | 0.000002 |
| System lock | 0.000026 | 0.000024 | 0.000002 |
| optimizing | 0.000091 | 0.000084 | 0.000008 |
| statistics | 0.000284 | 0.000269 | 0.000026 |
| preparing | 0.000126 | 0.000119 | 0.000011 |
| executing | 4.426675 | 6.156588 | 0.156978 |
| end | 0.000016 | 0.000005 | 0.000001 |
| query end | 0.000004 | 0.000003 | 0.000000 |
| waiting for handler commit | 0.000005 | 0.000005 | 0.000001 |
| closing tables | 0.000006 | 0.000006 | 0.000000 |
| freeing items | 0.000010 | 0.000014 | 0.000002 |
| logging slow query | 0.000027 | 0.000020 | 0.000001 |
| cleaning up | 0.000008 | 0.000007 | 0.000001 |
+--------------------------------+----------+----------+------------+
19 rows in set, 1 warning (0.00 sec)
[mysqld]
user = mysql
port = 3306
socket = /tmp/mysql.sock
bind-address = 0.0.0.0
datadir = /var/db/mysql
log-output = FILE
relay-log-recovery = 1
slow-query-log = 1
server-id = 29
sync_binlog = 1
sync_relay_log = 1
binlog_cache_size = 16M
binlog_expire_logs_seconds = 43200
default_password_lifetime = 0
enforce-gtid-consistency = 1
gtid-mode = On
safe-user-create = 1
lower_case_table_names = 1
explicit-defaults-for-timestamp = 1
myisam-recover-options = BACKUP,FORCE
table_open_cache = 16384
table_definition_cache = 8192
net_retry_count = 16384
key_buffer_size = 256M
max_allowed_packet = 64M
long_query_time = 0.2
innodb_buffer_pool_size = 42G
innodb_data_home_dir = /var/db/mysql
innodb_log_group_home_dir = /var/db/mysql
innodb_data_file_path = ibdata1:128M:autoextend
innodb_temp_data_file_path = ibtmp1:128M:autoextend
innodb_flush_method = O_DSYNC
innodb_log_buffer_size = 32M
innodb_write_io_threads = 12
innodb_read_io_threads = 12
innodb_autoinc_lock_mode = 2
innodb_redo_log_capacity = 8192M
log_error = /var/db/mysql/mysql-error.log
slow_query_log_file = /var/db/mysql/mysql-slow.log
skip_name_resolve
mysqlx = 0
tls_version = TLSv1.2
innodb_flush_log_at_trx_commit = 0
replica_parallel_workers = 1
binlog_group_commit_sync_delay = 10000
Editar para Ergest:
...
KEY `channel_id` (`videos_scanned_lock`,`channel_id`,`t_channel_id`) USING BTREE
SELECT t_channel_id,login FROM test force index (channel_id) WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
+--------------+----------------+
| t_channel_id | login |
+--------------+----------------+
| 921437844 | marryme2 |
+--------------+----------------+
1 row in set (50.80 sec)
describe SELECT t_channel_id,login FROM test force index (channel_id) WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
+----+-------------+-------+------------+------+---------------+------------+---------+-------+-------+----------+------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------------+---------+-------+-------+----------+------------------------------------+
| 1 | SIMPLE | test | NULL | ref | channel_id | channel_id | 4 | const | 68378 | 9.00 | Using index condition; Using where |
+----+-------------+-------+------------+------+---------------+------------+---------+-------+-------+----------+------------------------------------+
1 row in set, 1 warning (0.00 sec)
describe format=json SELECT t_channel_id,login FROM test force index (channel_id) WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
....
{
"query_block": {
"select_id": 1,
"cost_info": {
"query_cost": "2094461.53"
},
"table": {
"table_name": "test",
"access_type": "ref",
"possible_keys": [
"t_channel_id_2",
"channel_id"
],
"key": "channel_id",
"used_key_parts": [
"videos_scanned_lock"
],
"key_length": "4",
"ref": [
"const"
],
"rows_examined_per_scan": 16992061,
"rows_produced_per_join": 1529285,
"filtered": "9.00",
"index_condition": "(`db`.`test`.`t_channel_id` is not null)",
"cost_info": {
"read_cost": "395255.43",
"eval_cost": "152928.54",
"prefix_cost": "2094461.53",
"data_read_per_join": "4G"
},
"used_columns": [
"t_channel_id",
"login",
"videos_scanned",
"videos_scanned_lock"
],
"attached_condition": "(`db`.`test`.`videos_scanned` is null)"
}
}
} |
Para @Rick James
Simplesmente não funciona
show create table test;
....
KEY `t_channel_id` (`t_channel_id`,`login`,`videos_scanned`,`videos_scanned_lock`)
SELECT t_channel_id,login FROM test force index (t_channel_id) WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_loc
k=0 limit 1;
+--------------+----------------+
| t_channel_id | login |
+--------------+----------------+
| 921437844 | blahblahcar |
+--------------+----------------+
1 row in set (9.99 sec)
describe SELECT t_channel_id,login FROM test force index (t_channel_id) WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
+----+-------------+-------+------------+-------+---------------+--------------+---------+------+----------+----------+--------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+-------+---------------+--------------+---------+------+----------+----------+--------------------------+
| 1 | SIMPLE | test | NULL | range | t_channel_id | t_channel_id | 1023 | NULL | 16992061 | 0.02 | Using where; Using index |
+----+-------------+-------+------------+-------+---------------+--------------+---------+------+----------+----------+--------------------------+
explain format=json SELECT t_channel_id,login FROM test force index (t_channel_id) WHERE t_channel_id IS NOT NULL AND videos_scanned IS NULL AND videos_scanned_lock=0 limit 1;
{
"query_block": {
"select_id": 1,
"cost_info": {
"query_cost": "4712106.82"
},
"table": {
"table_name": "test",
"access_type": "range",
"possible_keys": [
"t_channel_id"
],
"key": "t_channel_id",
"used_key_parts": [
"t_channel_id"
],
"key_length": "1023",
"rows_examined_per_scan": 16992061,
"rows_produced_per_join": 3906,
"filtered": "0.02",
"using_index": true,
"cost_info": {
"read_cost": "4711716.19",
"eval_cost": "390.62",
"prefix_cost": "4712106.82",
"data_read_per_join": "11M"
},
"used_columns": [
"t_channel_id",
"login",
"videos_scanned",
"videos_scanned_lock"
],
"attached_condition": "((`db`.`test`.`videos_scanned_lock` = 0) and (`db`.`test`.`t_channel_id` is not null) and (`db`.`test`.`videos_scanned` is null))"
}
}
PROFILE
raramente tem alguma utilidade.Este índice composto deve ajudar
A breve explicação (para sua consulta):
=
IS NOT NULL
)Explicação longa: veja meu Index Cookbook
(não é muito emocionante aqui...)
Observações:
As questões mais importantes:
Sugira alterações de configuração:
Procure
SHOW ENGINE=INNODB STATUS
o 'último impasse'.Detalhes e outras observações:
( Key_reads + Key_writes + Innodb_pages_read + Innodb_pages_written + Innodb_dblwr_writes + Innodb_buffer_pool_pages_flushed ) = (0 + 0 + 25119175 + 81458209 + 8195499 + 80652334) / 400622 = 487 /sec
-- PIOs? -- Se o hardware puder lidar com isso, defina innodb_io_capacity (agora 200) para aproximadamente este valor.( ( Key_reads + Key_writes + Innodb_pages_read + Innodb_pages_written + Innodb_dblwr_writes + Innodb_buffer_pool_pages_flushed ) / innodb_io_capacity / Uptime ) = ( 0 + 0 + 25119175 + 81458209 + 8195499 + 80652334 ) / 200 / 400622 = 243.9%
- Esta pode ser uma métrica que indica qual innodb_io_capacity está definido razoavelmente. -- Aumente innodb_io_capacity (agora 200) se o hardware puder lidar com isso.( table_open_cache ) = 16,384
-- Número de descritores de tabela para armazenar em cache -- Várias centenas geralmente é bom.( binlog_cache_size * max_connections ) = (16M * 151) / 65536M = 3.7%
-- RAM usada para armazenar transações em cache no caminho para o log binário. -- Diminuir binlog_cache_size (agora 16777216) e/ou max_connections (agora 151)( innodb_buffer_pool_size / innodb_buffer_pool_instances ) = 43008M / 8 = 5376MB
-- Tamanho de cada instância buffer_pool. -- Uma instância deve ter pelo menos 1 GB. Em RAM muito grande, tenha 16 instâncias.( innodb_lru_scan_depth * innodb_page_cleaners ) = 1,024 * 4 = 4,096
-- Quantidade de trabalho para limpadores de páginas a cada segundo. - "InnoDB: page_cleaner: loop pretendido de 1000ms levado ..." pode ser corrigido diminuindo lru_scan_profundidade: Considere 1000 / innodb_page_cleaners (agora 4). Verifique também se há troca.( innodb_lru_scan_depth ) = 1,024
-- innodb_lru_scan_profundidade é uma variável com um nome muito ruim. Um nome melhor seria innodb_free_page_target_per_buffer_pool. É um número de páginas que o InnoDB tenta manter livres em cada instância do buffer pool para acelerar as operações de leitura e criação de páginas. - "InnoDB: page_cleaner: loop pretendido de 1000ms levado ..." pode ser corrigido diminuindo lru_scan_profundidade( innodb_io_capacity ) = 200
-- Ao lavar, use esta quantidade de IOPs. - As leituras podem ser lentas ou pontiagudas. Use 2000 se estiver usando uma unidade SSD.( innodb_io_capacity_max / innodb_io_capacity ) = 2,000 / 200 = 10
-- Capacidade: max/plain -- Recomendado 2. Max deve ser aproximadamente igual aos IOPs que seu subsistema de E/S pode suportar. (Se o tipo de unidade for desconhecido, 2000/200 pode ser um par razoável.)( (Innodb_buffer_pool_reads + Innodb_buffer_pool_pages_flushed) ) = ((19069505 + 80652334) ) / 400622 = 248 /sec
- E/S do InnoDB( Innodb_buffer_pool_pages_flushed ) = 80652334 / 400622 = 201 /sec
- Grava (liberações)( Innodb_os_log_written ) = 417798258688 / 400622 = 1042873 /sec
-- Este é um indicador de quão ocupado o InnoDB está. -- InnoDB muito ocupado.( innodb_log_buffer_size / innodb_log_file_size ) = 32M / 48M = 66.7%
-- O buffer está na RAM; arquivo está no disco. -- O buffer_size deve ser menor e/ou o file_size deve ser maior.( Innodb_log_writes ) = 318280758 / 400622 = 794 /sec
( Innodb_os_log_written / (Uptime / 3600) / innodb_log_files_in_group / innodb_log_file_size ) = 417,798,258,688 / (400622 / 3600) / 2 / 48M = 37.3
-- Proporção -- (ver ata)( Uptime / 60 * innodb_log_file_size / Innodb_os_log_written ) = 400,622 / 60 * 48M / 417798258688 = 0.804
-- Minutos entre rotações de log do InnoDB A partir da versão 5.6.8, innodb_log_file_size pode ser alterado dinamicamente; Não sei sobre o MariaDB. Certifique-se de alterar também my.cnf - (A recomendação de 60 minutos entre as rotações é um tanto arbitrária.) Ajuste innodb_log_file_size (agora 50331648). (Não é possível alterar na AWS.)( innodb_flush_method ) = innodb_flush_method = O_DSYNC
-- Como o InnoDB deve solicitar ao sistema operacional para escrever blocos. Sugira O_DIRECT ou O_ALL_DIRECT (Percona) para evitar buffer duplo. (Pelo menos para Unix.) Consulte chrischandler para advertências sobre O_ALL_DIRECT( Innodb_row_lock_time_max ) = 50,981
-- Tempo máximo para bloquear uma linha (milissegundos) -- Consultas possivelmente conflitantes; possivelmente varreduras de tabela.( Innodb_row_lock_waits ) = 1993787 / 400622 = 5 /sec
-- Com que frequência ocorre um atraso na obtenção de um bloqueio de linha. -- Pode ser causado por consultas complexas que podem ser otimizadas.( Innodb_dblwr_writes ) = 8195499 / 400622 = 20 /sec
-- "Doublewrite buffer" writes to disk. "Doublewrites" are a reliability feature. Some newer versions / configurations don't need them. -- (Symptom of other issues)( ( Innodb_pages_read + Innodb_pages_written ) / Uptime / innodb_io_capacity ) = ( 25119175 + 81458209 ) / 400622 / 200 = 133.0%
-- If > 100%, need more io_capacity. -- Increase innodb_io_capacity (now 200) if the drives can handle it.( innodb_io_capacity ) = 200
-- I/O ops per second capable on disk . 100 for slow drives; 200 for spinning drives; 1000-2000 for SSDs; multiply by RAID factor. Limits write IO requests per second (IOPS). -- For starters: HDD: 200; SSD: 2000.( innodb_adaptive_hash_index ) = innodb_adaptive_hash_index = ON
-- Whether to use the adapative hash (AHI). -- ON for mostly readonly; OFF for DDL-heavy( Innodb_row_lock_current_waits ) = 590
-- The number of row locks currently being waited for by operations on InnoDB tables. Zero is pretty normal. -- Something big is going on?( innodb_flush_log_at_trx_commit ) = 0
-- 1 = secure; 2 = faster -- (You decide) Use 1, along with sync_binlog (now 1)=1 for the greatest level of fault tolerance. 0 is best for speed. 2 is a compromise between 0 and 1.( innodb_adaptive_hash_index ) = innodb_adaptive_hash_index = ON
-- Usually should be ON. -- There are cases where OFF is better. See also innodb_adaptive_hash_index_parts (now 8) (after 5.7.9) and innodb_adaptive_hash_index_partitions (MariaDB and Percona). ON has been implicated in rare crashes (bug 73890). 10.5.0 decided to default OFF.( innodb_print_all_deadlocks ) = innodb_print_all_deadlocks = OFF
-- Whether to log all Deadlocks. -- If you are plagued with Deadlocks, turn this on. Caution: If you have lots of deadlocks, this may write a lot to disk.( bulk_insert_buffer_size ) = 8M / 65536M = 0.01%
-- Buffer for multi-row INSERTs and LOAD DATA -- Too small could hinder such operations.( Com_insert + Com_delete + Com_delete_multi + Com_replace + Com_update + Com_update_multi ) = (218991721 + 3627939 + 0 + 45 + 74927620 + 0) / 400622 = 742 /sec
-- writes/sec -- 50 writes/sec + log flushes will probably max out I/O write capacity of normal drives( log_slow_slave_statements ) = log_slow_slave_statements = OFF
-- (5.6.11, 5.7.1) By default, replicated statements won't show up in the slowlog; this causes them to show. -- It can be helpful in the slowlog to see writes that could be interfering with Replica reads.( Aborted_connects / Connections ) = 20,179 / 54134 = 37.3%
-- Perhaps a hacker is trying to break in? (Attempts to connect)Abnormally small:
Abnormally large:
Abnormal strings: