powered by simpleCommunicator - 2.0.61     © 2026 Programmizd 02
Целевая тема:
Создать новую тему:
Автор:
Закрыть
Цитировать
Форумы / Firebird, InterBase [игнор отключен] [закрыт для гостей] / Многочасовой тест на открытие и убиение сотен ISQL-окон
21 сообщений из 21, страница 1 из 1
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368509
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
hi all

Есть тест, который в беспробудн бесконечном цикле:
1) стартует сотни окон с запуском в них ISQL (start /min isql ...) с аттачем к базе (без какого либо входного скрипта, т.е. окна просто запускают ISQL и "ждуть");
2) делает паузу в 30 сек, ожидая пока все окна откроются
3) вызывает psList -m | findstr /i /c:%FIREBIRD_PROCESS%, с логированием потребляемой процессом firebird памяти
4) вызывает psKill isql, что вызывает практически одновременное убиение всех аттачей.
5) делает паузу в 30 сек, ожидая пока все isql-окна будут убиты
6) снова вызывает psList -m | findstr /i /c:%FIREBIRD_PROCESS%
7) goto "1)"

Количество открываемых isql-окон настраивается внутри батника, заданием переменной.
Например, для 100 коннектов на SS (WI-T3.0.0.30590) с кешем базы = 256 в логе psList'a будем видеть:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
firebird           3488  270284   51008  106236  262948    77936    142  111 -- до старта окон

firebird           3488  397900   88704  200308  262948    87523    240  147 -- isql'и стартовали, ждут
firebird           3488  204136   11952    8344  262948    87532     41   80 -- после убиения всех isql'ей

firebird           3488  358668   53432  108788  262948    98088    146  120 -- isql'и снова стартовали и ждут
firebird           3488  253288   12972    9424  262948    98090     43   80 -- isql'и снова убиты, и т.д.

firebird           3488  268556   51788  106980  262948   108408    142  119
firebird           3488  163176   11196    7540  262948   108408     40   79

firebird           3488  266376   51704  106708  262948   118729    142  119
firebird           3488  161128   11164    7496  262948   118729     40   79

firebird           3488  358668   53388  108728  262948   129471    146  120
firebird           3488  253288   12900    9376  262948   129471     43   80
Цель этого цикла была простая: проверить, не утекает ли память в системе после таких глумлений, повторенных сотни раз.

Оставленный на ночь с заданием открывать 400 окон, к утру он загадил firebird.log мессагами-паразитами (INET/inet_error: read errno = 10054), но также вижу в логе в двух местах вот это:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
CSMIRROR        Fri Aug 16 01:15:52 2013
        Fatal lock manager error: invalid lock id (62016), errno: 0

CSMIRROR        Fri Aug 16 02:40:49 2013
        Shutting down the server with 1 active connection(s) to 1 database(s), 0 active service(s)

CSMIRROR        Fri Aug 16 02:40:49 2013
        Fatal lock manager error: invalid lock id (83004), errno: 0

(один раз, как видим, ФБ не выдержал и рестартовал).

2 dimitr:
1) этот самый "errno: 0" - он критичен или нет ?
2) существует ли возможность заставить ФБ автоматически сбрасывать инфу из лок-таблицы в файл с именем типа fb_lock_print_YYYYMMDD_HHmmss.log, когда происходят вот такие ситуации и ФБ вынужден завершаться ?
3) (полуофф, но таки очень надо) нельзя ли в трёшке наконец-то добавить в конфиг параметр, запрещающий гадить в лог сообщениями, НЕ относящимися к работе собс-но движка или к состоянию базы ? (я всё про эти INET/inet_error'ы).

ЗЫ. Есть модификация этого же теста (прототип его - тут ), но в ней ISQL'и уже не сидят без дела в ожидании убиения, а кое-что молотят и завершаются. Там тоже логируется потребление памяти - но об этом попозже.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368539
dimitr
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Таблоид1) этот самый "errno: 0" - он критичен или нет ?
2) существует ли возможность заставить ФБ автоматически сбрасывать инфу из лок-таблицы в файл с именем типа fb_lock_print_YYYYMMDD_HHmmss.log, когда происходят вот такие ситуации и ФБ вынужден завершаться ?
3) (полуофф, но таки очень надо) нельзя ли в трёшке наконец-то добавить в конфиг параметр, запрещающий гадить в лог сообщениями, НЕ относящимися к работе собс-но движка или к состоянию базы ? (я всё про эти INET/inet_error'ы).
1) когда как. Надо его ловить и смотреть.
2) должен был создаться файл fb_lock_table.dump, на него можно натравить fb_lock_print
3) нельзя. А вот условно или безусловно вынести все сетевые ошибки в отдельный лог - можно подумать. Если в трекере этого еще нет, то пиши.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368572
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
dimitr2) должен был создаться файл fb_lock_table.dump, на него можно натравить fb_lock_printнарыл я его, у чёрта на рогах он был: "C:\Documents and Settings\All Users\Application Data\firebird\" (почему не в FIREBIRD_TMP или в TEMP ПРОСТО ??)
В аттаче - сам дамп и результаты fb_lock_print [-a] к нему.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368584
Фотография Симонов Денис
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Таблоид,

дык майкрософт туда рекомендует все настроечные и временные файлы сбрасывать. Одно время переводили одну программу, так там 7 все мозги высосала из-за прав администратора, пришлось складывать согласно их рекомендациям.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368612
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Симонов Денисдык майкрософт туда рекомендует все настроечные и временные файлы сбрасывать. Одно время переводили одну программу, так там 7 все мозги высосала из-за прав администратора, пришлось складывать согласно их рекомендациям.Ну ладно настроечные файлы (небольшого размера!), но ВРЕМЕННЫЕ, в т.ч. дампы, - какое дело маздаю маздаю, где я буду их держать ?
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368615
dimitr
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Таблоид,

там сервер держит лок-таблицы, там же и дампы заодно создаются
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368625
Фотография Симонов Денис
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Таблоид,

