powered by simpleCommunicator - 2.0.53     © 2025 Programmizd 02
Форумы / Firebird, InterBase [игнор отключен] [закрыт для гостей] / Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
18 сообщений из 43, страница 2 из 2
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718663
Dimitry Sibiryakov
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
ТаблоидНу вот скажи мне: где в этой "картинке" может быть побочный эффект ?
Ты мне сначала скажи: на какой таблице ты получаешь этот багчек?

ТаблоидИ только затем идут уже обмены кортежами между таблицами-"внуками" (см
триггер tdx_bud for tdx active before update or delete).
И идут они в nowait транзакции, где ошибку нарушения ключей можно получить наткнувшись на
ещё несобранный мусор. Стоит очень быстро перекинуть одну запись туда-обратно в
параллельных транзакциях и нате вам.
Posted via ActualForum NNTP Server 1.5
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718676
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Dimitry SibiryakovТы мне сначала скажи: на какой таблице ты получаешь этот багчек?Дык я НЕ получаю багчек! и вообще хрен с ним, не до него сейчас :-)

Я получаю вот это:

Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
2014-08-12T18:07:57.1050 (29313:0x7f7df94af960) ERROR AT JStatement::fetch
        /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
335544665 : violation of PRIMARY or UNIQUE KEY constraint "INTEG_112" on table " TQ2 "
335545072 : Problematic key value is ("ID" = 351866)
335544842 : At trigger 'TDX_BUD' line: 36, col: 19
At trigger 'CHECK_55'
At procedure 'P_TMX_HADLE_DOC' line: 42, col: 21
335544842 : At trigger 'TDX_BUD' line: 48, col: 7
At trigger 'CHECK_55'
At procedure 'P_TMX_HADLE_DOC' line: 42, col: 21
(тут либо TQ1, либо TQ2 - равновероятно).
Один раз получил еще и FK violation, ну да ладно, с PK бы сначала разобраться.

Dimitry SibiryakovТаблоидИ только затем идут уже обмены кортежами между таблицами-"внуками" (см триггер tdx_bud for tdx active before update or delete).И идут они в nowait транзакции, где ошибку нарушения ключей можно получить наткнувшись на ещё несобранный мусор . Стоит очень быстро перекинуть одну запись туда-обратно в параллельных транзакциях и нате вам.А разве в мусоре нет инфы о том, в какой транзакции была создана эта версия и какое сейчас состояние этой транзакции ?
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718688
hvlad
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Таблоид
Код: plaintext
1.
335544665 : violation of PRIMARY or UNIQUE KEY constraint  "INTEG_275"  on table " TQ1 "

Таблоид
Код: plaintext
1.
2.
3.
4.
5.
recreate table tq1(
    id int  primary key using index tq1_pk ,
    pid int,
    x int default 1
);

Ась ?
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718693
Dimitry Sibiryakov
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
ТаблоидА разве в мусоре нет инфы о том, в какой транзакции была создана эта версия
и какое сейчас состояние этой транзакции ?
Есть. Но ничто не мешает этой транзакции быть ещё активной. Твоя процедура может в одной и
той же транзакции переместить одни и те же записи туда и обратно несколько раз.
Posted via ActualForum NNTP Server 1.5
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718699
Dimitry Sibiryakov
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
hvladАсь ?
Индексы получают имена по констрейнам, не наоборот.
Posted via ActualForum NNTP Server 1.5
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718714
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
hvladАсь ?А чё ? :-) в ddl таблиц TQ1 & TQ2 нет имён констрейнтов , есть только имена у индексов:

Код: plaintext
1.
2.
3.
4.
recreate table tq1(
    id int  primary key using index tq1_pk ,
    . . .
)
commit;
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718717
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Dimitry SibiryakovТвоя процедура может в одной и той же транзакции переместить одни и те же записи туда и обратно несколько раз. НЕ может: там отбор по условию, что этот документ еще не обрабатывался в данной транзакции
Код: 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.
create or alter procedure p_tmx_hadle_doc returns(sel_id int, result char(3))
as
    declare v_curr_trn int;
    declare v_min_id double precision;
    declare v_max_id double precision;
    declare v_rnd_id double precision;
    declare r double precision;
    declare v_sel_id int;
    declare const_qty int = 100;
    declare v_handle_mode varchar(50);
