Привет всем!

Проясните, пожалуйста, сабж...
Вполне возможно, что вопрос тривиальный. Но я пока что не могу найти логичного объяснения этому...

Описание:
Заметил, что вот такой топик под Дебиан Линукс 3.0 (ядро 2.4.31) и на железе: 2 Intel Xeon (система видит 4 процессора, т.к. - гипертрединг), 4 Гб ОЗУ, RAID-5

# onstat -

IBM Informix Dynamic Server Version 7.31.UD8 -- On-Line (Prim) -- Up 22 days 10:20:46 -- 1739288 Kbytes

подозрительно много читает данных со своих дбспейсов в то время, когда к нему практически нет пользовательских запросов .

Характеристика нагрузки на сервер в рабочие дни:
1) с 8 утра до 18 часов вечера - интенсивное использование (пользовательские запросы);
2) с 0 до 2 утра - технологические операции (резервное копирование данных с помощью ontape -s -L 0 и dbacess, прочее...);
3) в остальное время (вечер и раннее утро) - нерегулярное использование;
4) по крону раз в неск. минут запускаются запросы для мониторинга параметров сервера, но они отрабатывают за секунды и ощутимой нагрузки на север не дают.
5) по крону раз в 10 мин. круглосуточно производится сброс логических журналов в бэкап (скрипт с вызовом "ontape -a") - тоже срабатывает за секунды.
6) UPDATE STATISTICS производится только раз в неделю, в выходные.

Проведенное расследование показало следующие факты:
1) средняя загрузка системы (LA, смотрим в top) c 18 до 0-ля часов не опускается ниже 1 и причиной тому не загрузка процессора (ничтожна), а именно дисковое чтение с RAID, где лежат только дбспейсы Информикса;
2) подтверждение тому, что читает именно Информикс видно в onstat -p (diskreads). Причем читает системная сессия Информикса (по onstat -u: sessid=12), а не пользовательская.
3) скорость чтения с диска (смотрел с пом. iostat) в этот период времени НЕ опускается ниже 2,7 Мб/с;
4) onstat -g iof говорит, что читаются данные с разных чанков разных дбспейсов;
5) после ночного архивирования 0-го уровня (ontape -s -L 0) эта непонятная "читательная активность" ВСЕГДА пропадает до 8-ми утра(когда начинается наплыв пользователей), но был один случай, что она исчезла и незадолго ДО архивирования 0-го уровня...

Как подтверждение прилагаю МРТЖ-графики загрузки системы, CPU и RAID (на котором лежат дбспейсы) - по ним все вышесказанное хорошо видно.

Конфиг Информикса прицепляю тоже, может будет чем-нибудь полезен.
Прочую информацию готов предоставить, если понадобится.

Заранее благодарен за любые советы по поводу... :)

============================================================

ROOTNAME rootdbs # Root dbspace name
ROOTPATH /dev/informix00/ifx00 # Path for device containing root dbspace
ROOTOFFSET 0 # Offset of root dbspace into device (Kbytes)
ROOTSIZE 500000 # Size of root dbspace (Kbytes)


MIRROR 0 # Mirroring flag (Yes = 1, No = 0)
MIRRORPATH # Path for device containing mirrored root
MIRROROFFSET 0 # Offset into mirrored device (Kbytes)


PHYSDBS phys_dbs # Location (dbspace) of physical log
PHYSFILE 499000 # Physical log file size (Kbytes)


LOGFILES 39 # Number of logical log files
LOGSIZE 20000 # Logical log size (Kbytes)
LOG_BACKUP_MODE MANUAL


MSGPATH /var/log/informix/online.log # System message log file path
CONSOLE /dev/console # System console message path
ALARMPROGRAM /usr/local/informix/etc/log_full.sh # Alarm program path
SYSALARMPROGRAM /usr/local/informix/etc/evidence.sh # System Alarm program path
TBLSPACE_STATS 0


TAPEDEV /tmp/tarc.dat.fifo
TAPEBLK 4 # Tape block size (Kbytes)
TAPESIZE 30000000 # Maximum amount of data to put on tape (Kbytes)


LTAPEDEV /tmp/larc.dat.fifo
LTAPEBLK 4 # Log tape block size (Kbytes)
LTAPESIZE 30000000 # Max amount of data to put on log tape (Kbytes)