В Windows все дампы падающих программ размещаются по такому принципу. Правда не знаю какое отношение к этому имеет fb_lock_table.dump и насколько он похож на те что генерятся виндой
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368886
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
dimitr2) должен был создаться файл fb_lock_table.dump, на него можно натравить fb_lock_printповторил забег - снова завалился, лок-таблу и фрагмент лога ФБ см в аттаче
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368903
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
dimitrТаблоид3) (полуофф, но таки очень надо) нельзя ли в трёшке наконец-то добавить в конфиг параметр, запрещающий гадить в лог сообщениями, НЕ относящимися к работе собс-но движка или к состоянию базы ? (я всё про эти INET/inet_error'ы)....
3) нельзя. А вот условно или безусловно вынести все сетевые ошибки в отдельный лог - можно подумать. Если в трекере этого еще нет, то пиши.Просмотрел трекер в поисках "inet" в темах топиков - не нашел просьб по этому вопросу. Короче, CORE-4182
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38368923
Гаджимурадов Рустам
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
dimitr > А вот условно или безусловно вынести все сетевые ошибки в отдельный лог - можно подумать

Хозяин барин, конечно, но не расплодится ли? Впрочем, если "условно"...

Posted via ActualForum NNTP Server 1.5
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38369018
dimitr
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Гаджимурадов РустамХозяин барин, конечно, но не расплодится ли? Впрочем, если "условно"...
расплодится число логов имеешь ввиду? В трекере еще вывод валидации предлагали в отдельный лог писать, АК/ДК вроде этого хотели.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38369035
Гаджимурадов Рустам
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
dimitr> расплодится число логов имеешь ввиду?

Ну да.

dimitr> В трекере еще вывод валидации предлагали в отдельный лог писать, АК/ДК вроде этого хотели.

gfix в смысле? Это поддерживаю, ибо валидация автоматом
никак не запускается и результат её работы нужен и важен
сразу и интерактивно - в отдельном логе gfix-a.

Posted via ActualForum NNTP Server 1.5
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38369807
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
В общем, нарыл следующее.
Если :
I. на машине-1 (машина-"паразит") выполнить вечный коннект к WI-T3.0.0.х,
II. на машине-2 (машина-"работяга") выполнять в цикле:
II. 1. логирование информации о потребляемой процессом firebird памяти (утилитой psList);
II. 2. открытие 100 isql-окон (даже просто чтобы они заходили в режим "SQL>"-подсказки и ничего больше не делали)
II. 3. их удержание в таком состоянии некоторое время (чтобы точно был промежуток времени, когда они ВСЕ загружены);
II. 4. одновременное (почти) убиение всех процессов isql утилитой psList.exe;
II. 5. повторное логирование информации о памяти процесса firebird (как в п. 1)

- то:
1. процесс firebird совершенно точно начинает отъедать память.
пример лога
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
19:06:22 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
19:06:22 firebird          12156   61592   12380   11868   12856     3570     38   72 -- перед первым открытием 100 isql'ей

19:06:33 firebird          12156  495928  117976  240732  240732    35252    227  115 -- открыты 100 isql
19:06:52 firebird          12156  273440   21748   21156  240744    35380     49   86 -- после одновременного убиения 100 isql

19:07:02 firebird          12156  498452  120328  243344  243344    65402    229  115 -- снова открыты 100 isql
19:07:21 firebird          12156  280056   25416   27944  243344    65403     53   86 -- и снова одновременно убиты 100 isql

19:07:30 firebird          12156  508244  124008  249164  249164    95357    233  116 -- и т.д.
19:07:49 firebird          12156  285496   26868   29416  249228    95360     54   86 -- и т.п.

19:07:59 firebird          12156  509652  124648  250592  250592   125111    234  116
19:08:18 firebird          12156  286840   28256   30792  250592   125117     55   86

19:08:27 firebird          12156  510996  126232  251944  251944   154918    235  116
19:08:46 firebird          12156  288184   29600   32184  251944   154919     56   86

2. Отъедание памяти происходит ТОЛЬКО при условии, что на машине-"паразите" всё время висит isql-дармоед, который просто залочил одну запись в таблице. (Смысл залочивания этой записи в том, чтобы в случае, когда 100 isql'ей с машины-"работяги" будут запущены с заданием обновить эту же запись, то они упрутся лбами в неё (при штатном TIL = snapshot wait) и НЕ завершатся "сами по себе". И тогда можно быть увренным, что команда pskill isql, выданная на машине-"работяге", точно убьёт сразу весь батальон isql'ей, а не остатки его - ведь они точно все были в ступоре от блокировки с машины-1.)

3. Отъедание памяти НЕ происходит, если тест переделать таким образом, что первый из загружаемых isql'ей выполнит апдейт и начнёт имитацию ожидания выполнением shell ping -t localhost > nul;
Хотя все остальные isql'и и будут также застревать, как если бы этот первый "паразит" выполнял коннект с чужой машины, эффекта роста памяти не наблюдалось. Так что приходится работать именно с двумя разными МАШИНАМИ.

4. Отъедание памяти заметно гораздо сильнее, если каждое из isql-окон на машине-"работяге" будет вместо тупого входа в "SQL>"-подсказку выполнять DML (update tlock set f01=... where id=1), но еще сильнее - если PSQL (execute block).

5. В какой-то момент, когда физическая память еще далеко не исчерпана, с большой вероятностью происходит рестарт ФБ-службы, что видно по смене PID'a процесса ФБ в логе теста:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
19:06:22 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
19:06:22 firebird          12156   61592   12380   11868   12856     3570     38   72
<... skipped ...> <... skipped ...> <... skipped ...> <... skipped ...> 
19:11:21 firebird          12156  516756  135148  259820  259820   334121    239  116
19:11:40 firebird          12156  296184   38732   42360  259820   334121     62   87

19:11:51 firebird          12156  522324  137736  263408  263408   364178    241  116
19:12:10 firebird          12156  299576   40116   43772  263408   364183     63   87

19:12:21 firebird          12156  523668  138716  264764  264764   394137    242  116
19:12:40 firebird           12156   300920   41500   45136  264764   394137     64   87

19:12:49 firebird           16808    80352   12488   10676   23316     6638     38   72
19:13:08 firebird          16808   68280    6676    2676   23316     6640     36   58

19:13:18 firebird          16808  260832   17472   16152   46824    34209     46   85
19:13:37 firebird          16808  248760   11656    8152   46824    34210     43   72

19:13:47 firebird          16808  260832   17536   16192   46824    59785     46   85
19:14:06 firebird          16808  248760   11716    8200   46824    59785     43   72

19:14:15 firebird          16808  260832   17616   16188   46824    86426     46   85
19:14:34 firebird          16808  248760   11720    8200   46824    86426     43   72

