ReSQL.ru
     
powered by simpleCommunicator - 2.0.30     © 2024 Programmizd 02
Мобильная версия    Контакт    Правила    FAQ    Помощь
Map
Доб. в избранное | Игнор. тему | Прикреп. тему | Пометить прочит. / непрочит. | Фильтр
Форумы / Informix [игнор отключен] [закрыт для гостей] / Частые контрольные точки с причиной Llog
25 сообщений из 32, страница 1 из 2
  1  все
Частые контрольные точки с причиной Llog
    #37650860
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
Здраствуйте товарищи !

Имеется:

- Informix 11.50FC8W2 на CentOS 5.5

- Разумеется "ничего не менялось"

- Через некоторе время после перезапуска (от едениц до десятков часов) начинаются тормоза при записи, что обычным пользователям незаметно, но видно нам по разрастанию очередей у разных демонов обрабатывающих всякие логи

- В onstat -g ckp картина такая - КТ почти каждую секунду

Изыскания что за причина такая Llog дали почти ничего - фразу из справочника админа Running out of logical log resources
Какие такие ресурсы ? Буфера логов ? Сами логи ? Успешно ротейтятся кстати (все U-B---- кроме текущего U---C-L)

Вобщем моск отказал. Или я торможу и что-то очень простое.

Какие параметры интересны - спрашивайте. ("весь конфиг", "onstat -a" не дам)

onstat -l
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
Physical Logging
Buffer bufused  bufsize  numpages   numwrits   pages/io
  P-2  25       256      6501191    153521     42.35
      phybegin         physize    phypos     phyused    %used   
      11:53            7864320    3581499    184        0.00    

Logical Logging
Buffer bufused  bufsize  numrecs    numpages   numwrits   recs/pages pages/io
  L-2  1        256      35732206   2368262    24985      15.1       94.8    
        Subsystem    numrecs    Log Space used
        OLDRSAM      35727284   4758774312    
        HA           4922       217444        

...............

oncheck -g ckp
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
AUTO_CKPTS=On   RTO_SERVER_RESTART=180 seconds   Estimated recovery time 21 seconds

                                                                    Critical Sections                          Physical Log    Logical Log    
           Clock                                  Total Flush Block #      Ckpt  Wait  Long  # Dirty   Dskflu  Total    Avg    Total    Avg   
Interval   Time      Trigger    LSN               Time  Time  Time  Waits  Time  Time  Time  Buffers   /Sec    Pages    /Sec   Pages    /Sec  
5603397    21:39:53  Llog       1580939:0x1375464 1.0   0.0   0.0   78     0.0   0.8   1.0   147       147     150      150    19       19    
5603398    21:39:54  Llog       1580939:0x138103c 1.0   0.0   0.0   86     0.0   0.8   1.0   146       146     103      103    12       12    
5603399    21:39:55  Llog       1580939:0x1392500 1.0   0.0   0.0   101    0.0   0.8   1.0   179       179     152      152    17       17    
5603400    21:39:56  Llog       1580939:0x13b115c 1.0   0.0   0.0   77     0.0   0.9   1.0   357       357     334      334    31       31    
5603401    21:39:57  Llog       1580939:0x13c5268 1.0   0.0   0.0   84     0.0   0.8   1.0   208       208     178      178    20       20    
5603402    21:39:58  Llog       1580939:0x13db738 1.2   0.0   0.0   100    0.0   1.0   1.1   227       227     211      211    23       23    
5603403    21:39:59  Llog       1580939:0x13f9180 0.8   0.0   0.0   79     0.0   0.7   0.8   283       283     255      255    29       29    
5603404    21:40:00  Llog       1580939:0x14160d8 1.0   0.0   0.0   76     0.0   0.8   1.0   226       226     208      208    29       29    
5603405    21:40:01  Llog       1580939:0x142b3c0 1.0   0.0   0.0   96     0.0   0.8   1.0   182       182     166      166    29       29    
5603406    21:40:02  Llog       1580939:0x1446590 1.0   0.0   0.0   95     0.0   0.8   1.0   264       264     242      242    28       28    
5603407    21:40:03  Llog       1580939:0x145e31c 1.4   0.1   0.0   108    0.0   1.1   1.3   200       200     169      169    23       23    
5603408    21:40:04  Llog       1580939:0x14a5018 0.7   0.1   0.0   66     0.0   0.5   0.6   549       549     585      585    71       71    
5603409    21:40:05  Llog       1580939:0x1501124 0.9   0.0   0.0   61     0.0   0.7   0.9   450       450     568      568    92       92    
5603410    21:40:06  Llog       1580939:0x15292a4 1.0   0.0   0.0   84     0.0   0.8   1.0   200       200     223      223    40       40    
5603411    21:40:07  Llog       1580939:0x1578558 1.0   0.1   0.0   83     0.0   0.8   1.0   321       321     321      321    79       79    
5603412    21:40:08  Llog       1580939:0x15d32b8 1.0   0.0   0.0   70     0.0   0.7   0.9   362       362     419      419    91       91    
5603413    21:40:09  Llog       1580939:0x162f7c8 1.0   0.1   0.0   73     0.0   0.8   1.0   292       292     350      350    93       93    
5603414    21:40:10  Llog       1580939:0x16e314c 1.0   0.0   0.0   63     0.0   0.8   0.9   626       626     703      703    179      179   
5603415    21:40:11  Llog       1580939:0x175454c 1.0   0.1   0.0   73     0.0   0.7   0.9   433       433     496      496    113      113   
5603416    21:40:12  Llog       1580939:0x17bd730 1.0   0.0   0.0   66     0.0   0.7   0.9   507       507     574      574    106      106   

