RONDB-956: Extended Rate limits and Quota test cases, more debugging

Author: mikaelronstrom

mysql-test/suite/ndb_quota/ndb_quota_commands.result

@@ -13,7 +13,7 @@ InMemorySize = 2 MByte
 DiskSpaceSize = 0 GByte
 RatePerSec = 500
 MaxTransactionSize = 4
-MaxParallelTransactions = 4
+MaxParallelTransactions = 3
 MaxParallelComplexQueries = 0
 Database Quotas for test2
 databaseId = 14
@@ -50,7 +50,7 @@ Database Quotas for test
   DiskSpaceSize = 0 GByte
   RatePerSec = 500
   MaxTransactionSize = 4
-  MaxParallelTransactions = 4
+  MaxParallelTransactions = 3
   MaxParallelComplexQueries = 0
 
 Database Quotas for test2
@@ -108,10 +108,10 @@ b26 CHAR(255) NULL,
 b27 CHAR(255) NULL,
 b28 VARCHAR(20000) NULL
 ) engine ndb character set latin1;
-CREATE TABLE t2 (a int not null primary key) engine ndb;
-INSERT INTO t2 VALUES (1),(2),(3),(4),(5);
+CREATE TABLE t2 (a int not null primary key, b int) engine ndb;
+INSERT INTO t2 VALUES (1,0),(2,0),(3,0),(4,0),(5,0);
 ERROR HY000: Got temporary error 247 'Too many operations in a transaction in database' from NDBCLUSTER
-INSERT INTO t2 VALUES (1),(2),(3);
+INSERT INTO t2 VALUES (1,0),(2,0),(3,0);
 INSERT INTO t1 (pk1,b1,b2,b3,b4,b28) VALUES (0, '0', '0', '0', '0',REPEAT('a', 19000)),(30,'30', '0', '0', '0',REPEAT('a', 19000));
 INSERT INTO t1 (pk1,b1,b2,b3,b4,b28) VALUES (1, '0', '0', '0', '0',REPEAT('a', 19000)),(31,'30', '0', '0', '0',REPEAT('a', 19000));
 INSERT INTO t1 (pk1,b1,b2,b3,b4,b28) VALUES (2, '0', '0', '0', '0',REPEAT('a', 19000)),(32,'30', '0', '0', '0',REPEAT('a', 19000));
@@ -178,7 +178,7 @@ DROP TABLE t2;
 Database Quota Backup command completed
 DATABASE QUOTA DROP successfully executed
 DATABASE QUOTA DROP successfully executed
-Execute DATABASE QUOTA SET test --in-memory-size = 2 --on-disk-size = 0 --rate-per-sec = 500 --max-transaction-size = 4 --max-parallel-transactions = 4 --max-parallel-complex-queries = 0
+Execute DATABASE QUOTA SET test --in-memory-size = 2 --on-disk-size = 0 --rate-per-sec = 5 --max-transaction-size = 100 --max-parallel-transactions = 10 --max-parallel-complex-queries = 0
 DATABASE QUOTA SET successfully executed
 DATABASE QUOTA SET command succeeded for RESTORE
 Execute DATABASE QUOTA SET test2 --in-memory-size = 11 --on-disk-size = 0 --rate-per-sec = 1500 --max-transaction-size = 0 --max-parallel-transactions = 0 --max-parallel-complex-queries = 0

mysql-test/suite/ndb_quota/ndb_quota_commands.test

@@ -60,10 +60,10 @@ CREATE TABLE t1 (
   b28 VARCHAR(20000) NULL
 ) engine ndb character set latin1;
 
-CREATE TABLE t2 (a int not null primary key) engine ndb;
+CREATE TABLE t2 (a int not null primary key, b int) engine ndb;
 --error 1297
-INSERT INTO t2 VALUES (1),(2),(3),(4),(5);
-INSERT INTO t2 VALUES (1),(2),(3);
+INSERT INTO t2 VALUES (1,0),(2,0),(3,0),(4,0),(5,0);
+INSERT INTO t2 VALUES (1,0),(2,0),(3,0);
 
 INSERT INTO t1 (pk1,b1,b2,b3,b4,b28) VALUES (0, '0', '0', '0', '0',REPEAT('a', 19000)),(30,'30', '0', '0', '0',REPEAT('a', 19000));
 INSERT INTO t1 (pk1,b1,b2,b3,b4,b28) VALUES (1, '0', '0', '0', '0',REPEAT('a', 19000)),(31,'30', '0', '0', '0',REPEAT('a', 19000));