В логе сервера при этом, помимо invalid lock id (NNNNN), errno: 0, будет нечто странное: якобы эта же база открыта "еще одним движком ФБ в еще одной Windows-сессии" (что есть ложь, разумеется: всё делаю силами одного инстанса ФБ).
firebird.log
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
CSMIRROR        Sat Aug 17 19:12:42 2013
        Fatal lock manager error: invalid lock id (69396), errno: 0

CSMIRROR        Sat Aug 17 19:12:42 2013
        INET/inet_error: read errno = 10054 // столько раз, сколько было срублено isql'ей

CSMIRROR        Sat Aug 17 19:12:42 2013
        ConfigStorage: Cannot initialize the shared memory region
        Database is probably already opened by another engine instance in another Windows session


CSMIRROR        Sat Aug 17 19:12:42 2013
        ConfigStorage: Cannot initialize the shared memory region
        Database is probably already opened by another engine instance in another Windows session
Пример дампа лок-таблицы, которая при этом создается, приведен тут (добавлено через почту, ссылка - вечная).

6. В случае, если ФБ всё-таки выдерживает оборону и память процесса firebird начинает иметь вот такие значения:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
firebird           3584   61444   12724   11876   13248     3692     38   71

firebird           3584  485664  114276  233616  234608    32958    223  113
firebird           3584  273700   22252   21416  234608    33086     49   86

firebird           3584  487596  116824  235616  236656    60502    224  113
firebird           3584  275244   23968   23084  236656    60502     50   86
<...>
-- примерно через 8 часов теста:
firebird           3584 2085504  350584 1557416 1562512 20500987   1083  168
firebird           3584 2085504  350584 1557416 1562512 20500987   1083  168

firebird           3584 2085504  350584 1557416 1562512 20500987   1083  168
firebird           3584 2085504  350584 1557416 1562512 20500987   1083  168

firebird           3584 2085504  350584 1557416 1562512 20500987   1083  168
firebird           3584 2085504  350584 1557416 1562512 20500987   1083  168
- в логе сервера появляется, и не один раз:
Код: plaintext
1.
2.
CSMIRROR	Sat Aug 17 09:17:58 2013
	unable to allocate memory from operating system

При этом, ФБ находится на самом деле в состоянии "грогги": он не отвечает на запросы и его службу невозможно остановить, приходится килять через ProcExplorer.

Далее приведу сам батник и его подробное описание. Для его работы нужны утилиты psList, psKill (от SysInternals), а также консольный rar для сохранения дампа лок-таблицы в отдельный архив.
Кроме того, в самом батнике юзается несколько set-переменных, завязанных на структуру каталогов - их надо будет подправить.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38369827
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Теперь - подробное описание теста.

Машина-1: с неё к базе TRNTEST (на машину -2 , с ниже) выполняется коннект (isql'ем от FB 2.5), выполняющий UPDATE единственной строки и НЕ делающий COMMIT:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
SQL> select * from tlock; update tlock set f01=rand()*1000; select * from tlock;

          ID          F01
============ ============
           1          680


          ID          F01
============ ============
           1          983
Назначение этого коннекта объяснялось выше, это - "стопорный болт" для гарантии загрузки всех isql-окон и их одновременного срубания.

Машина-2: Windows 2003 Server SP2, два ядра по 2.4 ГГц, память 1 Гб

На этой машине установлен WI-T3.0.0.30590, SuperServer, и создана база (alias = TRNTEST) и единственной табличкой TLOCK(id int primary key, f01 int) и одной записью в ней (id=1, f01=100).
Кроме того, на этой машине запускается батник следующего вида:
fblogmemo.bat
Код: 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.
41.
42.
43.
44.
45.
46.
47.
48.
49.
50.
51.
52.
53.
54.
55.
56.
57.
58.
59.
60.
61.
62.
63.
64.
65.
66.
67.
68.
69.
70.
71.
72.
73.
74.
75.
76.
77.
78.
79.
80.
81.
82.
83.
84.
85.
86.
87.
88.
89.
90.
91.
92.
93.
94.
95.
96.
97.
98.
99.
100.
101.
102.
@echo off
if .%1.==.. goto syntax
if .%2.==.. goto syntax
if .%3.==.. goto syntax

set mode=%1

@rem name of firebird process to be scanned by psList + parsing
set fbproc=firebird

@rem where firebird holds its LT dump when crashes:
set fbdump="%ALLUSERSPROFILE%\Application Data\firebird\fb_lock_table.dump"
@rem if exist %fbdump% rar u -ep -m5 -ag_YYYYMMDD_hhmm fb_lock_print_dump %fbdump%
@rem if exist *fb_lock_print_dump*.rar dir *fb_lock_print_dump*.rar | findstr /i /c:fb_lock_print_dump 2>nul

@rem number of test windows to be opened:
set n=%2
       
@rem seconds between kill test wondows and start new iteration:
set v=%3

@rem name of "main" log for this batch:
set logmain=fbmemo_%mode%_windows_cnt_%n%_interval_%v%.log

@rem path to temp folder where test window errors are logged:
set tmphome=c:\temp\trntest

@rem name of temp log for results of psList:
set logtemp=%tmphome%\tmp.tmp

del %logmain% 2>nul

@ rem. . . . . . . .     s t a r t i n g    . . . . . . . . 

@rem extract column titles from output of psList and put them into "main log" with current timestamp:
pslist -m | findstr /i /c:name >%logtemp% && call :addstamp %logtemp% %logmain%


@rem extract 1st memory snapshot before this run and put it into "main log" with current timestamp:
pslist -m | findstr /i /c:%fbproc% >%logtemp% && call :addstamp %logtemp% %logmain%

set k=1

set inswi=-i
set insql=fbmemo_%mode%.sql
if /i %mode%==idle set inswi=
if /i %mode%==idle set insql=
:m1
  @rem . . . . . . . . . . . .     l o o p      . . . . . . . . .

  @echo off
  @echo.>>%logmain%
  @echo iter # %k%
  @echo ##########

  if exist *fb_lock_print_dump*.rar echo ACHTUNG: FIREBIRD SERVER HAS BEEN RESTARTED! STOP THIS TEST!
  if exist *fb_lock_print_dump*.rar dir *fb_lock_print_dump*.rar | findstr /i /c:fb_lock_print_dump 2>nul

  for /L %%i in (1,1,%n%) do start %FB30BIN%\isql localhost/3330:trntest -n %inswi% %insql% 1>nul 2>>%tmphome%\fbmemo_%mode%_%%i.err


  @rem we must wait enough time for all test windows  loading has been finished:
  @echo 1. take some sleep before get memory snapshot. . .
  ping -n 10 127.0.0.1>nul

  pslist -m | findstr /i /c:%fbproc% >%logtemp% && call :addstamp %logtemp% %logmain%

  @rem drop isql which locking record:
  @rem pskill ping
  pskill isql
  @echo 2. take sleep %v% seconds before get memory snapshot. . .
  ping -n %v% 127.0.0.1>nul
  @rem echo %time% - memory after all test windows were killed: >>%logmain%%

  pslist -m | findstr /i /c:%fbproc% >%logtemp% && call :addstamp %logtemp% %logmain%

  if exist %fbdump% rar m -ep -m5 -ag_YYYYMMDD_hhmm fb_lock_print_dump %fbdump%
  @rem pause
  set /a k=k+1
goto m1

:addstamp

  @rem . . . . . . .      a d d    t i m e s t a m p   l e f t s i d e  . . . . . . .

  @rem echo args: 1= %logtemp%,  2 = %logmain%
  set /p row=<%1
  del %1
  for /F "tokens=1-3 delims=,:" %%i in ("%time%") do echo %%i:%%j:%%k %row% >>%2 2>nul 
  exit /b
:syntax
  @echo off
  cls
  echo.
  echo Usage: %0 mode n s
  echo where:
  echo      mode = idle ^| dml ^| psql
  echo         n = ^<number_of_test_windows^> 
  echo         s = ^<seconds_between_iterations^>
  echo.
  echo e.g:   %0 dml 100 30
  pause
:eof
Аргументы, требуемые им на вход:
Код: plaintext
1.
2.
3.
4.
5.
6.
Usage: fblogmemo.bat mode n s
where:
     mode = idle | dml | psql
        n = <number_of_test_windows>
        s = <seconds_between_iterations>

e.g:   fblogmemo.bat dml 100 30

Этот батник:
1) открывает через (start /min ...) нужное число isql-окон, задаваемое входным параметром #2, причём:
1.1) если батнику передан входящий аргумент #1 = idle, то эти окна ничего не делают, просто загружаются и остаются в режиме подсказки "SQL> _"
1.2) если передан аргумент = dml, то каждое из открываемых isql-окон выполнит скрипт с именем = fbmemo_dml.sql, в котором записаны команды, гарантирующие "ступор" всех isql'ей на команде обновления одной и той же записи, а именно - той, которая была залочена коннектом-"паразитом" (см предыдущий пост):
Код: sql
1.
2.
3.
4.
5.
commit;
set transaction wait;
select current_timestamp,k.* from tlock k where id=1;
update tlock set f01=rand()*100000 where id=1; -- упрётся! эта строка занята isql'ем с другой машины
quit;