STAGEBLOB # Informix Dynamic Server/Optical staging area


SERVERNUM 1 # Unique id corresponding to a Dynamic Server instance
DBSERVERNAME ol_psi # Name of default database server
DBSERVERALIASES # List of alternate dbservernames


NETTYPE ipcshm,1,100,CPU
NETTYPE soctcp,3,200,NET

DEADLOCK_TIMEOUT 60 # Max time to wait of lock in distributed env.
RESIDENT 1 # Forced residency flag (Yes = 1, No = 0)

MULTIPROCESSOR 1 # 0 for single-processor, 1 for multi-processor
NUMCPUVPS 4 # Number of user (cpu) vps
SINGLE_CPU_VP 0 # If non-zero, limit number of cpu vps to one

NOAGE 0 # Process aging
AFF_SPROC 0 # Affinity start processor
AFF_NPROCS 0 # Affinity number of processors


LOCKS 2000000 # Maximum number of locks
BUFFERS 400000 # Maximum number of shared buffers
NUMAIOVPS 4 # Number of IO vps
PHYSBUFF 256
LOGBUFF 256
LOGSMAX 100 # Maximum number of logical log files
CLEANERS 60 # Number of buffer cleaner processes
SHMBASE 0x50000000L # Shared memory base address
SHMVIRTSIZE 786432 # initial virtual shared memory segment size
SHMADD 32768 # Size of new shared memory segments (Kbytes)
SHMTOTAL 0 # Total shared memory (Kbytes). 0=>unlimited
CKPTINTVL 300 # Check point interval (in sec)
LRUS 127 # Number of LRU queues
LRU_MAX_DIRTY 60 # LRU percent dirty begin cleaning limit
LRU_MIN_DIRTY 30 # LRU percent dirty end cleaning limit
LTXHWM 45 # Long transaction high water mark percentage
LTXEHWM 54 # Long transaction high water mark (exclusive)
TXTIMEOUT 0x12c # Transaction timeout (in sec)
STACKSIZE 128 # Stack size (Kbytes)




OFF_RECVRY_THREADS 10 # Default number of offline worker threads
ON_RECVRY_THREADS 1 # Default number of online worker threads

DRAUTO 0 # DR automatic switchover
DRINTERVAL 30 # DR max time between DR buffer flushes (in sec)
DRTIMEOUT 30 # DR network timeout (in sec)
DRLOSTFOUND /usr/local/informix/etc/dr.lostfound # DR lost+found file path

CDR_LOGBUFFERS 2048 # size of log reading buffer pool (Kbytes)
CDR_EVALTHREADS 1,2 # evaluator threads (per-cpu-vp,additional)
CDR_DSLOCKWAIT 5 # DS lockwait timeout (seconds)
CDR_QUEUEMEM 4096 # Maximum amount of memory for any CDR queue (Kbytes)
CDR_LOGDELTA 30 # % of log space allowed in queue memory
CDR_NUMCONNECT 16 # Expected connections per server
CDR_NIFRETRY 300 # Connection retry (seconds)
CDR_NIFCOMPRESS 0 # Link level compression (-1 never, 0 none, 9 max)

BAR_ACT_LOG /var/log/informix/bar_act.log
# ON-Bar Log file - not in /tmp please
BAR_DEBUG_LOG /var/log/informix/bar_dbug.log
# ON-Bar Debug Log - not in /tmp please
BAR_MAX_BACKUP 0
BAR_RETRY 1
BAR_NB_XPORT_COUNT 10
BAR_XFER_BUF_SIZE 31

ISM_DATA_POOL ISMData # If the data pool name is changed, be sure to
# update $INFORMIXDIR/bin/onbar. Change to
# ism_catalog -create_bootstrap -pool <new name>
ISM_LOG_POOL ISMLogs

RA_PAGES 256
RA_THRESHOLD 240


DBSPACETEMP temp1_dbs,temp2_dbs,temp3_dbs,temp4_dbs # Default temp dbspaces


DUMPDIR /tmp # Preserve diagnostics in this directory
DUMPSHMEM 0 # Dump a copy of shared memory
DUMPGCORE 0 # Dump a core image using 'gcore'
DUMPCORE 0 # Dump a core image (Warning:this aborts Dynamic Server)
DUMPCNT 1 # Number of shared memory or gcore dumps for
# a single user's session