begin
    -- Performs action with ONE "doc", depending on random value (:r)
    -- if :r < 0.25 then add new "doc"
    -- else if :r < 0.75 then make update field tmx.op (this fires cascade update
    --                   in detail (tdx) and "exchange" operation between tq1 & tq2)
    -- else - remove "doc" (this fires cascade deletion in detail (tdx) and also
    --                      removing of all corresp. rows in tq1 & tq2)
    r = rand();
    if (r < 0.25) then
        begin
          select p.sel_id,'add' from p_tmx_add_doc( 1 + rand()*(:const_qty-1) ) p
          into sel_id, result;
        end
    else
        begin
            select id from tmx order by id rows 1 into v_min_id;
            select id from tmx order by id desc rows 1 into v_max_id;
            v_rnd_id = v_min_id - 0.5 + rand() * ( v_max_id - v_min_id + 1);

            select m.id
            from tmx m
            where m.id >= :v_rnd_id
                   and not exists(select * from gtt_trn_log g where g.sel_id = m.id) 
            order by id rows 1
             FOR UPDATE WITH LOCK 
            into sel_id;

            if ( r < 0.75 ) then
                begin
                    v_handle_mode='upd in tmx, id='||sel_id;
                    rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    update tmx m set m.op = iif(m.op=1, 2, 1) where id = :sel_id
                    returning 'upd' into result;
                end
            else
                begin
                    v_handle_mode='del in tmx, id='||sel_id;
                     rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    delete from tmx m where id = :sel_id
                    returning 'del' into result;
                end
        end
    if ( sel_id is NOT null ) then  insert into gtt_trn_log(sel_id) values(:sel_id); 

    suspend;

when any do
    begin
      v_curr_trn = current_transaction;
      in autonomous transaction do
      insert into tlog(sel_id, unit, handle_mode, fb_gdscode, trn_id)
      values( :sel_id, 'p_tmx_hadle_doc', :v_handle_mode, gdscode, :v_curr_trn);

      exception;

    end
end
- где gtt_trn_log есть:

Код: plaintext
1.
2.
recreate global temporary table gtt_trn_log(sel_id int primary key)
on commit delete rows;
commit;
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718722
hvlad
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
ТаблоидА чё ? :-)А то :) Я тоже не всё помню - вот чё :)
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718725
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
hvlad,

ну так шо, может, глянешь повнимательнее на "артефакты" ? А то я в трейс уже с головой ушёл, лог в 1.4 Гб тут изучаю...
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718726
Dimitry Sibiryakov
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Таблоидтам отбор по условию
В каком месте
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
        begin
             select id from tmx order by id rows 1 into v_min_id;
             select id from tmx order by id desc rows 1 into v_max_id;
             v_rnd_id = v_min_id - 0.5 + rand() * ( v_max_id - v_min_id + 1);
             select id from tmx where id >= :v_rnd_id order by id rows 1 into sel_id;
             if ( r < 0.75 ) then
                 begin
                     v_handle_mode='upd in tmx, id='||sel_id;
                     update tmx m set m.op = iif(m.op=1, 2, 1) where id = :sel_id
                     returning 'upd' into result;
                 end
             else
                 begin
                     v_handle_mode='del in tmx, id='||sel_id;
                     delete from tmx m where id = :sel_id
                     returning 'del' into result;
                 end
         end

это условие?
Posted via ActualForum NNTP Server 1.5
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718740
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Dimitry SibiryakovТаблоидтам отбор по условиюВ каком месте это условие?Это старый скрипт, там этого не было - ты же недавно токнул мну в эту сторону.
Вот что я гоняю сейчас и воспроизводимо получаю PK violation через 5-10 минут, при нагрузке 100 окон.
Полный DDL :
см в нём ХП "p_tmx_hadle_doc", нужное там выделено цветом
Код: 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.
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.
188.
189.
190.
191.
192.
193.
194.
195.
196.
197.
198.
199.
200.
201.
202.
203.
204.
205.
206.
207.
208.
209.
210.
211.
212.
213.
214.
215.
216.
217.
218.
219.
220.
221.
222.
223.
224.
225.
226.
227.
228.
229.
230.
231.
232.
233.
234.
235.
236.
237.
238.
239.
240.
241.
242.
243.
244.
245.
246.
247.
248.
249.
250.
251.
252.
253.
254.
255.
256.
257.
258.
259.
260.
261.
262.
263.
264.
265.
266.
267.
268.
269.
270.
271.
272.
273.
274.
275.
276.
277.
278.
279.
280.
281.
282.
283.
284.
285.
286.
287.
288.
289.
290.
291.
292.
293.
294.
295.
296.
297.
298.
299.
300.
301.
recreate exception ex_bad_error_encountered 'at least one forbidden error found, gdscode=@1';
commit;
create or alter procedure p_tmx_hadle_doc as begin end;
create or alter procedure p_tmx_add_doc as begin end;
create or alter function fn_halt_test returns int as begin end;
set term ^;
execute block as
begin
  begin execute statement 'drop trigger tdx_bi'; when any do begin end end
  begin execute statement 'drop trigger tdx_bud'; when any do begin end end
  begin execute statement 'drop trigger tmx_bud'; when any do begin end end
