Capturando seus statements SQL no RDS MySQL
Neste artigo, vou mostrar todos os recursos nativos do MySQL para capturar statements SQL quando se usa o AWS Relational Database Service (RDS). Identificar statements SQL é um princípio importante de design e operação para entender como sua aplicação é usada, qual é a carga, os impactos no desempenho e os gargalos de configuração no banco de dados.
O foco aqui é mostrar como "capturar" as informações dos statements SQL. Não vou abordar as informações complementares que também é possível obter junto com um statement SQL, como o Query Execution Plan (QEP), a estrutura da tabela, a cardinalidade dos índices, a configuração do otimizador e as estatísticas. Esses pontos ficam para um próximo post.
Coleta de statements SQL
O MySQL oferece várias formas de coletar statements SQL em execução ou já executados. Nenhum método é, por si só, o melhor — em geral, é preciso combinar diferentes abordagens para reunir informações suficientes para uma observabilidade detalhada do sistema e uma análise mais aprofundada dos statements SQL. Você pode usar estes métodos, e cada um deles ainda pode oferecer várias maneiras de obter os mesmos detalhes.
- Processlist
- Performance Schema
- Sys Schema
- Slow query log
- General query log
- Binary log
Salvo indicação em contrário, o cliente de linha de comando mysql é utilizado nos exemplos de saída a seguir.
OBSERVAÇÃO: os exemplos de SQL apresentados aqui são compatíveis com o MySQL 5.7 e o MySQL 8.0. Por causa do end-of-life (EOL) da edição community do MySQL 5.7 e do próximo EOL do AWS RDS MySQL 5.7, todas as saídas de exemplo e referências de documentação usam a versão atual, o MySQL 8.0. Algumas saídas mostradas neste artigo podem diferir das geradas pelo MySQL 5.7.
1\. SQL com a processlist do MySQL
A processlist do MySQL mostra os statements SQL em execução no momento. Ou seja, são os statements rodando no instante em que esse comando é executado. Para queries de longa duração, é uma forma simples de localizar os statements SQL. Já para statements de alta frequência e baixa latência, observá-los pela processlist pode ser bem difícil. Além do statement em execução, você obtém detalhes do usuário e host de origem, do schema do banco utilizado, do tempo de execução (em segundos) e do estado interno atual da query.
É possível obter a saída da processlist do MySQL por estes meios:
- performance schema
- sys schema
- information schema
- statement SHOW
- comando mysqladmin
Não há vantagem específica em usar uma das opções acima em vez de outra quando a saída traz as mesmas colunas. Algumas dessas opções não existiam em versões mais antigas do MySQL e foram adicionadas para atender a padrões da indústria com statements SQL ISO válidos — algo que o SHOW não atende. O comando mysqladmin oferece diferentes opções administrativas e permite combinar várias saídas, como mostrado no exemplo.
Processlist via Performance Schema
Quando habilitada, a tabela threads do performance_schema e a tabela processlist fornecem essas informações.
mysql> SELECT * FROM performance_schema.processlist;
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ID | USER | HOST | DB | COMMAND | TIME | STATE | INFO |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 5 | event_scheduler | localhost | NULL | Daemon | 456 | Waiting on empty queue | NULL |
| 9 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 11 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 19 | rdsadmin | localhost | NULL | Sleep | 3 | | NULL |
| 23 | rdsadmin | localhost | NULL | Sleep | 65 | | NULL |
| 263 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 404 | dba | 172.31.16.14:43464 | airport | Query | 0 | executing | SELECT SQL_NO_CACHE a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 406 | dba | 172.31.16.14:43484 | airport | Query | 0 | executing | SELECT * FROM performance_schema.processlist |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
- Para mais informações, consulte o MySQL 8.0 Reference Manual.
Processlist via Sys Schema
As views processlist e session do sys schema dão acesso aos statements SQL e a informações complementares. Essas views são construídas em cima do performance schema e exigem que ele esteja habilitado para que a coleta de SQL pelo sys schema funcione. Elas também trazem atributos adicionais de metadados junto com o statement SQL. Veja um exemplo usando a view sys.x$processlist.
mysql> SELECT * FROM sys.x$processlist WHERE command = 'Query'\G
*************************** 1. row ***************************
thd_id: 675
conn_id: 650
user: [email protected]
db: airport
command: Query
state: executing
time: 0
current_statement: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
statement_latency: 116727428000
progress: NULL
lock_latency: 506000000
rows_examined: 0
rows_sent: 0
rows_affected: 0
tmp_tables: 1
tmp_disk_tables: 0
full_scan: YES
last_statement: NULL
last_statement_latency: NULL
current_memory: 165019
last_wait: NULL
last_wait_latency: NULL
source: NULL
trx_latency: 116250140000
trx_state: ACTIVE
trx_autocommit: YES
pid: 15730
program_name: mysql
O terminador usado no statement acima gera uma tabela em formato vertical — coluna: valor por linha — em vez do tradicional formato horizontal de colunas e linhas. Aqui usamos o terminador ‘\G’ em vez do tradicional ponto e vírgula ‘;’. Essa sintaxe é específica do cliente mysql e não funciona em outros clientes GUI de terceiros.
OBSERVAÇÃO: se aparecer a mensagem de erro a seguir, basta executar SET SQL_BIG_SELECTS=1; antes do statement SQL acima.
ERROR 1104 (42000) at line 1: The SELECT would examine more than
MAX_JOIN_SIZE rows; check your WHERE and use SET SQL_BIG_SELECTS=1
or SET MAX_JOIN_SIZE=# if the SELECT is okay
- Para mais informações, consulte o MySQL 8.0 Reference Manual.
Processlist via Information Schema
Embora o Information Schema seja um padrão de fato adotado por vários RDBMS, a tabela processlist não é padronizada. No MySQL, você consulta essas informações com o seguinte statement.
mysql > SELECT * FROM information_schema.processlist;
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ID | USER | HOST | DB | COMMAND | TIME | STATE | INFO |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 88 | dba | 172.31.16.14:59474 | airport | Query | 0 | executing | SELECT SQL_NO_CACHE a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 9 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 26 | rdsadmin | localhost | NULL | Sleep | 1 | | NULL |
| 11 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 19 | rdsadmin | localhost | NULL | Sleep | 9 | | NULL |
| 5 | event_scheduler | localhost | NULL | Daemon | 352 | Waiting on empty queue | NULL |
| 94 | dba | 172.31.16.14:59522 | airport | Query | 0 | executing | SELECT * FROM information_schema.processlist |
| 23 | rdsadmin | localhost | NULL | Sleep | 261 | | NULL |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
- Para mais informações, consulte o MySQL 8.0 Reference Manual
Processlist via statement SHOW
Antes da chegada do Information Schema, na versão 5.1, e do Performance Schema, na versão 5.5, a principal forma de capturar a processlist no MySQL era pelo comando SHOW.
mysql> SHOW FULL PROCESSLIST;
Essa saída é idêntica à de SELECT * FROM performance_schema.processlist; mostrada acima. A palavra-chave FULL é necessária para obter os statements sem truncamento.
Para mais informações, consulte o MySQL 8.0 Reference Manual.
Processlist via cliente _mysqladmin_
Outra ferramenta cliente do MySQL, o mysqladmin — usada para diversas operações administrativas —, também consegue gerar uma saída da processlist em execução em formato tabular.
$ mysqladmin --verbose processlist status
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 5 | event_scheduler | localhost | | Daemon | 1419 | Waiting on empty queue | |
| 9 | rdsadmin | localhost | | Sleep | 1 | | |
| 11 | rdsadmin | localhost | | Sleep | 1 | | |
| 19 | rdsadmin | localhost | | Sleep | 6 | | |
| 23 | rdsadmin | localhost | | Sleep | 128 | | |
| 771 | rdsadmin | localhost | | Sleep | 3 | | |
| 830 | dba | 172.31.16.14:54000 | airport | Query | 0 | executing | SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 832 | dba | 172.31.16.14:54026 | | Query | 0 | init | show full processlist |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------+
Uptime: 1421 Threads: 8 Questions: 14058 Slow queries: 1290 Opens: 261 Flush tables: 3 Open tables: 181 Queries per second avg: 9.893
Sem o --verbose, os statements SQL aparecem truncados, mesmo neste exemplo curto. Por exemplo:
| 786 | dba | 172.31.16.14:59446 | airport | Query | 0 | executing | SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_c |
Para mais informações, consulte o MySQL 8.0 Reference Manual
2\. SQL com o Performance Schema
Com o Performance Schema habilitado e os consumers aplicáveis ativos, várias tabelas podem ser usadas para fornecer informações detalhadas sobre statements SQL executados e em execução.
Opções de configuração
No MySQL nativo, o performance schema é habilitado assim:
mysql> SET GLOBAL performance_schema=1;
No serviço gerenciado AWS RDS, é preciso usar parameter groups para alterar parâmetros. Por exemplo:
$ modify-parameter ${PG_NAME} performance_schema 1 pending-reboot
OBSERVAÇÃO: em uma instância RDS, isso se refere ao instance parameter group. Quando a instância faz parte de um cluster AWS RDS Aurora, existe um cluster parameter group, que é o padrão a menos que os valores sejam sobrescritos pelo instance parameter group.
Quando o performance schema é habilitado pela primeira vez, a instância MySQL — e, portanto, a instância AWS RDS — precisa ser reiniciada.
$ aws rds reboot-db-instance --db-instance-identifier ${INSTANCE_ID}
Os consumers e instruments do performance schema para captura de statements SQL ficam habilitados por padrão, mas podem ser ajustados em uma instância MySQL em execução. Você confere a configuração atual com:
mysql> SELECT * FROM performance_schema.setup_instruments WHERE NAME LIKE 'statement/%';
mysql> SELECT * FROM performance_schema.setup_consumers WHERE NAME LIKE '%statements%';
Validação das configurações
O statement a seguir confirma se o performance schema está habilitado.
mysql> SELECT @@performance_schema;
+----------------------+
| @@performance_schema |
+----------------------+
| 1 |
+----------------------+
Tabela processlist do Performance Schema
Como já vimos, a tabela processlist traz informações básicas dos statements em execução no momento.
Tabela threads do Performance Schema
A tabela threads mostra atributos adicionais dos statements SQL em execução no momento.
mysql> SELECT * FROM performance_schema.threads WHERE PROCESSLIST_STATE="executing"\G
*************************** 1. row ***************************
THREAD_ID: 960
NAME: thread/sql/one_connection
TYPE: FOREGROUND
PROCESSLIST_ID: 935
PROCESSLIST_USER: dba
PROCESSLIST_HOST: 172.31.16.14
PROCESSLIST_DB: airport
PROCESSLIST_COMMAND: Query
PROCESSLIST_TIME: 0
PROCESSLIST_STATE: executing
PROCESSLIST_INFO: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
PARENT_THREAD_ID: NULL
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: SSL/TLS
THREAD_OS_ID: 353
RESOURCE_GROUP: NULL
Tabelas events_statements_* do Performance Schema
O grande trunfo do performance schema é capturar statements SQL recém-executados — recurso essencial para statements que executam muito rápido.
mysql> SELECT * FROM performance_schema.events_statements_current WHERE SQL_TEXT like '%airport%'\G
*************************** 1. row ***************************
THREAD_ID: 981
EVENT_ID: 4
END_EVENT_ID: NULL
EVENT_NAME: statement/sql/select
SOURCE: init_net_server_extension.cc:110
TIMER_START: 2471111163284000
TIMER_END: 2471111453481000
TIMER_WAIT: 290197000
LOCK_TIME: 175000000
SQL_TEXT: SELECT * FROM performance_schema.events_statements_current WHERE SQL_TEXT like '%airport%'
DIGEST: 2fdfe28204e80c382a14597873be575ea8c7ede6e4757e77700a333bbe50b025
DIGEST_TEXT: SELECT * FROM `performance_schema` . `events_statements_current` WHERE `SQL_TEXT` LIKE ?
CURRENT_SCHEMA: NULL
OBJECT_TYPE: NULL
OBJECT_SCHEMA: NULL
OBJECT_NAME: NULL
OBJECT_INSTANCE_BEGIN: NULL
MYSQL_ERRNO: 0
RETURNED_SQLSTATE: NULL
MESSAGE_TEXT: NULL
ERRORS: 0
WARNINGS: 0
ROWS_AFFECTED: 0
ROWS_SENT: 0
ROWS_EXAMINED: 0
CREATED_TMP_DISK_TABLES: 0
CREATED_TMP_TABLES: 0
SELECT_FULL_JOIN: 0
SELECT_FULL_RANGE_JOIN: 0
SELECT_RANGE: 0
SELECT_RANGE_CHECK: 0
SELECT_SCAN: 1
SORT_MERGE_PASSES: 0
SORT_RANGE: 0
SORT_ROWS: 0
SORT_SCAN: 0
NO_INDEX_USED: 1
NO_GOOD_INDEX_USED: 0
NESTING_EVENT_ID: NULL
NESTING_EVENT_TYPE: NULL
NESTING_EVENT_LEVEL: 0
STATEMENT_ID: 22413
1 row in set (0.01 sec)
Outras tabelas de performance que contêm statements SQL executados são events_statements_current, events_statements_history e events_statements_long. Para mais informações, consulte o MySQL 8.0 Reference Manual.
3\. SQL com o Sys Schema
O sys schema do MySQL é um conjunto de objetos e views que interpretam os dados disponíveis no Performance Schema e oferecem uma visão mais amigável ao usuário final. Ele também exibe statements SQL executados e estatísticas agregadas das execuções. A primeira view a considerar é a statement_analysis (ou x$statement_analysis).
mysql> select * from sys.x$statement_analysis where query like '%airport%'\G
*************************** 1. row ***************************
query: SELECT `a` . `country_code` , `c` . `name` , COUNT ( * ) AS `cnt` FROM `airport` `a` INNER JOIN `country` `c` USING ( `country_code` ) GROUP BY `country_code` , NAME ORDER BY ? DESC LIMIT ?
db: airport
full_scan: *
exec_count: 8
err_count: 0
warn_count: 0
total_latency: 1330746923000
max_latency: 304276507000
avg_latency: 166343365000
lock_latency: 1937000000
rows_sent: 80
rows_sent_avg: 10
rows_examined: 1223680
rows_examined_avg: 152960
rows_affected: 0
rows_affected_avg: 0
tmp_tables: 8
tmp_disk_tables: 0
rows_sorted: 80
sort_merge_passes: 0
digest: 616aa31e4f99b22a194c91ae9f1cfbfb95d6957621b55393b4a01603d8e1fd47
first_seen: 2023-10-12 14:55:56.021003
last_seen: 2023-10-12 15:23:14.225503
Várias outras tabelas do sys schema incluem statements SQL executados e agregações de subconjuntos de statements. Alguns exemplos: statements_with_full_table_scans e statements_with_temp_tables. Para mais informações, consulte o MySQL 8.0 Reference Manual.
4\. SQL com o slow query log
Quando habilitado, o slow query log faz exatamente o que o nome sugere: registra todas as queries lentas que ultrapassem um tempo de execução pré-definido. Em versões antigas, esse limite era em segundos. A partir do MySQL 5.7, é em microssegundos. O valor 0 também é válido e significa registrar todos os statements SQL executados — mas atenção, isso gera overhead de desempenho e custo adicional em um banco com alta concorrência.
Opções de configuração
No MySQL nativo, o slow query log é habilitado assim:
mysql> SET GLOBAL slow_query_log=1;
mysql> SET GLOBAL long_query_time=0.001;
mysql> SET GLOBAL log_output=FILE; /* This is the default */
No serviço gerenciado AWS RDS, é preciso usar parameter groups para alterar parâmetros. As alterações são imediatas. Por exemplo:
$ modify-parameter ${PG_NAME} slow_query_log 1
$ modify-parameter ${PG_NAME} long_query_time 0.001
$ modify-parameter ${PG_NAME} log_output FILE
Existem outros parâmetros de configuração que não vamos abordar, como slow_query_log_file, log_queries_not_using_indexes e log_slow_admin_statements.
OBSERVAÇÃO: avalie com cuidado o impacto de habilitar essas opções extras do slow query log. Cada uma pode gerar grandes volumes de statements SQL e fazer o arquivo de log crescer rapidamente. Queries que fazem full-table scan de propósito (por terem poucas linhas) ou statements administrativos frequentes, essenciais para instrumentação e observabilidade com ferramentas de monitoramento, podem acabar sendo registrados.
Validação das configurações
Para confirmar se o slow query log está habilitado e configurado:
mysql> SELECT @@slow_query_log, @@long_query_time, @@log_output;
+------------------+-------------------+--------------+
| @@slow_query_log | @@long_query_time | @@log_output |
+------------------+-------------------+--------------+
| 1 | 0.001000 | FILE |
+------------------+-------------------+--------------+
Para mais informações, consulte o MySQL 8.0 Reference Manual.
Baixando o slow query log do AWS RDS
Quando habilitado, o slow query log grava em um arquivo de log na sua instância RDS. Você pode baixá-lo com a AWS CLI.
$ INSTANCE_ID=
$ aws rds download-db-log-file-portion \
--db-instance-identifier ${INSTANCE_ID} \
--starting-token 0 \
--output text \
--log-file-name slowquery/mysql-slowquery.log > slowquery.log
Os arquivos de slow log do RDS são rotacionados a cada hora. Use os comandos abaixo para listar todos os arquivos disponíveis para download.
$ aws rds describe-db-log-files --db-instance-identifier ${INSTANCE_ID}
{
"DescribeDBLogFiles": [\
...\
{\
"LogFileName": "slowquery/mysql-slowquery.log",\
"LastWritten": 1697125638054,\
"Size": 761426\
},\
{\
"LogFileName": "slowquery/mysql-slowquery.log.2023-10-12.14",\
"LastWritten": 1697121600696,\
"Size": 60517\
},\
{\
"LogFileName": "slowquery/mysql-slowquery.log.2023-10-12.15",\
"LastWritten": 1697122801087,\
"Size": 343085\
}\
]
}
Informações disponíveis no slow query log
Cada statement SQL no slow query log inclui as seguintes informações:
- Tempo de execução
- Usuário e Host
- Thread Id
- Query time
- Lock time
- Linhas enviadas
- Linhas examinadas
- Statement SQL completo
Exemplo de saída do slow query log
# Time: 2023-10-05T15:56:58.831165Z
# User@Host: dba[dba] @ [172.31.16.14] Id: 295
# Query_time: 0.259097 Lock_time: 0.000178 Rows_sent: 10 Rows_examined: 76733
SET timestamp=1696521418;
SELECT a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name
ORDER BY 3 DESC
LIMIT 10;
OBSERVAÇÃO: o slow query log é bem estruturado: todas as linhas não comentadas são statements SQL reais, devidamente terminados, o que facilita muito coletar, registrar e executar esses statements de forma geral. A única limitação é quando as tabelas não estão qualificadas com o schema — nesse caso, é preciso conhecer o schema do banco de dados das suas tabelas.
Slow query log via tabela SQL
Apesar de não ser recomendado de modo geral, é possível coletar slow queries via statement SQL quando o slow query log está habilitado e configurado com log_output=TABLE.
Coleta SQL das informações do slow query log
O statement SQL a seguir recupera as queries registradas na tabela mysql.slow_log.
# Table does not have a PK, so this is a crud hack
SELECT sl.*,
CONVERT(q.sql_text USING utf8mb4)AS query
FROM mysql.slow_log sl
INNER JOIN mysql.slow_log q USING (start_time)
WHERE CONVERT(q.sql_text USING utf8mb4) like '%airport%'\G
Exemplo de saída do slow query log via tabela
start_time: 2023-10-05 15:59:30.878226
user_host: dba[dba] @ [172.31.16.14]
query_time: 00:00:00.295653
lock_time: 00:00:00.000164
rows_sent: 10
rows_examined: 76733
db: airport
last_insert_id: 0
insert_id: 0
server_id: 1843089174
sql_text: 0x53454C45435420612E636F756E7472795F636F64652C20632E6E616D652C20434F554E54282A2920415320636E742046524F4D20616972706F72742061202020494E4E4552204A4F494E20636F756E7472792063205553494E472028636F756E7472795F636F6465292047524F555020425920636F756E7472795F636F64652C206E616D65204F5244455220425920332044455343204C494D4954203130
thread_id: 295
query: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
5\. SQL com o general query log
Quando configurado, o MySQL pode registrar todos os statements SQL no general query log.
OBSERVAÇÃO: pense bem em qual ambiente habilitar o general query log e por quanto tempo. O exemplo a seguir é de um sistema 100% ocioso, com 12 statements SQL adicionais executados no mesmo segundo do nosso statement de exemplo.
AVISO: assim como no slow query log, dá para registrar essa saída em uma tabela MySQL. Não recomendamos: pode impactar bastante o desempenho de um sistema em execução.
Opções de configuração
No MySQL nativo, o general query log é habilitado assim:
mysql> SET GLOBAL general_log=1;
mysql> SET GLOBAL log_output=FILE; /* This is the default */
No serviço gerenciado AWS RDS, é preciso usar parameter groups para alterar parâmetros. As alterações são imediatas. Por exemplo:
$ modify-parameter ${PG_NAME} general_log 1
$ modify-parameter ${PG_NAME} log_output FILE
Há um parâmetro de configuração adicional que não vamos abordar aqui: a variável general_log_file.
Validação das configurações
Para confirmar se o general query log está habilitado e configurado:
mysql> SELECT @@general_log, @@log_output, @@general_log_file;
+---------------+--------------+------------------------------------------+
| @@general_log | @@log_output | @@general_log_file |
+---------------+--------------+------------------------------------------+
| 1 | FILE | /rdsdbdata/log/general/mysql-general.log |
+---------------+--------------+------------------------------------------+
Para mais informações, consulte o MySQL 8.0 Reference Manual.
Baixando o general query log do AWS RDS
Quando habilitado, o general query log grava em um arquivo de log na sua instância RDS. Você pode baixá-lo com a AWS CLI.
$ INSTANCE_ID=
$ aws rds download-db-log-file-portion \
--db-instance-identifier ${INSTANCE_ID} \
--starting-token 0 \
--output text \
--log-file-name general/mysql-general.log > general.log
Como falamos na seção anterior, o argumento describe-db-log-files lista os arquivos do general query log que já foram rotacionados.
Exemplo de saída do general query log
2023-10-05T17:31:06.006853Z 9 Query set local oscar_local_only_replica_host_status=1;
2023-10-05T17:31:06.006963Z 9 Query SELECT durable_lsn, current_read_point, server_id, last_update_timestamp FROM information_schema.replica_host_status;
2023-10-05T17:31:06.007500Z 9 Query set local oscar_local_only_replica_host_status=0
2023-10-05T17:31:06.836552Z 540 Query SELECT
a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
2023-10-05T17:31:06.932194Z 9 Query set local oscar_local_only_replica_host_status=1;
2023-10-05T17:31:06.932368Z 9 Query SELECT durable_lsn, current_read_point, server_id, last_update_timestamp FROM information_schema.replica_host_status;
2023-10-05T17:31:06.933104Z 9 Query set local oscar_local_only_replica_host_status=0
2023-10-05T17:31:06.935817Z 11 Query SET @@sql_log_bin=off
2023-10-05T17:31:06.936615Z 11 Query select @@session.transaction_read_only
2023-10-05T17:31:06.937118Z 11 Query INSERT INTO mysql.rds_heartbeat2(id, value) values (1,1696527066936) ON DUPLICATE KEY UPDATE value = 1696527066936
2023-10-05T17:31:06.947853Z 11 Query select @@session.transaction_read_only
2023-10-05T17:31:06.948293Z 11 Query COMMIT
2023-10-05T17:31:06.948725Z 11 Query SET @@sql_log_bin=on
OBSERVAÇÃO: o general query log é semiestruturado. Os statements SQL podem ocupar várias linhas, preservando o formato enviado ao MySQL pelo seu programa cliente. Não basta remover os 41 primeiros caracteres de cada linha para coletar os statements SQL.
Para mais informações, consulte o MySQL 8.0 Reference Manual.
6\. SQL com o binary log
Frequentemente esquecido, o binary log do MySQL, quando habilitado, é uma fonte rica de informações sobre statements SQL que realizam escritas no seu banco. Ele pode ser fundamental para identificar fronteiras de transações e a sequência de statements SQL dentro de cada transação, ajudando na análise de bloqueios. O binary log também traz os detalhes completos das colunas em statements INSERT, UPDATE e DELETE.
Qualquer configuração de instância RDS que use read replicas já vem com o binary logging habilitado por padrão.
Validação das configurações
Para confirmar se o binary log está habilitado e configurado:
mysql> SELECT @@log_bin, @@binlog_format, @@log_statements_unsafe_for_binlog, @@log_bin_trust_function_creators;
+-----------+-----------------+------------------------------------+-----------------------------------+
| @@log_bin | @@binlog_format | @@log_statements_unsafe_for_binlog | @@log_bin_trust_function_creators |
+-----------+-----------------+------------------------------------+-----------------------------------+
| 0 | ROW | 1 | 0 |
+-----------+-----------------+------------------------------------+-----------------------------------+
Você pode listar os binary logs disponíveis na sua instância MySQL com:
mysql> SHOW BINARY LOGS;
É possível baixar os binary logs com o comando mysqlbinlog. Por exemplo:
$ TMP_DIR=${TMP_DIR:-/tmp}
$ AUTHENTICATION="-h<host> -u<user> -p<password"
$ BINLOG_FILE="binlog.00042"
mysqlbinlog --read-from-remote-server --raw --result-file=${TMP_DIR}/ ${AUTHENTICATION} ${BINLOG_FILE} 2>/dev/null # Kill warning message and not mess with $?
Você visualiza o conteúdo do binary log com o comando mysqlbinlog. Dependendo das suas opções de configuração, alguns argumentos são mais adequados, mas, em geral, esta é a melhor abordagem para todos os formatos:
$ mysqlbinlog -vvv --base64-output=DECODE-ROWS ${TMP_DIR}/${BINLOG_FILE}
A análise do binary log é um processo mais detalhado que não vamos aprofundar aqui. Ela também depende do valor da variável de configuração que define o formato de linha do binary log. Dá para obter um resumo por tabela para um arquivo específico, ou para um período com um ou mais arquivos, usando argumentos adicionais. O snippet abaixo gera esse resumo por tabela quando binlog_format=ROW é utilizado.
mysqlbinlog ${BINLOG_ADDITIONAL_ARGS} ${TMP_DIR}/${BINLOG_FILE} | \
sed -e "s/^### //;" | \
sed -e "/^#/d;s/\/\*.*\*\/[;]//;/^$/d" | \
cut -c1-100 | \
tr '[A-Z]' '[a-z]' | \
egrep "^(insert|update|delete|replace|commit|alter|drop|create)" | \
sed -e "s/\t/ /g;s/\`//g;s/(.*$//;s/ set .*$//;s/ as .*$//;s/ join .*$//;s/ values .*$//;" | sed -e "s/ where .*$//;s/ignore //g;s/ inner//g;s/ left//g;s/ right//g;s/ from//g;s/ into//g" | \
sed -e "s/or replace//;s/sql security definer//;s/algorithm=.* //;s/definer=.* //g" | \
sed -e "s/ \w.*\.\*//" | \
awk '{ print $1,$2 }' | \
sort | uniq -c | sort -nr
Você encontra uma cópia do script completo, que inclui o download e o processamento de um arquivo de binary log, neste gist no Github.
Para mais informações, consulte o MySQL 8.0 Reference Manual.
Resumo das opções de coleta de SQL
A seguir, os principais benefícios e limitações de cada opção. A melhor forma de descobrir qual delas atende às suas necessidades é testar cada uma seguindo os passos descritos neste artigo.
Benefícios da Processlist
- Habilitada por padrão
Limitações da Processlist
- Captura apenas statements SQL em execução no momento
- Exige privilégios elevados para enxergar todas as queries de todos os usuários
Benefícios do Performance Schema
- Captura statements executados anteriormente, além dos que estão em execução no momento
- Fornece resultados agregados, ideais para queries de alta frequência
Limitações do Performance Schema
- Precisa ser habilitado e exige reinicialização para a primeira ativação
- Exige tuning em sistemas de alta performance para limitar o overhead de recursos
Benefícios do Sys Schema
- Estende o performance schema com views e objetos altamente utilizáveis, muito bem nomeados e voltados para finalidades específicas
Limitações do Sys Schema
- Requer que o performance schema esteja habilitado
Benefícios do slow query log
- Captura todas as queries lentas que ultrapassam um tempo de execução pré-definido
Limitações do slow query log
- Praticamente sem limitações. Deve estar sempre habilitado, com um threshold adequado, em todas as instâncias MySQL.
Benefícios do general query log
- Fornece uma lista sequencial completa de todos os statements SQL. Ideal para análise de transações e avaliação de antipadrões de acesso a dados.
Limitações do general query log
- Overhead significativo em sistemas de produção com alto uso. Recomenda-se utilizá-lo com uma suíte de testes, idealmente com uma única thread.
Benefícios do binary log
- Geralmente sempre habilitado para garantir capacidades de HA e PITR
Limitações do binary log
- Captura apenas escritas quando habilitado
- Formato mais complicado de processar para capturar statements SQL completos
Apêndice
Dados de exemplo utilizados
Para este artigo, usamos o seguinte dataset de aeroportos, disponível em https://github.com/ronaldbradford/data/tree/main/mysql-data/airport
SQL de exemplo utilizado
Em cada método de coleta, usamos o seguinte statement SQL de exemplo.
SELECT a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10;
Esse statement SQL retorna um conjunto de resultados como:
+--------------+----------------+-------+
| country_code | name | cnt |
+--------------+----------------+-------+
| US | United States | 30581 |
| BR | Brazil | 6849 |
| JP | Japan | 3430 |
| CA | Canada | 3075 |
| AU | Australia | 2576 |
| MX | Mexico | 2288 |
| RU | Russia | 1556 |
| KR | South Korea | 1400 |
| GB | United Kingdom | 1398 |
| DE | Germany | 1042 |
+--------------+----------------+-------+
10 rows in set (0.47 sec)
OBSERVAÇÃO: os totais reais de aeroportos e a ordenação dos países podem variar conforme a data em que você baixou o dataset.
Coleta de SQL
Como este é um sistema de teste com uso mínimo, alguns statements retornaram todas as linhas possíveis, enquanto outros foram restringidos por uma cláusula WHERE apropriada para capturar este statement SQL específico. Ao capturar SQL no seu sistema, talvez seja preciso aplicar filtros adequados para limitar a saída de statements.
Função auxiliar Bash modify-parameter
A função a seguir é usada neste artigo para simplificar a sintaxe de modificação de variáveis de parameter group do AWS RDS.
modify-parameter() {
[[ $# -lt 3 ]] || [[ $# -gt 4 ]] && echo "ERROR: <parameter-group> <parameter> <value> [pending-reboot]" && return 1
local PARAMETER_GROUP="$1"
local PARAMETER_NAME="$2"
local PARAMETER_VALUE="$3"
local APPLY_METHOD="immediate"
[[ $# -eq 4 ]] && APPLY_METHOD="$4"
aws rds modify-db-parameter-group --db-parameter-group-name ${PARAMETER_GROUP} --parameters "ParameterName=${PARAMETER_NAME},ParameterValue='${PARAMETER_VALUE}',ApplyMethod=${APPLY_METHOD}"
aws rds describe-db-parameters --db-parameter-group-name ${PARAMETER_GROUP} --query 'Parameters[] | [?ParameterName == `'${PARAMETER_NAME}'`]'
}
Para mais informações, consulte a referência de comandos da AWS CLI para modify-db-parameter-group e a sintaxe de describe-db-parameters.
Dica de identificação de SQL
O MySQL permite incluir um comentário dentro de um statement SQL, mas nem toda ferramenta captura e registra essa informação. É boa prática de engenharia criar algum tipo de rótulo único para cada statement SQL. O conteúdo do comentário não importa — o que importa é a unicidade. Conseguir ver uma query com um comentário e localizar esse trecho no código-fonte reduz o tempo de identificação e o mean-time-to-resolve (MTTR) de qualquer problema.
SELECT /* Countries with the most airports */
a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name
ORDER BY 3 DESC LIMIT 10;
Para mais informações, consulte o MySQL 8.0 Reference Manual.
Existem vários métodos nativos, com ferramentas cliente do MySQL, para coletar statements SQL do MySQL rodando no AWS RDS. Há ainda outras ferramentas e técnicas capazes de coletar statements SQL no MySQL que não serão abordadas neste artigo.
Coletar um statement SQL é o primeiro passo essencial para reunir informações suficientes da sua aplicação sobre os padrões de acesso a dados. Essas informações podem ser fundamentais para o design arquitetural, os testes e a análise de desempenho.
Em um próximo artigo, vou falar sobre a coleta dos metadados de apoio, necessários junto com qualquer statement SQL para a análise de desempenho. Isso inclui o Query Execution Plan (QEP), metadados de tabelas e índices, estatísticas de distribuição de colunas e opções específicas de configuração que podem impactar a execução de um statement SQL.