1.3) если передан аргумент = psql, то каждое из окон выполнит execute block, содержание его аналогично пункту "1.2";
1.3) при передаче аргумента = atrn каждое из окон выполнит execute block с попыткой апдейта в автономной транзакции (было подозрение, что это еще быстрее заставит ФБ отъедать память).

Перед каждым тестом выполнялся рестарт ФБ. Затем сразу же - коннект к этой базе от машины-"паразита" с апдейтом строки таблицы TLOCK.

Далее перед основным циклом (внутри батника) выполняется два вызова psList + findstr:
1) для записи заголовков столбцов в лог.
2) для записи начального значения потребляемой процессом firebird'a памяти - когда к нему прицеплен только один коннект с машины-"паразита".
Вот этот фрагмент:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
@ rem. . . . . . . .     s t a r t i n g    . . . . . . . . 

@rem extract column titles from output of psList and put them into "main log" with current timestamp:
pslist -m | findstr /i /c:name >%logtemp% && call :addstamp %logtemp% %logmain%

@rem extract 1st memory snapshot before this run and put it into "main log" with current timestamp:
pslist -m | findstr /i /c:%fbproc% >%logtemp% && call :addstamp %logtemp% %logmain%
(вызов подпрограммы addstamp , добавляющей к строкам вывода psList'a текущее время, эквивалентен по своему результату скармливанию вывода утилите mtee с ключём /t. Но у мну не получилось вызвать эту утилиту в for-цикле, да и раз можно обойтись без неё - тем лучше).

Далее в цикле этого батника (см метку `m1`) выполняется:
1. Проверка наличия в текущем каталоге rar-файла - результата упаковки дампа лок-таблицы. И если он есть, то на консоль будет выведено сообщение, что ФБ рестартовал и тест надо прекращать. Ибо коннект в окне-"паразите" уже не действует как "универсальный ступор" для isql'ей, которые упираются лбами при попытках апдейтов (см предыдущий пост).
Вот эти строки:
Код: plaintext
1.
2.
  if exist *fb_lock_print_dump*.rar echo ACHTUNG: FIREBIRD SERVER HAS BEEN RESTARTED! STOP THIS TEST!
  if exist *fb_lock_print_dump*.rar dir *fb_lock_print_dump*.rar | findstr /i /c:fb_lock_print_dump 2>nul

2. Запуск 100500 isql'ей:
Код: plaintext
1.
  for /L %%i in (1,1,%n%) do start %FB30BIN%\isql localhost/3330:trntest -n %inswi% %insql% 1>nul 2>>%tmphome%\fbmemo_%mode%_%%i.err
NB: если каждое isql-окно должно "просто войти" и ничего больше не делать, то переменные %inswi% и %insql% будут пустыми. Если же окно должно выполнить скрипт, то %inswi% равна -i, а %insql% = имени скрипта (fbmemo_dml.sql etc).

3. 10-секундное ожидание (пингом в нулл) загрузки ВСЕХ isql-окошек (их число определяется аргументом номер 2 и сохранено в переменной %n% - см выше for /L %%i in ...).

4. Получение снимка памяти по процессам и парсинг его только для процесса 'firebird', с добавлением слева текущего штампа времени и далее - записью этой строки в накопительный лог %logmain%:
Код: plaintext
 pslist -m | findstr /i /c:%fbproc% >%logtemp% && call :addstamp %logtemp% %logmain%
Этот снимок будет содержать данные по расходу памяти при загруженных isql'ях. В накопительном логе батника это все чётные строки данных.

5. Убиение всех isql'ей и ожидание, пока оно выполнится. Поскольку сразу после этого ожидания цикл будет повторен, то было подозрение, что величина этой паузы может как-то влиять на утечку памяти. Дело в том, что внутри ФБ-3 есть специальный поток, который живет 10 секунд с момента последнего коннекта и ждёт следующий коннект. Так сделано, чтобы не пересоздавать этот поток при массовых коннектах. Но мну кажется, что величина этой паузы НЕ влияет. Я делал паузу и в 10 сек, и в 120 - результаты одинаковые:
Код: plaintext
1.
2.
3.
  @rem we must wait enough time for all test windows  loading has been finished:
  @echo 1. take some sleep before get memory snapshot. . .
  ping -n 10 127.0.0.1>nul
6. Повторный снимок памяти процесса 'firebird' после снятия всех isql и логирование его. В накопительном логе все такие снимки - в нечётных строках с данными.

7. Проверка наличия дампа лок-таблицы в каталоге настроек ФБ. Если он там есть, значит его надо упаковать и удалить оттуда, чтобы следующий запуск теста уже не делал этой же операции:
Код: plaintext
  if exist %fbdump% rar m -ep -m5 -ag_YYYYMMDD_hhmm fb_lock_print_dump %fbdump%
8. Инкремент номера итерации и переход на начало цикла.

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

Вот такой, значит, тест получился. И он либо заваливает ФБ, либо переводит его службу в "состояние нестояния".

Сейчас запущу его в режиме работы psql, т.е. чтобы он делал execute block'и, и приведу накопительный лог потребления памяти.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38369912
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Значицца, так.
Запустил в 21:13 тест на "открыть/подождать_20_сек/срубить" 100 isql-окон, каждое из которых выполняет попытку апдейта одной и той же строки PSQL-кодом
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
select current_timestamp,k.* from tlock k where id=1;
set term ^;
execute block as
begin
  update tlock set f01=rand()*100000 where id=1;
end^
set term ;^
quit;

Начало лога потребления памяти процессом firebird'a:
Код: 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.
21:13:21 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
21:13:21 firebird            680   59544   12324   11828   12856     3566     38   72

21:13:30 firebird            680  496060  117604  240908  240908    33468    227  115
21:13:49 firebird            680  273636   21880   21368  240920    33597     49   86

21:14:00 firebird            680  497792  119692  242680  242680    61655    228  115
21:14:19 firebird            680  274980   23368   22812  242680    61658     50   86

21:14:28 firebird            680  499200  121076  244104  244104    89691    229  115
21:14:48 firebird            680  276324   24732   24208  244104    89691     50   86

21:14:58 firebird            680  501376  122664  246296  246296   117778    231  115
21:15:17 firebird            680  278500   26444   26444  246296   117778     52   86

21:15:27 firebird            680  502656  124080  247588  247588   145792    231  115
21:15:46 firebird            680  279780   27808   27760  247588   145792     53   86

21:15:56 firebird            680  502084  125484  249068  249080   173815    232  115
21:16:15 firebird            680  279208   29152   29260  249080   173815     53   86

21:16:25 firebird            680  503760  126644  250756  250756   201792    232  115
21:16:44 firebird            680  283124   31540   33208  250756   201792     55   86

21:16:54 firebird            680  509264  129100  254272  254272   229783    235  116
21:17:13 firebird            680  286452   32948   34548  254272   229784     56   86

21:17:23 firebird            680  510608  130456  255632  255632   257763    236  116
21:17:42 firebird            680  287796   34296   35912  255632   257763     57   86
- показывает, что WorkingSet & PrivateBytes после каждой итерации увеличивались примерно на 1300-1400 байт.

Примерно через час после начала этот цирк закрылся и клоуны разбежались: в логе вижу смены PID'a при следующих показателях расхода памяти:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
21:13:21 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
......................................................................................
22:24:58 firebird            680  835996  350696  515924  515924  4144015    408  129
22:25:18 firebird            680  616128  255308  299172  515924  4144015    232  100

22:25:27 firebird            680  841692  352812  519640  519640  4171998    411  129
 22:25:46  firebird             680   619584   256656  300640   519640  4172000    233  100

 22:25:57  firebird           12672    94944   13048   11272   24412    11819     39   72
22:26:16 firebird          12672   82872    7200    3284   24412    11821     36   59

22:26:25 firebird          12672  256672   17344   15960   30224    37186     46   85
22:26:45 firebird          12672  244600   11544    7984   30224    37186     43   72
Интервалу времени 22:25:46 ... 22:25:57 соответствует следующий "скандал" в firebird.log'e:
Код: 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.
41.
42.
43.
44.
45.
46.
47.
48.
49.
50.
51.
52.
53.
54.
55.
56.
57.
58.
59.
60.
61.
62.
63.
64.
65.
66.
67.
68.
69.
70.
71.
72.
73.
74.
75.
76.
77.
78.
79.
80.
81.
82.
83.
84.
CSMIRROR	Sat Aug 17 22:25:48 2013
	 Fatal lock manager error: invalid lock id (197136), errno: 0 

CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054 
<...> /* повторено ниже еще 4 раза */

CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session


CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054


CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session
<...> /* повторено ниже еще 6 раз */

CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054
<...> повторено ниже еще 2 раза

CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session


CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054


CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session


CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054
<...> повторено ниже еще 1 раз

CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session

CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054

CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session

CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session


CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054
<...> повторено ниже еще 1 раз

CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session

CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054
<...> повторено ниже еще 1 раз

CSMIRROR	Sat Aug 17 22:25:48 2013
	ConfigStorage: Cannot initialize the shared memory region
	Database is probably already opened by another engine instance in another Windows session
 <...> повторено ниже еще 5 раз 

CSMIRROR	Sat Aug 17 22:25:48 2013
	INET/inet_error: read errno = 10054 /* повторено 11 раз */

 ared memory region   /* это НЕ результат случайного вырезания текста! именно так вижу в логе ФБ!! */ 
	Database is probably already opened by another engine instance in another Windows session

CSMIRROR	Sat Aug 17 22:41:37 2013
	Shutting down the server with 1 active connection(s) to 1 database(s), 0 active service(s)
PS. Из всего вышеприведенного больше всего забавляет, конечно, "ared memory region".
Ни в каком ководстве я этоф йразы еще не видел...
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38369919
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
... да, ну так вот: из лога следует, что в 22:25:57 Фб рестартовал с новым pid'ом:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
21:13:21 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
.....................................................................................
22:25:57 firebird          12672   94944   13048   11272   24412    11819     39   72
22:26:16 firebird          12672   82872    7200    3284   24412    11821     36   59

22:26:25 firebird          12672  256672   17344   15960   30224    37186     46   85
22:26:45 firebird          12672  244600   11544    7984   30224    37186     43   72

22:26:54 firebird          12672  266976   17704   16292   37520    61236     46   86
22:27:14 firebird          12672  254904   11860    8320   37520    61236     43   73

22:27:25 firebird          12672  266976   17736   16308   41748    85805     46   86
22:27:44 firebird          12672  254904   11880    8328   41748    85805     43   73

22:27:53 firebird          12672  266976   17724   16304   41748   109690     46   86
22:28:13 firebird          12672  254904   11888    8328   41748   109690     43   73


И всё бы ничего, да только... через полтора часа он опять грохнулся!
Причём, я в это время тут не был и ничего не знал про первый рестарт. След-но, Фб запускал и грохал isql-окна уже без всякого "стопорного болта" со стороны машины-паразита (объяснение см. выше на три поста).
Расход памяти на этом интервале практически НЕ увеличивался (смотрю на WS & Priv):
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
21:13:21 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
.....................................................................................
23:48:35 firebird          12672  266084   18792   17280   92728  4151226     46  202
23:48:54 firebird          12672  254012   12976    9312   92728  4151226     43  189

23:49:04 firebird          12672  266084   18808   17280   92728  4175529     46  202
23:49:23 firebird          12672  254012   12976    9312   92728  4175529     43  189

23:49:34 firebird          12672  235364   18216   16668   92728  4199915     44  201
 23:49:53  firebird           12672   223292   12384    8700   92728  4199915     42  188

 23:50:03  firebird            5080   150880   14820   13224   23236    20150     41   80
23:50:22 firebird           5080  138808    8996    5252   23236    20152     39   67

23:50:32 firebird           5080  213600   16448   14996   48912    45730     44   81
23:50:51 firebird           5080  201528   10632    7016   48912    45730     41   68

 <...> и так продолжается до 00:04:24, когда я оборвал тут всё 

 0:03:36 firebird           5080  246564   17664   16212  102684   709552     45  101
 0:03:55 firebird           5080  234492   11828    8220  102684   709552     42   88

 0:04:05 firebird           5080  246564   17684   16216  102684   734179     45  101
 0:04:24 firebird           5080  234492   11836    8224  102684   734180     42   88

А теперь, почтеннейшая публика, загадки.

Загадка-1. В ФБ-логе вижу, что активность ФБ шла только до момента 23:54:56:firebird.log
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
CSMIRROR        Sat Aug 17 23:29:15 2013
        Shutting down the server with 1 active connection(s) to 1 database(s), 0 active service(s)


CSMIRROR        Sat Aug 17 23:49:55 2013
        Fatal lock manager error: invalid lock id (39564), errno: 0

CSMIRROR        Sat Aug 17 23:54:56 2013
        Shutting down the server with 1 active connection(s) to 1 database(s), 0 active service(s)/FIXED]