end
^set term ;^
commit;

recreate table tq1(
    id int primary key using index tq1_pk,
    pid int,
    x int default 1,
    att_id int default current_connection,
    trn_id int default current_transaction,
    dts timestamp default 'now'
);
create index tq1_pid on tq1(pid);
commit;

recreate table tq2(
    id int primary key using index tq2_pk,
    pid int,
    x int default 1,
    att_id int default current_connection,
    trn_id int default current_transaction,
    dts timestamp default 'now'
);
create index tq2_pid on tq2(pid);
commit;


recreate table tdx(
    id int primary key using index tdx_pk,
    pid int,
    op int not null check(op in(1,2)),
    qty int not null check(qty>0),
    att_id int default current_connection,
    trn_id int default current_transaction,
    dts timestamp default 'now'
);
recreate table tlog(
    sel_id int,
    unit varchar(31),
    handle_mode varchar(50),
    fb_gdscode int,
    att_id int default current_connection,
    trn_id int default current_transaction,
    dts timestamp default 'now'
);
create index tlog_fb_gdscode on tlog(fb_gdscode);
commit;

recreate table tmx(
    id int primary key using index tmx_pk,
    op int not null check(op in(1,2)),
    att_id int default current_connection,
    trn_id int default current_transaction,
    dts timestamp default 'now',
    unique(id, op) using index tmx_unq_for_tdx_fk
);
create descending index tmx_id_desc on tmx(id);
commit;

recreate global temporary table gtt_trn_log(sel_id int primary key)
on commit delete rows;
commit;

recreate sequence g;
commit;

alter table tdx add constraint tdx_fk
    foreign key (pid, op) references tmx(id, op)
    on delete cascade
    on update cascade;
commit;

set term ^;
create or alter trigger tdx_bi for tdx active before insert as
    declare v_qty int;
    declare v_stt varchar(128);
begin
    -- Multiply rows in either in TQ1 or TQ2 - depending on new.op value
    -- (which is generated randomly and can be 1 or 2).
    -- Number of created rows = int values of new.qty,
    --  which is being inserted in tdx.qty field:
    v_stt = 'insert into ' || iif( new.op=1, 'tq1', 'tq2' ) || '(id, pid) values(:a_id, :a_pid)';
    v_qty = new.qty;
    while (v_qty>0) do
    begin
        execute statement (v_stt) ( a_id := gen_id(g,1), a_pid := new.pid );
        v_qty = v_qty - 1;
    end
end
^

create or alter trigger tdx_bud for tdx active before update or delete as
    declare v_sel_id int;
    declare v_curr_trn int;
    declare v_handle_mode varchar(50);
begin
    if (deleting) then  -- remove all rows in TQ1 and TQ2 which have pid = old.pid
        begin
            v_sel_id=old.pid;
            v_handle_mode='del in tq1, pid='||old.pid;
            rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
            delete from tq1 q where q.pid = old.pid;

            v_handle_mode='del in tq2, pid='||old.pid;
            rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
            delete from tq2 q where q.pid = old.pid;
        end
    else -- updating: MOVE all rows related to document, with DELETION in SOURCE
        begin
            v_sel_id=new.pid;
            if ( new.op = 1 ) then begin
              -- SOURCE = TQ2, TARGET = TQ1
              for select id, pid from tq2 where pid = new.pid as cursor c
              do begin
                  v_handle_mode='try: ins tq1, del in tq2, id='||c.id;
                  rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                  insert into tq1(id, pid) values (c.id, c.pid);
                  delete from tq2 where current of c;
              end
            end
            else begin
              -- SOURCE = TQ1, TARGET = TQ2
              for select id, pid from tq1 where pid = new.pid as cursor c
              do begin
                  v_handle_mode='try: ins tq2, del in tq1, id='||c.id;
                  rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                  insert into tq2(id, pid) values (c.id, c.pid);
                  delete from tq1 where current of c;
              end
            end
        end -- deleting or updating branch
when any do
    begin
      v_curr_trn = current_transaction;
      in autonomous transaction do
      insert into tlog(sel_id, unit, handle_mode, fb_gdscode, trn_id)
      values( :v_sel_id, 'tdx_bud', :v_handle_mode, gdscode, :v_curr_trn);

      exception;

    end
end

^

create or alter trigger tmx_bud for tmx active before update or delete as
  declare v_id int;
begin
    for
        select id from tdx d
        where d.pid = old.id
        for update with lock
        into v_id
    do begin
        -- nop! just ensure that we really lock all detail records --
    end
end
^
set term ;^
commit;
--------------------------------------------------------------------------------
set term ^;
create or alter procedure p_tmx_add_doc(m_rows int) returns(sel_id int)
as
    declare v_op int;
    declare i int;
    declare const_qty int = 100;
