|
|
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Доброй ночи. База на postgres 9.2, сейчас 461G, партицирование, при чём не по времени, так что БОЛЬШИХ таблиц сотни и изрядная часть из них дописывается всё время. Периодически (раньше раз в пару месяцев гдето) слетали индексы. реиндекс с вакуумом решали проблему. Последний раз работало без реиндекса больше полгода, но вчера загрузка дисков 100%, вобщем как раньше, когда индекс слетал. Остановил всё что с базой работало, запустил REINDEX DATABASE, и вот, он уже больше 6 часов пашет. есть загрузка в районе 50% и по CPU и по винтам. места в разделе полно (17% занято), рейд 5. Дефрагментация (e4defrag) не предлагалась. Ubuntu Linux 12.04, сервер естественно. какую ещё нужно инфу - спрашивайте. Вобщем, раньше, максимум было 3.5 часа вместе с вакуумом. А тут один реиндекс бесконечный. Чтото не то. Предложите что ни будь, пожалуйста. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 11.09.2014, 04:36:30 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel, какое значение стоит в maintenance_work_mem и сколько установлено памяти? ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 11.09.2014, 09:24:23 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel как раньше, когда индекс слетал Если в вашей базе повреждается индекс, что-то не в порядке с железом. В любом случае, это не повод для reindex database. Вы можете сделать reindex конкретного индекса, или создать новый, а потом удалить старый. Как правило, это много быстрее. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 11.09.2014, 10:25:36 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Всех прошу прощения за беспокойство. реиндекс завершился через 11 часов. База работает. То что с периодическим падением индексов надо чтото делать - отдельный вопрос. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 11.09.2014, 10:59:56 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Alexiusкакое значение стоит в maintenance_work_mem и сколько установлено памяти? Памяти 16G shared_buffers = 2GB work_mem = 64MB maintenance_work_mem = 2GB ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 11.09.2014, 21:00:45 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Что бы не заводить новую тему спрошу здесь же, т.к. всё про эту же базу (пока база ещё работает). Дело в том, что основные (большие) таблицы базы только заполняются (INSERT), ну и просматриваются конечно. Но UPDATE и DELETE на них не делается никогда. Таблицы хранят данные мониторинга, каждые по своему объекту (заполняются параллельно). Через некоторое время (месяцы) ненужные таблицы пользователи удаляют (для них они объекты мониторинга). И создание таблиц (с индексами, конечно) и удаление, через хранимки. Так вот, какие профилактические действия стОит делать с такой базой? Имеет ли в таком случае регулярный VACUUM FULL ANALYZE / CLUSTER ? Или достаточно просто ANALYZE ? В базе иногда слетают индексы (см. стартовое сообщение темы), это лечится REINDEX DATABASE. Отчего (кроме бедблоков) такое может быть? Как лечить. А то, с ростом базы (460Г) время REINDEX-а становится уже очень большим. Может можно найти какой именно индекс слетел, чтобы быстрее восстановится. Проблема усугубляется тем, что пользователи имеют доступ к серверу, и если он "виснет" (или им кажется что виснет), первым делом нажимают reset на сервере. Я им говорил что этого делать нельзя N раз, бесполезно, так что примем как данное. Предположить что индексы слетают ТОЛЬКО от их ресетов я тоже не могу. Система может работать два месяца без перезагрузок, потом, по непонятной причине, загрузка дисков (sar -d) быстро нарастает до 100%, пользователи делают свои ресеты несколько раз, потом связываются со мной. Я останавливаю приложения работающие с базой, запускаю реиндекс, потом вакуум и этого на какое то время хватает. Что в такой ситуации посоветуете? ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 14.09.2014, 13:07:39 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel, партиционируйте таблицы (по времени). сломайте кнопку ресет на сервере. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 14.09.2014, 13:53:41 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel, Что у Вас с настройками: - autovacuum (подозреваю, что off) - autovacuum_max_workers (подозреваю, что по умолчанию 3) Какой поток был в top, когда наблюдалась повышенная загрузка дисков. Подозреваю, что это был wraparound autovacuum Судя по вопросам, vacuum в ручном режиме не выполнялся. Предполагаю, что у Вас периодически запускался принудительный VACUUM всей базы для предотвращения wraparound транзакций. Из-за этого была экстремально высокая нагрузка к дискам. Поэтому пользователи не могли добраться до своих данных за разумное время. Если мое предположение верно, то Вас следует настроить либо автовакуум, либо ручной вакуум в период обслуживания. Переиндексация не требуется. Если будете настраивать автовакуум, то нужно увеличить число worker автовакуума. Так же можно поднастроить на существенно более агрессивные значения параметров работы автовакуума. Если будете делать ручной вакуум таблиц, то можете не уложиться в окно для технического обслуживания (то есть время работы ручного вакуума порядка нескольких суток). ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 14.09.2014, 14:57:09 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
/\/\/\/\/\/\/\- autovacuum (подозреваю, что off) - autovacuum_max_workers (подозреваю, что по умолчанию 3) autovacuum = on , все настройки вакуума по дефолту, да. /\/\/\/\/\/\/\Какой поток был в top, когда наблюдалась повышенная загрузка дисков. Подозреваю, что это был wraparound autovacuum Грешен. не смотрел. /\/\/\/\/\/\/\Судя по вопросам, vacuum в ручном режиме не выполнялся. Раньше делал VACUUM FULL ANALYZE и CLUSTER. Ещё бы понять в какой последовательности их делать. (Или не делать). Что это такое в документации, и тут на форуме, читал. Но, полагал, что раз UPDATE ... DELETE нет, то часто делать и не надо. Насколько понимаю, я не прав. /\/\/\/\/\/\/\Если будете настраивать автовакуум, то нужно увеличить число worker автовакуума. Так же можно поднастроить на существенно более агрессивные значения параметров работы автовакуума. Из каких критериев эти параметры выбирать? ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 14.09.2014, 15:32:58 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel/\/\/\/\/\/\/\- autovacuum (подозреваю, что off) - autovacuum_max_workers (подозреваю, что по умолчанию 3) autovacuum = on , все настройки вакуума по дефолту, да. AUTOVACUUM можно настраивать для каждой таблицы отдельно. Просмотрите, если он выключен хотя бы для одной, то счетчик транзакций не сбрасывается - именно той таблицей и может держаться. Для таблицы есть опция: WITH ( storage_parameter [= value] [, ... ] ). А в ней параметр: autovacuum_enabled, toast.autovacuum_enabled. Почитайте внимательно. Гадость в том, что через pgAdmin эту опцию посмотреть затруднительно. Лучше смотреть консольным клиентом. AltCtrlDelЧто это такое в документации, и тут на форуме, читал. Но, полагал, что раз UPDATE ... DELETE нет, то часто делать и не надо. Насколько понимаю, я не прав. Наверняка сказать не могу, но посмотрите пункт 4, и в какой момент он у Вас выполняется. AltCtrlDel/\/\/\/\/\/\/\Если будете настраивать автовакуум, то нужно увеличить число worker автовакуума. Так же можно поднастроить на существенно более агрессивные значения параметров работы автовакуума. Из каких критериев эти параметры выбирать? Методом научного тыка. Максим Богук приводил эти параметры на форуме несколько раз (например, здесь: 16288463 ). Можно поиграть параметрами из раздела 18.4.4. Эти параметры можно настроить для каждой таблицы отдельно. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 14.09.2014, 17:37:17 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
/\/\/\/\/\/\/\AUTOVACUUM можно настраивать для каждой таблицы отдельно. Просмотрите, если он выключен хотя бы для одной Там, из больших, две партицированные таблицы, у каждой по 100+ партиций. Они все одинаковые, естественно, параметры autovacuum_* не используются. /\/\/\/\/\/\/\Наверняка сказать не могу, но посмотрите пункт 4, и в какой момент он у Вас выполняется. Тут, вот, я не понял, про какой 4-ый пункт Вы говорите. В остальном, спасибо за подробное объяснение. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 14.09.2014, 18:45:13 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel..., естественно, ... На этом погорело очень много людей. Для меня фраза является детектором необходимости тщательной проверки. авторPostgreSQL's VACUUM command has to process each table on a regular basis for several reasons: 1. To recover or reuse disk space occupied by updated or deleted rows. 2. To update data statistics used by the PostgreSQL query planner. 3. To update the visibility map, which speeds up index-only scans. 4. To protect against loss of very old data due to transaction ID wraparound. Это из документации , параграф 23.1.1. Там же ниже указаны запросы для анализа frozenid. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 14.09.2014, 19:09:17 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
/\/\/\/\/\/\/\Какой поток был в top, когда наблюдалась повышенная загрузка дисков. Подозреваю, что это был wraparound autovacuum "Зависло" снова. Загрузка винтов под 100%, сервер не перезагружали - обратились ко мне. Грузил не автовакуум, а рабочие процессы постгреса и апач (там веб-приложение). по SELECT ... FROM pg_stat_activity видна туча повисших SELECT-ов. Туча, как я понимаю от приложения. Запросы были чаще чем время на ответ. Остановил всё что с базой работает. Перезапустил постгрес. Запустил всё что с базой работает. Очень быстро (минуты) начались тормоза опять. Остановил апач и пр., запустил VACUUM FULL ANALYZE, он работал 5 часов. Я не дождался, перезапустил постгрес, запустил скрипт Код: plsql 1. 2. 3. REINDEX выполнялся 5 часов. Остальное 3 часа. Сейчас система работает. Не знаю что делать. Кстати, пробовал ранее Код: html 1. 2. 3. 4. 5. 6. 7. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 18.09.2014, 11:27:16 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel/\/\/\/\/\/\/\Какой поток был в top, когда наблюдалась повышенная загрузка дисков. Подозреваю, что это был wraparound autovacuum "Зависло" снова. Загрузка винтов под 100%, сервер не перезагружали - обратились ко мне. Грузил не автовакуум, а рабочие процессы постгреса и апач (там веб-приложение). по SELECT ... FROM pg_stat_activity видна туча повисших SELECT-ов. Туча, как я понимаю от приложения. Запросы были чаще чем время на ответ. Остановил всё что с базой работает. Перезапустил постгрес. Запустил всё что с базой работает. Очень быстро (минуты) начались тормоза опять. Остановил апач и пр., запустил VACUUM FULL ANALYZE, он работал 5 часов. Я не дождался, перезапустил постгрес, запустил скрипт Код: plsql 1. 2. 3. REINDEX выполнялся 5 часов. Остальное 3 часа. Сейчас система работает. Не знаю что делать. Кстати, пробовал ранее Код: html 1. 2. 3. 4. 5. 6. 7. вполне возможно что у вас база уже доросла до размера при котором имеющийся сервер просто не справляется... vacuum full/reindex позволяет получить те самые 10-20% которых не хватает... дальше будет хуже вполне возможно. 1)какой у вас размер базы 2)сколько памяти на сервере и сколько выделено shared buffers 3)живет ли еще что то на сервере кроме базы 4)какая дисковая подсистема (сколько дисков в рейде, какие, какой рейд контроллер, есть ли кеш с батарейкой на борту контроллера)? Про autovacuum надо дать ему отработать 1 раз до конца потом он будет сильно меньше грузить... попробуйте или запустить его в ночное время или поднять autovacuum_vacuum_cost_delay до 10ms и уменьшить autovacuum_max_workers до 4рех например. --Maxim Boguk www.postgresql-consulting.ru ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 18.09.2014, 11:49:39 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Maxim Bogukкакой у вас размер базы 461Г Maxim Bogukсколько памяти на сервере и сколько выделено shared buffers Real memory 15.65 GB total, 2.54 GB used Virtual memory 7.45 GB total, 39.05 MB used shared_buffers = 2GB Maxim Bogukживет ли еще что то на сервере кроме базы Приложение которое пишет в базу через постгресовские команды COPY, восновном, оно практически ничего не грузит - 0.1%. Apache httpd c специальным модом апача в котором реализована серверная часть системы. Апач сейчас 20% CPU грузит. Сервер под одну задачу (цель) выделен. Maxim Bogukкакая дисковая подсистема (сколько дисков в рейде, какие, какой рейд контроллер, есть ли кеш с батарейкой на борту контроллера)? ext4. Сервер SRV-Legion 1U 2xXeon® 5500/5600\12xDDR3 ECC REG (192Gb/1333)\VGA Matrox 8Mb\Onboard Intel SW RAID 0, 1, 10\2*PCI-E 8X\4xUSB\2xGigabit Ethernet (Intel 82576)\до 4 HDD c горячей заменой\Рельсы\PSU 2x650W c резервированием\IPMI+IPKVM 1 шт Intel Xeon E5620 (2.4GHz // QPI 5.86 GT/s // DDR3 1066MHz, cache 12MB, Quad, TB, HT, 80W) 2 шт Жесткий диск 2TB SATA II 7200RPM Enterprise 4 шт Контроллер LSI 9240 4i (2MB, 4xSAS/SATA channels, RAID0, 1, 10, 5 no BBU support) 1 шт Модуль памяти 4GB ECC 1333 DDR3 Reg 8 шт Maxim BogukПро autovacuum надо дать ему отработать 1 раз до конца потом он будет сильно меньше грузить... попробуйте или запустить его в ночное время или поднять autovacuum_vacuum_cost_delay до 10ms и уменьшить autovacuum_max_workers до 4рех например. Система подразумевает работу почти в режиме 24/365. Что ночью, что днём - без разницы. Попробую настроить так. Не понял такой момент. Если только что выполнился VACUUM FULL, то что же делать вначале автовакууму, раз он сразу грузить начинает? Что истощаются ресурсы сервера? Ну, незнаю. Слишком резко загрузка подскакивает. Обычно 2-4 % загрузка дисков, и потом, сразу 95%. Поскольку происходит уже два раза в сутки, посоветуйте что посмотреть во время такой ситуации. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 18.09.2014, 18:44:25 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDelMaxim Bogukкакой у вас размер базы 461Г Maxim Bogukсколько памяти на сервере и сколько выделено shared buffers Real memory 15.65 GB total, 2.54 GB used Virtual memory 7.45 GB total, 39.05 MB used shared_buffers = 2GB Maxim Bogukживет ли еще что то на сервере кроме базы Приложение которое пишет в базу через постгресовские команды COPY, восновном, оно практически ничего не грузит - 0.1%. Apache httpd c специальным модом апача в котором реализована серверная часть системы. Апач сейчас 20% CPU грузит. Сервер под одну задачу (цель) выделен. Maxim Bogukкакая дисковая подсистема (сколько дисков в рейде, какие, какой рейд контроллер, есть ли кеш с батарейкой на борту контроллера)? ext4. Сервер SRV-Legion 1U 2xXeon® 5500/5600\12xDDR3 ECC REG (192Gb/1333)\VGA Matrox 8Mb\Onboard Intel SW RAID 0, 1, 10\2*PCI-E 8X\4xUSB\2xGigabit Ethernet (Intel 82576)\до 4 HDD c горячей заменой\Рельсы\PSU 2x650W c резервированием\IPMI+IPKVM 1 шт Intel Xeon E5620 (2.4GHz // QPI 5.86 GT/s // DDR3 1066MHz, cache 12MB, Quad, TB, HT, 80W) 2 шт Жесткий диск 2TB SATA II 7200RPM Enterprise 4 шт Контроллер LSI 9240 4i (2MB, 4xSAS/SATA channels, RAID0, 1, 10, 5 no BBU support) 1 шт Модуль памяти 4GB ECC 1333 DDR3 Reg 8 шт Maxim BogukПро autovacuum надо дать ему отработать 1 раз до конца потом он будет сильно меньше грузить... попробуйте или запустить его в ночное время или поднять autovacuum_vacuum_cost_delay до 10ms и уменьшить autovacuum_max_workers до 4рех например. Система подразумевает работу почти в режиме 24/365. Что ночью, что днём - без разницы. Попробую настроить так. Не понял такой момент. Если только что выполнился VACUUM FULL, то что же делать вначале автовакууму, раз он сразу грузить начинает? Что истощаются ресурсы сервера? Ну, незнаю. Слишком резко загрузка подскакивает. Обычно 2-4 % загрузка дисков, и потом, сразу 95%. Поскольку происходит уже два раза в сутки, посоветуйте что посмотреть во время такой ситуации. 1) log_checkpoints on; и смотреть не совпадают ли пики с окончанием checkpoints (как они у вас кстати настроены)? 2)такой размер базы на таких дисках и рейде жить не будет если в него пишут более менее активно... вам и памяти 64 хотябы надо и дисков штук 8 SAS 15000RPM на нормальной рейд контроллере с батарейкой (в общем нормальный сервер под базу а не low end для веба... нормальые рейды и SAS диски придумали не для того чтобы денег больше снимать а потому что это другой уровень производительности) ну или 2-4 intel s3700 SSD 800GB в рейд тоже поможет даже лучше чем SAS диски (по IOPS будет на 3-4 порядка больше чем ваша текущая дисковая система). 3)во время проблемы cat /proc/meminfo и смотреть что там в районе Dirty: 18372 kB Writeback: 0 kB (и лучше несколько раз посмотреть) 4)iostat -x -m 1 во время проблемы отсчетов 10-20 5)вывод SELECT (now() - pg_stat_activity.xact_start) AS age, pg_stat_activity.datname, pg_stat_activity.procpid, pg_stat_activity.usename, pg_stat_activity.waiting, pg_stat_activity.query_start, pg_stat_activity.client_addr, pg_stat_activity.client_port, pg_stat_activity.current_query FROM pg_stat_activity WHERE ((pg_stat_activity.xact_start IS NOT NULL) AND ((now() - pg_stat_activity.xact_start) > '00:00:10'::interval)) and pg_stat_activity.procpid<>pg_backend_pid() ORDER BY pg_stat_activity.xact_start; во время проблемыюююю особенно интересны первые 5 строк. после этого можно будет думать. Варианты: 1)antiwraparound autovacuum включается или 2)fsync в конце checkpoint диски перегружает или 3)просто сервер не тянет и его каким то запросом или парой убивают --Maxim Boguk www.postgresql-consulting.ru ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 18.09.2014, 19:05:54 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Maxim Boguk1) log_checkpoints on; и смотреть не совпадают ли пики с окончанием checkpoints (как они у вас кстати настроены)? checkpoint_segments = 8 остальное дефолтом Включил логирование, но что там смотреть? :( Проблема начиналась с 16:55 2014-09-20 15:35:26 SAMT ???????: checkpoint complete: wrote 777 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=77.527 s, sync=0.333 s, total=77.917 s; sync files=91, longest=0.048 s, average=0.003 s 2014-09-20 15:39:08 SAMT ???????: checkpoint starting: time 2014-09-20 15:41:38 SAMT ???????: checkpoint complete: wrote 1566 buffers (0.6%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=149.173 s, sync=0.159 s, total=149.351 s; sync files=95, longest=0.030 s, average=0.001 s 2014-09-20 15:44:08 SAMT ???????: checkpoint starting: time 2014-09-20 15:45:26 SAMT ???????: checkpoint complete: wrote 779 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=77.884 s, sync=0.200 s, total=78.104 s; sync files=94, longest=0.053 s, average=0.002 s 2014-09-20 15:49:08 SAMT ???????: checkpoint starting: time 2014-09-20 15:50:08 SAMT ???????: checkpoint complete: wrote 598 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=59.639 s, sync=0.094 s, total=59.801 s; sync files=96, longest=0.014 s, average=0.000 s 2014-09-20 15:54:08 SAMT ???????: checkpoint starting: time 2014-09-20 15:55:07 SAMT ???????: checkpoint complete: wrote 592 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=59.127 s, sync=0.174 s, total=59.307 s; sync files=94, longest=0.042 s, average=0.001 s 2014-09-20 15:59:08 SAMT ???????: checkpoint starting: time 2014-09-20 16:00:31 SAMT ???????: checkpoint complete: wrote 822 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=82.120 s, sync=0.189 s, total=82.394 s; sync files=90, longest=0.052 s, average=0.002 s 2014-09-20 16:04:08 SAMT ???????: checkpoint starting: time 2014-09-20 16:05:00 SAMT ???????: checkpoint complete: wrote 517 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=51.811 s, sync=0.197 s, total=52.032 s; sync files=84, longest=0.021 s, average=0.002 s 2014-09-20 16:09:08 SAMT ???????: checkpoint starting: time 2014-09-20 16:10:02 SAMT ???????: checkpoint complete: wrote 540 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=53.950 s, sync=0.127 s, total=54.082 s; sync files=84, longest=0.027 s, average=0.001 s 2014-09-20 16:14:08 SAMT ???????: checkpoint starting: time 2014-09-20 16:15:02 SAMT ???????: checkpoint complete: wrote 534 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=53.283 s, sync=0.213 s, total=53.526 s; sync files=82, longest=0.041 s, average=0.002 s 2014-09-20 16:19:08 SAMT ???????: checkpoint starting: time 2014-09-20 16:20:03 SAMT ???????: checkpoint complete: wrote 554 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=55.448 s, sync=0.231 s, total=55.748 s; sync files=86, longest=0.037 s, average=0.002 s 2014-09-20 16:24:09 SAMT ???????: checkpoint starting: time 2014-09-20 16:25:04 SAMT ???????: checkpoint complete: wrote 551 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=55.106 s, sync=0.422 s, total=55.591 s; sync files=85, longest=0.049 s, average=0.004 s 2014-09-20 16:29:09 SAMT ???????: checkpoint starting: time 2014-09-20 16:30:05 SAMT ???????: checkpoint complete: wrote 556 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=55.469 s, sync=0.186 s, total=55.686 s; sync files=80, longest=0.031 s, average=0.002 s 2014-09-20 16:34:09 SAMT ???????: checkpoint starting: time 2014-09-20 16:35:03 SAMT ???????: checkpoint complete: wrote 538 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=53.849 s, sync=0.123 s, total=53.998 s; sync files=85, longest=0.023 s, average=0.001 s 2014-09-20 16:39:09 SAMT ???????: checkpoint starting: time 2014-09-20 16:40:05 SAMT ???????: checkpoint complete: wrote 557 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=55.585 s, sync=0.256 s, total=55.898 s; sync files=88, longest=0.030 s, average=0.002 s 2014-09-20 16:44:09 SAMT ???????: checkpoint starting: time 2014-09-20 16:45:03 SAMT ???????: checkpoint complete: wrote 541 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=53.931 s, sync=0.398 s, total=54.369 s; sync files=93, longest=0.142 s, average=0.004 s 2014-09-20 16:49:10 SAMT ???????: checkpoint starting: time 2014-09-20 16:51:41 SAMT ???????: checkpoint complete: wrote 2625 buffers (1.0%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=149.892 s, sync=0.979 s, total=150.965 s; sync files=105, longest=0.241 s, average=0.009 s 2014-09-20 16:54:10 SAMT ???????: checkpoint starting: time 2014-09-20 16:55:08 SAMT ???????: checkpoint complete: wrote 577 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=57.724 s, sync=0.262 s, total=58.041 s; sync files=97, longest=0.058 s, average=0.002 s 2014-09-20 16:59:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:00:42 SAMT ???????: checkpoint complete: wrote 914 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=91.479 s, sync=0.289 s, total=91.774 s; sync files=99, longest=0.042 s, average=0.002 s 2014-09-20 17:04:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:05:16 SAMT ???????: checkpoint complete: wrote 661 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=66.234 s, sync=0.283 s, total=66.598 s; sync files=94, longest=0.053 s, average=0.003 s 2014-09-20 17:09:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:09:48 SAMT ???????: checkpoint complete: wrote 367 buffers (0.1%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=36.735 s, sync=0.464 s, total=37.217 s; sync files=84, longest=0.107 s, average=0.005 s 2014-09-20 17:14:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:14:56 SAMT ???????: checkpoint complete: wrote 457 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=46.197 s, sync=0.412 s, total=46.642 s; sync files=82, longest=0.071 s, average=0.005 s 2014-09-20 17:19:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:20:12 SAMT ???????: checkpoint complete: wrote 613 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=61.261 s, sync=0.441 s, total=61.718 s; sync files=90, longest=0.074 s, average=0.004 s 2014-09-20 17:24:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:24:55 SAMT ???????: checkpoint complete: wrote 442 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=44.154 s, sync=0.341 s, total=44.572 s; sync files=84, longest=0.091 s, average=0.004 s 2014-09-20 17:29:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:30:41 SAMT ???????: checkpoint complete: wrote 897 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=90.633 s, sync=0.380 s, total=91.051 s; sync files=96, longest=0.053 s, average=0.003 s 2014-09-20 17:34:10 SAMT ???????: checkpoint starting: time 2014-09-20 17:35:06 SAMT ???????: checkpoint complete: wrote 560 buffers (0.2%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=56.186 s, sync=0.260 s, total=56.514 s; sync files=92, longest=0.032 s, average=0.002 s Maxim Boguk3)во время проблемы cat /proc/meminfo и смотреть что там в районе Dirty: 18372 kB Writeback: 0 kB (и лучше несколько раз посмотреть) Dirty: 960 kB Writeback: 0 kB Dirty: 584 kB Writeback: 0 kB Dirty: 804 kB Writeback: 48 kB А вот, кстати, несколько строк по sar -d 00:00:01 DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util 15:35:01 dev8-0 11.18 1.28 319.20 28.66 0.10 8.81 2.65 2.96 15:45:01 dev8-0 7.16 1.25 216.45 30.40 0.09 11.90 3.61 2.58 15:55:01 dev8-0 7.75 7.59 194.04 26.01 0.09 11.29 3.47 2.69 16:05:01 dev8-0 7.24 0.01 187.58 25.90 0.07 9.69 3.27 2.37 16:15:01 dev8-0 6.21 0.43 160.10 25.86 0.07 11.75 3.76 2.33 16:25:01 dev8-0 7.89 4.70 551.06 70.47 0.44 55.30 3.93 3.10 16:35:01 dev8-0 6.95 0.43 174.61 25.17 0.07 10.68 3.70 2.57 16:45:01 dev8-0 8.54 1.49 201.04 23.71 0.06 7.55 2.67 2.28 16:55:01 dev8-0 38.40 903.96 314.22 31.72 0.59 15.29 1.06 4.06 17:05:01 dev8-0 25.93 300.74 190.52 18.95 0.12 4.56 1.58 4.10 17:15:01 dev8-0 1502.55 23934.45 192.22 16.06 1.30 0.87 0.63 95.18 17:25:01 dev8-0 1522.94 24259.18 188.55 16.05 1.37 0.90 0.62 95.12 17:35:01 dev8-0 1461.36 23261.93 251.86 16.09 1.57 1.08 0.65 95.49 и по sar 00:00:01 CPU %user %nice %system %iowait %steal %idle 15:35:01 all 3.27 0.00 0.36 0.14 0.00 96.23 15:45:01 all 4.03 0.00 0.73 0.14 0.00 95.10 15:55:01 all 3.94 0.00 0.70 0.16 0.00 95.20 16:05:01 all 4.28 0.00 0.90 0.13 0.00 94.69 16:15:01 all 4.24 0.00 0.88 0.13 0.00 94.75 16:25:01 all 4.37 0.00 0.87 0.19 0.00 94.57 16:35:01 all 4.10 0.00 0.81 0.13 0.00 94.95 16:45:01 all 4.13 0.00 0.79 0.11 0.00 94.96 16:55:01 all 4.16 0.00 0.79 0.20 0.00 94.84 17:05:01 all 4.37 0.00 0.85 0.31 0.00 94.47 17:15:01 all 5.26 0.00 1.67 11.84 0.00 81.24 17:25:01 all 4.95 0.00 1.55 11.86 0.00 81.64 17:35:01 all 4.72 0.00 1.38 12.04 0.00 81.86 Maxim Boguk4)iostat -x -m 1 во время проблемы отсчетов 10-20 как скажите > iostat -x -m 1 -c 1 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 172.33 22.49 3.74 3.54 76.56 2.72 13.96 2.58 101.14 1.06 20.69 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 172.49 22.49 3.74 3.54 76.50 2.72 13.95 2.58 101.14 1.06 20.70 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 172.58 22.49 3.74 3.54 76.47 2.72 13.94 2.58 101.14 1.06 20.71 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 172.83 22.49 3.74 3.54 76.38 2.72 13.93 2.58 101.14 1.06 20.72 > iostat -x -m 1 -c 1 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 172.86 22.48 3.74 3.54 76.37 2.72 13.92 2.58 101.14 1.06 20.72 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 172.92 22.48 3.74 3.54 76.35 2.72 13.92 2.58 101.14 1.06 20.73 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 172.93 22.48 3.74 3.54 76.34 2.72 13.92 2.58 101.14 1.06 20.73 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.93 0.00 91.28 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 173.00 22.48 3.74 3.54 76.32 2.72 13.91 2.58 101.14 1.06 20.73 avg-cpu: %user %nice %system %iowait %steal %idle 4.14 0.00 0.65 3.94 0.00 91.27 Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.52 5.27 173.83 22.48 3.75 3.54 76.03 2.72 13.85 2.57 101.13 1.06 20.78 Maxim Boguk5)вывод SELECT (now() - pg_stat_activity.xact_start) AS age, pg_stat_activity.datname, pg_stat_activity.procpid, pg_stat_activity.usename, pg_stat_activity.waiting, pg_stat_activity.query_start, pg_stat_activity.client_addr, pg_stat_activity.client_port, pg_stat_activity.current_query FROM pg_stat_activity WHERE ((pg_stat_activity.xact_start IS NOT NULL) AND ((now() - pg_stat_activity.xact_start) > '00:00:10'::interval)) and pg_stat_activity.procpid<>pg_backend_pid() ORDER BY pg_stat_activity.xact_start; ОШИБКА: колонка pg_stat_activity.procpid не существует ОШИБКА: колонка pg_stat_activity.current_query не существует ОШИБКА: колонка pg_stat_activity.procpid Поудаляв все эти колонки получил одну строку age datname usename waiting query_start client_addr client_port 04:33:04.91313 postgres postgres 0 2014-09-20 17:04:53.470526+04 -1 наверное, надо было какойто доппакет установить? ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 20.09.2014, 21:52:49 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel, Ага так... записи у вас на диски почти что нет. Хотя конечно я бы всеравно посоветовал поднять checkpoint_segments до 64 и checkpoint_timeout до 1h и checkpoint_completion_target до 0.9. По факту у вас откуда то прилетает пачка тяжелого линейного чтения (и скорее всего не одна) Почему линейного - 20.000 sector/s ваш рейд может только на линейном чтении давать. Если линейное (и мы предполагаем что это база) - скорее всего seq_scan. Я не обратил внимание что у вас 9.2 тогда как проблема начнется через минут 5 после начала сделайте от postgres: SELECT (now() - pg_stat_activity.xact_start) AS ts_age, pg_stat_activity.state, (now() - pg_stat_activity.query_start) as query_age, (now() - state_change) as change_age, pg_stat_activity.datname, pg_stat_activity.pid, pg_stat_activity.usename, pg_stat_activity.waiting, pg_stat_activity.client_addr, pg_stat_activity.client_port, pg_stat_activity.query FROM pg_stat_activity WHERE ((now() - pg_stat_activity.xact_start) > '00:00:10'::interval) and pg_stat_activity.pid<>pg_backend_pid() ORDER BY pg_stat_activity.xact_start LIMIT 10; Текущая теория - время от времени пользователи или ПО генерируют неожиданный/непроиндексированный запрос который вылетает в база seq scan по нескольким таблицам и начинает перегружать диск. PS: вообще полезно держать log_min_duratuion_statenent скажем в 1000 и анализировать логи базы на предмет длинныз запросов. Много чего интересного сможете узнать. --Maxim Boguk www.postgresql-consulting.ru ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 07:38:24 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Maxim Boguk, прилагаю анализ "зависа" насколько смог. Воздержался от своих выводов. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 13:32:32 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDelMaxim Boguk, прилагаю анализ "зависа" насколько смог. Воздержался от своих выводов. Покажите исходник JSONCURDERRINFO у вас а)партиционирование б)хранимка при этом для сочетания а+б вы совершенно неверно проверяете explain analyze... попробуйте проверить самый первый запрос следуюшим образом вместо explain SELECT s from strdat where did=134 and cid=28624 and datetime<=1411117512 order by datetime desc limit 1 сделайте prepare test(int,int,int) as SELECT s from strdat where did=134 and cid=28624 and datetime<=1411117512 order by datetime desc limit 1 и после этого explain (analyze, costs, buffers, timing) execute qqq(134,28624,1411117512); и покажите что у вас нарисовалось. Аналогично сделайте для первого запроса из GetBottomInfo. Я боюсь что результаты вас неприятно удивят. Если нет - будем смотреть дальше. --Maxim Boguk www.postgresql-consulting.ru ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 13:58:05 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Maxim BogukAltCtrlDelMaxim Boguk, прилагаю анализ "зависа" насколько смог. Воздержался от своих выводов. Покажите исходник JSONCURDERRINFO у вас а)партиционирование б)хранимка при этом для сочетания а+б вы совершенно неверно проверяете explain analyze... попробуйте проверить самый первый запрос следуюшим образом вместо explain SELECT s from strdat where did=134 and cid=28624 and datetime<=1411117512 order by datetime desc limit 1 сделайте prepare test(int,int,int) as SELECT s from strdat where did=134 and cid=28624 and datetime<=1411117512 order by datetime desc limit 1 и после этого explain (analyze, costs, buffers, timing) execute qqq(134,28624,1411117512); и покажите что у вас нарисовалось. Аналогично сделайте для первого запроса из GetBottomInfo. Я боюсь что результаты вас неприятно удивят. Если нет - будем смотреть дальше. --Maxim Boguk www.postgresql-consulting.ru тьфу забыл после copy/paste поправить не Код: plsql 1. а Код: plsql 1. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 13:59:46 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Maxim Boguk, хранимки CREATE OR REPLACE FUNCTION GetBottomInfo(did_ integer) RETURNS SETOF varchar LANGUAGE plpgsql AS $$ DECLARE t integer; BEGIN select max(datetime) into t from dat where did=did_ and cid=0; if t is null then t:=0; end if; RETURN NEXT t; SELECT v into t from dat where did=did_ and cid=32463 order by datetime desc limit 1; if (not found) or (t is null) then t:=0; end if; RETURN NEXT t; END; $$; CREATE OR REPLACE FUNCTION JSONCURDERRINFO(d_id integer, mintime integer, maxtime integer, actionmask integer) RETURNS varchar LANGUAGE plpgsql AS $$ DECLARE r varchar; hname varchar; x real; i integer; BEGIN r:=''; if (actionmask & 1)<>0 then hname:=''; SELECT s into hname from strdat where did=d_id and cid=28624 and datetime<=maxtime order by datetime desc limit 1; if hname is null then hname:=''; end if; r:=r||',"hname":'||JSONQUOTE(hname); end if; if (actionmask & 2)<>0 then x:=0; SELECT v into x from dat where did=d_id and cid=28160 and datetime<=maxtime order by datetime desc limit 1; if x is null then x:=0; end if; r:=r||',"runnum":'||trunc(x); end if; if (actionmask & 4)<>0 then x:=0; SELECT max(deep) into x from dat where did=d_id and cid=0 and datetime between mintime and maxtime; if x is null then x:=0; end if; r:=r||',"bottomdeep":'||trunc(x::numeric,2); end if; if (actionmask & 8)<>0 then x:=0; SELECT v into x from dat where did=d_id and cid=1549 and datetime<=maxtime order by datetime desc limit 1; if x is null then x:=0; end if; r:=r||',"otkl0":'||trunc(x); end if; if (actionmask & 16)<>0 then x:=0; SELECT v into x from dat where did=d_id and cid=1550 and datetime<=maxtime order by datetime desc limit 1; if x is null then x:=0; end if; r:=r||',"dOtkl":'||trunc(x); end if; if (actionmask & 32)<>0 then i:=10; SELECT op into i from dat where did=d_id and datetime<=maxtime order by datetime desc limit 1; if i is null then i:=10; end if; r:=r||',"op":'||i; end if; if (actionmask & 64)<>0 then -- 26.04.2014 x:=0; SELECT v into x from dat where did=d_id and cid=32462 and datetime<=maxtime order by datetime desc limit 1; if x is null then x:=0; end if; r:=r||',"nadzab":'||trunc(x::numeric,2); end if; RETURN r; END; $$; Код: plsql 1. 2. 3. 4. 5. 6. 7. 8. 9. 10. 11. 12. результат PREPARE QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.21 rows=1 width=28) (actual time=0.028..0.028 rows=1 loops=1) Buffers: shared hit=7 -> Result (cost=0.01..11.76 rows=58 width=28) (actual time=0.026..0.026 rows=1 loops=1) Buffers: shared hit=7 -> Merge Append (cost=0.01..11.76 rows=58 width=28) (actual time=0.025..0.025 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=7 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.015..0.015 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime <= 1411117512) AND (cid = 28624)) Buffers: shared hit=4 -> Index Scan Backward using strdat_134_28624 on strdat_134 strdat (cost=0.00..6.76 rows=57 width=19) (actual time=0.009..0.009 rows=1 loops=1) Index Cond: (datetime <= 1411117512) Filter: (did = 134) Buffers: shared hit=3 Total runtime: 0.088 ms (15 rows) PREPARE QUERY PLAN ---------------------------------------------------------------------------------------------------------------------------------------------------------------- Result (cost=0.04..0.05 rows=1 width=0) (actual time=0.045..0.045 rows=1 loops=1) Buffers: shared hit=6 InitPlan 1 (returns $0) -> Limit (cost=0.01..0.04 rows=1 width=4) (actual time=0.043..0.043 rows=1 loops=1) Buffers: shared hit=6 -> Merge Append (cost=0.01..443071.24 rows=12929831 width=4) (actual time=0.043..0.043 rows=1 loops=1) Sort Key: public.dat.datetime Buffers: shared hit=6 -> Index Only Scan Backward using dat_pkey on dat (cost=0.00..4.26 rows=1 width=4) (actual time=0.009..0.009 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime IS NOT NULL) AND (cid = 0)) Heap Fetches: 0 Buffers: shared hit=1 -> Index Scan Backward using dat_134_0 on dat_134 dat (cost=0.00..281444.08 rows=12929830 width=4) (actual time=0.033..0.033 rows=1 loops=1) Index Cond: (datetime IS NOT NULL) Filter: (did = 134) Buffers: shared hit=5 Total runtime: 0.090 ms (17 rows) PREPARE QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.21 rows=1 width=28) (actual time=0.023..0.023 rows=1 loops=1) Buffers: shared hit=3 -> Result (cost=0.01..11.76 rows=58 width=28) (actual time=0.020..0.020 rows=1 loops=1) Buffers: shared hit=3 -> Merge Append (cost=0.01..11.76 rows=58 width=28) (actual time=0.020..0.020 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=3 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.006..0.006 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime <= 1411117512) AND (cid = 28624)) Buffers: shared hit=1 -> Index Scan Backward using strdat_134_28624 on strdat_134 strdat (cost=0.00..6.76 rows=57 width=19) (actual time=0.012..0.012 rows=1 loops=1) Index Cond: (datetime <= 1411117512) Filter: (did = 134) Buffers: shared hit=2 Total runtime: 0.072 ms (15 rows) PREPARE QUERY PLAN ---------------------------------------------------------------------------------------------------------------------------------------------------------------- Result (cost=0.04..0.05 rows=1 width=0) (actual time=0.025..0.025 rows=1 loops=1) Buffers: shared hit=5 InitPlan 1 (returns $0) -> Limit (cost=0.01..0.04 rows=1 width=4) (actual time=0.024..0.024 rows=1 loops=1) Buffers: shared hit=5 -> Merge Append (cost=0.01..443071.24 rows=12929831 width=4) (actual time=0.023..0.023 rows=1 loops=1) Sort Key: public.dat.datetime Buffers: shared hit=5 -> Index Only Scan Backward using dat_pkey on dat (cost=0.00..4.26 rows=1 width=4) (actual time=0.007..0.007 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime IS NOT NULL) AND (cid = 0)) Heap Fetches: 0 Buffers: shared hit=1 -> Index Scan Backward using dat_134_0 on dat_134 dat (cost=0.00..281444.08 rows=12929830 width=4) (actual time=0.015..0.015 rows=1 loops=1) Index Cond: (datetime IS NOT NULL) Filter: (did = 134) Buffers: shared hit=4 Total runtime: 0.068 ms (17 rows) ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 17:56:34 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
AltCtrlDel, Hm а с каким интервалом у вас новые партиции создаются? Нет ли связи между появлением новых партиций в strdat и началом проблем... hm а если сделать вот так вот: --- Т.к. числа 28624 и 0 (коды cid) заданы жёстко (не параметрами), то проверяю их задание в prepare prepare test3(int,int) as SELECT s from strdat where did=$1 and cid=28624 and datetime<=$2 order by datetime desc limit 1; --3 раза для надежности... (тут планы особо не интересны кроме случая если он сменится вдруг) explain (analyze, costs, buffers, timing) execute test3(134,1411117512); explain (analyze, costs, buffers, timing) execute test3(134,1411117512); explain (analyze, costs, buffers, timing) execute test3(134,1411117512); --теперь эмулируем появление новой партиции (135)... если план совсем другой стал то приведите его 1 раз explain (analyze, costs, buffers, timing) execute test3(135,1411117512); explain (analyze, costs, buffers, timing) execute test3(135,1411117512); --и еще раз для старой партиции explain (analyze, costs, buffers, timing) execute test3(134,1411117512); Я собственно уже на 95% уверен в чем у вас проблема, так что следующий раз если проблема проявятся вместо рестарта и реиндекса базы попробуйте выполнить от postgres сброс всех коннектов к базе: select pg_terminate_backend(pid) from pg_stat_activity where usename<>'postgres'; и возможно она исправится (в общем они никак не связана с индексами вообще). --Maxim Boguk www.postgresql-consulting.ru ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 18:45:58 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Maxim Bogukа с каким интервалом у вас новые партиции создаются? Партиции - это объекты мониторинга. Реально, физические объекты обвешанные датчиками, данные с которых и сохраняются. Партиции создаются только вызовом хранимки create_part, я её приводил ранее. По логу, за последнии двое суток новых партиций не создавалось, а висло 5 раз. Создают вручную, подключая новые объекты. Раз в несколько дней. Может несколько в день случится. JSONCURDERRINFO, (из которой вызывается и SELECT s from strdat where did=$1 and cid=28624 and datetime<=$2 order by datetime desc limit 1), после старта приложения, для одной партиции, вызывается, почти всегда один раз, когда клиент обращается первый раз к этому объекту (этой партиции). Дальше данные кешируются на уровне приложения. Код: sql 1. 2. 3. 4. 5. 6. 7. 8. 9. 10. PREPARE QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.21 rows=1 width=28) (actual time=0.027..0.028 rows=1 loops=1) Buffers: shared hit=7 -> Result (cost=0.01..11.76 rows=58 width=28) (actual time=0.025..0.025 rows=1 loops=1) Buffers: shared hit=7 -> Merge Append (cost=0.01..11.76 rows=58 width=28) (actual time=0.025..0.025 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=7 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.014..0.014 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime <= 1411117512) AND (cid = 28624)) Buffers: shared hit=4 -> Index Scan Backward using strdat_134_28624 on strdat_134 strdat (cost=0.00..6.76 rows=57 width=19) (actual time=0.008..0.008 rows=1 loops=1) Index Cond: (datetime <= 1411117512) Filter: (did = 134) Buffers: shared hit=3 Total runtime: 0.083 ms (15 rows) QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.21 rows=1 width=28) (actual time=0.019..0.019 rows=1 loops=1) Buffers: shared hit=3 -> Result (cost=0.01..11.76 rows=58 width=28) (actual time=0.018..0.018 rows=1 loops=1) Buffers: shared hit=3 -> Merge Append (cost=0.01..11.76 rows=58 width=28) (actual time=0.017..0.017 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=3 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.006..0.006 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime <= 1411117512) AND (cid = 28624)) Buffers: shared hit=1 -> Index Scan Backward using strdat_134_28624 on strdat_134 strdat (cost=0.00..6.76 rows=57 width=19) (actual time=0.010..0.010 rows=1 loops=1) Index Cond: (datetime <= 1411117512) Filter: (did = 134) Buffers: shared hit=2 Total runtime: 0.065 ms (15 rows) QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.21 rows=1 width=28) (actual time=0.019..0.019 rows=1 loops=1) Buffers: shared hit=3 -> Result (cost=0.01..11.76 rows=58 width=28) (actual time=0.017..0.017 rows=1 loops=1) Buffers: shared hit=3 -> Merge Append (cost=0.01..11.76 rows=58 width=28) (actual time=0.016..0.016 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=3 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.006..0.006 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime <= 1411117512) AND (cid = 28624)) Buffers: shared hit=1 -> Index Scan Backward using strdat_134_28624 on strdat_134 strdat (cost=0.00..6.76 rows=57 width=19) (actual time=0.010..0.010 rows=1 loops=1) Index Cond: (datetime <= 1411117512) Filter: (did = 134) Buffers: shared hit=2 Total runtime: 0.064 ms (15 rows) QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.19 rows=1 width=26) (actual time=0.025..0.025 rows=1 loops=1) Buffers: shared hit=4 -> Result (cost=0.01..11.84 rows=67 width=26) (actual time=0.023..0.023 rows=1 loops=1) Buffers: shared hit=4 -> Merge Append (cost=0.01..11.84 rows=67 width=26) (actual time=0.023..0.023 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=4 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.005..0.005 rows=0 loops=1) Index Cond: ((did = 226) AND (datetime <= 1411292950) AND (cid = 28624)) Buffers: shared hit=1 -> Index Scan Backward using strdat_226_28624 on strdat_226 strdat (cost=0.00..6.73 rows=66 width=19) (actual time=0.016..0.016 rows=1 loops=1) Index Cond: (datetime <= 1411292950) Filter: (did = 226) Buffers: shared hit=3 Total runtime: 0.067 ms (15 rows) QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.19 rows=1 width=26) (actual time=0.015..0.016 rows=1 loops=1) Buffers: shared hit=3 -> Result (cost=0.01..11.84 rows=67 width=26) (actual time=0.013..0.013 rows=1 loops=1) Buffers: shared hit=3 -> Merge Append (cost=0.01..11.84 rows=67 width=26) (actual time=0.012..0.012 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=3 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.005..0.005 rows=0 loops=1) Index Cond: ((did = 226) AND (datetime <= 1411292950) AND (cid = 28624)) Buffers: shared hit=1 -> Index Scan Backward using strdat_226_28624 on strdat_226 strdat (cost=0.00..6.73 rows=66 width=19) (actual time=0.006..0.006 rows=1 loops=1) Index Cond: (datetime <= 1411292950) Filter: (did = 226) Buffers: shared hit=2 Total runtime: 0.054 ms (15 rows) QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.21 rows=1 width=28) (actual time=0.012..0.012 rows=1 loops=1) Buffers: shared hit=3 -> Result (cost=0.01..11.76 rows=58 width=28) (actual time=0.011..0.011 rows=1 loops=1) Buffers: shared hit=3 -> Merge Append (cost=0.01..11.76 rows=58 width=28) (actual time=0.011..0.011 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=3 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.004..0.004 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime <= 1411117512) AND (cid = 28624)) Buffers: shared hit=1 -> Index Scan Backward using strdat_134_28624 on strdat_134 strdat (cost=0.00..6.76 rows=57 width=19) (actual time=0.005..0.005 rows=1 loops=1) Index Cond: (datetime <= 1411117512) Filter: (did = 134) Buffers: shared hit=2 Total runtime: 0.049 ms (15 rows) QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.01..0.21 rows=1 width=28) (actual time=0.019..0.019 rows=1 loops=1) Buffers: shared hit=3 -> Result (cost=0.01..11.76 rows=58 width=28) (actual time=0.018..0.018 rows=1 loops=1) Buffers: shared hit=3 -> Merge Append (cost=0.01..11.76 rows=58 width=28) (actual time=0.017..0.017 rows=1 loops=1) Sort Key: public.strdat.datetime Buffers: shared hit=3 -> Index Scan Backward using strdat_pkey on strdat (cost=0.00..4.26 rows=1 width=520) (actual time=0.006..0.006 rows=0 loops=1) Index Cond: ((did = 134) AND (datetime <= 1411117512) AND (cid = 28624)) Buffers: shared hit=1 -> Index Scan Backward using strdat_134_28624 on strdat_134 strdat (cost=0.00..6.76 rows=57 width=19) (actual time=0.010..0.010 rows=1 loops=1) Index Cond: (datetime <= 1411117512) Filter: (did = 134) Buffers: shared hit=2 Total runtime: 0.068 ms (15 rows) Maxim BogukЯ собственно уже на 95% уверен в чем у вас проблема, так что следующий раз если проблема проявятся вместо рестарта и реиндекса базы попробуйте выполнить от postgres сброс всех коннектов к базе: select pg_terminate_backend(pid) from pg_stat_activity where usename<>'postgres'; Это уронит оба серверных приложения. Тогда проще их остановить и выполнить то что Вы указываете. (Если не лучше перезапустить постгрес?) и запустить их снова. Вообще то проблем нет такой скрипт соорудить. Знать бы критерий когда запускать. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 19:49:43 |
|
||
|
REINDEX DATABASE выполняется уже 6 часов и конца не видно
|
|||
|---|---|---|---|
|
#18+
Сегодня несколько раз пытался, при загрузке дисков 100%, просто перезапускать постгрес без реиндекса - работы хватает на полчаса. Сейчас пробовал select pg_terminate_backend(pid) from pg_stat_activity where usename<>'postgres'; после остановки приложений. по данным pg_stat_activity и после этого остаются висеть "зависшие" селекты. Только перезапуск постгреса их прибивает. Запустил Код: sql 1. 2. 3. Хотя, это без толку. Опять скоро зависнет. Наверное, только абгрейт железа поможет. Или железо глючит? На винтах ничего подозрительного не горит. ... |
|||
|
:
Нравится:
Не нравится:
|
|||
| 21.09.2014, 20:30:27 |
|
||
|
|

start [/forum/topic.php?fid=53&msg=38746266&tid=1998481]: |
0ms |
get settings: |
8ms |
get forum list: |
13ms |
check forum access: |
3ms |
check topic access: |
3ms |
track hit: |
193ms |
get topic data: |
8ms |
get forum data: |
2ms |
get page messages: |
44ms |
get tp. blocked users: |
1ms |
| others: | 232ms |
| total: | 507ms |

| 0 / 0 |