Max Plog       Max Llog       Max Dskflush   Avg Dskflush   Avg Dirty      Blocked      
pages/sec      pages/sec      Time           pages/sec      pages/sec      Time         
4737           7816           17             141            97             0
...
Рейтинг: 0 / 0
07.02.2012, 21:58
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37651134
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
Яковлев Павел,

У вас параметр RTO_SERVER_RESTART=180 seconds что может быть причиной частых контрольных точек. Предлагаю для начала совсем отключить его и посмотреть как это скажется на частоте КТ.


RTO_SERVER_RESTART and its effect on checkpoints

The RTO_SERVER_RESTART configuration parameter specifies the amount of time, in seconds, that Informix® has to recover from an unplanned outage.
...

The performance disadvantages of enabling this configuration parameter are:

Increased physical log activity which might slightly impact transaction performance
Increased checkpoint frequency , because the physical log space is depleted more quickly (You can increase the size of the physical log to avoid the increase in checkpoint frequency.)
...
Рейтинг: 0 / 0
08.02.2012, 08:39
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37651150
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
Физический журнал я смотрю немаленький:

Physical Logging
Buffer bufused bufsize numpages numwrits pages/io
P-2 25 256 6501191 153521 42.35
phybegin physize phypos phyused %used
11:53 7864320 3581499 184 0.00


Какой размер у отдельного файла логического журнала? параметр LOGSIZE
...
Рейтинг: 0 / 0
08.02.2012, 08:53
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652687
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
AndronЯковлев Павел,
У вас параметр RTO_SERVER_RESTART=180 seconds что может быть причиной частых контрольных точек. Предлагаю для начала совсем отключить его и посмотреть как это скажется на частоте КТ.

При контрольных точках требующихся для поддержания RTO причина так и называется - RTO
А тут Llog :(

Но отключение RTO одни из пунктов в плане "что-бы-такое-отломать-что-бы-таки-заработало"
...
Рейтинг: 0 / 0
08.02.2012, 22:00
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652693
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
AndronФизический журнал я смотрю немаленький:

Physical Logging
Buffer bufused bufsize numpages numwrits pages/io
P-2 25 256 6501191 153521 42.35
phybegin physize phypos phyused %used
11:53 7864320 3581499 184 0.00


Какой размер у отдельного файла логического журнала? параметр LOGSIZE

Да, размер physlog ставился что бы Informix отвязался со своими рекомендациями + следуя совету про 110% от размера буферов

Данные о logical log
Код: plaintext
1.
2.
3.
4.
LOGFILES        534             
LOGSIZE         20000           
LOGBUFF         512           
DYNAMIC_LOGS    2

Так стоит уже с год. А траблы свежие.
...
Рейтинг: 0 / 0
08.02.2012, 22:04
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652696
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
И все таки

Какой размер у отдельного файла логического журнала? параметр LOGSIZE
Может быть журналы слишком малы и поэтому происходит частый чекпоинт, при переключении очередного журнала.
...
Рейтинг: 0 / 0
08.02.2012, 22:05
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652707
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
Яковлев Павел,

Спросил когда ты уже ответил :)