begin
    -- NB: trigger tdx_bi will "multiply" rows in either TQ1 or TQ2,
    -- number of added rows = new.qty:
    insert into tmx(id, op) values( gen_id(g,1), iif(rand()<0.5, 1, 2))
    returning id, op into sel_id, v_op;
    i=0;
    while (i < m_rows) do
    begin
        insert into tdx(id, pid, op, qty) values( gen_id(g,1), :sel_id, :v_op, 1+rand()*(:const_qty-1) );
        i=i+1;
    end
    suspend;
end
^

create or alter procedure  p_tmx_hadle_doc  returns(sel_id int, result char(3))
as
    declare v_curr_trn int;
    declare v_min_id double precision;
    declare v_max_id double precision;
    declare v_rnd_id double precision;
    declare r double precision;
    declare v_sel_id int;
    declare const_qty int = 100;
    declare v_handle_mode varchar(50);
begin
    -- Performs action with ONE "doc", depending on random value (:r)
    -- if :r < 0.25 then add new "doc"
    -- else if :r < 0.75 then make update field tmx.op (this fires cascade update
    --                   in detail (tdx) and "exchange" operation between tq1 & tq2)
    -- else - remove "doc" (this fires cascade deletion in detail (tdx) and also
    --                      removing of all corresp. rows in tq1 & tq2)
    r = rand();
    if (r < 0.25) then
        begin
          select p.sel_id,'add' from p_tmx_add_doc( 1 + rand()*(:const_qty-1) ) p
          into sel_id, result;
        end
    else
        begin
            select id from tmx order by id rows 1 into v_min_id;
            select id from tmx order by id desc rows 1 into v_max_id;
            v_rnd_id = v_min_id - 0.5 + rand() * ( v_max_id - v_min_id + 1);

            select m.id
            from tmx m
            where m.id >= :v_rnd_id
                   and not exists(select * from gtt_trn_log g where g.sel_id = m.id) 
            order by id rows 1
            FOR UPDATE WITH LOCK
            into sel_id;

            if ( r < 0.75 ) then
                begin
                    v_handle_mode='upd in tmx, id='||sel_id;
                    rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    update tmx m set m.op = iif(m.op=1, 2, 1) where id = :sel_id
                    returning 'upd' into result;
                end
            else
                begin
                    v_handle_mode='del in tmx, id='||sel_id;
                     rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    delete from tmx m where id = :sel_id
                    returning 'del' into result;
                end
        end
     if ( sel_id is NOT null ) then insert into gtt_trn_log(sel_id) values(:sel_id); 

    suspend;

when any do
    begin
      v_curr_trn = current_transaction;
      in autonomous transaction do
      insert into tlog(sel_id, unit, handle_mode, fb_gdscode, trn_id)
      values( :sel_id, 'p_tmx_hadle_doc', :v_handle_mode, gdscode, :v_curr_trn);

      exception;

    end
end

^

create or alter function fn_halt_test returns int
as
    declare result int;
begin
    -- Used in .sql to immediatelly stop test (via set bail on) if one of the
    -- following errors registered in tlog: PK / UQ / FK violation.
    select first 1 g.fb_gdscode
    from tlog g
                       where g.fb_gdscode
                       in (
                                 335544665 -- unique_key_violation
                                ,335544349 -- no_dup 
                                ,335544466 -- violation of FOREIGN KEY
                                ,335544838 -- Foreign key reference target does not exist 
                                ,335544839 -- Foreign key references are present for the record
                           )
    into result;
    return result;
end
^
set term ;^
commit;

------------------------------- initial data filling ---------------------------
set term ^;
execute block as
    declare n int = 500;
    declare const_qty int = 100;
    declare i int;
begin
    while (n>0) do
    begin
        execute procedure p_tmx_add_doc(1 + rand()*(:const_qty-1)) returning_values i;
        n = n-1;
    end
end
^set term ;^
commit;

Скрипт, скармливаемый isql'ям:
repeat 100500 times
Код: 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.
set term ^;
execute block as
    declare n int = -1;
begin
    n=fn_halt_test();
    if ( n > 0 ) then
      exception ex_bad_error_encountered using (:n);
end
^ set term ;^
set bail off;

commit; set transaction snapshot no wait;
set term ^;
execute block returns(trn_id int, dts varchar(12), sel_id int, result varchar(3))
as
  declare n int = 10;
begin
  trn_id = current_transaction;
  while ( n>0 ) do begin
    select sel_id, result from  p_tmx_hadle_doc  into sel_id, result;
    dts=substring(cast(cast('now' as timestamp) as varchar(24)) from 12 for 12);
    suspend;
    n=n-1;
  end
end
^ set term ;^

