在AWS RDS中为Postgresql开启慢查询日志

sql遇到性能问题，就需要开启慢查询日志，将执行时间超过某个限定值的sql输出到日志，给后续开发人员分析。下面是AWS RDS中Postgresql开启慢查询日志的方法。包含

  • RDS设置
  • 下载RDS log的方法
  • 一些注意点

RDS设置步骤

  1. 登陆aws console，切换到RDS
    switch_to_rds.png
  2. 在左边菜单栏中，找到”Parameter Groups”
    parameter_groups.png
  3. 选中要开启慢查询日志的PostgreSQL使用的参数组, 此处是myparametergroup, 点击”Edit Parameters”修改配置
    select_parameter_group.png
  4. 修改log_min_duration_statement为超限的毫秒数，超过这个数值，PostgreSQL就会记录下相关的log。日志格式参见后续说明。
    set_log_min_duration_statement.png
  5. 如果原来开启了log_statement和log_duration的，需要将log_statement设为默认的none，将log_duration设为0, 否则输出的慢查询日志的sql和执行时间就不在同一行，不便于观察。
  6. 因为log_min_duration_statement是动态参数的(修改页面上的Apply Type属性是Dynamic)，因此修改设置后不需要重启，RDS会自动load新的设置。
    load_parameter_group.png
  7. 注意: 如果RDS原先使用的是default的参数组，那么RDS换为自己定义的参数组的时候，RDS会重启

下载日志的方法

设置IAM权限来允许下载RDS logs

将如下Policy 添加到IAM User或者Role中，就可以使用API或者CLI来下载RDS的log了

1
2
3
4
5
6
7
8
9
10
11
12
13
{
    "Version": "2012-10-17",
    "Statement": [
        {
            "Action": [
                "rds:Describe*",
                "rds:DownloadDBLogFilePortion"
            ],
            "Effect": "Allow",
            "Resource": "*"
        }
    ]
}

aws cli下载文件的命令

aws rds download-db-log-file-portion help中有下载完整log的用法

1
aws rds download-db-log-file-portion --db-instance-identifier myinstance --log-file-name log.txt --starting-token 0 --output text > full.txt

如下是下载名为mydb的Instance中某个指定日志的示例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
[ec2-user@ip-172-31-13-115 rds_log]$ aws rds describe-db-log-files --db-instance-identifier=mydb
{
    "DescribeDBLogFiles": [
        {
            "LastWritten": 1511938537000,
            "LogFileName": "error/postgres.log",
            "Size": 307
        },
        {
            "LastWritten": 1511938540000,
            "LogFileName": "error/postgresql.log.2017-11-29-06",
            "Size": 1051
        },
        {
            "LastWritten": 1511942140000,
            "LogFileName": "error/postgresql.log.2017-11-29-07",
            "Size": 4032
        },
        {
            "LastWritten": 1511942441000,
            "LogFileName": "error/postgresql.log.2017-11-29-08",
            "Size": 336
        }
    ]
}
[ec2-user@ip-172-31-13-115 rds_log]$ aws rds download-db-log-file-portion --db-instance-identifier mydb --log-file-name error/postgresql.log.2017-11-29-07 --starting-token 0 --output text > postgresql.log.2017-11-29-07
[ec2-user@ip-172-31-13-115 rds_log]$ ll
总用量 4
-rw-rw-r-- 1 ec2-user ec2-user 4033 11月 29 08:02 postgresql.log.2017-11-29-07
[ec2-user@ip-172-31-13-115 rds_log]$

注意下载下来文件的大小，会比describe-db-log-files显示的文件大小大1 Byte, 因为下载下来的文件末尾会额外多一个空行

Ruby SDK 下载log的一个例子

参见GithubGist

摘录关键点如下:

1
2
3
4
5
6
7
8
9
10
additional_data_pending = true
File.open(out_log_file, "wb+") do |file|
  while additional_data_pending do
    out = rds.download_db_log_file_portion(opts)
    file.write(out[:log_file_data])
    #puts out[:marker]
    opts[:marker] = out[:marker]
    additional_data_pending = out[:additional_data_pending]
  end
end

注意点

log_min_duration_statement和log_statement同时使用的格式

按照官方文档说明,开启了log_statement和log_duration后，error log中输出的日志格式如下.

1
2
3
4
5
6
7
8
9
10
11
12
2013-11-05 16:51:10 UTC:[local]:master@postgres:[9193]:LOG:  statement: SELECT c2.relname, i.indisprimary, i.indisunique, i.indisclustered, i.indisvalid, pg_catalog.pg_get_indexdef(i.indexrelid, 0, true),
	  pg_catalog.pg_get_constraintdef(con.oid, true), contype, condeferrable, condeferred, c2.reltablespace
	FROM pg_catalog.pg_class c, pg_catalog.pg_class c2, pg_catalog.pg_index i
	  LEFT JOIN pg_catalog.pg_constraint con ON (conrelid = i.indrelid AND conindid = i.indexrelid AND contype IN ('p','u','x'))
	WHERE c.oid = '1255' AND c.oid = i.indrelid AND i.indexrelid = c2.oid
	ORDER BY i.indisprimary DESC, i.indisunique DESC, c2.relname;
2013-11-05 16:51:10 UTC:[local]:master@postgres:[9193]:LOG:  duration: 3.367 ms
2013-11-05 16:51:10 UTC:[local]:master@postgres:[9193]:LOG:  statement: SELECT c.oid::pg_catalog.regclass FROM pg_catalog.pg_class c, pg_catalog.pg_inherits i WHERE c.oid=i.inhparent AND i.inhrelid = '1255' ORDER BY inhseqno;
2013-11-05 16:51:10 UTC:[local]:master@postgres:[9193]:LOG:  duration: 1.002 ms
2013-11-05 16:51:10 UTC:[local]:master@postgres:[9193]:LOG:  statement: SELECT c.oid::pg_catalog.regclass FROM pg_catalog.pg_class c, pg_catalog.pg_inherits i WHERE c.oid=i.inhrelid AND i.inhparent = '1255' ORDER BY c.oid::pg_catalog.regclass::pg_catalog.text;
2013-11-05 16:51:18 UTC:[local]:master@postgres:[9193]:LOG:  statement: select proname from pg_proc;
2013-11-05 16:51:18 UTC:[local]:master@postgres:[9193]:LOG:  duration: 3.469 ms

如果关闭了log_statement和log_duration, 只开启了log_min_duration_statement时，输出的日志格式中，duration和sql在同一行，比较便于阅读。

1
2017-11-26 08:01:32 UTC:172.31.13.115(40782):user@mydb:[4234]:LOG: duration: 1326.449 ms execute <unnamed>: SELECT COUNT("location_properties"."id") FROM "location_properties" WHERE (location_record_id = 175034)

RDS Parameter Groups动态和静态参数的描述

官方文档Working with DB Parameter Groups中对修改RDS动态参数和静态参数的描述

When you change a dynamic parameter and save the DB parameter group, the change is applied immediately regardless of the Apply Immediately setting. When you change a static parameter and save the DB parameter group, the parameter change will take effect after you manually reboot the DB instance.

总结起来就是:

  • 修改动态参数, RDS会立即apply
  • 修改静态参数, 只能reboot后才能生效

Reference

留言

▲