hi all
Всем задание на НГ каникулы!
Поможыте понять, почему скрипт, занимающийся удалением некоторой пачки строк, "не хочет" прекращаться.
Условие прекращения его работы: наличие хотя бы одной строки во внешней таблице (определена в базе с именем = ext_stoptest, соотв-щий файл = 'stop.txt', находится в каталоге /var/db/fb30; параметр конфига: ExternalFileAccess = Restrict /var/db/fb30).
Вот фрагмент скрипта, который должен прекращать его работу:
1.
2.
3.
4.
5.
6.
7.
8.
if (exists( select * from ext_stoptest )) then
begin
msg='-- isql, attach #'||current_connection||': test was cancelled, dts='||cast('now' as timestamp);
suspend;
exception ex_test_cancellation;
-- leave;
exit;
end
А вот он сам, полностью (в суть его можно не врубаться, просто для ознакомления): нехороший скрипт (НЕ реагирует на команду остановки) 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.
103.
104.
105.
106.
107.
108.
109.
110.
111.
112.
113.
114.
115.
116.
117.
118.
119.
120.
121.
122.
123.
124.
125.
126.
127.
128.
129.
130.
131.
132.
133.
COMMIT;
SET TRANSACTION READ WRITE READ COMMITTED RECORD_VERSION NO WAIT;
set heading off;
set list off;
set stat on;
set term ^;
execute block returns(msg varchar(100)) as
declare MIN_DELETED_COUNT int = 10;
declare MAX_DELETED_COUNT int = 100;
declare i int;
declare v_id_max int;
declare v_rnd_id int;
declare v_cur_id int;
declare v_result int;
declare v_rndval double precision;
declare v_rnd4err double precision;
declare v_deleted_cnt int;
declare v_stt varchar(2048);
declare v_comment varchar(255);
declare v_log varchar(2048);
declare v_dts_beg timestamp;
declare v_dts_end timestamp;
declare MIN_TIME_FOR_LOGGING int = 2000;
declare LOWER_THRESHOLD_FOR_ERR double precision = 0; -- 0=no errors, 1=max errors
declare LOG_STATEMENTS smallint=0; -- 1=log in autonom trn if statementtime more than MIN_TIME_FOR_LOGGING
-- ######################################################################
-- DELETE DELETE DELETE DELETE DELETE DELETE DELETE DELETE DELETE DELETE
-- ######################################################################
begin
v_dts_beg = cast('now' as timestamp);
msg = '-- attach_id='||current_connection||', intro .sql at '||cast('now' as timestamp);
suspend;
select max(id) from tmp into v_id_max; -- 18.11.2012: added desc index on tmp(id);
v_deleted_cnt=MIN_DELETED_COUNT+rand()*(MAX_DELETED_COUNT-MIN_DELETED_COUNT);
v_rndval=rand();
v_rnd4err=rand(); -- error probability
v_rnd_id=cast(:v_rndval * :v_id_max as int); -- get random id to delete rows
msg='-- Start deleting '||v_deleted_cnt||' rows from first id >= '||v_rnd_id||', v_rnd4err='||cast(v_rnd4err as numeric(6,2))||', LOWER_THRESHOLD_FOR_ERR='||cast(LOWER_THRESHOLD_FOR_ERR as numeric(6,2));
suspend;
v_result=0;
i=0;
for
select first (:v_deleted_cnt) id
from tmp t
where t.id >= :v_rnd_id
order by id
into :v_cur_id
do begin
if (exists( select * from ext_stoptest )) then
begin
msg='-- isql, attach #'||current_connection||': test was cancelled, dts='||cast('now' as timestamp);
suspend;
exception ex_test_cancellation;
-- leave;
exit;
end
i=i+1;
begin
if (:v_rnd4err < :LOWER_THRESHOLD_FOR_ERR and :i >= :v_deleted_cnt ) then begin
msg='delete from tmp t where t.id = '||:v_cur_id||' and 1/0>0; -- i='||i;
delete from tmp t where t.id = :v_cur_id and 1/0 > 0; -- error will be here
end
else begin
msg='delete from tmp t where t.id = '||:v_cur_id||'; -- i='||i;
delete from tmp t where t.id = :v_cur_id;
end
if (i in(0,1) or i>=v_deleted_cnt-1 ) then
suspend; -- 17.03.2012: minimize output
end
when any do
begin
suspend; -- msg: delete-statement with zero division
v_result=gdscode;
msg='rollback; -- ABORT, gds='||v_result
||', i='||i
||', at '||cast('now' as timestamp)||': '
||decode(v_result,
335544665, 'violation of PK/UK',
335544321, 'num/string ovf',
335544345, 'lock on no_wait trn',
335544349, 'dup val in idx',
335544334, 'can`t upd erased row',
'UNKNOWN'
);
-- gds=335544321: arithmetic exception, numeric overflow, or string truncation
-- gds=335544345: lock conflict on no wait transaction
suspend;
leave;
end
end
if (v_result=0) then begin
-- 26.11.2013: log duration of all DML statements in just finished EB:
insert into log_activity(mode, dts_beg, dts_end, rows_cnt, id)
values('D', :v_dts_beg, 'now', :i, gen_id(log_activity_seq,1));
msg='commit; -- finish deleting '||v_deleted_cnt||' rows starting from '||:v_rnd_id||' at '||cast('now' as timestamp)||', i='||i;
suspend;
end
end
^set term ;^
set stat off;
-- какого фига вот этот стейтмент всё равно срабатывает при исключении внутри execute block'a ?
select 'Last statistics for att='||current_connection||', dts='||cast('now' as timestamp) msg from rdb$database;
set heading on;
set stat on;
set plan on;
set echo on;
select mode,dts_beg,time_ms,rows_cnt,rows_sec
from log_activity
where attach_id=current_connection
order by attach_id desc,id desc rows 20;
COMMIT;
set echo off;
set plan off;
set stat off;
shell rndpause.bat random 5 15;
----------------------------------------------------------------------------------
Скрипт запускается c bail_on_errors :
%fb_isql% %fb_testdb% -b -n -now -q -user %fb_usr% -pas %fb_psw% -i t004-%mode%-log.sql 2>&1 1>>%fb_log% | mtee /d/t/+ %fb_err% > nul
Здесь:
1) %fb_log% = лог, в который направляется "нормальный" вывод скрипта (командами suspend, см. out-параметр в execute block'e с именем = `msg`)
2) %fb_err% = лог, в который направляются ошибки
Если возникает исключение внутри EB, то должен прекращаться как EB, так и вообще весь скрипт - ведь я запустил его с bail_on_errors.
А значит, по идее , если затолкать в файл `stoptest.txt` пару строк и сохранить, то должно быть вот так:
1) в логе "нормальной работы":
1.
2.
3.
4.
5.
-- PACKET # 10:
-- attach_id=3867, intro .sql at 2013-12-31 20:02:45.3300
-- adding 58 rows, v_rnd4err=0.84, LOWER_THRESHOLD_FOR_ERR=0.00
-- isql, attach #3867: test was cancelled, dts=2013-12-31 20:02:45.3300
-- 20:03:03,33 INSERTING, window # 007. Finish iter # 0010
-- .bat/.sh: STOPFILE has non-zero size, test has been cancelled
, %fb_err%:
1.
2.
3.
4.
5.
2013-12-31 20:03:02.601 Statement failed, SQLSTATE = HY000
2013-12-31 20:03:02.601 exception 1
2013-12-31 20:03:02.601 -EX_TEST_CANCELLATION
2013-12-31 20:03:02.601 -test_has_been_calcelled
2013-12-31 20:03:02.601 After line 1857 in file t004-ins-log.sql
(так и происходит для скриптов, которые занимаются только insert'ами)
По факту же получается, что:
1) в логе работы:
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.
-- PACKET # 16:
-- attach_id=3656, intro .sql at 2013-12-31 20:02:46.6720
-- Start deleting 36 rows from first id >= 17399549, v_rnd4err=0.38, LOWER_THRESHOLD_FOR_ERR=0.00
-- isql, attach #3656: test was cancelled, dts=2013-12-31 20:02:46.6730
-- isql, attach #3656: test was cancelled, dts=2013-12-31 20:02:46.6730
rollback; -- ABORT, gds=335544517, i=0, at 2013-12-31 20:02:46.6730: UNKNOWN
Current memory = 2618952128
Delta memory = -9807800
Max memory = 2876932392
Elapsed time= 0.02 sec
Buffers = 524288
Reads = 6
Writes 11
Fetches = 810
-- а дальше он прёт как ни в чём не бывало:
Last statistics for att=3656, dts=2013-12-31 20:02:46.6760
select mode,dts_beg,time_ms,rows_cnt,rows_sec
from log_activity
where attach_id=current_connection
order by attach_id desc,id desc rows 20;
PLAN (LOG_ACTIVITY ORDER LA_DESC_ATTACH_ID)
MODE DTS_BEG TIME_MS ROWS_CNT ROWS_SEC
====== ========================= ===================== ============ =====================
D 2013-12-31 20:02:35.5210 3 80 26666
D 2013-12-31 20:02:18.4230 2 61 30500
D 2013-12-31 20:02:13.3260 4 73 18250
. . .
никакого сообщения про остановку теста нет.
PS.
Скрипт, который делает только insert'ы и "слушается" команду остановки, вот: хороший скрипт (реагирует на команду остановки) 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.
103.
104.
105.
106.
107.
108.
109.
110.
111.
112.
113.
114.
115.
116.
117.
118.
119.
120.
121.
122.
123.
124.
125.
126.
127.
128.
129.
130.
131.
132.
133.
134.
135.
136.
137.
138.
139.
140.
141.
142.
143.
144.
145.
146.
147.
148.
149.
150.
151.
152.
153.
154.
155.
156.
157.
158.
159.
160.
161.
162.
163.
164.
165.
166.
167.
168.
169.
170.
171.
172.
173.
174.
175.
176.
177.
178.
179.
180.
181.
182.
183.
184.
185.
186.
187.
COMMIT;
SET TRANSACTION READ WRITE READ COMMITTED RECORD_VERSION NO WAIT;
set heading off;
set list off;
set stat on;
set term ^;
execute block returns(msg varchar(200)) as
declare MIN_ROWS_FOR_INSERTING INT = 10;
declare MAX_ROWS_FOR_INSERTING int = 100;
declare MAX_FLD_VALUE int = 100;
declare v_inserted_cnt int;
declare i int=0;
declare v_result int;
declare v_rnd4err double precision;
declare v_rndval double precision;
declare v_stt varchar(2048);
declare v_log varchar(2048);
declare v_id type of column tmp.id;
declare v_f00 type of column tmp.f00;
declare v_f01 type of column tmp.f01;
declare v_f02 type of column tmp.f02;
declare v_f03 type of column tmp.f03;
declare v_f04 type of column tmp.f04;
declare v_f05 type of column tmp.f05;
declare v_f06 type of column tmp.f06;
declare v_f07 type of column tmp.f07;
declare v_f08 type of column tmp.f08;
declare v_f09 type of column tmp.f09;
declare v_f10 type of column tmp.f10;
declare v_f11 type of column tmp.f11;
declare v_dt1 type of column tmp.dt1;
declare v_dts_beg timestamp;
declare v_dts_end timestamp;
declare MIN_TIME_FOR_LOGGING int = 2000;
declare LOWER_THRESHOLD_FOR_ERR double precision = 0; -- 0=no errors, 1=max errors
declare LOG_STATEMENTS smallint=0; -- 1=log in autonom trn if statementtime more than MIN_TIME_FOR_LOGGING
-- ######################################################################
-- INSERT INSERT INSERT INSERT INSERT INSERT INSERT INSERT INSERT INSERT
-- ######################################################################
begin
v_dts_beg = cast('now' as timestamp);
msg=
'-- attach_id='||current_connection||', intro .sql at '
||v_dts_beg; -- ||', init gen_test='||gen_id(gen_test,0);
suspend;
v_rndval=rand();
v_rnd4err=rand(); -- error probability
v_inserted_cnt=MIN_ROWS_FOR_INSERTING + v_rndval * (MAX_ROWS_FOR_INSERTING-MIN_ROWS_FOR_INSERTING);
msg='-- adding '||v_inserted_cnt||' rows'
||', v_rnd4err='||cast(:v_rnd4err as numeric(6,2))
||', LOWER_THRESHOLD_FOR_ERR='||cast(LOWER_THRESHOLD_FOR_ERR as numeric(6,2))
;
suspend;
v_result=0;
i=0;
while (i < v_inserted_cnt and v_result=0) do begin
if ( mod(i,20)=0 and exists( select * from ext_stoptest )) then
begin
msg='-- isql, attach #'||current_connection||': test was cancelled, dts='||cast('now' as timestamp);
suspend;
exception ex_test_cancellation; -- 17.12.2013
-- leave;
exit;
end
v_id=gen_id(gen_test,1); -- 23.03.2012 fuck off this gens!! :v_last_gen + :i;
v_f00=rand()*:MAX_FLD_VALUE;
v_f01=rand()*:MAX_FLD_VALUE;
v_f02=rand()*:MAX_FLD_VALUE;
v_f03=rand()*:MAX_FLD_VALUE;
v_f04=rand()*:MAX_FLD_VALUE;
v_f05=rand()*:MAX_FLD_VALUE;
v_f06=rand()*:MAX_FLD_VALUE;
v_f07=iif(:v_rnd4err < :LOWER_THRESHOLD_FOR_ERR and i>=v_inserted_cnt-1, rand()*:MAX_FLD_VALUE, -:v_id);
v_f08=iif(:v_rnd4err < :LOWER_THRESHOLD_FOR_ERR and i>=v_inserted_cnt-1, rand()*:MAX_FLD_VALUE, :v_id);
v_f09=rand()*:MAX_FLD_VALUE;
v_f10=rand()*:MAX_FLD_VALUE;
v_f11=rand()*:MAX_FLD_VALUE;
v_dt1='01.03.2012 03:00:00';
begin
msg='insert into tmp(id,f00,f01,f02,f03,f04,f05,f06,f07,f08,f09,f10,f11,dt1)'
||' values('
||cast(:v_id as varchar(11))||','
||cast(:v_f00 as varchar(11))||','
||cast(:v_f01 as varchar(11))||','
||cast(:v_f02 as varchar(11))||','
||cast(:v_f03 as varchar(11))||','
||cast(:v_f04 as varchar(11))||','
||cast(:v_f05 as varchar(11))||','
||cast(:v_f06 as varchar(11))||','
||cast(:v_f07 as varchar(11))||','
||cast(:v_f08 as varchar(11))||','
||cast(:v_f09 as varchar(11))||','
||cast(:v_f10 as varchar(11))||','
||cast(:v_f11 as varchar(11))||','
||''''||cast(:v_dt1 as varchar(30))||''''
||'); -- i='||i;
insert into tmp(id,f00,f01,f02,f03,f04,f05,f06,f07,f08,f09,f10,f11,dt1)
values(:v_id
,:v_f00
,:v_f01
,:v_f02
,:v_f03
,:v_f04
,:v_f05
,:v_f06
,:v_f07
,:v_f08
,:v_f09
,:v_f10
,:v_f11
,:v_dt1
);
if (i in(0,1) or mod(i,100)=0 or i>=v_inserted_cnt-1 ) then
suspend; -- 17.03.2012: minimize output
when any do
begin
suspend; -- msg: insert-statement with zero division
v_result=gdscode;
msg='rollback; -- ABORT, gds='||v_result
||', i='||i
||', curr gen_test='||gen_id(gen_test,0)
||' at '||cast('now' as timestamp)||': '
||decode(v_result,
335544665, 'violation of PK/UK',
335544321, 'num/string ovf',
335544345, 'lock on no_wait trn',
335544349, 'dup val in idx',
335544334, 'can`t upd erased row',
'UNKNOWN'
);
-- gds=335544321: arithmetic exception, numeric overflow, or string truncation
-- gds=335544345: lock conflict on no wait transaction
-- gds=335544349: Attempt to store duplicate value (visible to active transactions) in unique index "@1".
-- gds=335544334: Can not update erased record
suspend;
leave;
end
end
i=i+1;
end
if (v_result=0) then begin
-- 26.11.2013: log duration of all DML statements in just finished EB:
insert into log_activity(mode, dts_beg, dts_end, rows_cnt, id)
values('I', :v_dts_beg, 'now', :i, gen_id(log_activity_seq,1) );
msg='commit; -- finish adding '||v_inserted_cnt||' rows at '||cast('now' as timestamp)
||', i='||i
||', curr gen_test='||gen_id(gen_test,0)
;
suspend;
end
end
^set term ;^
set stat off;
select 'Last statistics for att='||current_connection||', dts='||cast('now' as timestamp) msg from rdb$database;
set heading on;
set stat on;
set plan on;
set echo on;
select mode,dts_beg,time_ms,rows_cnt,rows_sec
from log_activity
where attach_id=current_connection
order by attach_id desc,id desc rows 20;
COMMIT;
set echo off;
set plan off;
set stat off;
shell rndpause.bat random 5 15;
В где ошибка (я про первый, "нехороший" скрипт) ?
PS. Сильно не пинайте, что многабукф, но так уж получилось... :-) |
