UTM5 подвисает на 1-2 минуты с завидной периодичностью

[mix1717]

Добрый день.

Все началось с проблемы 2010. Пришлось отлично работающий utm обновлять с 005 на 5.2.1-007. Все делалось по инструкции с сайта netup.

После обновления начались проблемы, периодичное (раз в 5-10 минут) подвисание сервиса. В момент проблемы невозможно подконектиться
ни клиентом, ни по web никак. Все существующие соединения замирают. Все проходит через 1-2 минуты.

Ниже привожу информацию о системе а также вывод команды top в момент проблемы.



netup 5.2.1-007-update10-rhel5
postgresql-server-8.1.11-1.el5_1.1 размер базы ~8gb
Red Hat 5.1 kern: 2.6.18-53.1.6.el5xen
xeon 2000mhz 2kern/ 2048 mb

в момент подвисаний, через phppgadmin видны след. запросыв базу:
SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='8' AND tclass_id='50'
SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='8' AND tclass_id='50'

INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('11026330','8','0','0','2','8','1270128954','1270126800','1270065600','1270065600','50','0','1540365592','404','2')
INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('11026426','8','0','0','2','8','1270129050','1270126800','1270065600','1270065600','50','0','1540365802','404','2')
UPDATE downloaded SET qnt='6037198692447', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='8' AND tclass_id='50'
UPDATE downloaded SET qnt='6037198753327', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='8' AND tclass_id='50'

UPDATE accounts SET balance='0' WHERE id = '2'
UPDATE downloaded SET qnt='111928980469', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='44' AND tclass_id='248'
SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='3' AND tclass_id='10'
UPDATE accounts SET balance='0' WHERE id = '1'

UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='349105315' WHERE id='1137'
UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='11836946' WHERE id='851'
UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='11844152' WHERE id='798'


также привожу кусочек дебаг файла в момент подвисания:

[root@spectre log]# tail -f debug.log
Info : Апр 06 12:15:24 TransactionHandlerImpl: plugin handler for event 95 not defined, event not handled
Info : Апр 06 12:15:24 TransactionHandlerImpl: some plugins not loaded due to license limitations, contact NetUP,Inc for more info
?Debug : Апр 06 12:15:24 TransactionFilter: transaction sent to the internal queue
?Debug : Апр 06 12:15:24 TransactionQueueManager: pushing transaction <0x8b0e050> into queue <1> (default)
?Debug : Апр 06 12:15:24 TransactionHandlerImpl: push: empty transaction ptr <0x08b0e050> dropped
?Debug : Апр 06 12:15:24 DummyTransactionQueue: commit: 0 transactions
?Debug : Апр 06 12:15:24 DBA:Ctx: Pushing back free context (system=1)
?Debug : Апр 06 12:15:24 TransactionHandlerImpl: incoming transaction ptr <0x53c77fc0> done
?Debug : Апр 06 12:15:24 DBCtx: Ctx: <144647208> SQL query: UPDATE downloaded SET qnt='148628402581', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='2' AND tclass_id='42'
?Debug : Апр 06 12:15:24 DBCtx: Ctx: <144647208> SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='13050582191' WHERE id='1031'
?Debug : Апр 06 12:15:25 UTM5 DBA: Charge:0.000000 p.u. for link:2 account 2
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144647208> SQL query: UPDATE accounts SET balance='0' WHERE id = '2'
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144647208> SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_with_tax,service_id,service_type,slink_id,discount_date,charge_type,discount_period_id) VALUES('2','0','0','0','0','2','3','2','1270541724','3','2')
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144647208> SQL select: SELECT setval('discount_transactions_all_id_seq', 11150743)
?Debug : Апр 06 12:15:25 UTM5 DBA: Checking for rehash: flags 3, balance 0.000 (old 0.000), credit 0.000
?Debug : Апр 06 12:15:25 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b66a7e98
?Debug : Апр 06 12:15:25 BusLogic: currently blm with code 37 executing
?Debug : Апр 06 12:15:25 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144647208> SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('11150744','2','0','0','2','2','1270541724','1270540800','1270497600','1270065600','42','0','-1017266940','11056749','2')
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144647208> SQL select: SELECT setval('discount_transactions_iptraffic_all_id_seq', 11150743)
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144647208> SQL query: COMMIT
?Debug : Апр 06 12:15:25 DBCtx: DB transaction commit
?Debug : Апр 06 12:15:25 DBA:Ctx: Pushing back free context (system=1)
-Stats : Апр 06 12:15:25 UTM5 DBA: Stats: Uptime: 00:00:01. Events: 0; Errors: 0
?Debug : Апр 06 12:15:25 BusClassif: aggregation interval reached for slink <2> ip <-1017266939> tclass <42>
?Debug : Апр 06 12:15:25 UTM5 DBA: DBAccess instance created
?Debug : Апр 06 12:15:25 DBA:Ctx: Looking for free context (system=1)
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL query: BEGIN
?Debug : Апр 06 12:15:25 DBCtx: DB transaction begin
?Debug : Апр 06 12:15:25 TransactionQueueManager: pushing transaction <0xb3514b20> into queue <1> (default)
?Debug : Апр 06 12:15:25 TransactionHandlerImpl: push: transaction ptr <0xb3514b20> (size 1, Events [ 95 ])
?Debug : Апр 06 12:15:25 DBCtx: Ctx:<144612368> SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='2' AND tclass_id='42'
?Debug : Апр 06 12:15:25 TransactionHandlerImpl: incoming transaction ptr <0xb3514b20>, outgoing transaction ptr <0xb0c743f8>
?Debug : Апр 06 12:15:25 DBA:Ctx: Looking for free context (system=1)
?Debug : Апр 06 12:15:25 PluginManagerImpl: no registered plugin for event_id <95>
Info : Апр 06 12:15:25 TransactionHandlerImpl: plugin handler for event 95 not defined, event not handled
Info : Апр 06 12:15:25 TransactionHandlerImpl: some plugins not loaded due to license limitations, contact NetUP,Inc for more info
?Debug : Апр 06 12:15:25 TransactionFilter: transaction sent to the internal queue
?Debug : Апр 06 12:15:25 TransactionQueueManager: pushing transaction <0xb0c743f8> into queue <0> (default)
?Debug : Апр 06 12:15:25 TransactionHandlerImpl: push: empty transaction ptr <0xb0c743f8> dropped
?Debug : Апр 06 12:15:25 DummyTransactionQueue: commit: 0 transactions
?Debug : Апр 06 12:15:25 DBA:Ctx: Pushing back free context (system=1)
?Debug : Апр 06 12:15:25 TransactionHandlerImpl: incoming transaction ptr <0xb3514b20> done
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL query: UPDATE downloaded SET qnt='148628402709', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='2' AND tclass_id='42'
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='91427983' WHERE id='3172'
?Debug : Апр 06 12:15:25 UTM5 DBA: Charge:0.000000 p.u. for link:2 account 2
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL query: UPDATE accounts SET balance='0' WHERE id = '2'
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_with_tax,service_id,service_type,slink_id,discount_date,charge_type,discount_period_id) VALUES('2','0','0','0','0','2','3','2','1270541725','3','2')
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL select: SELECT setval('discount_transactions_all_id_seq', 11150744)
?Debug : Апр 06 12:15:25 UTM5 DBA: Checking for rehash: flags 3, balance 0.000 (old 0.000), credit 0.000
?Debug : Апр 06 12:15:25 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b66a7e98
?Debug : Апр 06 12:15:25 BusLogic: currently blm with code 37 executing
?Debug : Апр 06 12:15:25 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('11150745','2','0','0','2','2','1270541725','1270540800','1270497600','1270065600','42','0','-1017266939','128','2')
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL select: SELECT setval('discount_transactions_iptraffic_all_id_seq', 11150744)
?Debug : Апр 06 12:15:25 DBCtx: Ctx: <144612368> SQL query: COMMIT


