Несложный SIMILAR TO выполняется 10 минут, без возм-сти срубить его по delete from mon$att

Таблоид
Дата: 29.05.2012 20:10:12
hi all

Имеется вот такой запрос:
select iif('sdf--asdf_sd.dsfsfh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\-])+' escape '\', 1, 0) from rdb$database
- а также машинка windows-2000 sp 4, P-IV 3.00GHz RAM 1Gb.

Выполняю на этой машине запуск двух isql-окон, одно - для этого запроса, второе - "мониторное", для срубания коннектов через mon$attachments. Разумеется, коннекты делаю по протоколу TCP.

session #1
C:\MIX\firebird\fb25>bin\isql -n -c 2048 localhost/3050:C:\MIX\firebird\fb25\T1.FDB
Database: localhost/3050:C:\MIX\firebird\fb25\T1.FDB
SQL> show version;
ISQL Version: WI-V2.5.2.26482 Firebird 2.5
Server version:
Firebird/x86/Windows NT (access method), version "WI-V2.5.2.26482 Firebird 2.5"
Firebird/x86/Windows NT (remote server), version "WI-V2.5.2.26482 Firebird 2.5/tcp (csprog)/P12"
Firebird/x86/Windows NT (remote interface), version "WI-V2.5.2.26482 Firebird 2.5/tcp (csprog)/P12"
on disk structure version 11.2

session #2 // "мониторное"
SQL> commit; connect localhost/3050:C:\MIX\firebird\fb25\T1.FDB;
Database: localhost/3050:C:\MIX\firebird\fb25\T1.FDB

session #1
SQL> set stat on; select iif('sdf--asdf_sd.dsfsfh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\
])+' escape '\', 1, 0) from rdb$database; set stat off;
-- с этого момента ФБ уходит в нирвану на... ~10 минут.

session #2 // через 10-20 сек после начала работы окна_1; впрочем, можно и через 3-5 минут:-)
SQL> delete from mon$attachments where mon$attachment_id<>current_connection; commit;
-- висит! никакой реакции в первом окне на эту команду нет,
-- вплоть до получения в session #1 итогового результата этого "сложнейшего" селекта.

session #1 // через почти 10 минут!
CASE
============
0

Current memory = 292066885652
Delta memory = 292057870028
Max memory = 5331600611687596
Elapsed time= 542.22 sec
Buffers = 1241520
Reads = 39192027332856388
Writes -2
Fetches = 1152990181135150929

Привожу трейс:
+
Trace session ID 8 started
2012-05-29T17:07:56.2710 (1936:020EB958) TRACE_INIT

SESSION_8





2012-05-29T17:07:56.2710 (1936:020EB958) ATTACH_DATABASE

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

C:\MIX\firebird\fb25\bin\isql.exe:1704



2012-05-29T17:07:56.2710 (1936:020EB958) START_TRANSACTION

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

C:\MIX\firebird\fb25\bin\isql.exe:1704

(TRA_352, CONCURRENCY | WAIT | READ_WRITE)



2012-05-29T17:08:08.2080 (1936:020EB958) PREPARE_STATEMENT

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

C:\MIX\firebird\fb25\bin\isql.exe:1704

(TRA_352, CONCURRENCY | WAIT | READ_WRITE)



Statement 307:

-------------------------------------------------------------------------------

select iif('sdf--asdf_sd.dsfsfh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\-])+' escape '\', 1, 0) from rdb$database

6 ms



2012-05-29T17:08:08.2080 (1936:020EB958) EXECUTE_STATEMENT_START

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

C:\MIX\firebird\fb25\bin\isql.exe:1704

(TRA_352, CONCURRENCY | WAIT | READ_WRITE)



Statement 307:

-------------------------------------------------------------------------------

select iif('sdf--asdf_sd.dsfsfh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\-])+' escape '\', 1, 0) from rdb$database



2012-05-29T17:08:21.8800 (1936:020ECA0C) TRACE_INIT

SESSION_8





2012-05-29T17:08:21.8800 (1936:020ECA0C) START_TRANSACTION

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

C:\MIX\firebird\fb25\bin\isql.exe:1856

(TRA_353, CONCURRENCY | WAIT | READ_WRITE)



2012-05-29T17:08:21.8800 (1936:020ECA0C) START_TRANSACTION

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

C:\MIX\firebird\fb25\bin\isql.exe:1856

(TRA_354, READ_COMMITTED | NO_REC_VERSION | WAIT | READ_WRITE)



2012-05-29T17:08:21.8800 (1936:020ECA0C) PREPARE_STATEMENT

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

C:\MIX\firebird\fb25\bin\isql.exe:1856

(TRA_354, READ_COMMITTED | NO_REC_VERSION | WAIT | READ_WRITE)



Statement 84:

-------------------------------------------------------------------------------

delete from mon$attachments where mon$attachment_id<>current_connection

0 ms



2012-05-29T17:08:21.8800 (1936:020ECA0C) EXECUTE_STATEMENT_START

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

C:\MIX\firebird\fb25\bin\isql.exe:1856

(TRA_353, CONCURRENCY | WAIT | READ_WRITE)



Statement 84:

-------------------------------------------------------------------------------

delete from mon$attachments where mon$attachment_id<>current_connection



2012-05-29T17:17:10.3960 (1936:020EB958) EXECUTE_STATEMENT_FINISH

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

C:\MIX\firebird\fb25\bin\isql.exe:1704

(TRA_352, CONCURRENCY | WAIT | READ_WRITE)



Statement 307:

-------------------------------------------------------------------------------

select iif('sdf--asdf_sd.dsfsfh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\-])+' escape '\', 1, 0) from rdb$database

1 records fetched

542200 ms, 13 fetch(es)



Table Natural Index Update Insert Delete Backout Purge Expunge

***************************************************************************************************************

RDB$DATABASE 1

RDB$CHARACTER_SETS 1

RDB$COLLATIONS 1



2012-05-29T17:17:10.3960 (1936:020ECA0C) EXECUTE_STATEMENT_FINISH

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

C:\MIX\firebird\fb25\bin\isql.exe:1856

(TRA_353, CONCURRENCY | WAIT | READ_WRITE)



Statement 84:

-------------------------------------------------------------------------------

delete from mon$attachments where mon$attachment_id<>current_connection

0 records fetched

528529 ms, 1 read(s), 1 fetch(es)



2012-05-29T17:17:10.4110 (1936:020ECA0C) FREE_STATEMENT

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

C:\MIX\firebird\fb25\bin\isql.exe:1856



Statement 84:

-------------------------------------------------------------------------------

delete from mon$attachments where mon$attachment_id<>current_connection



2012-05-29T17:17:10.4110 (1936:020EB958) ROLLBACK_TRANSACTION

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

C:\MIX\firebird\fb25\bin\isql.exe:1704

(TRA_352, CONCURRENCY | WAIT | READ_WRITE)

0 ms



2012-05-29T17:17:10.4110 (1936:020EB958) CLOSE_CURSOR

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

C:\MIX\firebird\fb25\bin\isql.exe:1704



Statement 307:

-------------------------------------------------------------------------------

select iif('sdf--asdf_sd.dsfsfh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\-])+' escape '\', 1, 0) from rdb$database



2012-05-29T17:17:10.4110 (1936:020EB958) DETACH_DATABASE

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

C:\MIX\firebird\fb25\bin\isql.exe:1704



2012-05-29T17:17:10.4110 (1936:020EB958) FREE_STATEMENT

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

C:\MIX\firebird\fb25\bin\isql.exe:1704



Statement 307:

-------------------------------------------------------------------------------

select iif('sdf--asdf_sd.dsfsfh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\-])+' escape '\', 1, 0) from rdb$database



2012-05-29T17:17:10.4110 (1936:020EB958) TRACE_FINI

SESSION_8

Обратите внимание:
1) select-запрос стартовал в 2012-05-29T17:08:08.2080 // 2 hvlad: тут бы сослаться на уникальный id "блока" в трейсе, а его нету!
2) запрос на прерывание "всего и всех" (delete from mon$att) сратовал в 2012-05-29T17:08:21.8800
3) "отклик" от ФБ на пункт 2) показался в трейсе в 2012-05-29T17:17:10.3960
4) в этот же момент в трейсе показался exec_stt_finish для селекта

Итого время "внутри движка" по данным трейса:
1) на select: 542200 ms
2) на delete from mon$attach: 528529 ms