FILLFACTOR 90 # Fill factor for building indexes

USEOSTIME 0 # 0: use internal time(fast), 1: get time from OS(slow)

MAX_PDQPRIORITY 90 # Maximum allowed pdqpriority
DS_MAX_QUERIES 3 # Maximum number of decision support queries
DS_TOTAL_MEMORY 524288 # Decision support memory (Kbytes)
DS_MAX_SCANS 1048576 # Maximum number of decision support scans
DATASKIP off # List of dbspaces to skip

OPTCOMPIND 2 # To hint the optimizer

ONDBSPACEDOWN 2 # Dbspace down option: 0 = CONTINUE, 1 = ABORT, 2 = WAIT
LBU_PRESERVE 0 # Preserve last log for log backup
OPCACHEMAX 0 # Maximum optical cache size (Kbytes)

HETERO_COMMIT 1

OPT_GOAL 0

DIRECTIVES 1

RESTARTABLE_RESTORE on


DD_HASHMAX 4
DD_HASHSIZE 503

PC_HASHSIZE 30
PC_POOLSIZE 100

В данный момент флаги имеют вид (попеременно)

---P--B
---PR-B (реже)

Надо еще посмотреть вечером, для надежности, когда сабж имеет место быть.
А то визуально припоминаю, что вроде бы где-то видел среди флагов еще и "D", но точно вспомнить сейчас не могу... :(

ЗЫ. "btree cleaner thread" - мне тоже ничего не говорит пока в контексте сабжа...

Но за идею копать в направлении типа треда - спасибо! :)

Журавлев Денис

У вас delete-ов в системе много?


Подскажите, плиз, что за "delete" имеются ввиду, где и как их количество можно посмотреть...

ЗЫ. я вообще-то по роду работы больше сисадмин, чем администратор СУБД...
Так что не судите строго, если чего глупого спрошу...

"Однако!" (с)
Вот сижу и считаю:

В среднем скорость чтения за период с 18 до 0 часов (смотрю в МТРЖ) - порядка 4 Мб/с. Объем ВСЕХ данных во всех дибиспейсах - 28,5 Гб.

Какой объем данных прочтется Информиксом за это время:

4Мб/с * 60 с. * 60мин. * 6 часов = 86400Мб = 86,4 Гб.

Выходит, что за вечер он успевает перечитать все, что можно
86,4 / 28,5 = 3 раза ! (округл.)

И думаю себе: не многовато ли? Может где-то что-то можно подкрутить у этого btree cleaner'a ? ... чтоб он работал оптимальнее или не был аж настолько ретив... :)

Статистику МРТЖ делал сам, так что уверен, что там точно зеленое - чтение с диска, а синее - запись.
Поставил скрипт, который с 18 до 0 снимет показания с iostat и с onstat.
Результаты опубликую завтра или в понедельник...

ЗЫ. сразу попутно вопрос: цифры в столбце nreads вывода onstat -u в каких попугаях?
Может как и везде: в кол-ве 2Кб-блоков? (такое число у меня в выводе onstat -b, размер буфера.).
Аналогичный вопрос насчет параметра dskreads в выводе команды onstat -р .

вот что показали пятничные измерения...

Предисловие.
"Красивой" картины не получилось, т.к. эффект "непонятного чтения" именно в эту пятницу длился не до 0-я часов, а закончился в полодиннадцатого плюс один пользователь задержался после 18 и довольно существенно понагружал сервер. Но тем не менее, статистика есть и она показательна.

Процедура замеров (упрощенно).
1) onstat -z (обнуляем статистику)
2) iostat -k 21600 2 (включаем на 6 часов замер дисковой активности)
3) onstat -u; onstat -p (снимаем накопленную за 6 часов статистику Информикса)

Результаты за 6 часов измерений.





Видимые выводы.

Если предположить, что параметры nreads и dskreads в выводе команд onstat -u и onstat -p измеряются в одних и тех же попугаях, то получается, что:
а) процесс btree cleaner выполнил 77% (9930679 / 12851874) всех операций чтения;
б) 77% от общего объема данных, считанных с RAID равно 61,7 Гб ( 79885320 Kb * 0,77)
в) апроксимирую объем данных, которые могли бы быть считаны процессом btree cleaner, если бы реально он "бузил" до 0-ля часов, а не затих в полодиннадцатого: 61,7 Гб + 61,7 Гб * (1.5часа / 6часов) = 77,2 Гб