Но тест-то шевелился, показывал расход памяти firebird'ом вплоть до 00:04! Да и вообще вижу, что служба живая.
Тест срубал isql-окна после 23:54, в этом нет сомнений судя по его логу. Тогда почему в ФБ-логе нет спама типа inet-error 104 ?

Загадка-2 . Спам вида inet_error=... отсутсвует также почти 45 минут вот на этом интервале работы:firebird.log
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
ared memory region
        Database is probably already opened by another engine instance in another Windows session

 
CSMIRROR        Sat Aug 17 22:41:37 2013
        Shutting down the server with 1 active connection(s) to 1 database(s), 0 active service(s)


CSMIRROR        Sat Aug 17 23:29:15 2013
        Shutting down the server with 1 active connection(s) to 1 database(s), 0 active service(s) 


CSMIRROR        Sat Aug 17 23:49:55 2013
        Fatal lock manager error: invalid lock id (39564), errno: 0
И опять вопрос про спам: куда это он подевался в течение 45 минут, когда тест совершенно точно работал:
пример лога теста
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
22:54:43 firebird          12672  248676   17992   16432   89064  1451836     45  125
22:55:02 firebird          12672  236604   12128    8452   89064  1451836     42  112

22:55:13 firebird          12672  263012   18200   16700   89064  1475821     45  126
22:55:32 firebird          12672  250940   12384    8728   89064  1475821     43  112