Any comments ?
dimitr
Дата: 29.05.2012 21:24:41
прервать внутренности алгоритма SIMILAR TO сейчас невозможно, насколько я в курсе
Таблоид
Дата: 29.05.2012 21:35:06
dimitr
прервать внутренности алгоритма SIMILAR TO сейчас невозможно, насколько я в курсе
да, но что он там делает 9 минут с этой строкой ?
BTW, если её немного уменьшить в длине, то уже "прогресс", аж 17 сек:
SQL> set stat on; select iif('sdf--sdf_sd.fh-.sdjskdjfh-_.' SIMILAR TO '(([[:ALNUM:]\_\-])+.?)+([[:ALNUM:]\_\-])+'
escape '\', 1, 0) from rdb$database; set stat off;

CASE
============
0

Current memory = 9107188
Delta memory = 91588
Max memory = 9225900
Elapsed time= 17.32 sec
Buffers = 2048
Reads = 24
Writes 0
Fetches = 332
Таблоид
Дата: 29.05.2012 22:20:15
В общем, вот: CORE-3858 - подарок Кальтенбруннеру.
Гаджимурадов Рустам
Дата: 29.05.2012 22:25:37

Таблоид> В общем, вот: CORE-3858 - подарок Кальтенбруннеру.

Очевидно же, что он ответит.

Posted via ActualForum NNTP Server 1.5

Таблоид
Дата: 29.05.2012 22:37:27
Гаджимурадов Рустам,

и ЧТО же ?
Гаджимурадов Рустам
Дата: 29.05.2012 22:43:06

Он скажет, что мотороллер не его и переадресует.

Posted via ActualForum NNTP Server 1.5

Таблоид
Дата: 29.05.2012 22:46:32
Как это ?!.. в релнотах над соотв-щим разделом - его ФИО.
И вот, еще:
/doc/sql.extensions/README.similar_to.txt 
====================
SIMILAR TO predicate
====================
<...>
Author:
Adriano dos Santos Fernandes <adrianosf@uol.com.br>
<...>
Гаджимурадов Рустам
Дата: 29.05.2012 22:52:40

Таблоид> Как это ?!.. в релнотах над соотв-щим разделом - его ФИО.

Это если он с нуля реализовал, а не готовую реализацию стянул.

Posted via ActualForum NNTP Server 1.5

Гаджимурадов Рустам
Дата: 29.05.2012 22:53:34

Хотя ХЗ, может, конкретный частный случай и пофиксит.

Posted via ActualForum NNTP Server 1.5