Ну, и батник тоже повторю сюда:
run: tq_run.bat NN, NN = number of ISQLs to be opened
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
setlocal enabledelayedexpansion enableextensions

@rem path to ISQL utility, without trailing backslash:
set fbc=C:\MIX\firebird\fb25\bin

@rem path where temp logs will be created:
set tmpdir=c:\temp\tq

md %tmpdir% 2>nul
del %tmpdir%\tq_run_*.log 2>nul
del %tmpdir%\tq_run_*.err 2>nul
if not .%1.==.. set /a winq=%1
if .%winq%.==.0. set winq=10
@echo off
for /l %%i in (1, 1, %winq%) do (
  set str=%fbc%\isql 192.168.0.220/3333:/var/db/fb30/tq.fdb -n -i tq_run.sql 1^>%tmpdir%\tq_run_%%i.log 2^>%tmpdir%\tq_run_%%i.err
  echo str = !str!
  start /min cmd /c !str!
)
goto end
:end
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718820
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
ТаблоидА то я в трейс уже с головой ушёл, лог в 1.4 Гб тут изучаю... Ну, вот я и вернулся. И хочу там/нам/вам всем рассказать одну страшную историю.

Вот что записано в таблице-логе для "плохой ошибки" (335544665 = PK/UK violation):SEL_IDUNITHANDLE_MODEFB_GDSCODEATT_IDTRN_IDDTS351821tdx_budtry: ins tq2, del in tq1 , id= 351866 3355446654701727612.08.2014 18:07:57.024351821p_tmx_hadle_docupd in tmx , id= 351821 3355446654701727612.08.2014 18:07:57.084Здесь:
0) 17276 - номер транзакции, которая обломалась;
1) id=351866 - это ПК, который странным образом был "увиден" транзакцией 17276 в таблице tq2;
2) id=351821 - это ID заголовка документа (т.е. master-записи), который должна была предварительно залочить транзакция 17276, прежде чем обрабатывать далее подчинённые строки, и в том числе - делать перекидку кортежей из tq1 в tq2.

Слова " должна была " - потому что в ХП p_tmx_hadle_doc делается вот это:
Код: sql
1.
2.
3.
4.
5.
6.
7.
            select m.id
            from tmx m
            where m.id >= :v_rnd_id
                  and not exists(select * from gtt_trn_log g where g.sel_id = m.id)
            order by id rows 1
            FOR UPDATE WITH LOCK
            into sel_id;

- и при невозможности залочить запись управление должно перескочить в when-секцию.
А при успехе залочивания код будет продолжен и выполнится вот это:
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
            if ( r < 0.75 ) then
                begin
                    v_handle_mode='upd in tmx, id='||sel_id;
                    rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    update tmx m set m.op = iif(m.op=1, 2, 1) where id = :sel_id
                    returning 'upd' into result;
                end
            else
                begin
                    v_handle_mode='del in tmx, id='||sel_id;
                    rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    delete from tmx m where id = :sel_id
                    returning 'del' into result;
                end

(натыканные в коде вызовы rdb$set_context'ов нужны для анализа трейса: сразу видно, "куда попали и с каким значением").

А теперь - внимание, уважаемые знатоки.

Имеется две транзакции, 16396 и 17276 .
И вот что по ним получено при расковыривании трейса (данные упорядочены по графе " Время "):NN п/пНомер транзакцииСобытие трейса Время Результат события или примечание116936START_TRANSACTION18:07:00.3910216936EXECUTE_PROCEDURE_START - Procedure P_TMX_HADLE_DOC18:07:31.1350316936SET_CONTEXT: DEBUG_TRACED_ACTION = "try: ins tq2, del in tq1, id=351866"18:07:31.1450SUCCESS - см ниже строку 6416936EXECUTE_TRIGGER_START - TDX_BUD FOR TDX (BEFORE UPDATE)18:07:31.1450517276START_TRANSACTION18:07:48.7540616936EXECUTE_TRIGGER_FINISH - TDX_BUD FOR TDX (BEFORE UPDATE)18:07:56.459025314 ms, 28 write(s), 73735 fetch(es), 16582 mark(s) 7 16936 EXECUTE_PROCEDURE_FINISH - Procedure P_TMX_HADLE_DOC18:07:56.9660817276EXECUTE_PROCEDURE_START - Procedure P_TMX_HADLE_DOC18:07:56.9950 9 17276 SET_CONTEXT: DEBUG_TRACED_ACTION = "try: ins tq2, del in tq1, id=351866" 18:07:57.0060FAILED - см ниже строку N 111017276EXECUTE_TRIGGER_START - TMX_BUD FOR TMX (BEFORE UPDATE)18:07:57.00601117276FAILED EXECUTE_TRIGGER_FINISH - TDX_BUD FOR TDX (BEFORE UPDATE)18:07:57.04201217276FAILED EXECUTE_PROCEDURE_FINISH - Procedure P_TMX_HADLE_DOC18:07:57.100013335544665 : violation of PRIMARY or UNIQUE KEY constraint "INTEG_112" on table "TQ2", 335545072 : Problematic key value is ("ID" = 351866)18:07:57.1050ATT_4701417276COMMIT_TRANSACTION18:07:57.11501516936COMMIT_TRANSACTION18:07:58.4750

Таким обр., транзакция 17276 всё-таки как-то смогла добраться до кода, обновляющего кортежи таблиц TQ1 & TQ2 - - "внуков" для оглавления документов TMX, и добралась она туда:
1) *после* того, как транзакция 16936 УСПЕШНО завершила процедуру обновления TMX (см строки 7 и 9);
2) *до* того, как транзакция 16936 выполнила свой коммит, т.е. обновлённая запись TMX с id = 351821 еще удерживалась этой (16936-ой) транзакцией.

