Cloud Intelligence™Cloud Intelligence™

Cloud Intelligence™

Como capturar statements SQL no AWS RDS MySQL

By Ronald BradfordNov 9, 202321 min read

Esta página também está disponível em English, Deutsch, Español, Français, Italiano e 日本語.

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.

  1. Processlist
  2. Performance Schema
  3. Sys Schema
  4. Slow query log
  5. General query log
  6. 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                                                                                                                              |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

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

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                                                                                                                                                                      |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

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.