Uploaded image for project: 'Percona XtraDB Cluster'
  1. Percona XtraDB Cluster
  2. PXC-3243

Modify the BF-abort process to propagate and abort and retry the Stored Procedure instead of the statement

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Done
    • Priority: Medium
    • Resolution: Fixed
    • Affects Version/s: 5.7.28-31.41.2, 5.6.48-28.40
    • Fix Version/s: 5.6.49-28.42, 5.7.31-31.45
    • Component/s: None
    • Labels:
      None

      Description

      This is a variant of PXC-2684PXC-2684 did not fix all the code-paths.

      This is the log from the code path that was fixed in PXC-2684

      2020-05-10T08:35:49.428566Z 30 [Note] WSREP: Generating new auto-inc next-value (Current: 371966634, New: 371966635)
      2020-05-10T08:35:49.428648Z 2 [Note] WSREP: wsrep: applying write-set (100120)
      2020-05-10T08:35:49.428713Z 30 [Note] WSREP: Generating new auto-inc next-value (Current: 371976082, New: 371976083)
      2020-05-10T08:35:49.428869Z 30 [Note] WSREP: Generating new auto-inc next-value (Current: 372366659, New: 372366660)
      2020-05-10T08:35:49.428972Z 2 [Note] WSREP: --------- CONFLICT DETECTED --------
      2020-05-10T08:35:49.429025Z 2 [Note] WSREP: cluster conflict due to high priority abort for threads:2020-05-10T08:35:49.429055Z 2 [Note] WSREP: Winning thread:
         THD: 2, mode: applier, state: executing, conflict: no conflict, seqno: 100120
         SQL: (null)2020-05-10T08:35:49.429074Z 2 [Note] WSREP: Victim thread:
         THD: 30, mode: local, state: executing, conflict: no conflict, seqno: -1
         SQL: INSERT INTO t2 VALUES(pk2c_ordercol, pk2c_pk2)2020-05-10T08:35:49.429089Z 2 [Note] WSREP: BF thread 2 (with write-set: 100120) aborting Victim thread 30 with transaction (101969)
      2020-05-10T08:35:49.429107Z 2 [Note] WSREP: Aborting query: INSERT INTO t2 VALUES(pk2c_ordercol, pk2c_pk2)
      2020-05-10T08:35:49.429122Z 2 [Note] WSREP: Killing Transaction (101969) in QUERY_EXEC state
      2020-05-10T08:35:49.429135Z 2 [Note] WSREP: kill query for: 30
      2020-05-10T08:35:49.429228Z 30 [Note] WSREP: Generating new auto-inc next-value (Current: 372589031, New: 372589032)
      2020-05-10T08:35:49.429927Z 30 [Note] WSREP: Initiating rollback. Transaction (query: call p1()) triggered by thread 30 was BF aborted
      2020-05-10T08:35:50.280798Z 2 [Note] WSREP: wsrep: updating row for write-set (100120)
      2020-05-10T08:35:50.280980Z 2 [Note] WSREP: wsrep: applied write set (100120)
      2020-05-10T08:35:50.281026Z 2 [Note] WSREP: wsrep: committing write set (100120)
      2020-05-10T08:35:50.281971Z 2 [Note] WSREP: wsrep: committed write set (100120)
      2020-05-10T08:35:50.282431Z 30 [Note] WSREP: abort in exec query state, avoiding autocommit
      2020-05-10T08:35:50.282460Z 30 [Note] WSREP: Brute-Force Abort, thd: 30 is_AC: 1, retry: 1 - 1 SQL: call p1()
      2020-05-10T08:35:50.282473Z 30 [Note] WSREP: Release retry query buffer conflict-state NO_CONFLICT sent 0 kill 0 errno 1213 SQL call p1()
      2020-05-10T08:35:50.283024Z 30 [Note] WSREP: set_query_id(), assigned new next trx id: 347743
      2020-05-10T08:35:50.680010Z 4 [Note] WSREP: wsrep: applying write-set (100121)
      

      Note that the aborted thread (thread 30) kills the transaction and it gets rolled back, and the threads continue on.

       

      Now, in the logs below, the thread is BF-aborted, but the thread continues on, is NOT aborted, and we get to the point where the thread hangs due to the deadlock described in PXC-2684.

      2020-05-10T08:35:53.765924Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 327852748, New: 327852749)
      2020-05-10T08:35:53.766086Z 4 [Note] WSREP: wsrep: applying write-set (100124)
      2020-05-10T08:35:53.766193Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 328241996, New: 328241997)
      2020-05-10T08:35:53.766251Z 4 [Note] WSREP: --------- CONFLICT DETECTED --------
      2020-05-10T08:35:53.766347Z 4 [Note] WSREP: cluster conflict due to high priority abort for threads:2020-05-10T08:35:53.766358Z 4 [Note] WSREP: Winning thread:
         THD: 4, mode: applier, state: executing, conflict: no conflict, seqno: 100124
         SQL: (null)2020-05-10T08:35:53.766362Z 4 [Note] WSREP: Victim thread:
         THD: 31, mode: local, state: executing, conflict: no conflict, seqno: -1
         SQL: INSERT INTO t2 VALUES(pk2c_ordercol, pk2c_pk2)2020-05-10T08:35:53.766366Z 4 [Note] WSREP: BF thread 4 (with write-set: 100124) aborting Victim thread 31 with transaction (101988)
      2020-05-10T08:35:53.766376Z 4 [Note] WSREP: Aborting query: INSERT INTO t2 VALUES(pk2c_ordercol, pk2c_pk2)
      2020-05-10T08:35:53.766380Z 4 [Note] WSREP: Killing Transaction (101988) in QUERY_EXEC state
      2020-05-10T08:35:53.766383Z 4 [Note] WSREP: kill query for: 31
      2020-05-10T08:35:53.769709Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 328674295, New: 328674296)
      2020-05-10T08:35:53.769919Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 329025090, New: 329025091)
      2020-05-10T08:35:53.770105Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 329199935, New: 329199936)
      ... many other lines ...
      2020-05-10T08:35:55.432878Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 2146415954, New: 2146415955)
      2020-05-10T08:35:55.433057Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 2146505782, New: 2146505783)
      2020-05-10T08:35:55.433237Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 2146906266, New: 2146906267)
      2020-05-10T08:35:55.433416Z 31 [Note] WSREP: Generating new auto-inc next-value (Current: 2147014767, New: 2147014768)
      2020-05-10T08:35:55.433969Z 31 [Note] WSREP: wsrep: replicating commit (-1)
      2020-05-10T08:35:55.436578Z 31 [Note] WSREP: wsrep: initiating replication for write set (-1)
      2020-05-10T08:35:55.444374Z 31 [Note] WSREP: wsrep: write set replicated (100126)
      2020-05-10T08:35:55.444464Z 31 [Note] WSREP: wsrep: initiating pre-commit for write set (100126)
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              kenn.takara Kenn Takara
              Reporter:
              kenn.takara Kenn Takara
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - 0 minutes
                  0m
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 5 weeks, 2 hours, 31 minutes
                  5w 2h 31m

                    Smart Checklist