Журналы тоже немаленькие
А какой характер работы с базой? Может какие то lob'ы (или lvarchar к примеру) часто и много в базу пишутся (стали писаться)?
...
Рейтинг: 0 / 0
08.02.2012, 22:09
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652728
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
AndronЖурналы тоже немаленькие
А какой характер работы с базой? Может какие то lob'ы (или lvarchar к примеру) часто и много в базу пишутся (стали писаться)?
От посетилей сайт мелкие транзакции по их данным.
От демонов - обработка разных логов, но тут таблицы без lob и строчки не особо большие. Транзакции собираются из действий по обработке строк логов ( 1-2 тысяч строк на транзакцию). insert/update.
Есть одна часть с регулярной вставкой byte и в пару к ней с удалением старых byte, но не там не мега-объёмы.

И фигня в том что все эти нагрузки по дню равномерны. А время через которое база оказывается в описанном состоянии - пока выглядит произвольным.

Вот кстати пример начала работы после перезапуска - интервалы 3-5 минут, а не каждую секунду
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
5599024    15:48:32  Startup    1580706:0x6f6754  2.1   2.1   0.0   0      0.0   0.0   0.0   60063     28835   60407    170    5653     15    
5599025    16:08:59  Llog       1580738:0x24f9370 16.7  16.5  0.0   21     0.0   0.1   0.1   187548    11348   710004   585    329959   272   
5599026    16:11:53  Llog       1580745:0x22de478 14.1  13.8  0.0   6      0.0   0.0   0.0   153991    11131   144031   818    70554    400   
5599027    16:13:45  Llog       1580749:0x242c594 16.2  16.1  0.0   12     0.0   0.0   0.0   165375    10258   171293   1557   43563    396   
5599028    16:14:49  Llog       1580752:0x138b2b4 9.1   9.0   0.0   8      0.0   0.0   0.0   181748    20127   181163   2551   26767    377   
5599029    16:18:06  Llog       1580757:0x16dd1d4 16.7  16.3  0.0   10     0.0   0.0   0.0   164226    10079   168630   887    52035    273   
5599030    16:23:39  Llog       1580765:0x2610734 10.9  10.9  0.0   5      0.0   0.0   0.0   92064     8484    180292   531    84286    248   
5599031    16:26:36  Llog       1580770:0x26df048 9.9   9.9   0.0   5      0.0   0.0   0.0   91335     9266    105704   593    50964    286   
5599032    16:29:55  Llog       1580774:0x25c5494 10.6  10.1  0.0   3      0.0   0.0   0.0   87475     8683    103776   524    40208    203   
5599033    16:38:43  Llog       1580783:0x26720a4 11.2  11.1  0.0   3      0.0   0.0   0.0   82814     7455    195674   371    90481    171   
5599034    16:41:56  Llog       1580787:0x211076c 12.8  12.8  0.0   4      0.0   0.0   0.0   100982    7916    104635   544    39390    205   
5599035    16:44:48  Llog       1580790:0x26df6bc 12.0  11.9  0.0   9      0.0   0.0   0.0   95253     7972    92514    534    32054    185   
5599036    16:47:23  Llog       1580793:0x25aa4b0 9.8   9.7   0.0   8      0.0   0.0   0.0   75488     7798    79273    504    30069    191   
5599037    16:50:11  Llog       1580796:0x25090f0 10.5  10.5  0.0   3      0.0   0.0   0.0   73936     7058    87489    523    32136    192   
5599038    16:53:45  Llog       1580800:0x24f8560 10.6  10.2  0.0   4      0.0   0.0   0.0   78717     7729    108197   505    40248    188   
5599039    17:05:12  Llog       1580810:0x1a38228 1.6   1.6   0.0   7      0.0   0.0   0.0   36735     22663   185756   266    98487    141   
5599040    17:06:43  Llog       1580812:0x1f8856c 0.2   0.2   0.0   1      0.0   0.0   0.0   13088     13088   26883    292    21360    232   
5599041    17:08:14  Llog       1580813:0x175365c 1.9   1.8   0.0   2      0.0   0.0   0.0   29645     16040   28360    315    7899     87
...
Рейтинг: 0 / 0
08.02.2012, 22:25
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652729
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
Вот кстати пример со срывом в штопор