Чтобы точно в этом убедиться, я полез в трейс с поисками записей, в которых видно, как обе эти транзакции проходят точку блокировки заголовка документа с id=351821.

И вот что я вижу там для trn = 16936 :
Код: 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.
2014-08-12T 18:07:00.3910 (29313:0x7f7e2da16388) START_TRANSACTION 
       /var/db/fb30/tq.fdb (ATT_483, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
       C:\1INSTALL\FB25SNAP\bin\isql.exe:2232
               (TRA_16936, CONCURRENCY | NOWAIT | READ_WRITE)
. . .
2014-08-12T 18:07:31.1420  (29313:0x7f7e2da16388) SET_CONTEXT
        /var/db/fb30/tq.fdb (ATT_483, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2232
                (TRA_16936, CONCURRENCY | NOWAIT | READ_WRITE)
 -- этот "SET_CONTEXT" значит, что только что было успешно выполнено: select id from TMX where id = 351821 FOR UPDATE WITH LOCK: 
[USER_TRANSACTION]  DEBUG_TRACED_ACTION = "upd in tmx, id=351821" 

-- А начало before_update_delete-триггера значит, что вслед за ним будет уже делаться
-- вот это:  update tmx m set m.op = iif(m.op=1, 2, 1) where id = :sel_id 
2014-08-12T 18:07:31.1420  (29313:0x7f7e2da16388)  EXECUTE_TRIGGER_START 
        /var/db/fb30/tq.fdb (ATT_483, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2232
                (TRA_16936, CONCURRENCY | NOWAIT | READ_WRITE)
        TMX_BUD FOR TMX (BEFORE UPDATE)
-- Дальше идёт уже переброска данных из TQ1 в TQ2. В том числе там ниже будет строка с id=351866:
2014-08-12T18:07:31.1420 (29313:0x7f7e35281c18) SET_CONTEXT
        /var/db/fb30/tq.fdb (ATT_441, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:1756
                (TRA_16815, CONCURRENCY | NOWAIT | READ_WRITE)
[USER_TRANSACTION] DEBUG_TRACED_ACTION = "try: ins tq2, del in tq1, id=1863100"
. . . 

 -- триггер завершился УСПЕШНО (хоть и молотило всё 25 сек) 
2014-08-12T18:07:56.4590 (29313:0x7f7e2da16388) EXECUTE_TRIGGER_FINISH
        /var/db/fb30/tq.fdb (ATT_483, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2232
                (TRA_16936, CONCURRENCY | NOWAIT | READ_WRITE)
        TDX_BUD FOR TDX (BEFORE UPDATE)
  25314 ms, 28 write(s), 73735 fetch(es), 16582 mark(s)

 -- процедура, обновлявшая мастер-запись в TMX для id = 351821, также завершается УСПЕШНО: 
2014-08-12T18:07:56.9660 (29313:0x7f7e2da16388) EXECUTE_PROCEDURE_FINISH
        /var/db/fb30/tq.fdb (ATT_483, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2232
                (TRA_16936, CONCURRENCY | NOWAIT | READ_WRITE)

 -- закончился execute block, после выхода из которого в .sql-скрипте всегда делается COMMIT: 
2014-08-12T 18:07:58.4750 (29313:0x7f7e2da16388) COMMIT_TRANSACTION 
       /var/db/fb30/tq.fdb (ATT_483, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
       C:\1INSTALL\FB25SNAP\bin\isql.exe:2232
               (TRA_16936, CONCURRENCY | NOWAIT | READ_WRITE)
   1317 ms, 2489 write(s), 9 fetch(es), 6 mark(s)

А вот что в трейсе для trn = 17276 :
Код: 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.
2014-08-12T 18:07:48.7540 (29313:0x7f7e50784480) START_TRANSACTION 
       /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
       C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
               (TRA_17276, CONCURRENCY | NOWAIT | READ_WRITE)
. . .
 -- этот "SET_CONTEXT" значит, что только что было успешно выполнено: select id from TMX where id = 351821 FOR UPDATE WITH LOCK: 
 -- КАК ТАКОЕ МОГЛО ПРОИЗОЙТИ, ЕСЛИ ЭТА ЗАПИСЬ СЕЙЧАС ЗАЛОЧЕНА ТРАНЗАКЦИЕЙ 16936 
-- И ДЛЯ НЕЁ УСПЕШНО БЫЛА ВЫПОЛНЕНА ПРОЦЕДУРА ОБНОВЛЕНИЯ ДАННЫХ В ТАБЛИЦЕ `TMX` 
-- И В ПОДЧИНЁННЫХ ЕЙ TQ1 & TQ2 ? 
2014-08-12T 18:07:57.0020  (29313:0x7f7e50784480) SET_CONTEXT
        /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
                (TRA_17276, CONCURRENCY | NOWAIT | READ_WRITE)
[USER_TRANSACTION]  DEBUG_TRACED_ACTION = "upd in tmx, id=351821" 

 -- начинаем (почему-то!) переброску данных, хотя как мы могли вообще сюда попасть ?! 
2014-08-12T 18:07:57.0020  (29313:0x7f7e50784480) EXECUTE_TRIGGER_START
        /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
                (TRA_17276, CONCURRENCY | NOWAIT | READ_WRITE)
        TMX_BUD FOR TMX (BEFORE UPDATE)

2014-08-12T18:07:57.0020 (29313:0x7f7dce639db8) SET_CONTEXT
        /var/db/fb30/tq.fdb (ATT_510, SYSDBA:NONE, NONE, TCPv4:192.168.43.96)
        C:\MIX\firebird\fb25\bin\isql.exe:1904
                (TRA_17213, CONCURRENCY | NOWAIT | READ_WRITE)
[USER_TRANSACTION] DEBUG_TRACED_ACTION = "try: ins tq2, del in tq1, id=3908179"

 -- обломались в триггере (см ниже сообщение о PK violation): 
2014-08-12T18:07:57.0420 (29313:0x7f7e50784480) FAILED EXECUTE_TRIGGER_FINISH
        /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
                (TRA_17276, CONCURRENCY | NOWAIT | READ_WRITE)
        TDX_BUD FOR TDX (BEFORE UPDATE)
     36 ms, 1 write(s), 293 fetch(es), 8 mark(s)

 -- облом перешёл в ХП: 
2014-08-12T18:07:57.1000 (29313:0x7f7e50784480) FAILED EXECUTE_PROCEDURE_FINISH
        /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
                (TRA_17276, CONCURRENCY | NOWAIT | READ_WRITE)
Procedure P_TMX_HADLE_DOC:
    105 ms, 4 write(s), 2835 fetch(es), 412 mark(s)

 -- облом показался на клиенте: 
2014-08-12T18:07:57.1050 (29313:0x7f7e50784480) ERROR AT JStatement::fetch
        /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
        C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
335544665 : violation of PRIMARY or UNIQUE KEY constraint "INTEG_112" on table "TQ2"
335545072 : Problematic key value is ("ID" = 351866)
335544842 : At trigger 'TDX_BUD' line: 36, col: 19
At trigger 'CHECK_55'
At procedure 'P_TMX_HADLE_DOC' line: 42, col: 21
335544842 : At trigger 'TDX_BUD' line: 48, col: 7
At trigger 'CHECK_55'
At procedure 'P_TMX_HADLE_DOC' line: 42, col: 21
. . .

 -- закончился execute block, после выхода из которого в .sql-скрипте всегда делается COMMIT: 
2014-08-12T 18:07:57.1150  (29313:0x7f7e50784480) COMMIT_TRANSACTION
       /var/db/fb30/tq.fdb (ATT_470, SYSDBA:NONE, NONE, TCPv4:192.168.43.62)
       C:\1INSTALL\FB25SNAP\bin\isql.exe:2744
               (TRA_17276, CONCURRENCY | NOWAIT | READ_WRITE)
      7 ms, 54 write(s), 9 fetch(es), 6 mark(s)

Ну, и как могло случиться такое горе с транзакцией 17276 ?
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718829
hvlad
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
ТаблоидСлова " должна была " - потому что в ХП p_tmx_hadle_doc делается вот это:
Код: sql
1.
2.
3.
4.
5.
6.
7.
            select m.id
            from tmx m
            where m.id >= :v_rnd_id
                  and not exists(select * from gtt_trn_log g where g.sel_id = m.id)
            order by id rows 1
            FOR UPDATE WITH LOCK
            into sel_id;

А ты уверен, что здесь v_rnd_id == sel_id ?
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718835
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
hvladА ты уверен, что здесь v_rnd_id == sel_id ?Они почти в 100% случаев НЕ будут равны. А в чём, собс-но, трабл ? Переменная v_rnd_id ("якорь" для старта поиска) после этого места в ХП уже не используется:
SP p_tmx_hadle_doc
Код: 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.
create or alter procedure p_tmx_hadle_doc returns(sel_id int, result char(3))
as
    declare v_curr_trn int;
    declare v_min_id double precision;
    declare v_max_id double precision;
    declare v_rnd_id double precision;
    declare r double precision;
    declare v_sel_id int;
    declare const_qty int = 100;
    declare v_handle_mode varchar(50);
begin
    -- Performs action with ONE "doc", depending on random value (:r)
    -- if :r < 0.25 then add new "doc"
    -- else if :r < 0.75 then make update field tmx.op (this fires cascade update
    --                   in detail (tdx) and "exchange" operation between tq1 & tq2)
    -- else - remove "doc" (this fires cascade deletion in detail (tdx) and also
    --                      removing of all corresp. rows in tq1 & tq2)
    r = rand();
    if (r < 0.25) then
        begin
          select p.sel_id,'add' from p_tmx_add_doc( 1 + rand()*(:const_qty-1) ) p
          into sel_id, result;
        end
    else
        begin
            select id from tmx order by id rows 1 into v_min_id;
            select id from tmx order by id desc rows 1 into v_max_id;
            v_rnd_id = v_min_id - 0.5 + rand() * ( v_max_id - v_min_id + 1);

            select m.id
            from tmx m
            where m.id >=  :v_rnd_id 
                  and not exists(select * from gtt_trn_log g where g.sel_id = m.id)
            order by id rows 1
            FOR UPDATE WITH LOCK
            into sel_id;

            if ( r < 0.75 ) then
                begin
                    v_handle_mode='upd in tmx, id='||sel_id;
                    rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    update tmx m set m.op = iif(m.op=1, 2, 1) where id = :sel_id
                    returning 'upd' into result;
                end
            else
                begin
                    v_handle_mode='del in tmx, id='||sel_id;
                    rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', v_handle_mode);
                    delete from tmx m where id = :sel_id
                    returning 'del' into result;
                end
        end
    if ( sel_id is NOT null ) then insert into gtt_trn_log(sel_id) values(:sel_id);

    suspend;

when any do
    begin
      v_curr_trn = current_transaction;
      rdb$set_context('USER_TRANSACTION','DEBUG_TRACED_ACTION', 'gds='||gdscode||' for "'||:v_handle_mode||'"');
      in autonomous transaction do
      insert into tlog(sel_id, unit, handle_mode, fb_gdscode, trn_id)
      values( :sel_id, 'p_tmx_hadle_doc', :v_handle_mode, gdscode, :v_curr_trn);

      exception;

    end
end
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718843
hvlad
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
ТаблоидПеременная v_rnd_id ("якорь" для старта поиска) после этого места в ХП уже не используется:Согласен

Но я уже потерялся - то у тебя проблемы с 351821, то с 351866
В общем - 16431065 никуда не делось
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #38718849
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
hvladНо я уже потерялся - то у тебя проблемы с 351821, то с 351866да там всё просто :-)
Таблоид1) id=351866 - это ПК, который странным образом был "увиден" транзакцией 17276 в таблице tq2;
2) id=351821 - это ID заголовка документа (т.е. master-записи), который должна была предварительно залочить транзакция 17276, прежде чем обрабатывать далее подчинённые строки, и в том числе - делать перекидку кортежей из tq1 в tq2.
hvladВ общем - 16431065 никуда не делосьААААА!!! НЕЕЕЕТТТ!!!
Блин, ну поможи разобрацца-то! Всё равно ведь все дороги в твою степь ведут...

Ты можешь запустить на своей тачанке 30-40 isql'ей ? Ресурсы её позволят ?
...
Рейтинг: 0 / 0
Период между сообщениями больше года.
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #39154297
Cobalt747
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Интересно, чем закончилось-то?
...
Рейтинг: 0 / 0
Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
    #39154689
Таблоид
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Cobalt747,

закончилось это перепиской с Главным Источником Света и удивительнейшим открытием, которое расписано тут .
...
Рейтинг: 0 / 0
18 сообщений из 43, страница 2 из 2
Форумы / Firebird, InterBase [игнор отключен] [закрыт для гостей] / Нарушение PK при интенсивном обмене данными между таблицами. Не могу понять причину.
Целевая тема:
Создать новую тему:
Автор:
Закрыть
Цитировать
Найденые пользователи ...
Разблокировать пользователей ...
Читали форум (0):
Пользователи онлайн (0):
x
x
Закрыть


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