22:55:41 firebird          12672  263012   18268   16712   89064  1500435     45  126
22:56:00 firebird          12672  250940   12392    8736   89064  1500435     43  112

22:56:11 firebird          12672  242532   17908   16452   92728  1526778     45  125
22:56:30 firebird          12672  230460   12088    8452   92728  1526778     42  112

22:56:40 firebird          12672  236388   17828   16308   92728  1551105     44  125
22:56:59 firebird          12672  224316   11980    8308   92728  1551105     42  112

22:57:08 firebird          12672  236388   17828   16288   92728  1575665     44  125
22:57:27 firebird          12672  224316   11968    8296   92728  1575665     42  112

22:57:37 firebird          12672  236388   17848   16272   92728  1599615     44  125
22:57:56 firebird          12672  224316   11964    8292   92728  1599616     42  112

22:58:06 firebird          12672  252772   18124   16592   92728  1623408     45  129
22:58:25 firebird          12672  240700   12280    8608   92728  1623408     42  116
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38369921
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Гаджимурадов РустамГде ты "ared memory"-то откопал, кстати? :)Дык в firebird.log'e, вот где!
А вот ссылка на этот лог, а также на лог стеста и на два дампа лок-таблицы:
http://yadi.sk/d/NPlD8esO813a8 (вечная, на сгорит)
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38370161
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Провел вариант теста, при котором каждый из 100 isql'ей пытается обновить запись в автономной транзации:
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
select current_timestamp,k.* from tlock k where id=1;
set echo on;
set term ^;
execute block as
begin
  in autonomous transaction do
    update tlock set f01=rand()*100000 where id=1;
end^
set term ;^
quit;

Предусловие то же: с другой машины в базу смотрит isql-"паразит", который проапдейтил эту же строку, но не делает commit/rollback.
Итого:
1. Сразу после начала теста стало ясно, что ничем хорошим это не закончится: после каждой итерации от памяти откусывалось по 2-3 Кб:
Код: 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.
11:03:35 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
11:03:35 firebird          14456   61592   12460   11868   12856     3589     38   72