С 9:47 до 12:07 вообще без КТ. Потом пара точек с интервавлом в 2.5 часа от RTO. И потом через почти два часа и одну промежуточную точку начинается цирк.

Я сейчас коплю onstat-a раз в пару минуту, что бы тупо делать diff в момент начала проблемы. Но тут надо ещё добраться исследовать на что блин времени не хватает.

Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
5524455    09:40:53  Llog       1580102:0x25cb708 9.3   9.2   0.0   6      0.0   0.0   0.0   59828     6493    78231    518    29779    197
5524456    09:43:50  Llog       1580105:0x24c33bc 7.6   7.1   0.0   4      0.0   0.0   0.0   59243     8313    91562    511    29736    166
5524457    09:47:33  Llog       1580109:0x21991c4 7.9   7.9   0.0   1      0.0   0.0   0.0   70024     8862    106278   476    39190    175
5524458    12:07:12  RTO        1580166:0x21237c  0.3   0.3   0.0   7      0.0   0.0   0.0   17055     17055   743102   88     561929   67
5524459    14:42:04  RTO        1580221:0x1462158 2.6   0.0   0.0   101    0.0   1.5   2.5   907       907     781259   84     554688   59
5524460    15:14:55  Llog       1580233:0x25010a0 2.9   2.7   0.0   1      0.0   0.0   0.0   55330     20363   224697   114    124255   63
5524461    17:05:20  Llog       1580274:0x15d61f0 0.9   0.8   0.0   11     0.0   0.0   0.0   31834     31834   617871   93     406117   61
5524462    17:05:56  Llog       1580274:0x2089610 1.4   1.4   0.0   10     0.0   0.0   0.0   10324     7645    9795     279    2747     78
5524463    17:06:06  Llog       1580274:0x26f30dc 0.2   0.2   0.0   4      0.0   0.0   0.0   1980      1980    3232     293    1642     149
5524464    17:06:07  Llog       1580274:0x26fa184 0.9   0.0   0.0   44     0.0   0.5   0.8   28        28      36       36     7        7
5524465    17:06:08  Llog       1580274:0x270f0d0 1.0   0.0   0.0   68     0.0   0.7   1.0   181       181     150      150    21       21
5524471    17:07:25  Llog       1580275:0x24f21f8 1.0   0.0   0.0   76     0.0   0.8   1.0   223       223     141      141    18       18
5524472    17:07:26  Llog       1580275:0x24ff170 1.0   0.0   0.0   87     0.0   0.8   1.0   178       178     123      123    13       13
5524473    17:07:27  Llog       1580275:0x251418c 1.1   0.0   0.0   109    0.0   0.9   1.1   285       285     228      228    21       21
5524474    17:07:28  Llog       1580275:0x252c114 0.9   0.0   0.0   92     0.0   0.7   0.9   251       251     220      220    24       24
5524475    17:07:29  Llog       1580275:0x253b29c 1.0   0.0   0.0   99     0.0   0.9   1.0   196       196     145      145    15       15
5524476    17:07:30  Llog       1580275:0x254d224 1.0   0.0   0.0   111    0.0   0.8   1.0   314       314     274      274    18       18
5524477    17:07:31  Llog       1580275:0x2566318 1.0   0.0   0.0   99     0.0   0.9   1.0   220       220     176      176    25       25
5524478    17:07:32  Llog       1580275:0x25791e4 1.0   0.0   0.0   83     0.0   0.8   1.0   192       192     166      166    19       19
5524479    17:07:33  Llog       1580275:0x25880b0 1.0   0.0   0.0   84     0.0   0.9   1.0   173       173     140      140    15       15
5524480    17:07:34  Llog       1580275:0x2598620 1.0   0.0   0.0   97     0.0   0.9   1.0   170       170     143      143    16       16
5524481    17:07:35  Llog       1580275:0x25ae150 1.0   0.0   0.0   83     0.0   0.8   1.0   223       223     191      191    22       22
5524482    17:07:36  Llog       1580275:0x25b913c 1.0   0.0   0.0   86     0.0   0.8   1.0   158       158     125      125    11       11
5524483    17:07:37  Llog       1580275:0x25cf1c0 1.0   0.0   0.0   79     0.0   0.8   1.0   202       202     184      184    22       22
...
Рейтинг: 0 / 0
08.02.2012, 22:30
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652990
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
Обновить до 11.50.xC9 которая вышла еще в прошлом году ?
...
Рейтинг: 0 / 0
09.02.2012, 08:52
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37652992
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
Кстати приведи вывод onstat -u |grep -v Y в момент возникновения проблемы.
Логи в момент проблемы часто переключаются?
...
Рейтинг: 0 / 0
09.02.2012, 08:56
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37653351
яфшуеі
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
яфшуеі
Гость
Что-то такое біло, но правда давно:
http://www-01.ibm.com/support/docview.wss?uid=swg1IC61144