@@ -155,8 +155,6 @@ while ($c)
   SELECT * from t2;
   dec $c;
 }
---enable_result_log
---enable_query_log
 
 connect(mysqld2,127.0.0.1,root,,test,$MASTER_MYPORT1);
 connect(mysqld3,127.0.0.1,root,,test,$MASTER_MYPORT1);
@@ -166,30 +164,30 @@ connect(mysqld6,127.0.0.1,root,,test,$MASTER_MYPORT1);
 
 connection default;
 BEGIN;
-INSERT INTO t2 VALUES (4);
+INSERT INTO t2 VALUES (4,0);
 
 connection mysqld2;
 BEGIN;
-INSERT INTO t2 VALUES (5);
+INSERT INTO t2 VALUES (5,0);
 
 connection mysqld3;
 BEGIN;
-INSERT INTO t2 VALUES (6);
+INSERT INTO t2 VALUES (6,0);
 
 connection mysqld4;
 BEGIN;
 --error 1297
-INSERT INTO t2 VALUES (7);
+INSERT INTO t2 VALUES (7,0);
 
 connection mysqld5;
 BEGIN;
 --error 1297
-INSERT INTO t2 VALUES (8);
+INSERT INTO t2 VALUES (8,0);
 
 connection mysqld6;
 BEGIN;
 --error 1297
-INSERT INTO t2 VALUES (9);
+INSERT INTO t2 VALUES (9,0);
 
 connection default;
 COMMIT;
@@ -203,6 +201,56 @@ COMMIT;
 connection default;
 SELECT * FROM t2;
 
+--exec $NDB_MGM -e "DATABASE QUOTA ALTER test --rate-per-sec = 5 --in-memory-size=2 --max-transaction-size=100 --max-parallel-transactions=10"
+
+--error 0,1297
+SELECT * from t2;
+--error 0,1297
+SELECT * from t2;
+--error 0,1297
+UPDATE t2 SET b = 0 where a = 4;
+COMMIT;
+
+connection mysqld2;
+--error 0,1297
+SELECT * from t2;
+--error 0,1297
+UPDATE t2 SET b = 0 where a = 5;
+COMMIT;
+
+connection mysqld3;
+--error 0,1297
+SELECT * from t2;
+--error 0,1297
+UPDATE t2 SET b = 0 where a = 6;
+COMMIT;
+
+connection mysqld4;
+--error 0,1297
+SELECT * from t2;
+--error 0,1297
+UPDATE t2 SET b = 0 where a = 0;
+COMMIT;
+
+connection mysqld5;
+--error 0,1297
+SELECT * from t2;
+--error 0,1297
+UPDATE t2 SET b = 0 where a = 1;
+COMMIT;
+
+connection mysqld6;
+--error 0,1297
+SELECT * from t2;
+--error 0,1297
+UPDATE t2 SET b = 0 where a = 2;
+COMMIT;
+
+--enable_result_log
+--enable_query_log
+
+connection default;
+
 DROP TABLE t1;
 DROP TABLE t2;
 

storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp

@@ -3795,7 +3795,7 @@ void Dblqh::execTAB_COMMITREQ(Signal *signal) {
   NdbMutex_Unlock(&tabptr.p->m_usage_count);
 #endif
   tabptr.p->usageCountR = 0;
-  D(tabptr.i << "Init2 usageCountR = 0");
+  D(tabptr.i << "Init2 usageCountR and W = 0");
   tabptr.p->usageCountW = 0;
   tabptr.p->tableStatus = Tablerec::TABLE_DEFINED;
   DEB_SCHEMA_VERSION(
@@ -4118,7 +4118,8 @@ void Dblqh::dropTab_wait_usage(Signal *signal) {
 
   if (tabPtr.p->usageCountR > 0 || tabPtr.p->usageCountW > 0) {
     jam();
-    D(tabPtr.i << "usageCountR = " << tabPtr.p->usageCountR);
+    D(tabPtr.i << "usageCountR = " << tabPtr.p->usageCountR
+      << "usageCountW = " << tabPtr.p->usageCountW);
 #ifdef DEBUG_USAGE_COUNT
     NdbMutex_Lock(&tabPtr.p->m_usage_count);
     TcConnectionrecPtr tcPtr;
@@ -9384,6 +9385,9 @@ void Dblqh::execLQHKEYREQ(Signal *signal) {
   else
   {
     tabptr.p->usageCountW++;
+    D("++usageCountW[" << tabptr.i << "] = " << tabptr.p->usageCountW
+      << " transid[0x" << hex << tcConnectptr.p->transid[0]
+      << ",0x" << hex << tcConnectptr.p->transid[1] << "]");
   }
 
   if (LqhKeyReq::getNrCopyFlag(Treqinfo) &&
@@ -14099,6 +14103,9 @@ void Dblqh::releaseTcrec(Signal *signal, TcConnectionrecPtr locTcConnectptr) {
     {
       Uint32 pre_usageCountW = tabPtr.p->usageCountW--;
       ndbrequire(pre_usageCountW > 0);
+      D("--usageCountW[" << tabPtr.i << "] = " << tabPtr.p->usageCountW
+        << " transid: 0x" << hex << locTcConnectptr.p->transid[0]
+        << ", 0x" << hex << locTcConnectptr.p->transid[1]);
     }
   }
   locTcConnectptr.p->original_operation = 0xFF;
@@ -33049,7 +33056,7 @@ Dblqh::initTable(Tablerec *tabPtrP)
   tabPtrP->tableStatus = Tablerec::NOT_DEFINED;
   tabPtrP->usageCountR = 0;
   tabPtrP->usageCountW = 0;
-  D(tabptr.i << "Init usageCountR = 0");
+  D(tabptr.i << "Init usageCountR and W = 0");
   tabPtrP->m_addfragptr_i = RNIL;
   tabPtrP->num_fragments_in_array = 0;
   tabPtrP->num_fragments = 0;

storage/ndb/src/kernel/blocks/dbtc/DbtcMain.cpp

@@ -145,6 +145,7 @@
 //#define DEBUG_QUOTA_ABORT 1
 //#define DEBUG_TRACK_EXEC_FLAG 1
 //#define DEBUG_SCAN_MANY 1
+//#define DEBUG_RATE_OVERFLOW 1
 #endif
 
 #define MAX_QUEUE_TIME_MS 60
@@ -162,6 +163,12 @@
 #define DEBUG(x)
 #endif
 
+#ifdef DEBUG_RATE_OVERFLOW
+#define DEB_RATE_OVERFLOW(arglist) do { g_eventLogger->info arglist ; } while (0)
+#else
+#define DEB_RATE_OVERFLOW(arglist) do { } while (0)
+#endif
+
 #ifdef DEBUG_TRACK_EXEC_FLAG
 #define DEB_TRACK_EXEC_FLAG(arglist) do { g_eventLogger->info arglist ; } while (0)
 #else
@@ -6159,11 +6166,6 @@ Dbtc::CommitAckMarker::insert_in_commit_ack_marker_all(Dbtc *tc,
 void Dbtc::execLQHKEYCONF(Signal *signal) {
   const LqhKeyConf *lqhKeyConf =
       CAST_CONSTPTR(LqhKeyConf, signal->getDataPtr());
-#ifdef UNUSED
-  ndbout << "TC: Received LQHKEYCONF"
-         << " transId1=" << lqhKeyConf->transId1
-         << " transId2=" << lqhKeyConf->transId2 << endl;
-#endif /*UNUSED*/
   UintR compare_transid1, compare_transid2;
   BlockReference tlastLqhBlockref;
   UintR tlastLqhConnect;
@@ -6214,6 +6216,14 @@ void Dbtc::execLQHKEYCONF(Signal *signal) {
   apiConnectptr.i = regTcPtr->apiConnect;
   commitAckMarker.i = regTcPtr->commitAckMarker;
 
+  DEB_RATE_QUEUE(("(%u) LQHKEYCONF: tcPtrI: %u, apiPtrI: %u,"
+                  " transid[0x%x,0x%x]",
+                  instance(),
+                  tcConnectptr.i,
+                  regTcPtr->apiConnect,
+                  lqhKeyConf->transId1,
+                  lqhKeyConf->transId2));
+
   OperationState TtcConnectstate = regTcPtr->tcConnectstate;
   if (unlikely(TtcConnectstate != OS_OPERATING))
   {
@@ -6594,6 +6604,14 @@ void Dbtc::lqhKeyConf_checkTransactionState(Signal *signal,
   UintR Tlqhkeyreqrec = apiConnectptr.p->lqhkeyreqrec;
   int TnoOfOutStanding = Tlqhkeyreqrec - Tlqhkeyconfrec;
 
+  DEB_RATE_QUEUE(("(%u) LQHKEYCONF(2): apiPtrI: %u, state: %u,"
+                  " transid[0x%x,0x%x]",
+                  instance(),
+                  apiConnectptr.i,
+                  TapiConnectstate,
+                  apiConnectptr.p->transid[0],
+                  apiConnectptr.p->transid[1]));
+
   switch (TapiConnectstate) {
     case CS_START_COMMITTING:
       if (TnoOfOutStanding == 0) {
@@ -7567,6 +7585,13 @@ void Dbtc::execCOMMITTED(Signal *signal) {
      */
     return;
   }
+  DEB_RATE_QUEUE(("(%u) COMMITTED: tcPtrI: %u, apiPtrI: %u,"
+                  " transid[0x%x,0x%x]",
+                  instance(),
+                  localTcConnectptr.i,
+                  localTcConnectptr.p->apiConnect,
+                  conf->transid1,
+                  conf->transid2));
   UintR Tcounter = localApiConnectptr.p->counter - 1;
   ConnectionState TapiConnectstate = localApiConnectptr.p->apiConnectstate;
   UintR Tdata1 = localApiConnectptr.p->transid[0] - conf->transid1;
@@ -8532,6 +8557,13 @@ void Dbtc::execCOMPLETED(Signal *signal) {
     warningReport(signal, 6, localTcConnectptr.i);
     return;
   }
+  DEB_RATE_QUEUE(("(%u) COMPLETED: tcPtrI: %u, apiPtrI: %u,"
+                  " transid[0x%x,0x%x]",
+                  instance(),
+                  localTcConnectptr.i,
+                  localTcConnectptr.p->apiConnect,
+                  conf->transid1,
+                  conf->transid2));
   bool Tcond1 = (localTcConnectptr.p->tcConnectstate != OS_COMPLETING);
   localApiConnectptr.i = localTcConnectptr.p->apiConnect;
   if (Tcond1) {
@@ -8915,8 +8947,14 @@ void Dbtc::execLQHKEYREF(Signal *signal) {
     warningReport(signal, 25, tcConnectptr.i);
     return;
   }
-  DEB_RATE_QUEUE(("(%u) LQHKEYREF: %u, errCode: %u",
-                  instance(), tcConnectptr.i, errCode));
+  DEB_RATE_QUEUE(("(%u) LQHKEYREF: tcPtrI: %u, apiPtrI: %u, errCode: %u,"
+                  " transid[0x%x,0x%x]",
+    instance(),
+    tcConnectptr.i,
+    tcConnectptr.p->apiConnect,
+    errCode,
+    lqhKeyRef->transId1,
+    lqhKeyRef->transId2));
   {
     /*-----------------------------------------------------------------------
      * WE HAVE TO CHECK THAT THE TRANSACTION IS STILL VALID. FIRST WE CHECK
@@ -9272,6 +9310,12 @@ void Dbtc::execTC_COMMITREQ(Signal *signal) {
     const Uint32 transId2 = regApiPtr->transid[1];
     Uint32 errorCode = 0;
 
+    DEB_RATE_QUEUE(("(%u) TC_COMMITREQ: apiPtrI: %u,"
+                    " transid[0x%x,0x%x]",
+      instance(),
+      apiConnectptr.i,
+      regApiPtr->transid[0],
+      regApiPtr->transid[1]));
     tc_clearbit(regApiPtr->m_flags, ApiConnectRecord::TF_NOT_OUTSTANDING_FLAG);
     regApiPtr->m_flags |= ApiConnectRecord::TF_EXEC_FLAG;
     DEB_TRACK_EXEC_FLAG(("(%u) Set TF_EXEC_FLAG, apiPtrI: %u, line: %u",
@@ -15621,6 +15665,8 @@ void Dbtc::execSCAN_TABREQ(Signal *signal) {
           ndbrequire(m_databaseRecordPool.getPtr(databaseRecordPtr));
           if (databaseRecordPtr.p->m_is_queueing_abort_read) {
             jam();
+            DEB_RATE_OVERFLOW(("(%u) db: %llu, apiPtrI: %u",
+              instance(), databaseRecordPtr.i, apiConnectptr.i));
             releaseSections(handle);
             errCode = ZRATE_OVERFLOW_ERROR;
             goto SCAN_TAB_error;
@@ -15655,6 +15701,8 @@ void Dbtc::execSCAN_TABREQ(Signal *signal) {
           if (databaseRecordPtr.p->m_is_queueing_abort_read) {
             jam();
             releaseSections(handle);
+            DEB_RATE_OVERFLOW(("(%u) db: %llu, transOwnerPtrI: %u",
+              instance(), databaseRecordPtr.i, transOwnerPtr.i));
             errCode = ZRATE_OVERFLOW_ERROR;
             goto SCAN_TAB_error;
           }
@@ -27237,9 +27285,11 @@ bool Dbtc::queue_tckeyreq(Signal *signal,
       char *ai_area = key_area + 4 * key_length;
       copy((Uint32*)ai_area, ai_ptr);
     }
+#ifdef DEBUG_RATE_QUEUE
+    const TcKeyReq * const tcKeyReq = (TcKeyReq *)&signal->theData[0];
     DEB_RATE_QUEUE(("(%u) Queue TCKEYREQ, now: %llu, ptr: %p, apiPtr.i: %u"
               ", sig_len: %u, sections: %u, key_len: %u, ai_len: %u"
-              ", key[%u,%u,%u,%u,%u,%u]",
+              ", key[%u,%u,%u,%u,%u,%u], transid[0x%x,0x%x)]",
               instance(),
               now.getUint64(),
               queue_record,
@@ -27253,7 +27303,10 @@ bool Dbtc::queue_tckeyreq(Signal *signal,
               key_length > 2 ? ((Uint32*)key_area)[2] : 0xFFFF,
               key_length > 3 ? ((Uint32*)key_area)[3] : 0xFFFF,
               key_length > 4 ? ((Uint32*)key_area)[4] : 0xFFFF,
-              key_length > 5 ? ((Uint32*)key_area)[5] : 0xFFFF ));
+              key_length > 5 ? ((Uint32*)key_area)[5] : 0xFFFF,
+              tcKeyReq->transId1,
+              tcKeyReq->transId2));
+#endif
   }
 
   insert_queue_record_tc(transPtr.p, queue_record);
@@ -27661,7 +27714,8 @@ void Dbtc::debug_db_no_queue(DatabaseRecordPtr databaseRecordPtr,
     DEB_RATE_QUEUE(("(%u):%u TCKEYREQ no queueing, passQueueFlag: %u,"
               " DB:first_queue: %p, start_queued: %u, all_queued: %u,"
               " tcPtrI: %u, Trans:first_queue: %p,"
-              " startTrans: %u, op_type: %s, tableId: %u",
+              " startTrans: %u, op_type: %s, tableId: %u"
+              ", transid[0x%x,0x%x]",
               instance(),
               databaseRecordPtr.p->m_database_id,
               passQueueingFlag,
@@ -27679,6 +27733,8 @@ void Dbtc::debug_db_no_queue(DatabaseRecordPtr databaseRecordPtr,
                 opType == ZREAD_EX ? "ReadEx" :
                 opType == ZUNLOCK ? "Unlock" :
                 opType == ZREFRESH ? "Refresh" : "Other",
-              tableId));
+              tableId,
+              regApiPtr->transid[0],
+              regApiPtr->transid[1]));
   }
 }