Bug #20897 race condition between drop table and suma drop trigger
Submitted: 7 Jul 2006 10:37 Modified: 8 Jul 2006 7:43
Reporter: Tomas Ulin Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Cluster: Cluster (NDB) storage engine Severity:S2 (Serious)
Version:5.1 OS:
Assigned to: Tomas Ulin CPU Architecture:Any

[7 Jul 2006 10:37] Tomas Ulin
Description:
seen every now and then in pushbuild, symproms as follows:

060707  3:08:23 [Note] NDB Binlog: drop table ./test/t7_c.
060707  3:08:25 [Note] NDB Binlog: Node: 2, down, Subscriber bitmask 00

- i.e. node failure

Message: Internal program error (failed ndbrequire) (Internal error, programming error or missing error message, please report a bug)
Error: 2341
Error data: suma/Suma.cpp
Error object: SUMA (Line: 3002) 0x0000000a

DROP_TRIG_REF

trace:

--------------- Signal ----------------
r.bn: 257 "SUMA", r.proc: 2, r.sigId: 2086499 gsn: 515 "DROP_TRIG_REF" prio: 1
s.bn: 249 "DBTUP", s.proc: 2, s.sigId: 2086494 length: 9 trace: 0 #sec: 0 fragInf: 0
User: 16842754, Trigger id: 3145734, Table id: 20, Error code: 4238, 
 H'01010002 H'00000006 H'00000001 H'00000014 H'ffffff00 H'00300006 H'0000108e
 H'000000d3 H'00000002

...

--------------- Signal ----------------
r.bn: 249 "DBTUP", r.proc: 2, r.sigId: 2086494 gsn: 513 "DROP_TRIG_REQ" prio: 1
s.bn: 257 "SUMA", s.proc: 2, s.sigId: 2086490 length: 7 trace: 0 #sec: 0 fragInf: 0
User: 16842752, Trigger id: 3145734, Table id: 20, 
 H'01010000 H'00000006 H'00000001 H'00000014 H'ffffff00 H'00300006 H'80000309

...

--------------- Signal ----------------
r.bn: 250 "DBDICT", r.proc: 2, r.sigId: 2086411 gsn: 204 "DROP_TAB_CONF" prio: 1
s.bn: 246 "DBDIH", s.proc: 2, s.sigId: 2086408 length: 3 trace: 0 #sec: 0 fragInf: 0
 senderRef: f60002 senderData: 5826 TableId: 20
--------------- Signal ----------------

...

--------------- Signal ----------------
r.bn: 250 "DBDICT", r.proc: 2, r.sigId: 2086362 gsn: 204 "DROP_TAB_CONF" prio: 1
s.bn: 249 "DBTUP", s.proc: 2, s.sigId: 2086361 length: 3 trace: 0 #sec: 0 fragInf: 0
 senderRef: f90002 senderData: 5826 TableId: 20

^ triggers dropped here...

How to repeat:
.
[7 Jul 2006 11:08] Tomas Ulin
hmm, this race was already taken care of, the real issue was another:

Suma is notified of drop on FSCLOSECONF below... so it hit an assertion on triggerId check

void
Suma::Table::runDropTrigger(Signal* signal,
				       Uint32 triggerId,
				       Suma &suma)
{
  jam();
  Uint32 type = (triggerId >> 16) & 0x3;

  suma.suma_ndbrequire(type < 3);
  suma.suma_ndbrequire(m_triggerIds[type] == triggerId);

--------------- Signal ----------------
r.bn: 257 "SUMA", r.proc: 2, r.sigId: 2086499 gsn: 515 "DROP_TRIG_REF" prio: 1
s.bn: 249 "DBTUP", s.proc: 2, s.sigId: 2086494 length: 9 trace: 0 #sec: 0 fragInf: 0
User: 16842754, Trigger id: 3145734, Table id: 20, Error code: 4238, 
 H'01010002 H'00000006 H'00000001 H'00000014 H'ffffff00 H'00300006 H'0000108e
 H'000000d3 H'00000002
--------------- Signal ----------------
r.bn: 253 "NDBFS", r.proc: 2, r.sigId: 2086498 gsn: 164 "CONTINUEB" prio: 1
s.bn: 253 "NDBFS", s.proc: 2, s.sigId: 2086493 length: 1 trace: 0 #sec: 0 fragInf: 0
 Scanning the memory channel again with no delay
--------------- Signal ----------------
r.bn: 250 "DBDICT", r.proc: 2, r.sigId: 2086497 gsn: 255 "FSCLOSECONF" prio: 1
s.bn: 253 "NDBFS", s.proc: 2, s.sigId: 2086493 length: 1 trace: 0 #sec: 0 fragInf: 0
 UserPointer: 0
--------------- Signal ----------------
r.bn: 249 "DBTUP", r.proc: 2, r.sigId: 2086496 gsn: 513 "DROP_TRIG_REQ" prio: 1
s.bn: 257 "SUMA", s.proc: 2, s.sigId: 2086490 length: 7 trace: 0 #sec: 0 fragInf: 0
User: 16842752, Trigger id: 3276806, Table id: 20, 
 H'01010000 H'00000006 H'00000001 H'00000014 H'ffffff00 H'00320006 H'80020309
--------------- Signal ----------------
r.bn: 249 "DBTUP", r.proc: 2, r.sigId: 2086495 gsn: 513 "DROP_TRIG_REQ" prio: 1
s.bn: 257 "SUMA", s.proc: 2, s.sigId: 2086490 length: 7 trace: 0 #sec: 0 fragInf: 0
User: 16842752, Trigger id: 3211270, Table id: 20, 
 H'01010000 H'00000006 H'00000001 H'00000014 H'ffffff00 H'00310006 H'80010309
--------------- Signal ----------------
r.bn: 249 "DBTUP", r.proc: 2, r.sigId: 2086494 gsn: 513 "DROP_TRIG_REQ" prio: 1
s.bn: 257 "SUMA", s.proc: 2, s.sigId: 2086490 length: 7 trace: 0 #sec: 0 fragInf: 0
User: 16842752, Trigger id: 3145734, Table id: 20, 
 H'01010000 H'00000006 H'00000001 H'00000014 H'ffffff00 H'00300006 H'80000309
[7 Jul 2006 14:00] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/8909
[7 Jul 2006 14:07] Tomas Ulin
pushed to 5.1.12
[8 Jul 2006 7:43] Jon Stephens
Documented fix in 5.1.12 changelog.