GTT: проигрыш произв-сти при создании с опцией DELETE вместо PRESERVE

Таблоид
Дата: 25.05.2012 19:56:02
hi all

В каком-то топике (найти не смог) говорилось, что статистика по GTT'шкам должна быть совершенно одинаковая, независимо от того, как они были созданы: на уровне сеанса или на уровне транзакции.
Так вот: смею заметить, что это утверждение - ложь.

Многократно вводил вот этот скрипт на выполнение:
+
set echo off;
recreate global temporary table tmpdel(s blob) on commit DELETE ROWS; commit;
set term ^;
execute block as 
declare s type of column tmpdel.s;
declare n int = 1000000;
begin
 --s=rpad('',50,'x');
 while (n>0) do insert into tmpdel(s) values(rpad('',50,'x')) returning :n-1 into n;
end
^set term ;^
set stat on;
commit;
set stat off;
-------------
recreate global temporary table tmppre(s blob) on commit PRESERVE ROWS; commit;
set term ^;
execute block as 
declare s type of column tmpdel.s;
declare n int = 1000000;
begin
 --s=rpad('',50,'x');
 while (n>0) do insert into tmppre(s) values(rpad('',50,'x')) returning :n-1 into n;
end
^set term ;^
set stat on;
commit;
set stat off;
- и получил в итоге следующие результаты (данные из трейса):
GTT on commit:операция (buffers=1024)elapsed, msreadswritesfetchesmarks
DELETE ROWSвставка 1 млн rpad('',50,'x')257330130100115090534626028324
DELETE ROWScommit8171075102410020971001049
DELETE ROWSвставка 1 млн rpad('',50,'x')109124156100111990534036028264
DELETE ROWScommit10031075102310020971001049
DELETE ROWSвставка 1 млн rpad('',50,'x')146924156100111890534036028264
DELETE ROWScommit7611075102410020971001049
PRESERVE ROWSвставка 1 млн rpad('',50,'x')2282513238952667762200108
PRESERVE ROWScommit301102511
PRESERVE ROWSвставка 1 млн rpad('',50,'x')2423513238952667762200108
PRESERVE ROWScommit1311102511
PRESERVE ROWSвставка 1 млн rpad('',50,'x')2660813238952667762200108
PRESERVE ROWScommit331102511


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

И еще.
Увидел недавно бравурное 'Resolved' в своём тикете CORE-3598 (он был создан по итогам вот этой беседы) - и решил проверить, что там теперь.

Кажется, ничего там не 'Resolved'. Сообщения в трейсе для вот такого конфига:
+
  enabled true
log_connections true
log_transactions true
log_errors true

log_statement_finish true

log_trigger_start true
log_trigger_finish true
print_perf true
max_sql_length 4096
time_threshold 0
max_log_size 10
- по-прежнему НЕ показывают затраты, которые происходят ПОСЛЕ завершения commit'a. Трейс - в аттаче.

PS.
ISQL Version: WI-V2.5.2.26488 Firebird 2.5
Server version:
Firebird/x86/Windows NT (access method), version "WI-V2.5.2.26488 Firebird 2.5"
Firebird/x86/Windows NT (remote server), version "WI-V2.5.2.26488 Firebird 2.5/tcp (csprog)/P12"
Firebird/x86/Windows NT (remote interface), version "WI-V2.5.2.26488 Firebird 2.5/tcp (csprog)/P12"
on disk structure version 11.2
hvlad
Дата: 25.05.2012 21:42:45
Таблоид
Увидел недавно бравурное 'Resolved' в своём тикете CORE-3598 (он был создан по итогам вот этой беседы) - и решил проверить, что там теперь.

Кажется, ничего там не 'Resolved'
Доказательства ?
Таблоид
Дата: 25.05.2012 23:31:32
В том же топеге:
Таблоид: Почему значение фетчей для этого коммита в ISQL больше, чем в трейсе ? Кто из них врёт ?

hvlad: Трейс не включает действия, выполняющиеся после окончания тр-ции - например очистку GTT и удаление временных блобов.

dimitr: IMHO, надо бы включать

hvlad: Обсудим. Не здесь. ;)
Ваше с ДЕ обсуждение и его результаты мне неведомы. Но раз тикет 'resolved', то видеть затраты на удаление временных блобов видеть теперь я должен - так или нет ? Если так, то покажи пример, плз, когда эти затраты действительно видны в трейсе.
hvlad
Дата: 25.05.2012 23:54:34
Таблоид
Если так, то покажи пример, плз, когда эти затраты действительно видны в трейсе.
Нет, это ты мне покажи - чего ты там не видишь из того, что должен бы.
Таблоид
Дата: 26.05.2012 00:03:05
Вот здесь, к примеру:

2012-05-25T19:02:16.9350 (1328:022FBE6C) COMMIT_TRANSACTION