top:
top - 12:12:13 up 582 days, 3:20, 1 user, load average: 2.56, 2.75, 2.25
Tasks: 148 total, 2 running, 146 sleeping, 0 stopped, 0 zombie
Cpu0 : 12.3%us, 8.6%sy, 0.0%ni, 6.6%id, 71.4%wa, 0.0%hi, 1.0%si, 0.0%st
Cpu1 : 7.6%us, 12.6%sy, 0.0%ni, 77.8%id, 1.7%wa, 0.0%hi, 0.0%si, 0.3%st
Mem: 1817600k total, 1806052k used, 11548k free, 2324k buffers
Swap: 4095992k total, 1798156k used, 2297836k free, 459520k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
25606 postgres 15 0 22256 10m 9.8m S 24 0.6 2035:01 postmaster
25604 postgres 16 0 22360 10m 9.8m R 13 0.6 2043:13 postmaster

До обновления все летало. Кроме utm ничего больше не обновлялось.

Буду признателен за любую информацию по теме.

Спасибо.

Михаил Петров.

[dk]

Винт не справляется? 71.4%wa

P.S. Swap: 1798156k used <--- памяти ОЧЕНЬ не хватает...

[mix1717]

памяти на машине 2гб, да и задач никаких больше не крутится,
2 гига мало думаете?

сегодня был период где 46.8%wa и всеравно не работало...

top - 14:26:59 up 583 days, 5:35, 2 users, load average: 2.00, 2.08, 1.59
Tasks: 190 total, 3 running, 187 sleeping, 0 stopped, 0 zombie
Cpu0 : 20.6%us, 28.2%sy, 0.0%ni, 3.0%id, 46.8%wa, 0.0%hi, 1.3%si, 0.0%st
Cpu1 : 1.0%us, 2.3%sy, 0.0%ni, 92.4%id, 4.3%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 1817600k total, 1806412k used, 11188k free, 6860k buffers
Swap: 4095992k total, 1451412k used, 2644580k free, 453268k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
25605 postgres 16 0 22220 10m 9.8m S 28 0.6 2129:19 postmaster
25604 postgres 16 0 22360 10m 9.8m R 16 0.6 2092:28 postmaster
25606 postgres 16 0 22256 10m 9.9m S 7 0.6 2083:42 postmaster
20216 apache 15 0 7772 1876 1628 S 1 0.1 0:00.04 aaa5
18317 mix 15 0 10456 2664 1012 S 0 0.1 0:02.74 sshd
18492 mix 15 0 48872 13m 10m S 0 0.8 0:07.99 gnome-system-mo
25602 root 18 0 1596m 926m 4144 S 0 52.2 219:38.64 utm5_core
1 root 15 0 2076 604 520 S 0 0.0 0:04.64 init
2 root RT 0 0 0 0 S 0 0.0 0:08.47 migration/0
3 root 34 19 0 0 0 S 0 0.0 0:16.54 ksoftirqd/0

[dk]

памяти на машине 2гб, да и задач никаких больше не крутится,
2 гига мало думаете?

Судя по свопу, нужно ещё два.

P.S. попробуйте установить sysstat и помониторить загрузку через iostat -x 1

[littlesavage]

Добрый день.

Все началось с проблемы 2010. Пришлось отлично работающий utm обновлять с 005 на 5.2.1-007. Все делалось по инструкции с сайта netup.

Интересен конфиг постгреса и индексы таблиц discount_transactions_all и discount_transactions_iptraffic_all

Ну и выполните, на всякий случай, vavvum full и reindex database utm5

[mix1717]

Интересен конфиг постгреса и индексы таблиц discount_transactions_all и discount_transactions_iptraffic_all

Ну и выполните, на всякий случай, vavvum full и reindex database utm5