а срепликациями что у вас?9903
...
Рейтинг: 0 / 0
09.02.2012, 11:51
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37654815
ifmx_support
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
ifmx_support
Гость
IMHO слишком маленький размер файлов журнала. Вместо 500 по 20000 сделай 50 по 200000.
А лучше обратитесь в поддержку ;-)
...
Рейтинг: 0 / 0
09.02.2012, 20:55
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37654943
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
ifmx_supportIMHO слишком маленький размер файлов журнала. Вместо 500 по 20000 сделай 50 по 200000.
А обоснование ?

ifmx_supportА лучше обратитесь в поддержку ;-)
ifmx_suport уже помогает :)
...
Рейтинг: 0 / 0
09.02.2012, 22:43
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37654948
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
яфшуеіЧто-то такое біло, но правда давно:
http://www-01.ibm.com/support/docview.wss?uid=swg1IC61144

а с репликациями что у вас?9903
спасибо за наводку но не то - вообще индексов не делаем на временных таблицах

если репликация это ER то почти ничего - была для теста, а сейчас давно уже все replset-ы удалены, а парный сервер загашен.
...
Рейтинг: 0 / 0
09.02.2012, 22:46
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37654956
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
AndronОбновить до 11.50.xC9 которая вышла еще в прошлом году ?
пока не вариант - там нет ничего нам интересного, а обновить "может там ЭТОГО нет" - пока не на столько отчаился :)
хотца таки до причины докопаться

AndronКстати приведи вывод onstat -u |grep -v Y в момент возникновения проблемы.
Логи в момент проблемы часто переключаются?
Нет - лог один и тот же (клонка LSN до двоеточия) но в нём 100500 КТ

в приложении запрошеный onstat -u для листинга КТ который в моём ответе от 8го в 22:30 (тот что с парой RTO)

время снятия onstat -u - 16:09 - за час до начала траблов
...
Рейтинг: 0 / 0
09.02.2012, 22:53
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37654958
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
а вот onstat -u для времени 17:08 - когда тока-тока попёрло раз в секунду
...
Рейтинг: 0 / 0
09.02.2012, 22:55
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37655206
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
Посмотрел приложенный onstat -u, вполне коррелирует с выводом onstat -g ckp, много нитей ждут на чекпоинте. Но что интересно, нить Btree scanner имеет просто таки большое кол-во чтений nreads:

395ffa9c8 ---P--B 616 ******** - 0 0 0 913350569 608541

и если связать это как то с тем что ранее написал яфшуеі про http://www-01.ibm.com/support/docview.wss?uid=swg1IC61144 то напрашивается вывод что возможно имеет место баг?
На моих серверах Informix с uptime в неск.месяцев нигде нет такого большого значения для чистильщика индексов, хотя пользователи активно работают с данными. Какой uptime у твоего информикса?

Как часто в выводе onstat -g act есть нитка Btree когда возникает проблема а также когда проблемы нет? Еще бы неплохо вывод onstat -C
...
Рейтинг: 0 / 0
10.02.2012, 08:40
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37655402
Фотография Andron
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Andron
Участник
Мой пост насчет большого значения nreads для Btree сканера возможно не в тему, я не учел что у меня на серверах сбрасывается системная статистика каждые сутки.
...
Рейтинг: 0 / 0
10.02.2012, 11:12
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37655596
DrGonzo
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
DrGonzo
Участник
Яковлев Павел,

HDR используете?
...
Рейтинг: 0 / 0
10.02.2012, 12:39
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37655771
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
AndronПосмотрел приложенный onstat -u, вполне коррелирует с выводом onstat -g ckp, много нитей ждут на чекпоинте. Но что интересно, нить Btree scanner имеет просто таки большое кол-во чтений nreads:

395ffa9c8 ---P--B 616 ******** - 0 0 0 913350569 608541

и если связать это как то с тем что ранее написал яфшуеі про http://www-01.ibm.com/support/docview.wss?uid=swg1IC61144 то напрашивается вывод что возможно имеет место баг?
На моих серверах Informix с uptime в неск.месяцев нигде нет такого большого значения для чистильщика индексов, хотя пользователи активно работают с данными. Какой uptime у твоего информикса?

Как часто в выводе onstat -g act есть нитка Btree когда возникает проблема а также когда проблемы нет? Еще бы неплохо вывод onstat -C
в тему - не в тему но отвечу

сейчас аптайм 14 часов (это я перезапускал что бы получить момент просветления. до начала проблем он приближался к году)

нить сканёра то есть то нет

onstat -c
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
B-tree Scanner Information
Profile
=======
Active Threads                               1
Global Commands                              0  
Number of partition scans                 3611
Main Block                          0x00000003956d9dc0
BTC Admin                           0x0000000000000000


BTS info             id   Prio    Partnum      Key     Cmd  
0x396653a88           0   High   0x00500179     1 10000000  Scan index
    Number of leaves pages scanned                 1657712675
    Number of leaves with deleted items               2950976
    Time spent cleaning (sec)                           40036
    Number of index compresses                         134615
    Number of deleted items                          27721632
    Number of index range scans                             0
    Number of index leaf scans                           1509
    Number of index alice scans                         25630

совсем в теории ему есть чего делать - перед новым годом мы заводит новый dbspacе log.20xx и настраиваем туда по условию порции таблиц и индексов для тех логов которые хорошо делятся по годам (а не нужный поза-поза-прошлый год архивируем и отстреливаем)

это вполне может вызвать нужду в перетасовке индексов но уже февраль и все процессы давно закончится должны были
других причин массово менять индексы нет
...
Рейтинг: 0 / 0
10.02.2012, 13:48
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37655778
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
DrGonzoHDR используете?

нет
...
Рейтинг: 0 / 0
10.02.2012, 13:49
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37655993
яфшуеі
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
яфшуеі
Гость
Когда-то задался целью хранить историю к.т.
просмотрел у себя историю с 2010-01-27
Ни одной к.т. по Trigger llog не нашел.

Правда, у меня подход к к.т. немного другой и система судя по всему отличается.
11.50.FC5W2
AUTO_CKPTS=Off RTO_SERVER_RESTART=Off
РТО не использую, так как он не учитывает длину транзакции, а то,
что он пишет дополнительно в физ журнал - как-то так скользко сказано.
Во всяком случае, документация пока не убедила меня, возможно
кто-то даст примеры для сравнения.

Как по мне более критично именно логическое восстановление.
Поэтому, согласно требованиям системы выставляем CKPTINTVL и устанавливаем LTXHWM.
Так выглядит значительно проще для понимания что и как настроено, во всяком случае для себя.

Еще момент у меня
DYNAMIC_LOGS 0

У вас с физ. журалом интенсивность чуток поболее чем у меня.
А при включенном RTO туда больше пишется.

IBM дал краткое описание что такое llog, но как всегда - далеко не полное.
Хотя б расписали при каких условиях.

Возможно, что єто и AUTO_CKPTS так сказівается, описание как оно там все учитывается довольно расплывчатое.
Как вариант - может ДМ притормаживать и механизм AUTO_CKPTS посчитает что нужно чаще.

Попробуйте вернуться на старый подход по определению интенсивности к.т.
...
Рейтинг: 0 / 0
10.02.2012, 15:10
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37656756
Яковлев Павел
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Яковлев Павел
Гость
ну чтожжжж решение нейтрализующие проблему найдено (яфшуеі тоже верно наметил куда копать но только на 15 часов позже :) )

в очередной раз перечитывая " Non-blocking checkpoints in Informix Dynamic Server " таки повнимательнее прочёл про AUTO_CKPTS (раньше оказывается не сознавал что он сам по себе а не часть RTO)
Код: plaintext
1.
2.
3.
Automatic checkpoints
You can set the AUTO_CKPTS configuration parameter in the ONCONFIG file to turn off automatic triggering of checkpoints by ignoring past checkpoint performance. 
This has the effect of returning the server to triggering checkpoints based only on the four events noted above in the Tuning checkpoints section.