В принципе, довольно близко к моим выкладкам в предыдущем посте.
Т.е. вопрос остается - зачем этому процессу читать с диска объем данных в 3 раза превышающих общий объем данных во всех дбспейсах? Странно, ИМХО.

Модератор: Есть чудесный тег fixed, пользуйтесь им пож-а.

vasilis
Да, соглашусь, что странно, но ситуация, на самом деле, еще более странная, если посмотреть не только дисковое чтение, а и общий объем прочитанных данных, т.е. из буферного пула.
Это более 600Гб!!!


Разве это много для такого размера БД (с парой-тройкой таблиц под 2Гб каждая)? Т.е. реакция сервера на такую нагрузку может выражаться в озабоченности btree cleaner'a по вечерам и это нормально? Рекомендуете обратиться к программистам с вопросом об оптимизации запросов или ... ?

Кстати, аналогичные данные за вчерашний вечер:
iostat:

onstat -u (btree cleaner)

onstat -p (сокращенно)


Итого имеем:
Доля чтений btree cleaner'а - 81.6% или 87,5 Гб за 6 часов.
Т.е. результат довольно стабилен.


vasilis
И еще - если не ошибаюсь, в версии 9.40 btree cleaner стал уже называться btree Scanner , а это означает, что его функции сильно изменились и расширились.


я писал в первом посте, что на этой машине стоит версия 7.31 UD8


Журавлев Денис А чего пользователь делал?

запускал отчет какой-то, 9 раз, за разные месяцы (отчет формируется около 10-15 минут в зависимости от загрузки сервера).
Подробностей по содержимому сейчас не скажу. А это важно?

И еще, по ссылке, что дал Daugava был намек на возможное вредное действие синхронизации времени на машине на работу Информикс-сервера. У меня синхронизация производится раз в сутки, в полвосьмого утра. На всякий случай временно отключу - "а вдруг"?

Журавлев Денис
Если бы этот отчет сделал 75тыс. транзакций и удалил 382тыс. записей, то я бы не стал удивляться активности btree.
Т.е. нужен чистый экспиремент (100% без пользователей), иначе гадаем на кофейной гуще.

Спасибо, понятно. Считаю дальнейшие разбирательства ненужными, т.к.
провести чистый эксперимент нет возможности. Сервер рабочий, д.б. доступен круглосуточно. К тому же в выходные, когда пользователи работают поменьше, нет самого эффекта чтения btree cleaner'ом - эксперимента не выйдет уже по этой причине.
Делаю для себя вывод, что такое поведение Информикса вследствие больших нагрузок (транзакции, удаления) - вполне оправданно и нормально.
Еще раз спасибо всем!

СугубыйЧуть в сторону: загляние в кроны - вдруг разработчик что-то решил пересчитать/перезалить ночью/когда нет запросов? :)

это я вам как "тот самый" разработчик говорю, у меня по ночам всякие утилиты запускаются. update statistics, к примеру.

Кроны исключительно в моей власти, так же как и ночные запуски всякого нужного. У разработчиков нет доступа к ним, кроме как через меня.


VGКак понял для архивирования ontape -s -L 0 <БД> используется без перевода БД в буферный режим у себя так не пробовал но наверно будет плохо.
Лучше так ontape -s -L 0 -B <БД>
Хотя может имелось ввиду само собой тогда сории.

Все БД еще при вгрузке переведены таким образом в режим "buffered logging" и в дальнейшем не трогаются.

VG svat2
5) после ночного архивирования 0-го уровня (ontape -s -L 0)
....
Все БД еще при вгрузке переведены таким образом в режим "buffered logging" и в дальнейшем не трогаются.
Не бить за непонятливость, но каким образом БД выгружаются ontape -s -L 0 а дальше какие ключи (-A | -B | -N | -U) ?

все эти ключи ОПЦИОНАЛЬНЫ.
Т.е. попросту говоря:
"ontape -s -L 0" - сделать архивирование 0-го уровня всех данных IDS,
"[-A | -B | -N | -U]" - а возможно заодно изменить и режим буферизации некоторых БД.