C:\MIX\FIREBIRD\FB25\T1.FDB (ATT_30, SYSDBA:NONE, NONE, TCPv4:127.0.0.1)

C:\MIX\firebird\fb25.2\bin\isql.exe:1300

(TRA_300, CONCURRENCY | WAIT | READ_WRITE)

817 ms, 1075 read(s), 1024 write(s), 1002097 fetch(es), 1001049 mark(s)

<<<<<<<<<<<<<<<<<<<<<<<<<??????????????>>>>>>>>>>>>>>>>>>>>>>>>>>>>

2012-05-25T19:02:16.9350 (1328:022FBE6C) START_TRANSACTION

C:\MIX\FIREBIRD\FB25\T1.FDB (ATT_30, SYSDBA:NONE, NONE, TCPv4:127.0.0.1)

C:\MIX\firebird\fb25.2\bin\isql.exe:1300

(TRA_301, CONCURRENCY | WAIT | READ_WRITE)
- не должно ли было что-то "новенькое" появиться там, где выделено цветом ? Затраты на очистку GTT или удаление временных блобов там или что-то еще ?
hvlad
Дата: 26.05.2012 00:04:48
Таблоид
Увидел недавно бравурное 'Resolved' в своём тикете CORE-3598 (он был создан по итогам вот этой беседы) - и решил проверить, что там теперь.
Ну так проверил что там теперь ? Тот тест сделай и сравни, что было, и что стало.
Таблоид
Дата: 26.05.2012 00:05:10
Или когда я завершаю окно:
+
Statement 125:
-------------------------------------------------------------------------------
execute block as
declare s type of column tmpdel.s;
declare n int = 1000000;
begin
--s=rpad('',50,'x');
while (n>0) do insert into tmppre(s) values(rpad('',50,'x')) returning :n-1 into n;
end

0 records fetched
25134 ms, 1 read(s), 32389 write(s), 5266776 fetch(es), 2200108 mark(s)

Table Natural Index Update Insert Delete Backout
*********************************************************************************************
TMPPRE 1000000

2012-05-25T23:53:26.4320 (1328:022FBE6C) COMMIT_TRANSACTION
C:\MIX\FIREBIRD\FB25\T1.FDB (ATT_31, SYSDBA:NONE, NONE, TCPv4:127.0.0.1)
C:\MIX\firebird\fb25.2\bin\isql.exe:620
(TRA_318, CONCURRENCY | WAIT | READ_WRITE)
67 ms, 1 read(s), 1025 write(s), 1 fetch(es), 1 mark(s)

2012-05-26T00:03:26.3690 (1328:022FBE6C) DETACH_DATABASE
C:\MIX\FIREBIRD\FB25\T1.FDB (ATT_31, SYSDBA:NONE, NONE, TCPv4:127.0.0.1)
C:\MIX\firebird\fb25.2\bin\isql.exe:620

2012-05-26T00:03:26.3690 (1328:022FBE6C) TRACE_FINI
SESSION_2
-- не должно ли появиться что-то между COMMIT_TRANSACTION и DETACH_DATABASE ?
hvlad
Дата: 26.05.2012 00:05:56
Таблоид
не должно ли было что-то "новенькое" появиться там, где выделено цветом ? Затраты на очистку GTT или удаление временных блобов там или что-то еще ?
А что ты там видишь, а ?
А что раньше видел ?
Таблоид
Дата: 26.05.2012 00:11:29
hvlad
Тот тест сделай и сравни, что было, и что стало.
я и делаю ТОТ САМЫЙ тест, только дополнил его еще и GTT с кляузой on commit PRESERVE rows.

Для GTT с кляузой on commit DELETE rows:
1) было:
1.1) вставки 1 лям строк: 29182 ms, 1 read(s), 39844 write(s), 3163342 fetch(es), 1142934 mark(s)
1.2) commit: 12 ms, 1 read(s), 1025 write(s), 1 fetch(es), 1 mark(s)
2) стало:
2.1) вставки 1 лям строк: 257330 ms, 130 read(s), 1001150 write(s), 9053462 fetch(es), 6028324 mark(s)
2.2) commit: 817 ms, 1075 read(s), 1024 write(s), 1002097 fetch(es), 1001049 mark(s)

Прибавку вижу только в блоке COMMIT_TRANSACTION, а не после него!

Кроме того, вернусь к главному вопросу: не понимаю, почему вставка в GTT c кляузой on commit PRESERVE rows работает настолько быстрее! ЕМНИП, раньше такого не было!
Таблоид
Дата: 26.05.2012 00:12:43
hvlad
А что ты там видишь, а ?
А что раньше видел ?
я и сейчас, и прежде видел там... ничего :-)
Ну так ДОЛЖНО было появиться "что-то" после блока COMMIT_TRAN ? или ты это включил "внутрь" статистики этого блока ?