Получается что параметр разрешает КТ на основе "прошлой производительности КТ". И так как других кандидатов на КТ по причине Llog в перовом часу ночи не было, то я AUTO_CKPTS и отключил (RTO осталось). Судя по всему (листинг внизу) - угадал.

Получается что checkpoint с причиной Llog это деятельность AUTO_CKPTS .

К сожалению, почему у меня оно сошло с ума остаётся неясным. Попробую вытянуть из саппорта детали как оно устроено. Получится - напишу.

Буду сидеть с AUTO_CKPTS=0 и делать КТ сам тупо по крону и/или при ротации логов. Месяца через 2-3 попробую из любопытства вернуть - вдруг "история производительности КТ" как-то волшебно прочистится (или покопаюсь с системных таблицах где там история эта прячится).

Вот текущий onstat -g ckp - просто загляденье

Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
39.
40.
AUTO_CKPTS=Off   RTO_SERVER_RESTART=180 seconds   Estimated recovery time 149 seconds

                                                                    Critical Sections                          Physical Log    Logical Log    
           Clock                                  Total Flush Block #      Ckpt  Wait  Long  # Dirty   Dskflu  Total    Avg    Total    Avg   
Interval   Time      Trigger    LSN               Time  Time  Time  Waits  Time  Time  Time  Buffers   /Sec    Pages    /Sec   Pages    /Sec  
5764058    23:14:08  Startup    1581991:0x1c6429c 0.5   0.5   0.0   0      0.0   0.0   0.0   28440     28440   28594    223    3424     26    
5764059    23:24:13  Llog       1582008:0x268d204 16.8  16.7  0.0   15     0.0   0.0   0.0   280043    16748   516195   874    175639   297   
5764060    23:26:49  Llog       1582013:0x264a4a4 16.8  16.7  0.0   12     0.0   0.0   0.0   249783    14945   234057   1500   53222    341   
5764061    23:35:39  Llog       1582024:0x21d07e4 9.4   9.3   0.0   7      0.0   0.0   0.0   235852    25350   454546   846    110418   205   
5764062    23:45:10 *Admin      1582035:0x5ec11c  0.1   0.0   0.0   31     0.0   0.1   0.1   303       303     283494   488    102859   177   
5764063    23:45:15 *Admin      1582035:0x8fa1b4  0.1   0.0   0.0   7      0.0   0.1   0.1   40        40      3662     732    782      156   
5764064    23:59:59  Llog       1582049:0x259e524 8.2   8.0   0.0   11     0.0   0.1   0.1   87609     10888   199750   228    152156   173   
5764065    00:00:27  Llog       1582052:0x207c228 5.1   4.9   0.0   14     0.2   0.2   0.2   133225    27151   151171   4876   31694    1022  
5764066    00:01:07  Llog       1582054:0x252348c 5.7   5.6   0.0   5      0.0   0.0   0.0   78221     14054   78682    1967   23219    580   
5764067    00:02:21  Llog       1582055:0x25ab418 4.0   3.8   0.0   2      0.0   0.0   0.0   73903     19204   73837    984    10136    135   
5764068    00:11:48  Llog       1582062:0x25fa644 5.7   5.5   0.0   5      0.0   0.0   0.0   60618     11089   124129   219    70079    123   
5764069    00:13:58  Llog       1582064:0x1ae51f4 9.4   9.3   0.0   7      0.0   0.0   0.0   101052    10914   118911   943    17419    138   
5764070    00:15:27 *Backup     1582067:0xb8558   1.8   1.7   0.0   6      0.0   1.8   1.8   15452     9299    50266    518    17961    185   
5764071    00:17:37  Llog       1582068:0x20e0154 8.6   8.5   0.0   6      0.0   0.0   0.0   70651     8292    68697    558    18488    150   
5764072    00:23:16  Llog       1582074:0x24d6184 5.7   5.6   0.0   7      0.0   0.0   0.0   66260     11873   142490   416    61270    179   
5764073    00:26:15  Llog       1582078:0x2020768 7.8   7.6   0.0   4      0.0   0.0   0.0   71603     9369    89757    507    39479    223   
5764074    00:29:08  Llog       1582082:0x21e8114 10.1  10.0  0.0   5      0.0   0.0   0.0   80231     8049    92465    543    41511    244   
(вот тут я и отключил "это")
5764075    01:07:51  RTO        1582139:0x153c2b8 5.6   5.3   0.0   5      0.0   0.0   0.1   48854     9138    780573   335    567281   243   
5764076    01:51:38  RTO        1582195:0x22676b0 2.7   2.6   0.0   3      0.0   0.1   0.1   17799     6777    852159   324    563371   214   
5764077    02:38:40  RTO        1582251:0xea02dc  0.5   0.5   0.0   1      0.0   0.0   0.0   25658     25658   891480   315    554937   196   
5764078    04:18:37  RTO        1582310:0x24da624 0.3   0.3   0.0   5      0.0   0.0   0.0   15661     15661   555560   92     595690   99    
5764079    06:09:16  RTO        1582370:0x12e7600 0.3   0.3   0.0   7      0.0   0.0   0.0   6630      6630    531595   80     595405   89    
5764080    07:46:20  RTO        1582430:0x20497c0 0.4   0.4   0.0   2      0.0   0.0   0.0   19900     19900   478741   82     603427   103   
5764081    09:30:00  RTO        1582489:0x1669500 0.6   0.5   0.0   3      0.0   0.0   0.0   28607     28607   594397   95     587471   94    
5764082    11:08:25  RTO        1582547:0x2253470 1.6   0.9   0.0   12     0.0   0.0   0.0   34946     34946   665653   112    583050   98    
5764083    12:47:52  RTO        1582606:0x1690558 3.1   3.0   0.0   4      0.0   0.0   0.0   35355     11841   609469   102    586987   98    
5764084    14:35:13  RTO        1582665:0x1bbf354 0.8   0.5   0.0   5      0.0   0.0   0.0   24216     24216   588251   91     591327   91    
5764085    16:20:15  RTO        1582723:0x17b75d0 2.4   2.3   0.0   6      0.0   0.0   0.0   33465     14430   684760   108    578968   91    
5764086    18:23:37  RTO        1582782:0xc71620  0.5   0.4   0.0   4      0.0   0.0   0.0   19242     19242   603279   81     587114   79    
5764087    20:03:10  RTO        1582840:0x1cfd0fc 0.2   0.1   0.0   6      0.0   0.0   0.0   2176      2176    631434   105    584235   97    

