Troubleshooting PostgreSQL for Developers (RU)

Russian version of slides from my talk at Yandex MeetUp Yekaterinburg

Transcript

1. Troubleshooting PostgreSQL for Developers Alexey Lesovsky alexey.lesovsky@dataegret.com
2. • Получить представление о быстром траблшутинге PostgreSQL. • Получить представление о том какие молотки использовать. • И по каким местам нужно стучать. Цели 01 dataegret.com
3. dataegret.com Введение • Зачем это всё, ведь есть же админы. Кто виноват и Что делать? • Инструменты • С чего начать • И как закончить 01 02
4. Ну, и зачем это мне? 01
5. Зачем это мне? Ведь есть же админы! • Кто здесь админ локалхоста? • Админ любит prod и не любит staging. • Чтобы обрести славу среди коллег. • Можно придумать еще много других причин... Зачем это мне? 01 dataegret.com
6. Экспресс траблшутинг это: • Быстрый поиск источника проблемы. • И устранение источника (если это возможно). • Без применения сложных инструментов. • Легко доступен даже в проде. Что значит экспресс? 01 dataegret.com
7. Экспресс траблшутинг в базе это: • Утилизация ресурсов и выявление «криминальной» активности. • Определение «проблемных» запросов. • Влияние фоновых процессов СУБД на качество сервиса. • Проверка наличия ошибок. Что значит экспресс? 01 dataegret.com
8. Экспресс траблшутинг не решает проблемы связанные с: • дизайном Postgres'а; • дизайном схемы БД; • недостаточной мощностью серверов. Введение 01 dataegret.com
9. /* хватит слов, ближе к делу */ Введение 01 dataegret.com
10. Что делать и с чего начать? 02
11. /* Эмм… похоже что база снова тормозит... */ С чего начать? 02 dataegret.com
12. Проверка со стороны операционной системы: • Проверка утилизации ресурсов. • Пик трафика? • Тяжелые запросы? • Или взбесившийся вакуум (или его друзья по цеху). С чего начать? 02 dataegret.com
13. top – проверяем CPU, память, всплески нагрузки. iostat, iotop – проверка дисков. nicstat – проверка сетевых интерфейсов. Проверка утилизации ресурсов 02 dataegret.com
14. top – смотрим нагрузку на CPU: • user time, %us – время пользовательских процессов. • system time, %sy – время процессов ядра. • iowait, %wa – ожидание ввода-вывода. Проверка утилизации ресурсов 02 dataegret.com
15. 02 dataegret.com top - 15:11:35 up 219 days, 23:42, 2 users, load average: 35.52, 35.00, 36.37 Tasks: 643 total, 36 running, 607 sleeping, 0 stopped, 0 zombie %Cpu(s): 58.9 us, 3.7 sy, 1.7 ni, 34.0 id, 0.4 wa, 0.0 hi, 1.3 si, 0.0 st KiB Mem : 26412424+total, 7072312 free, 22974694+used, 27304972 buff/cache KiB Swap: 3996668 total, 3955448 free, 41220 used, 26503692 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 19980 postgres 20 0 0.208t 26700 11844 R 36.2 0.0 2:36.19 postgres: ui.app ui 127.0.0.1(44645) UPDATE 16690 postgres 20 0 0.208t 26220 11908 R 33.9 0.0 2:59.41 postgres: ui.app ui 127.0.0.1(44435) SELECT 19982 postgres 20 0 0.208t 25576 11844 R 30.6 0.0 2:48.58 postgres: ui.app ui 127.0.0.1(44647) SELECT 727 postgres 20 0 0.208t 38888 11908 S 29.3 0.0 5:26.45 postgres: ui.app ui 127.0.0.1(43493) SELECT 18475 postgres 20 0 0.208t 26720 11844 R 29.3 0.0 2:54.66 postgres: ui.app ui 127.0.0.1(44537) SELECT 2181 postgres 0 -20 43972 8548 2448 R 28.6 0.0 30226:12 /usr/sbin/pgbouncer /etc/pgbouncer/pgbouncer.ini 9057 postgres 39 19 0.208t 19672 11540 R 27.0 0.0 3:28.95 postgres: cron.app ui 127.0.0.1(43997) UPDATE 21995 postgres 20 0 0.208t 34644 11688 R 26.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(34412) SELECT 10393 postgres 39 19 0.208t 66748 11560 R 26.3 0.0 3:37.78 postgres: cron.app ui 127.0.0.1(44047) SELECT 18180 postgres 20 0 0.208t 27032 11844 S 26.3 0.0 2:44.31 postgres: ui.app ui 127.0.0.1(44503) SELECT 22109 postgres 20 0 0.208t 31736 11888 R 25.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(44628) SELECT 18480 postgres 20 0 0.208t 28400 11844 S 25.0 0.0 2:45.62 postgres: ui.app ui 127.0.0.1(44547) SELECT 18481 postgres 39 19 0.208t 17620 11432 R 25.0 0.0 2:27.73 postgres: cron.app ui 127.0.0.1(44549) UPDATE 19979 postgres 20 0 0.208t 26448 11888 R 25.0 0.0 2:37.60 postgres: ui.app ui 127.0.0.1(44643) SELECT 21961 postgres 20 0 0.208t 32332 11716 S 24.6 0.0 2:03.02 postgres: ui.app ui 127.0.0.1(29205) SELECT 21844 postgres 20 0 0.208t 31312 11716 R 24.3 0.0 2:03.92 postgres: ui.app ui 127.0.0.1(64894) SELECT 21892 postgres 39 19 0.208t 17088 11432 R 24.3 0.0 2:09.89 postgres: cron.app ui 127.0.0.1(44759) SELECT 21933 postgres 20 0 0.208t 32908 11888 R 24.3 0.0 2:03.83 postgres: ui.app ui 127.0.0.1(57208) SELECT 22037 postgres 20 0 0.208t 32348 11688 S 24.3 0.0 2:03.61 postgres: ui.app ui 127.0.0.1(40971) SELECT 22099 postgres 20 0 0.208t 31252 11688 R 24.3 0.0 2:02.11 postgres: ui.app ui 127.0.0.1(17933) SELECT 22998 postgres 20 0 0.208t 31660 11716 R 24.3 0.0 2:02.06 postgres: ui.app ui 127.0.0.1(50091) BIND 21971 postgres 20 0 0.208t 32684 11752 R 24.0 0.0 2:03.68 postgres: ui.app ui 127.0.0.1(60455) SELECT 22073 postgres 20 0 0.208t 30188 11688 R 24.0 0.0 2:02.77 postgres: ui.app ui 127.0.0.1(51742) UPDATE
16. 02 dataegret.com top - 15:11:35 up 219 days, 23:42, 2 users, load average: 35.52, 35.00, 36.37 Tasks: 643 total, 36 running, 607 sleeping, 0 stopped, 0 zombie %Cpu(s): 58.9 us, 3.7 sy, 1.7 ni, 34.0 id, 0.4 wa, 0.0 hi, 1.3 si, 0.0 st KiB Mem : 26412424+total, 7072312 free, 22974694+used, 27304972 buff/cache KiB Swap: 3996668 total, 3955448 free, 41220 used, 26503692 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 19980 postgres 20 0 0.208t 26700 11844 R 36.2 0.0 2:36.19 postgres: ui.app ui 127.0.0.1(44645) UPDATE 16690 postgres 20 0 0.208t 26220 11908 R 33.9 0.0 2:59.41 postgres: ui.app ui 127.0.0.1(44435) SELECT 19982 postgres 20 0 0.208t 25576 11844 R 30.6 0.0 2:48.58 postgres: ui.app ui 127.0.0.1(44647) SELECT 727 postgres 20 0 0.208t 38888 11908 S 29.3 0.0 5:26.45 postgres: ui.app ui 127.0.0.1(43493) SELECT 18475 postgres 20 0 0.208t 26720 11844 R 29.3 0.0 2:54.66 postgres: ui.app ui 127.0.0.1(44537) SELECT 2181 postgres 0 -20 43972 8548 2448 R 28.6 0.0 30226:12 /usr/sbin/pgbouncer /etc/pgbouncer/pgbouncer.ini 9057 postgres 39 19 0.208t 19672 11540 R 27.0 0.0 3:28.95 postgres: cron.app ui 127.0.0.1(43997) UPDATE 21995 postgres 20 0 0.208t 34644 11688 R 26.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(34412) SELECT 10393 postgres 39 19 0.208t 66748 11560 R 26.3 0.0 3:37.78 postgres: cron.app ui 127.0.0.1(44047) SELECT 18180 postgres 20 0 0.208t 27032 11844 S 26.3 0.0 2:44.31 postgres: ui.app ui 127.0.0.1(44503) SELECT 22109 postgres 20 0 0.208t 31736 11888 R 25.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(44628) SELECT 18480 postgres 20 0 0.208t 28400 11844 S 25.0 0.0 2:45.62 postgres: ui.app ui 127.0.0.1(44547) SELECT 18481 postgres 39 19 0.208t 17620 11432 R 25.0 0.0 2:27.73 postgres: cron.app ui 127.0.0.1(44549) UPDATE 19979 postgres 20 0 0.208t 26448 11888 R 25.0 0.0 2:37.60 postgres: ui.app ui 127.0.0.1(44643) SELECT 21961 postgres 20 0 0.208t 32332 11716 S 24.6 0.0 2:03.02 postgres: ui.app ui 127.0.0.1(29205) SELECT 21844 postgres 20 0 0.208t 31312 11716 R 24.3 0.0 2:03.92 postgres: ui.app ui 127.0.0.1(64894) SELECT 21892 postgres 39 19 0.208t 17088 11432 R 24.3 0.0 2:09.89 postgres: cron.app ui 127.0.0.1(44759) SELECT 21933 postgres 20 0 0.208t 32908 11888 R 24.3 0.0 2:03.83 postgres: ui.app ui 127.0.0.1(57208) SELECT 22037 postgres 20 0 0.208t 32348 11688 S 24.3 0.0 2:03.61 postgres: ui.app ui 127.0.0.1(40971) SELECT 22099 postgres 20 0 0.208t 31252 11688 R 24.3 0.0 2:02.11 postgres: ui.app ui 127.0.0.1(17933) SELECT 22998 postgres 20 0 0.208t 31660 11716 R 24.3 0.0 2:02.06 postgres: ui.app ui 127.0.0.1(50091) BIND 21971 postgres 20 0 0.208t 32684 11752 R 24.0 0.0 2:03.68 postgres: ui.app ui 127.0.0.1(60455) SELECT 22073 postgres 20 0 0.208t 30188 11688 R 24.0 0.0 2:02.77 postgres: ui.app ui 127.0.0.1(51742) UPDATE
17. 02 dataegret.com top - 15:11:35 up 219 days, 23:42, 2 users, load average: 35.52, 35.00, 36.37 Tasks: 643 total, 36 running, 607 sleeping, 0 stopped, 0 zombie %Cpu(s): 58.9 us, 3.7 sy, 1.7 ni, 34.0 id, 0.4 wa, 0.0 hi, 1.3 si, 0.0 st KiB Mem : 26412424+total, 7072312 free, 22974694+used, 27304972 buff/cache KiB Swap: 3996668 total, 3955448 free, 41220 used, 26503692 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 19980 postgres 20 0 0.208t 26700 11844 R 36.2 0.0 2:36.19 postgres: ui.app ui 127.0.0.1(44645) UPDATE 16690 postgres 20 0 0.208t 26220 11908 R 33.9 0.0 2:59.41 postgres: ui.app ui 127.0.0.1(44435) SELECT 19982 postgres 20 0 0.208t 25576 11844 R 30.6 0.0 2:48.58 postgres: ui.app ui 127.0.0.1(44647) SELECT 727 postgres 20 0 0.208t 38888 11908 S 29.3 0.0 5:26.45 postgres: ui.app ui 127.0.0.1(43493) SELECT 18475 postgres 20 0 0.208t 26720 11844 R 29.3 0.0 2:54.66 postgres: ui.app ui 127.0.0.1(44537) SELECT 2181 postgres 0 -20 43972 8548 2448 R 28.6 0.0 30226:12 /usr/sbin/pgbouncer /etc/pgbouncer/pgbouncer.ini 9057 postgres 39 19 0.208t 19672 11540 R 27.0 0.0 3:28.95 postgres: cron.app ui 127.0.0.1(43997) UPDATE 21995 postgres 20 0 0.208t 34644 11688 R 26.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(34412) SELECT 10393 postgres 39 19 0.208t 66748 11560 R 26.3 0.0 3:37.78 postgres: cron.app ui 127.0.0.1(44047) SELECT 18180 postgres 20 0 0.208t 27032 11844 S 26.3 0.0 2:44.31 postgres: ui.app ui 127.0.0.1(44503) SELECT 22109 postgres 20 0 0.208t 31736 11888 R 25.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(44628) SELECT 18480 postgres 20 0 0.208t 28400 11844 S 25.0 0.0 2:45.62 postgres: ui.app ui 127.0.0.1(44547) SELECT 18481 postgres 39 19 0.208t 17620 11432 R 25.0 0.0 2:27.73 postgres: cron.app ui 127.0.0.1(44549) UPDATE 19979 postgres 20 0 0.208t 26448 11888 R 25.0 0.0 2:37.60 postgres: ui.app ui 127.0.0.1(44643) SELECT 21961 postgres 20 0 0.208t 32332 11716 S 24.6 0.0 2:03.02 postgres: ui.app ui 127.0.0.1(29205) SELECT 21844 postgres 20 0 0.208t 31312 11716 R 24.3 0.0 2:03.92 postgres: ui.app ui 127.0.0.1(64894) SELECT 21892 postgres 39 19 0.208t 17088 11432 R 24.3 0.0 2:09.89 postgres: cron.app ui 127.0.0.1(44759) SELECT 21933 postgres 20 0 0.208t 32908 11888 R 24.3 0.0 2:03.83 postgres: ui.app ui 127.0.0.1(57208) SELECT 22037 postgres 20 0 0.208t 32348 11688 S 24.3 0.0 2:03.61 postgres: ui.app ui 127.0.0.1(40971) SELECT 22099 postgres 20 0 0.208t 31252 11688 R 24.3 0.0 2:02.11 postgres: ui.app ui 127.0.0.1(17933) SELECT 22998 postgres 20 0 0.208t 31660 11716 R 24.3 0.0 2:02.06 postgres: ui.app ui 127.0.0.1(50091) BIND 21971 postgres 20 0 0.208t 32684 11752 R 24.0 0.0 2:03.68 postgres: ui.app ui 127.0.0.1(60455) SELECT 22073 postgres 20 0 0.208t 30188 11688 R 24.0 0.0 2:02.77 postgres: ui.app ui 127.0.0.1(51742) UPDATE
18. 02 dataegret.com top - 15:11:35 up 219 days, 23:42, 2 users, load average: 35.52, 35.00, 36.37 Tasks: 643 total, 36 running, 607 sleeping, 0 stopped, 0 zombie %Cpu(s): 58.9 us, 3.7 sy, 1.7 ni, 34.0 id, 0.4 wa, 0.0 hi, 1.3 si, 0.0 st KiB Mem : 26412424+total, 7072312 free, 22974694+used, 27304972 buff/cache KiB Swap: 3996668 total, 3955448 free, 41220 used, 26503692 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 19980 postgres 20 0 0.208t 26700 11844 R 36.2 0.0 2:36.19 postgres: ui.app ui 127.0.0.1(44645) UPDATE 16690 postgres 20 0 0.208t 26220 11908 R 33.9 0.0 2:59.41 postgres: ui.app ui 127.0.0.1(44435) SELECT 19982 postgres 20 0 0.208t 25576 11844 R 30.6 0.0 2:48.58 postgres: ui.app ui 127.0.0.1(44647) SELECT 727 postgres 20 0 0.208t 38888 11908 S 29.3 0.0 5:26.45 postgres: ui.app ui 127.0.0.1(43493) SELECT 18475 postgres 20 0 0.208t 26720 11844 R 29.3 0.0 2:54.66 postgres: ui.app ui 127.0.0.1(44537) SELECT 2181 postgres 0 -20 43972 8548 2448 R 28.6 0.0 30226:12 /usr/sbin/pgbouncer /etc/pgbouncer/pgbouncer.ini 9057 postgres 39 19 0.208t 19672 11540 R 27.0 0.0 3:28.95 postgres: cron.app ui 127.0.0.1(43997) UPDATE 21995 postgres 20 0 0.208t 34644 11688 R 26.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(34412) SELECT 10393 postgres 39 19 0.208t 66748 11560 R 26.3 0.0 3:37.78 postgres: cron.app ui 127.0.0.1(44047) SELECT 18180 postgres 20 0 0.208t 27032 11844 S 26.3 0.0 2:44.31 postgres: ui.app ui 127.0.0.1(44503) SELECT 22109 postgres 20 0 0.208t 31736 11888 R 25.6 0.0 2:04.17 postgres: ui.app ui 127.0.0.1(44628) SELECT 18480 postgres 20 0 0.208t 28400 11844 S 25.0 0.0 2:45.62 postgres: ui.app ui 127.0.0.1(44547) SELECT 18481 postgres 39 19 0.208t 17620 11432 R 25.0 0.0 2:27.73 postgres: cron.app ui 127.0.0.1(44549) UPDATE 19979 postgres 20 0 0.208t 26448 11888 R 25.0 0.0 2:37.60 postgres: ui.app ui 127.0.0.1(44643) SELECT 21961 postgres 20 0 0.208t 32332 11716 S 24.6 0.0 2:03.02 postgres: ui.app ui 127.0.0.1(29205) SELECT 21844 postgres 20 0 0.208t 31312 11716 R 24.3 0.0 2:03.92 postgres: ui.app ui 127.0.0.1(64894) SELECT 21892 postgres 39 19 0.208t 17088 11432 R 24.3 0.0 2:09.89 postgres: cron.app ui 127.0.0.1(44759) SELECT 21933 postgres 20 0 0.208t 32908 11888 R 24.3 0.0 2:03.83 postgres: ui.app ui 127.0.0.1(57208) SELECT 22037 postgres 20 0 0.208t 32348 11688 S 24.3 0.0 2:03.61 postgres: ui.app ui 127.0.0.1(40971) SELECT 22099 postgres 20 0 0.208t 31252 11688 R 24.3 0.0 2:02.11 postgres: ui.app ui 127.0.0.1(17933) SELECT 22998 postgres 20 0 0.208t 31660 11716 R 24.3 0.0 2:02.06 postgres: ui.app ui 127.0.0.1(50091) BIND 21971 postgres 20 0 0.208t 32684 11752 R 24.0 0.0 2:03.68 postgres: ui.app ui 127.0.0.1(60455) SELECT 22073 postgres 20 0 0.208t 30188 11688 R 24.0 0.0 2:02.77 postgres: ui.app ui 127.0.0.1(51742) UPDATE
19. iostat – смотрим нагрузку на диски: • %util – утилизация устройств. • await – отзывчивость устройств. • Пропускная способность в MB/s и IOPS'ах. Проверка утилизации ресурсов 02 dataegret.com
20. 02 dataegret.com # iostat -x -m 1 avg-cpu: %user %nice %system %iowait %steal %idle 29.42 0.00 8.71 43.45 0.00 18.43 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sdb 0.00 1.00 0.00 2.00 0.00 0.01 12.00 0.00 0.00 0.00 0.00 0.00 0.00 sde 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 sdd 0.00 0.00 0.00 19.00 0.00 8.13 876.63 0.26 13.68 0.00 13.68 6.11 11.60 sdf 1.00 0.00 2106.00 4.00 88.28 0.08 85.76 15.63 7.30 7.32 0.00 0.47 100.00 sdc 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-2 0.00 0.00 2121.00 4.00 88.46 0.08 85.33 15.69 7.26 7.27 0.00 0.47 100.40 dm-3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-4 0.00 0.00 0.00 19.00 0.00 8.13 876.63 0.26 13.47 0.00 13.47 6.11 11.60 dm-5 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-6 0.00 0.00 0.00 3.00 0.00 0.01 8.00 0.00 0.00 0.00 0.00 0.00 0.00
21. 02 dataegret.com # iostat -x -m 1 avg-cpu: %user %nice %system %iowait %steal %idle 29.42 0.00 8.71 43.45 0.00 18.43 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sdb 0.00 1.00 0.00 2.00 0.00 0.01 12.00 0.00 0.00 0.00 0.00 0.00 0.00 sde 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 sdd 0.00 0.00 0.00 19.00 0.00 8.13 876.63 0.26 13.68 0.00 13.68 6.11 11.60 sdf 1.00 0.00 2106.00 4.00 88.28 0.08 85.76 15.63 7.30 7.32 0.00 0.47 100.00 sdc 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-2 0.00 0.00 2121.00 4.00 88.46 0.08 85.33 15.69 7.26 7.27 0.00 0.47 100.40 dm-3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-4 0.00 0.00 0.00 19.00 0.00 8.13 876.63 0.26 13.47 0.00 13.47 6.11 11.60 dm-5 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dm-6 0.00 0.00 0.00 3.00 0.00 0.01 8.00 0.00 0.00 0.00 0.00 0.00 0.00
22. iotop – как обстоят дела с IO на уровне процессов: • Ввод-вывод per-process. • Продолжение от iostat. Проверка утилизации ресурсов 02 dataegret.com
23. 02 dataegret.com # iotop -Poa Total DISK READ : 38.73 M/s | Total DISK WRITE : 12.37 M/s Actual DISK READ: 38.62 M/s | Actual DISK WRITE: 11.00 M/s PID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND 13025 be/4 postgres 6.40 M 224.00 K 0.00 % 1.24 % postgres: app_user instance_db [local] SELECT 2197 be/3 root 0.00 B 56.00 K 0.00 % 1.00 % [jbd2/sdb1-8] 22403 be/4 postgres 3.98 M 232.00 K 0.00 % 0.60 % postgres: app_backoffice instance_db [local] idle 190966 be/4 postgres 2.00 M 360.00 K 0.00 % 0.49 % postgres: app_user instance_db [local] idle 20272 be/4 root 8.00 K 0.00 B 0.00 % 0.45 % [kworker/u384:1] 77775 be/4 postgres 2.35 M 480.00 K 0.00 % 0.44 % postgres: app_user instance_db [local] idle 57858 be/4 postgres 1160.00 K 1160.00 K 0.00 % 0.38 % postgres: app_user instance_db [local] idle 21605 be/4 postgres 704.00 K 472.00 K 0.00 % 0.34 % postgres: app_user instance_db [local] SELECT 22393 be/4 postgres 192.00 K 6.83 M 0.00 % 0.32 % postgres: api_v1 instance_db [local] idle 73678 be/4 postgres 968.00 K 128.00 K 0.00 % 0.31 % postgres: app_user instance_db [local] idle 35836 be/4 postgres 720.00 K 2.02 M 0.00 % 0.30 % postgres: app_user instance_db [local] idle 154927 idle postgres 173.88 M 0.00 B 0.00 % 0.28 % postgres: autovacuum worker process instance_db 35830 be/4 postgres 384.00 K 1992.00 K 0.00 % 0.25 % postgres: app_user instance_db [local] idle 22396 be/4 postgres 976.00 K 1448.00 K 0.00 % 0.25 % postgres: app_user instance_db [local] idle 35835 be/4 postgres 760.00 K 1992.00 K 0.00 % 0.22 % postgres: app_user instance_db [local] idle 62742 be/4 postgres 1136.00 K 936.00 K 0.00 % 0.22 % postgres: app_backoffice instance_db [local] idle 62000 be/4 postgres 612.00 K 800.00 K 0.00 % 0.21 % postgres: app_user instance_db [local] idle 54678 be/4 root 0.00 B 0.00 B 0.00 % 0.21 % [kworker/u384:0] 66977 idle postgres 172.38 M 0.00 B 0.00 % 0.21 % postgres: autovacuum worker process instance_db 77466 be/4 postgres 56.00 K 2.66 M 0.00 % 0.19 % postgres: api_v1 instance_db [local] idle 49641 be/4 postgres 848.00 K 408.00 K 0.00 % 0.18 % postgres: app_user instance_db [local] idle 51555 be/4 postgres 96.00 K 4.21 M 0.00 % 0.17 % postgres: api_v1 instance_db [local] idle
24. 02 dataegret.com # iotop -Poa Total DISK READ : 38.73 M/s | Total DISK WRITE : 12.37 M/s Actual DISK READ: 38.62 M/s | Actual DISK WRITE: 11.00 M/s PID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND 13025 be/4 postgres 6.40 M 224.00 K 0.00 % 1.24 % postgres: app_user instance_db [local] SELECT 2197 be/3 root 0.00 B 56.00 K 0.00 % 1.00 % [jbd2/sdb1-8] 22403 be/4 postgres 3.98 M 232.00 K 0.00 % 0.60 % postgres: app_backoffice instance_db [local] idle 190966 be/4 postgres 2.00 M 360.00 K 0.00 % 0.49 % postgres: app_user instance_db [local] idle 20272 be/4 root 8.00 K 0.00 B 0.00 % 0.45 % [kworker/u384:1] 77775 be/4 postgres 2.35 M 480.00 K 0.00 % 0.44 % postgres: app_user instance_db [local] idle 57858 be/4 postgres 1160.00 K 1160.00 K 0.00 % 0.38 % postgres: app_user instance_db [local] idle 21605 be/4 postgres 704.00 K 472.00 K 0.00 % 0.34 % postgres: app_user instance_db [local] SELECT 22393 be/4 postgres 192.00 K 6.83 M 0.00 % 0.32 % postgres: api_v1 instance_db [local] idle 73678 be/4 postgres 968.00 K 128.00 K 0.00 % 0.31 % postgres: app_user instance_db [local] idle 35836 be/4 postgres 720.00 K 2.02 M 0.00 % 0.30 % postgres: app_user instance_db [local] idle 154927 idle postgres 173.88 M 0.00 B 0.00 % 0.28 % postgres: autovacuum worker process instance_db 35830 be/4 postgres 384.00 K 1992.00 K 0.00 % 0.25 % postgres: app_user instance_db [local] idle 22396 be/4 postgres 976.00 K 1448.00 K 0.00 % 0.25 % postgres: app_user instance_db [local] idle 35835 be/4 postgres 760.00 K 1992.00 K 0.00 % 0.22 % postgres: app_user instance_db [local] idle 62742 be/4 postgres 1136.00 K 936.00 K 0.00 % 0.22 % postgres: app_backoffice instance_db [local] idle 62000 be/4 postgres 612.00 K 800.00 K 0.00 % 0.21 % postgres: app_user instance_db [local] idle 54678 be/4 root 0.00 B 0.00 B 0.00 % 0.21 % [kworker/u384:0] 66977 idle postgres 172.38 M 0.00 B 0.00 % 0.21 % postgres: autovacuum worker process instance_db 77466 be/4 postgres 56.00 K 2.66 M 0.00 % 0.19 % postgres: api_v1 instance_db [local] idle 49641 be/4 postgres 848.00 K 408.00 K 0.00 % 0.18 % postgres: app_user instance_db [local] idle 51555 be/4 postgres 96.00 K 4.21 M 0.00 % 0.17 % postgres: api_v1 instance_db [local] idle
25. nicstat – смотрим нагрузку на сеть. • %util - утилизация интерфейсов. • Ошибки на интерфейсах. Проверка утилизации ресурсов 02 dataegret.com
26. 02 dataegret.com # nicstat -x -m 1 15:50:58 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 2.50 2.50 512.3 512.3 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.04 0.00 99.87 1.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 20.43 264.5 20533.4 33675.7 0.00 0.00 0.00 0.00 0.00 2.77 br1 14.16 255.1 19051.4 15021.8 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.05 0.00 99.87 1.00 0.00 0.00 0.00 0.00 0.00 0.00 15:50:59 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 2.47 2.47 508.9 508.9 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.02 0.00 65.98 1.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 21.75 352.3 22447.8 42242.3 0.00 0.00 0.00 0.00 0.00 3.69 br1 15.44 339.5 21032.2 16915.3 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.03 0.00 67.98 1.00 0.00 0.00 0.00 0.00 0.00 0.00 15:51:00 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 2.72 2.72 578.8 578.8 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.02 0.00 45.99 1.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 34.06 362.2 30542.5 46948.9 0.00 0.00 0.00 0.00 0.00 3.80 br1 23.44 349.6 28163.2 21896.9 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.02 0.00 46.99 1.00 0.00 0.00 0.00 0.00 0.00 0.00 15:51:01 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 4.16 4.16 870.6 870.6 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.01 0.01 24.02 6.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 71.25 629.3 69202.4 91344.6 0.00 0.00 0.00 0.00 0.00 6.60 br1 57.94 609.5 67075.9 51967.9 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.01 0.01 25.02 6.00 0.00 0.00 0.00 0.00 0.00 0.00
27. 02 dataegret.com # nicstat -x -m 1 15:50:58 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 2.50 2.50 512.3 512.3 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.04 0.00 99.87 1.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 20.43 264.5 20533.4 33675.7 0.00 0.00 0.00 0.00 0.00 2.77 br1 14.16 255.1 19051.4 15021.8 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.05 0.00 99.87 1.00 0.00 0.00 0.00 0.00 0.00 0.00 15:50:59 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 2.47 2.47 508.9 508.9 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.02 0.00 65.98 1.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 21.75 352.3 22447.8 42242.3 0.00 0.00 0.00 0.00 0.00 3.69 br1 15.44 339.5 21032.2 16915.3 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.03 0.00 67.98 1.00 0.00 0.00 0.00 0.00 0.00 0.00 15:51:00 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 2.72 2.72 578.8 578.8 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.02 0.00 45.99 1.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 34.06 362.2 30542.5 46948.9 0.00 0.00 0.00 0.00 0.00 3.80 br1 23.44 349.6 28163.2 21896.9 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.02 0.00 46.99 1.00 0.00 0.00 0.00 0.00 0.00 0.00 15:51:01 RdMbps WrMbps RdPkt WrPkt IErr OErr Coll NoCP Defer %Util lo 4.16 4.16 870.6 870.6 0.00 0.00 0.00 0.00 0.00 0.00 br0 0.01 0.01 24.02 6.00 0.00 0.00 0.00 0.00 0.00 0.00 eno2 71.25 629.3 69202.4 91344.6 0.00 0.00 0.00 0.00 0.00 6.60 br1 57.94 609.5 67075.9 51967.9 0.00 0.00 0.00 0.00 0.00 0.00 eno4 0.01 0.01 25.02 6.00 0.00 0.00 0.00 0.00 0.00 0.00
28. Проверка утилизации ресурсов. Есть ли сейчас пик трафика? – много running процессов. Подозрение на тяжелые запросы – загружены диски. Нагрузка от фоновых процессов базы – загружены диски. Но бывает, что с точки зрения ОС, всё хорошо... Итого 02 dataegret.com
29. А что там внутри ПГ? 03
30. Для проверки хватит: • psql – встроенный cli клиент для postgresql. • stat views – https://www.postgresql.org/docs/10/static/monitoring-stats.html Что использовать 03 dataegret.com
31. Performance Observability Views 03 dataegret.com
32. Самые частые типы проблем: • Криминальная активность (idle транзакции, блокировки). • Тяжелые запросы; частые запросы. • Фоновые процессы (вакуум, чекпоинты, репликация). • Ошибки. Какие могут быть проблемы 03 dataegret.com
33. pg_stat_activity: • Криминальная активность (idle транзакции, блокировки). • Долгие запросы. • Фоновые процессы (вакуум, чекпоинты, репликация). Какие могут быть проблемы 03 dataegret.com
34. pg_stat_activity: • xact_start – время старта транзакции. • query_start – время старта запроса. • state_change – время последнего изменения состояния. • state – состояние. • wait_event_type, wait_event – чего ждет клиент (транзакция, запрос). Трюки с pg_stat_activity 03 dataegret.com
35. pg_stat_activity: • now() - xact_start – возраст транзакции. • now() - query_start – возраст запроса. • now() - state_change – возраст текущего состояния. • state in ('idle in transaction', 'active') – все остальные не интересуют. • wait_event_type, wait_event IS NOT NULL – ожидание. Трюки с pg_stat_activity 03 dataegret.com
36. Криминал: • Долгие idle in transaction. • Долгие запросы (на запись). • Большое количество ожидающих запросов. Что должно вызывать подозрения 03 dataegret.com
37. Что делать: • pg_cancel_backend(), pg_terminate_backend(). • SELECT pg_terminate_backend(pid) FROM pg_stat_activity WHERE … • pg_locks, логи Postgres'а. Что с этим делать? 03 dataegret.com
38. pg_stat_statements: • Выключен по-умолчанию — всегда должен быть включен. • query – текст запроса. • сalls, rows – количество вызовов и строк. • total_time, blk_read_time, blk_write_time – суммарное время выполнения. pg_stat_statements_reset() – сброс статистики. Проблемные запросы 03 dataegret.com
39. EXPLAIN ANALYZE: • План запроса. • Поначалу пугает и требует некоторого изучения. Если хочется большего – auto_explain, pg_badplan. Что делать с запросами? 03 dataegret.com
40. По-умолчанию малоинформативны и вообще непонятно где они: • как узнать где логи? log_directory + log_filename. • log_min_duration_statement – пишем долгие запросы в лог. • log_line_prefix – формат строки лога. • log_lock_waits – логирование блокировок. • log_temp_files – логирование временных файлов. Логи 03 dataegret.com
41. Что искать в логах? • Грепнуть по шаблону 'ERROR|PANIC|FATAL'. • Самые частые ошибки – cat … |grep … |sort |uniq -c |sort -nk1 pgBadger – штука для анализа логов. Логи 03 dataegret.com
42. Смотрим что творится в ОС: • Что по утилизации ресурсов — top, iostat, iotop, nicstat. Затем заглядываем в Postgres: • Проверяем на предмет криминальной активности – pg_stat_activity. • Выявляем жадные до ресурсов запросы – pg_stat_statements. • В случае проблем с фоновыми процессами – читать документацию. И не забываем про логи: • Ошибки, блокировки, дедлоки. Что в итоге 03 dataegret.com
43. Thanks for watching! dataegret.com alexey.lesovsky@dataegret.com
44. Thanks for watching! dataegret.com alexey.lesovsky@dataegret.com