11:03:45 firebird          14456  508728  123596  253588  253588    34954    235  115
11:04:04 firebird          14456  275872   22976   23604  253600    35089     51   86

11:04:14 firebird          14456  514944  126588  257844  257844    64602    238  116
11:04:33 firebird          14456  279332   24452   25148  257844    64603     52   86

11:04:43 firebird          14456  516420  128136  259360  259360    94130    239  116
11:05:02 firebird          14456  285544   28040   31468  259360    94130     56   87

11:05:12 firebird          14456  526532  131384  265496  265496   123568    244  116
11:05:31 firebird          14456  293352   30800   35328  265500   123572     59   87

11:05:41 firebird          14456  532164  134000  269148  269148   152987    246  117
11:06:00 firebird          14456  301480   34476   41504  269148   152994     64   88

11:06:10 firebird          14456  542604  137532  275616  275616   182370    251  117
11:06:30 firebird          14456  311920   37704   47968  275616   182373     68   88

11:06:40 firebird          14456  552780  141000  281820  281820   211798    256  118
11:06:59 firebird          14456  319728   40480   51816  281820   211800     71   89

11:07:09 firebird          14456  558412  143644  285468  285468   241193    258  118
11:07:28 firebird          14456  325424   42932   55548  285468   241194     74   89
2. Через ~2 часа после начала в логе ФБ появилось три раза подряд:
Код: plaintext
1.
2.
CSMIRROR	Sun Aug 18  13:13:53  2013
	unable to allocate memory from operating system
- и этим сообщениям соотв-вует следующий расход памяти ФБ по логу теста:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
11:03:35 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
...
13:12:03 firebird          14456 2075676  681636 1270812 1270812  7839846    979  223  
13:12:22 firebird          14456 1841152  578512 1039392 1270820  7839849    793  193  

13:12:32 firebird          14456 2079004  683264 1272160 1272160  7869639    979  223  
13:12:51 firebird          14456 1846784  581080 1043044 1272160  7869639    795  193  

13:13:02 firebird          14456 2082652  685744 1275832 1275832  7899458    982  223  
13:13:21 firebird          14456 1850432  583560 1046720 1275832  7899459    798  194  

13:13:32 firebird          14456 2088348  688248 1279548 1279548  7929233    985  223  
 13:13:51 firebird          14456 1858432  586968 1052740 1279548   7929234    803  194  

13:14:01 firebird          14456 2090012  688064 1277212 1279548  7958584    983  223  
13:14:20 firebird          14456 1863872  588244 1054188 1279548  7958584    804  194  

13:14:30 firebird          14456 2089180  687964 1276388 1279548  7987735    982  223  
13:14:50 firebird          14456 1867584  590828 1057916 1279548  7987737    806  195  

13:14:59 firebird          14456 2090332  688936 1275548 1279548  8016112    981  222  
13:15:18 firebird          14456 1873216  593124 1061552 1279548  8016113    809  195  
Это же сообщение в firebird.log'e появилось и в 13:14:23 (также три раза), в 13:14:52 (опять три раза), ну и так далее на каждой итерации.
Последний раз это сообщение вылезло в 13:15:20 (уже один раз, а не три).

3) В моменты 13:15:49...13:15:50 нехватка памяти перешла критическую отметку:

3.1) в лог вылезло одновременно 168 сообщений вида
Код: plaintext
1.
	Operating system call _beginthreadex failed. Error code 8
- все они вспыхнули в течение 13:15:49...13:15:50 и между ними нет никаких других мессаг. Даже спама про errno=-104.
3.2) Дальше между ними воткнулось опять
Код: plaintext
1.
CSMIRROR	Sun Aug 18 13:15:50 2013
	unable to allocate memory from operating system
- после чего был некоторое время винегрет из этих двух видов сообщений (всё опять-таки влезло в одну секунду - 13:15:50).

3.3) После этого вылезло еще новое сообщение на тему "дай память!", но относилось оно уже security-базы:
Код: plaintext
1.
2.
CSMIRROR	Sun Aug 18 13:15:50 2013
	Error in isc_start_transaction() API call when working with security database
	unable to allocate memory from operating system

Последний раз non_spam-сообщение в логе ФБ появилось в 13:16:48 и оно гласило:
Код: plaintext
1.
2.
CSMIRROR	Sun Aug 18 13:16:48 2013
	Operating system call _beginthreadex failed. Error code 8

4) Дальше почти три часа шёл только спам, прекратившийся в 16:01
Код: plaintext
1.
CSMIRROR	Sun Aug 18 16:01:49 2013
	INET/inet_error: send errno = 10054

5) После этого в логе ФБ наступила тишина, хотя сама службы ФБ _не_ рестартовала, что было видно по неизменному PID.
6) Окно-"паразит", которое держало апдейт, больше не выдает ничего в ответ на запрос к таблице. К этой базе вообще стало нельзя подключиться:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
C:\1Install\FBTEST>%FB30BIN%\isql localhost/3330:trntest -n
Statement failed, SQLSTATE = 08006
Unable to complete network request to host "localhost".
-Failed to establish a connection.
Use CONNECT or CREATE DATABASE to specify a database
SQL> ^C

C:\1Install\FBTEST>%fb30bin%\isql C:\1Install\FBTEST\TRNTEST.FDB -n -user sysdba -pas masterke
Statement failed, SQLSTATE = 08001
I/O error during "CreateFile (open)" operation for file "C:\1INSTALL\FBTEST\TRNTEST.FDB"
-Error while trying to open file
-Процесс не может получить доступ к файлу, так как этот файл занят другим процессом
Use CONNECT or CREATE DATABASE to specify a database
SQL>
7) хотя НОВУЮ (другую) базу создать на этом хосте можно, сделать это удастся только по локальному протоколу. Пытаться подключиться к этой (новой) базе по TCP - бесполезняк.
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
SQL> create database 'tmpbase.fdb' user 'sysdba' password 'masterke';
SQL> show version;
ISQL Version: WI-T3.0.0.30590 Firebird 3.0 Alpha 1
Server version:
Firebird/Windows/Intel/i386 (access method), version "WI-T3.0.0.30590 Firebird 3.0 Alpha 1"
on disk structure version 12.0
SQL> commit;
SQL> connect 'localhost/3330:c:\1install\fbtest\tmpbase.fdb' user 'sysdba' password 'masterke';
Statement failed, SQLSTATE = 08006
Unable to complete network request to host "localhost".
-Failed to establish a connection.
8) служба ФБ *не* останавливается штатным средством (net stop "Firebird Server - fb30ss"), выдает "Не удалось остановить ..."