Max Plog       Max Llog       Max Dskflush   Avg Dskflush   Avg Dirty      Blocked      
pages/sec      pages/sec      Time           pages/sec      pages/sec      Time         
10233          2297           17             15882          452            0

спасибо за попытки помочь.
...
Рейтинг: 0 / 0
10.02.2012, 22:38
| Ответить | Цитировать | Написать  
Частые контрольные точки с причиной Llog
    #37659058
vasilis
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
vasilis
Участник
Прошу прощения за наивный вопрос, но все же:
Традиционный параметр CKPTINTVL в вашей версии уже не актуален ?

P.S. Как то стрЁмно видеть КТ с интервалом в 2 часа при активно работающей системе...
...
Рейтинг: 0 / 0
13.02.2012, 14:16
| Ответить | Цитировать | Написать  
25 сообщений из 32, страница 1 из 2
  1  все
Форумы / Informix [игнор отключен] [закрыт для гостей] / Частые контрольные точки с причиной Llog
Целевая тема:
Создать новую тему:
Автор:
Закрыть
Цитировать
Найденые пользователи ...
Разблокировать пользователей ...
Читали тему (0):
Читали форум (0):
Пользователи онлайн (0):
Польз. соглашение
NoSQL.ru, Чат Кролика       Пашэ: Рисунки, Чат       Фотоальбом: Участники, Встречи
Закрыть
start [/forum/topic.php?fid=44&fpage=14&tid=1607198]:
 0ms
get settings:
 17ms
get forum list:
 5ms
check forum access:
 1ms
check topic access:
 1ms
track hit:
 35ms
get topic data:
 5ms
get forum data:
 1ms
get page messages:
 689ms
get tp. blocked users:
 1ms
others: 312ms
total:  1067ms
созд. / загр.: 1067ms
x
x
Закрыть


Просмотр
0 / 0
Close
Debug Console [Select Text]