/var/lib/pgsql/data/postgresql.conf
listen_addresses = '*' # comma-separated list of addresses;
port = 5432
max_connections = 100
shared_buffers = 1000 # min 16 or max_connections*2, 8KB each
redirect_stderr = on # Enable capturing of stderr into log
log_directory = 'pg_log' # Directory where log files are written
log_filename = 'postgresql-%a.log' # Log file name pattern.
log_truncate_on_rotation = on # If on, any existing log file of the same
log_rotation_age = 1440 # Automatic rotation of logfiles will
log_rotation_size = 0 # Automatic rotation of logfiles will
lc_messages = 'ru_RU.UTF-8' # locale for system error message
lc_monetary = 'ru_RU.UTF-8' # locale for monetary formatting
lc_numeric = 'ru_RU.UTF-8' # locale for number formatting
lc_time = 'ru_RU.UTF-8' # locale for time formattin


discount_transactions_all
---
schemaname tablename indexname tablespace indexdef
public discount_transactions_all index_92e08f5e788b4bcd2bd08d642d1f16f2 NULL CREATE INDEX index_92e08f5e788b4bcd2bd08d642d1f16f2 ON discount_transactions_all USING btree (service_id, discount_date, account_id, service_type, charge_type, discount, slink_id, discount_period_id, discount_with_tax)
public discount_transactions_all index_b3e12acadb1bbd7f8eb9b8a9ac479e6c NULL CREATE INDEX index_b3e12acadb1bbd7f8eb9b8a9ac479e6c ON discount_transactions_all USING btree (discount_date, account_id, service_type, discount, discount_with_tax)
public discount_transactions_all first_disc1 NULL CREATE INDEX first_disc1 ON discount_transactions_all USING btree (account_id)
public discount_transactions_all first_disc NULL CREATE INDEX first_disc ON discount_transactions_all USING btree (discount_date)
public discount_transactions_all discount_transactions_all_pkey NULL CREATE UNIQUE INDEX discount_transactions_all_pkey ON discount_transactions_all USING btree (id)



discount_transactions_iptraffic_all
---
public discount_transactions_iptraffic_all index_71be80c932a1d596a863a4f87ba05a03 NULL CREATE INDEX index_71be80c932a1d596a863a4f87ba05a03 ON discount_transactions_iptraffic_all USING btree (discount_date, account_id, ipid, discount_date_hour, discount_date_day, discount_date_month, t_class, base_cost, slink_id, bytes, discount, discount_with_tax)
public discount_transactions_iptraffic_all first_dtr NULL CREATE INDEX first_dtr ON discount_transactions_iptraffic_all USING btree (discount_date, account_id, slink_id)
public discount_transactions_iptraffic_all discount_transactions_iptraffic_all_pkey NULL CREATE UNIQUE INDEX discount_transactions_iptraffic_all_pkey ON discount_transactions_iptraffic_all USING btree (id)

[littlesavage]

discount_transactions_all
---
index_92e08f5e788b4bcd2bd08d642d1f16f2 NULL index_b3e12acadb1bbd7f8eb9b8a9ac479e6c

discount_transactions_iptraffic_all
---
index_71be80c932a1d596a863a4f87ba05a03 NULL

Попробуйте удалить эти 3 индекса. И затем добавить индекс на account_id в discount_transactions_iptraffic_all.

[mix1717]

discount_transactions_all
---
index_92e08f5e788b4bcd2bd08d642d1f16f2 NULL index_b3e12acadb1bbd7f8eb9b8a9ac479e6c

discount_transactions_iptraffic_all
---
index_71be80c932a1d596a863a4f87ba05a03 NULL

Попробуйте удалить эти 3 индекса. И затем добавить индекс на account_id в discount_transactions_iptraffic_all.

littlesavage! cпасибо Вам огромное, похоже все заработало.

Инженерам netup, не помешало бы в инструкцию по обновлению utm добавить рекомендации реиндексировать базы.

[mikkey finn]

Им DBA надо купить правильного. И кучку тестовых паттернов по данным иметь разных.