9) ссылка на архив с логом ФБ и снимком лок-таблицы в момент, когда ФБ тихо перешёл в кому: http://yadi.sk/d/A5FLURgP82lao (вечная, не сгорит)
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38370175
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Наверное, глупый вопрос задам, но...
Различает ли ФБ (да и в состоянии ли), что физической памяти на машине 1 Гб, а остальное (3 Гб) - виртуальная память файла подкачки ?
Появление первых сообщений о нехватке памяти (см предыдущий пост) случилось в тот именно момент, когда значение Priv стало равно почти 1 Гб:
Код: plaintext
1.
2.
3.
11:03:35 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page
...
13:13:32 firebird          14456 2088348  688248 1279548 1279548  7929233    985  223  
 13:13:51 firebird          14456 1858432  586968 1052740 1279548  7929234    803  194   
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38370215
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Провел еще несколько "забегов", прихожу к однозначному выводу.
Утечка памяти серверного процесса 'firebird' возникает при убиении N коннектов (где N может быть равно даже 1) т олько в случае, когда:
1) существует как минимум один коннект-"паразит", который:
1.1) либо залочил запись, которую хотят обновить другие (убиваемые "скопом") isql-окна;
1.2) либо провёл вставку новой записи в уникальный ключ , а другие isql-окна также "хотели" добавить запись с таким же значением ключа (т.е. хотели нарушить PK/UK).
2) этот коннект-"паразит" не делает commit/rollback и просто продолжает висеть в бездействии на какой-то "недоступной машине" (т.е. он не подпадает под групповой отстрел).

Например, когда каждое тестовое окно "хочет" нарушить уникальность таблицы вот таким кодом:
Код: sql
1.
2.
3.
4.
select current_timestamp,k.* from tlock k where id=1;
set echo on;
insert into tlock(id, f01) select max(id)+1,123 from tlock; -- тут оно намертво застрянет в ожидании
quit;


- то даже когда число таких тестовых окон равно ОДНОМУ , вижу в логе теста неуклонное увеличение памяти, пусть всего на 10-20 Кб за итерацию, но оно - есть:
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
23:47:37 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page  
23:47:37 firebird            344   57412   12624   11940   15052    11764     38   71  

23:47:38 firebird            344   65568   14276   14984   15052    12215     40   74  
23:47:39 firebird            344   64544   13696   13960   15052    12215     39   73  

23:47:40 firebird            344   65568   14324   14984   15056    12408     40   74  
23:47:41 firebird            344   64544   13720   13960   15056    12408     39   73  
<...>
23:49:37 firebird            344   66272   15072   15696   15768    23079     41   74  
23:49:38 firebird            344   65248   14468   14672   15768    23079     39   73  

23:49:39 firebird            344   66336   15084   15760   15832    23269     41   74  
23:49:40 firebird            344   65312   14480   14736   15832    23269     40   73 
А когда число тестовых окон равно 300, то "болезнь" прогрессирует уже совсем быстро:
Код: 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.
23:52:17 Name                Pid      VM      WS    Priv Priv Pk   Faults   NonP Page  
23:52:17 firebird           9336   61252   12288   11708   12824     3498     38   71  

23:52:30 firebird           9336 1294908  320232  646516  646564    91701    562  192  
23:52:39 firebird           9336  693604   46664   47704  646564    92086     70  108  

23:52:53 firebird           9336 1304256  327240  653976  654048   173226    567  193  
23:53:02 firebird           9336  730276   65488   82756  654048   173236     97  113  

23:53:16 firebird           9336 1370432  346884  689656  689704   254506    596  201  
23:53:25 firebird           9336  778724   76916  100756  689704   254603    111  119  

23:53:39 firebird           9336 1399040  358292  706524  706548   335767    608  203  
23:53:48 firebird           9336  805156   86408  115508  706548   335779    122  120  

23:54:02 firebird           9336 1423424  367440  721120  721164   416863    620  204  
23:54:11 firebird           9336  835620   98460  136272  721164   416876    138  122  

23:54:23 firebird           9336 1459968  379820  741968  742104   498240    636  207  
23:54:33 firebird           9336  866276  108160  151268  742104   498269    150  124  
<...>
 0:05:14 firebird           9336 2035012  479976 1096968 1097040  2851589    901  254  
 0:05:23 firebird           9336 1443496  209052  508536 1097040  2851600    416  171  

 0:05:35 firebird           9336 2059332  477312 1111500 1111572  2932608    912  255  
 0:05:44 firebird           9336 1459816  202528  515060 1111572  2932617    420  172  

 0:05:57 firebird           9336 2067332  470168 1117572 1117640  3013562    916  256  
 0:06:06 firebird           9336 1467880  195420  521204 1117640  3013568    425  172  

 0:06:20 firebird           9336 2075396  474776 1123720 1123768  3094309    920  256  
 0:06:29 firebird           9336 1481896  203144  533304 1123768  3094318    434  173  
Одним словом, здесь что-то завязано на лок-менеджер, все эти дампы ЛТ были неспроста.
...
Рейтинг: 0 / 0
Многочасовой тест на открытие и убиение сотен ISQL-окон
    #38372068
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
На линухе всё воспроизвелось еще быстрее. Для 200 тестовых isql'ей краш ФБ происходит менее чем через 1 минуту. Для 10 окошек - за полтора часа. Потребляемая память при этом не растёт, ФБ просто заваливается с коркой.
Источник Света, отвечающий "там" за всё, что связано с линухом, подтвердил багу и сказал, что сиё связано с новой фичей, а именно... модулем шифрования базы!
В общем, дальнейшие новости и фиксы смотрим тут: http://tracker.firebirdsql.org/browse/CORE-4185
...
Рейтинг: 0 / 0
21 сообщений из 21, страница 1 из 1
Форумы / Firebird, InterBase [игнор отключен] [закрыт для гостей] / Многочасовой тест на открытие и убиение сотен ISQL-окон
Найденые пользователи ...
Разблокировать пользователей ...
Читали форум (0):
Пользователи онлайн (0):
x
x
Закрыть


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