crash_gen.py 66.6 KB
Newer Older
1
#!/usr/bin/python3.7
S
Steven Li 已提交
2 3 4 5 6 7 8 9 10 11 12 13
###################################################################
#           Copyright (c) 2016 by TAOS Technologies, Inc.
#                     All rights reserved.
#
#  This file is proprietary and confidential to TAOS Technologies.
#  No part of this file may be reproduced, stored, transmitted,
#  disclosed or used in any form or by any means other than as
#  expressly provided by the written permission from Jianhui Tao
#
###################################################################

# -*- coding: utf-8 -*-
14 15
from __future__ import annotations  # For type hinting before definition, ref: https://stackoverflow.com/questions/33533148/how-do-i-specify-that-the-return-type-of-a-method-is-the-same-as-the-class-itsel    

S
Steven Li 已提交
16
import sys
17
import os
18
import traceback
19 20 21 22
# Require Python 3
if sys.version_info[0] < 3:
    raise Exception("Must be using Python 3")

S
Steven Li 已提交
23
import getopt
24
import argparse
25
import copy
S
Steven Li 已提交
26 27 28

import threading
import random
29
import time
S
Steven Li 已提交
30
import logging
31
import datetime
32
import textwrap
33 34
import requests
from requests.auth import HTTPBasicAuth
S
Steven Li 已提交
35

36
from typing import List
37
from typing import Dict
38
from typing import Set
39

S
Steven Li 已提交
40 41 42 43 44
from util.log import *
from util.dnodes import *
from util.cases import *
from util.sql import *

45
import crash_gen
S
Steven Li 已提交
46 47
import taos

48
# Global variables, tried to keep a small number. 
49 50 51 52

# Command-line/Environment Configurations, will set a bit later
# ConfigNameSpace = argparse.Namespace
gConfig = argparse.Namespace() # Dummy value, will be replaced later
53
logger = None
S
Steven Li 已提交
54

55 56
def runThread(wt: WorkerThread):    
    wt.run()
57

58 59 60 61 62 63 64 65
class CrashGenError(Exception):
    def __init__(self, msg=None, errno=None):
        self.msg = msg    
        self.errno = errno
    
    def __str__(self):
        return self.msg

S
Steven Li 已提交
66
class WorkerThread:
67
    def __init__(self, pool: ThreadPool, tid, 
68 69 70 71
            tc: ThreadCoordinator,
            # te: TaskExecutor,
            ): # note: main thread context!
        # self._curStep = -1 
72
        self._pool = pool
73
        self._tid = tid        
74
        self._tc = tc # type: ThreadCoordinator
S
Steven Li 已提交
75
        # self.threadIdent = threading.get_ident()
76 77
        self._thread = threading.Thread(target=runThread, args=(self,))
        self._stepGate = threading.Event()
S
Steven Li 已提交
78

79
        # Let us have a DB connection of our own
80
        if ( gConfig.per_thread_db_connection ): # type: ignore
81 82
            # print("connector_type = {}".format(gConfig.connector_type))
            self._dbConn = DbConn.createNative() if (gConfig.connector_type == 'native') else DbConn.createRest()
83

84 85
        self._dbInUse = False # if "use db" was executed already

86
    def logDebug(self, msg):
S
Steven Li 已提交
87
        logger.debug("    TRD[{}] {}".format(self._tid, msg))
88 89

    def logInfo(self, msg):
S
Steven Li 已提交
90
        logger.info("    TRD[{}] {}".format(self._tid, msg))
91

92 93 94 95 96 97 98 99
    def dbInUse(self):
        return self._dbInUse

    def useDb(self):
        if ( not self._dbInUse ):
            self.execSql("use db")
        self._dbInUse = True

100 101
    def getTaskExecutor(self):
        return self._tc.getTaskExecutor()     
102

S
Steven Li 已提交
103
    def start(self):
104
        self._thread.start()  # AFTER the thread is recorded
S
Steven Li 已提交
105

106
    def run(self): 
S
Steven Li 已提交
107
        # initialization after thread starts, in the thread context
108
        # self.isSleeping = False
109 110
        logger.info("Starting to run thread: {}".format(self._tid))

111
        if ( gConfig.per_thread_db_connection ): # type: ignore
112
            logger.debug("Worker thread openning database connection")
113
            self._dbConn.open()
S
Steven Li 已提交
114

115 116
        self._doTaskLoop()       
        
117
        # clean up
118
        if ( gConfig.per_thread_db_connection ): # type: ignore 
119
            self._dbConn.close()
120

121 122 123
    def _doTaskLoop(self) :
        # while self._curStep < self._pool.maxSteps:
        # tc = ThreadCoordinator(None)
124 125 126
        while True:  
            tc = self._tc # Thread Coordinator, the overall master            
            tc.crossStepBarrier()  # shared barrier first, INCLUDING the last one
S
Steven Li 已提交
127
            logger.debug("[TRD] Worker thread [{}] exited barrier...".format(self._tid))
128
            self.crossStepGate()   # then per-thread gate, after being tapped
S
Steven Li 已提交
129
            logger.debug("[TRD] Worker thread [{}] exited step gate...".format(self._tid))
130
            if not self._tc.isRunning():
S
Steven Li 已提交
131
                logger.debug("[TRD] Thread Coordinator not running any more, worker thread now stopping...")
132 133
                break

134
            # Fetch a task from the Thread Coordinator
S
Steven Li 已提交
135
            logger.debug("[TRD] Worker thread [{}] about to fetch task".format(self._tid))
136
            task = tc.fetchTask()
137 138

            # Execute such a task
S
Steven Li 已提交
139
            logger.debug("[TRD] Worker thread [{}] about to execute task: {}".format(self._tid, task.__class__.__name__))
140
            task.execute(self)
141
            tc.saveExecutedTask(task)
S
Steven Li 已提交
142
            logger.debug("[TRD] Worker thread [{}] finished executing task".format(self._tid))
143 144

            self._dbInUse = False # there may be changes between steps
145
  
S
Steven Li 已提交
146
    def verifyThreadSelf(self): # ensure we are called by this own thread
147
        if ( threading.get_ident() != self._thread.ident ): 
S
Steven Li 已提交
148 149 150 151 152 153 154
            raise RuntimeError("Unexpectly called from other threads")

    def verifyThreadMain(self): # ensure we are called by the main thread
        if ( threading.get_ident() != threading.main_thread().ident ): 
            raise RuntimeError("Unexpectly called from other threads")

    def verifyThreadAlive(self):
155
        if ( not self._thread.is_alive() ):
S
Steven Li 已提交
156 157
            raise RuntimeError("Unexpected dead thread")

158
    # A gate is different from a barrier in that a thread needs to be "tapped"
S
Steven Li 已提交
159 160 161 162
    def crossStepGate(self):
        self.verifyThreadAlive()
        self.verifyThreadSelf() # only allowed by ourselves
        
163
        # Wait again at the "gate", waiting to be "tapped"
S
Steven Li 已提交
164
        logger.debug("[TRD] Worker thread {} about to cross the step gate".format(self._tid))
165 166
        self._stepGate.wait() 
        self._stepGate.clear()
S
Steven Li 已提交
167
        
168
        # self._curStep += 1  # off to a new step...
S
Steven Li 已提交
169 170 171 172

    def tapStepGate(self): # give it a tap, release the thread waiting there
        self.verifyThreadAlive()
        self.verifyThreadMain() # only allowed for main thread
173
 
S
Steven Li 已提交
174
        logger.debug("[TRD] Tapping worker thread {}".format(self._tid))
175 176
        self._stepGate.set() # wake up!        
        time.sleep(0) # let the released thread run a bit
177

178
    def execSql(self, sql): # TODO: expose DbConn directly
179 180 181
        if ( gConfig.per_thread_db_connection ):
            return self._dbConn.execute(sql)            
        else:
182
            return self._tc.getDbManager().getDbConn().execute(sql)
183

184 185 186 187 188 189 190 191 192 193 194 195
    def querySql(self, sql): # TODO: expose DbConn directly
        if ( gConfig.per_thread_db_connection ):
            return self._dbConn.query(sql)            
        else:
            return self._tc.getDbManager().getDbConn().query(sql)

    def getQueryResult(self):
        if ( gConfig.per_thread_db_connection ):
            return self._dbConn.getQueryResult()       
        else:
            return self._tc.getDbManager().getDbConn().getQueryResult()

196 197 198 199
    def getDbConn(self):
        if ( gConfig.per_thread_db_connection ):
            return self._dbConn     
        else:
200
            return self._tc.getDbManager().getDbConn()
201

202 203 204 205 206
    # def querySql(self, sql): # not "execute", since we are out side the DB context
    #     if ( gConfig.per_thread_db_connection ):
    #         return self._dbConn.query(sql)            
    #     else:
    #         return self._tc.getDbState().getDbConn().query(sql)
207

208
class ThreadCoordinator:
209
    def __init__(self, pool: ThreadPool, dbManager):
210 211
        self._curStep = -1 # first step is 0
        self._pool = pool
212
        # self._wd = wd
213
        self._te = None # prepare for every new step
214
        self._dbManager = dbManager
215 216
        self._executedTasks: List[Task] = [] # in a given step
        self._lock = threading.RLock() # sync access for a few things
S
Steven Li 已提交
217

218
        self._stepBarrier = threading.Barrier(self._pool.numThreads + 1) # one barrier for all threads
219
        self._execStats = ExecutionStats()
S
Steven Li 已提交
220

221 222 223
    def getTaskExecutor(self):
        return self._te

224 225
    def getDbManager(self) -> DbManager :
        return self._dbManager
226

227 228 229
    def crossStepBarrier(self):
        self._stepBarrier.wait()

230 231
    def run(self):              
        self._pool.createAndStartThreads(self)
S
Steven Li 已提交
232 233

        # Coordinate all threads step by step
234 235
        self._curStep = -1 # not started yet
        maxSteps = gConfig.max_steps # type: ignore
236 237 238
        self._execStats.startExec() # start the stop watch
        failed = False
        while(self._curStep < maxSteps-1 and not failed):  # maxStep==10, last curStep should be 9
S
Steven Li 已提交
239 240 241
            if not gConfig.debug: 
                print(".", end="", flush=True) # print this only if we are not in debug mode
            logger.debug("[TRD] Main thread going to sleep")
242

243
            # Now ready to enter a step
244 245 246 247
            self.crossStepBarrier() # let other threads go past the pool barrier, but wait at the thread gate
            self._stepBarrier.reset() # Other worker threads should now be at the "gate"            

            # At this point, all threads should be pass the overall "barrier" and before the per-thread "gate"
248
            try:
249 250 251 252
                sm = self._dbManager.getStateMachine()
                logger.debug("[STT] starting transitions")
                sm.transition(self._executedTasks) # at end of step, transiton the DB state
                logger.debug("[STT] transition ended")
253
                # Due to limitation (or maybe not) of the Python library, we cannot share connections across threads
254 255 256 257 258 259
                if sm.hasDatabase() :
                    for t in self._pool.threadList:
                        logger.debug("[DB] use db for all worker threads")
                        t.useDb()
                        # t.execSql("use db") # main thread executing "use db" on behalf of every worker thread

260 261 262 263 264 265 266 267 268 269 270 271 272
            except taos.error.ProgrammingError as err:
                if ( err.msg == 'network unavailable' ): # broken DB connection
                    logger.info("DB connection broken, execution failed")
                    traceback.print_stack()
                    failed = True
                    self._te = None # Not running any more
                    self._execStats.registerFailure("Broken DB Connection")
                    # continue # don't do that, need to tap all threads at end, and maybe signal them to stop
                else:
                    raise 
            finally:
                pass
            
273
            self.resetExecutedTasks() # clear the tasks after we are done
274 275

            # Get ready for next step
S
Steven Li 已提交
276
            logger.debug("<-- Step {} finished".format(self._curStep))
277
            self._curStep += 1 # we are about to get into next step. TODO: race condition here!                
278
            logger.debug("\r\n\n--> Step {} starts with main thread waking up".format(self._curStep)) # Now not all threads had time to go to sleep
279

280
            # A new TE for the new step
281 282
            if not failed: # only if not failed
                self._te = TaskExecutor(self._curStep)
283

S
Steven Li 已提交
284
            logger.debug("[TRD] Main thread waking up at step {}, tapping worker threads".format(self._curStep)) # Now not all threads had time to go to sleep            
S
Steven Li 已提交
285 286
            self.tapAllThreads()

287
        logger.debug("Main thread ready to finish up...")
288 289 290 291 292 293 294 295
        if not failed: # only in regular situations
            self.crossStepBarrier() # Cross it one last time, after all threads finish
            self._stepBarrier.reset()
            logger.debug("Main thread in exclusive zone...")
            self._te = None # No more executor, time to end
            logger.debug("Main thread tapping all threads one last time...")
            self.tapAllThreads() # Let the threads run one last time

296 297
        logger.debug("Main thread joining all threads")
        self._pool.joinAll() # Get all threads to finish
298
        logger.info("\nAll worker threads finished")
299 300 301
        self._execStats.endExec()

    def logStats(self):
302
        self._execStats.logStats()
S
Steven Li 已提交
303 304 305

    def tapAllThreads(self): # in a deterministic manner
        wakeSeq = []
306
        for i in range(self._pool.numThreads): # generate a random sequence
S
Steven Li 已提交
307 308 309 310
            if Dice.throw(2) == 1 :
                wakeSeq.append(i)
            else:
                wakeSeq.insert(0, i)
311
        logger.debug("[TRD] Main thread waking up worker threads: {}".format(str(wakeSeq)))
312
        # TODO: set dice seed to a deterministic value
S
Steven Li 已提交
313
        for i in wakeSeq:
314
            self._pool.threadList[i].tapStepGate() # TODO: maybe a bit too deep?!
S
Steven Li 已提交
315 316
            time.sleep(0) # yield

317 318 319 320 321 322
    def isRunning(self):
        return self._te != None

    def fetchTask(self) -> Task :
        if ( not self.isRunning() ): # no task
            raise RuntimeError("Cannot fetch task when not running")
323 324
        # return self._wd.pickTask()
        # Alternatively, let's ask the DbState for the appropriate task
325 326 327 328 329 330 331
        # dbState = self.getDbState()
        # tasks = dbState.getTasksAtState() # TODO: create every time?
        # nTasks = len(tasks)
        # i = Dice.throw(nTasks)
        # logger.debug(" (dice:{}/{}) ".format(i, nTasks))
        # # return copy.copy(tasks[i]) # Needs a fresh copy, to save execution results, etc.
        # return tasks[i].clone() # TODO: still necessary?
332
        taskType = self.getDbManager().getStateMachine().pickTaskType() # pick a task type for current state
333
        return taskType(self.getDbManager(), self._execStats) # create a task from it
334 335 336

    def resetExecutedTasks(self):
        self._executedTasks = [] # should be under single thread
337 338 339 340

    def saveExecutedTask(self, task):
        with self._lock:
            self._executedTasks.append(task)
341 342

# We define a class to run a number of threads in locking steps.
343
class ThreadPool:
344
    def __init__(self, numThreads, maxSteps):
345 346 347 348
        self.numThreads = numThreads
        self.maxSteps = maxSteps
        # Internal class variables
        self.curStep = 0
349
        self.threadList = [] # type: List[WorkerThread]
350 351
        
    # starting to run all the threads, in locking steps
352
    def createAndStartThreads(self, tc: ThreadCoordinator):
353
        for tid in range(0, self.numThreads): # Create the threads
354
            workerThread = WorkerThread(self, tid, tc)            
355 356 357 358 359 360 361 362
            self.threadList.append(workerThread)
            workerThread.start() # start, but should block immediately before step 0

    def joinAll(self):
        for workerThread in self.threadList:
            logger.debug("Joining thread...")
            workerThread._thread.join()

363 364
# A queue of continguous POSITIVE integers, used by DbManager to generate continuous numbers
# for new table names
S
Steven Li 已提交
365 366
class LinearQueue():
    def __init__(self):
367
        self.firstIndex = 1  # 1st ever element
S
Steven Li 已提交
368
        self.lastIndex = 0
369
        self._lock = threading.RLock() # our functions may call each other
370
        self.inUse = set() # the indexes that are in use right now
S
Steven Li 已提交
371

372 373 374 375 376 377 378 379 380
    def toText(self):
        return "[{}..{}], in use: {}".format(self.firstIndex, self.lastIndex, self.inUse)

    # Push (add new element, largest) to the tail, and mark it in use
    def push(self): 
        with self._lock:
            # if ( self.isEmpty() ): 
            #     self.lastIndex = self.firstIndex 
            #     return self.firstIndex
381 382
            # Otherwise we have something
            self.lastIndex += 1
383 384
            self.allocate(self.lastIndex)
            # self.inUse.add(self.lastIndex) # mark it in use immediately
385
            return self.lastIndex
S
Steven Li 已提交
386 387

    def pop(self):
388
        with self._lock:
389
            if ( self.isEmpty() ): 
390 391 392
                # raise RuntimeError("Cannot pop an empty queue") 
                return False # TODO: None?
            
393
            index = self.firstIndex
394
            if ( index in self.inUse ):
395 396
                return False

397 398 399 400 401 402 403
            self.firstIndex += 1
            return index

    def isEmpty(self):
        return self.firstIndex > self.lastIndex

    def popIfNotEmpty(self):
404
        with self._lock:
405 406 407 408
            if (self.isEmpty()):
                return 0
            return self.pop()

S
Steven Li 已提交
409
    def allocate(self, i):
410
        with self._lock:
411
            # logger.debug("LQ allocating item {}".format(i))
412 413 414 415
            if ( i in self.inUse ):
                raise RuntimeError("Cannot re-use same index in queue: {}".format(i))
            self.inUse.add(i)

S
Steven Li 已提交
416
    def release(self, i):
417
        with self._lock:
418 419
            # logger.debug("LQ releasing item {}".format(i))
            self.inUse.remove(i) # KeyError possible, TODO: why?
420 421 422 423

    def size(self):
        return self.lastIndex + 1 - self.firstIndex

S
Steven Li 已提交
424
    def pickAndAllocate(self):
425 426 427
        if ( self.isEmpty() ):
            return None
        with self._lock:
428 429 430 431
            cnt = 0 # counting the interations
            while True:
                cnt += 1
                if ( cnt > self.size()*10 ): # 10x iteration already
432 433
                    # raise RuntimeError("Failed to allocate LinearQueue element")
                    return None
434 435
                ret = Dice.throwRange(self.firstIndex, self.lastIndex+1)
                if ( not ret in self.inUse ):
436 437 438 439
                    self.allocate(ret)
                    return ret

class DbConn:
440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455 456 457 458 459 460
    TYPE_NATIVE = "native-c"
    TYPE_REST = "rest-api"
    TYPE_INVALID = "invalid"

    @classmethod
    def create(cls, connType):
        if connType == cls.TYPE_NATIVE:
            return DbConnNative()
        elif connType == cls.TYPE_REST:
            return DbConnRest()
        else:
            raise RuntimeError("Unexpected connection type: {}".format(connType))

    @classmethod
    def createNative(cls):
        return cls.create(cls.TYPE_NATIVE)

    @classmethod
    def createRest(cls):
        return cls.create(cls.TYPE_REST)

461 462
    def __init__(self):
        self.isOpen = False
463 464 465
        self._type = self.TYPE_INVALID

    def open(self):
466 467 468
        if ( self.isOpen ):
            raise RuntimeError("Cannot re-open an existing DB connection")

469 470
        # below implemented by child classes
        self.openByType()
471

472
        logger.debug("[DB] data connection opened, type = {}".format(self._type))
473 474 475 476 477
        self.isOpen = True

    def resetDb(self): # reset the whole database, etc.
        if ( not self.isOpen ):
            raise RuntimeError("Cannot reset database until connection is open")
478 479
        # self._tdSql.prepare() # Recreate database, etc.

480
        self.execute('drop database if exists db')
481 482
        logger.debug("Resetting DB, dropped database")
        # self._cursor.execute('create database db')
483
        # self._cursor.execute('use db')
484 485
        # tdSql.execute('show databases')

486 487 488 489 490 491 492 493 494 495 496 497 498 499 500 501 502 503 504 505 506 507 508 509 510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544 545 546 547 548 549 550 551 552 553 554 555 556 557 558 559 560 561 562 563 564 565 566 567 568 569 570 571 572 573 574 575 576 577 578 579 580 581 582 583 584 585 586 587 588 589 590 591 592 593 594 595 596
    def queryScalar(self, sql) -> int :
        return self._queryAny(sql)

    def queryString(self, sql) -> str :
        return self._queryAny(sql)

    def _queryAny(self, sql) : # actual query result as an int
        if ( not self.isOpen ):
            raise RuntimeError("Cannot query database until connection is open")
        nRows = self.query(sql)
        if nRows != 1 :
            raise RuntimeError("Unexpected result for query: {}, rows = {}".format(sql, nRows))
        if self.getResultRows() != 1 or self.getResultCols() != 1:
            raise RuntimeError("Unexpected result set for query: {}".format(sql))
        return self.getQueryResult()[0][0]

    def execute(self, sql):
        raise RuntimeError("Unexpected execution, should be overriden")
    def openByType(self):
        raise RuntimeError("Unexpected execution, should be overriden")
    def getQueryResult(self):
        raise RuntimeError("Unexpected execution, should be overriden")
    def getResultRows(self):
        raise RuntimeError("Unexpected execution, should be overriden")
    def getResultCols(self):
        raise RuntimeError("Unexpected execution, should be overriden")

# Sample: curl -u root:taosdata -d "show databases" localhost:6020/rest/sql
class DbConnRest(DbConn):
    def __init__(self):
        super().__init__()
        self._type = self.TYPE_REST
        self._url = "http://localhost:6020/rest/sql" # fixed for now
        self._result = None

    def openByType(self): # Open connection
        pass # do nothing, always open
        
    def close(self):
        if ( not self.isOpen ):
            raise RuntimeError("Cannot clean up database until connection is open")
        # Do nothing for REST
        logger.debug("[DB] REST Database connection closed")
        self.isOpen = False

    def _doSql(self, sql):
        r = requests.post(self._url, 
            data = sql,
            auth = HTTPBasicAuth('root', 'taosdata'))
        rj = r.json()
        # Sanity check for the "Json Result"
        if (not 'status' in rj):
            raise RuntimeError("No status in REST response")

        if rj['status'] == 'error': # clearly reported error
            if (not 'code' in rj): # error without code
                raise RuntimeError("REST error return without code")            
            errno = rj['code'] # May need to massage this in the future
            # print("Raising programming error with REST return: {}".format(rj))
            raise taos.error.ProgrammingError(rj['desc'], errno) # todo: check existance of 'desc'

        if rj['status'] != 'succ': # better be this
            raise RuntimeError("Unexpected REST return status: {}".format(rj['status']))

        nRows = rj['rows'] if ('rows' in rj) else 0
        self._result = rj        
        return nRows

    def execute(self, sql): 
        if ( not self.isOpen ):
            raise RuntimeError("Cannot execute database commands until connection is open")
        logger.debug("[SQL-REST] Executing SQL: {}".format(sql))
        nRows = self._doSql(sql)
        logger.debug("[SQL-REST] Execution Result, nRows = {}, SQL = {}".format(nRows, sql))
        return nRows

    def query(self, sql) :  # return rows affected
        return self.execute(sql)

    def getQueryResult(self):
        return self._result['data']

    def getResultRows(self):
        print(self._result)
        raise RuntimeError("TBD")
        # return self._tdSql.queryRows

    def getResultCols(self):
        print(self._result)
        raise RuntimeError("TBD")
    
class DbConnNative(DbConn):
    def __init__(self):
        super().__init__()
        self._type = self.TYPE_REST
        self._conn = None 
        self._cursor = None
        
    def openByType(self): # Open connection
        cfgPath = "../../build/test/cfg" 
        self._conn = taos.connect(host="127.0.0.1", config=cfgPath) # TODO: make configurable
        self._cursor = self._conn.cursor()

        # Get the connection/cursor ready
        self._cursor.execute('reset query cache')
        # self._cursor.execute('use db') # do this at the beginning of every step

        # Open connection
        self._tdSql = TDSql()
        self._tdSql.init(self._cursor)
        
597 598 599 600
    def close(self):
        if ( not self.isOpen ):
            raise RuntimeError("Cannot clean up database until connection is open")
        self._tdSql.close()
601
        logger.debug("[DB] Database connection closed")
602
        self.isOpen = False
S
Steven Li 已提交
603

604
    def execute(self, sql): 
605
        if ( not self.isOpen ):
606
            raise RuntimeError("Cannot execute database commands until connection is open")
607 608 609 610
        logger.debug("[SQL] Executing SQL: {}".format(sql))
        nRows = self._tdSql.execute(sql)
        logger.debug("[SQL] Execution Result, nRows = {}, SQL = {}".format(nRows, sql))
        return nRows
S
Steven Li 已提交
611

612
    def query(self, sql) :  # return rows affected
613 614
        if ( not self.isOpen ):
            raise RuntimeError("Cannot query database until connection is open")
615 616
        logger.debug("[SQL] Executing SQL: {}".format(sql))
        nRows = self._tdSql.query(sql)
617
        logger.debug("[SQL] Query Result, nRows = {}, SQL = {}".format(nRows, sql))
618
        return nRows
619
        # results are in: return self._tdSql.queryResult
620

621 622 623
    def getQueryResult(self):
        return self._tdSql.queryResult

624 625
    def getResultRows(self):
        return self._tdSql.queryRows
626

627 628
    def getResultCols(self):
        return self._tdSql.queryCols
629 630 631

    
class AnyState:
632
    STATE_INVALID    = -1
633 634 635 636
    STATE_EMPTY      = 0  # nothing there, no even a DB
    STATE_DB_ONLY    = 1  # we have a DB, but nothing else
    STATE_TABLE_ONLY = 2  # we have a table, but totally empty
    STATE_HAS_DATA   = 3  # we have some data in the table
637 638 639 640 641
    _stateNames = ["Invalid", "Empty", "DB_Only", "Table_Only", "Has_Data"]

    STATE_VAL_IDX = 0
    CAN_CREATE_DB = 1
    CAN_DROP_DB = 2
642 643
    CAN_CREATE_FIXED_SUPER_TABLE = 3
    CAN_DROP_FIXED_SUPER_TABLE = 4
644 645 646 647 648 649 650
    CAN_ADD_DATA = 5
    CAN_READ_DATA = 6

    def __init__(self):
        self._info = self.getInfo()

    def __str__(self):
S
Steven Li 已提交
651
        return self._stateNames[self._info[self.STATE_VAL_IDX] + 1] # -1 hack to accomodate the STATE_INVALID case
652 653 654 655

    def getInfo(self):
        raise RuntimeError("Must be overriden by child classes")

S
Steven Li 已提交
656 657 658 659 660 661 662 663
    def equals(self, other):
        if isinstance(other, int):
            return self.getValIndex() == other
        elif isinstance(other, AnyState):
            return self.getValIndex() == other.getValIndex()
        else:
            raise RuntimeError("Unexpected comparison, type = {}".format(type(other)))

664 665 666
    def verifyTasksToState(self, tasks, newState):
        raise RuntimeError("Must be overriden by child classes")

S
Steven Li 已提交
667 668 669
    def getValIndex(self):
        return self._info[self.STATE_VAL_IDX]

670 671 672 673 674 675
    def getValue(self):
        return self._info[self.STATE_VAL_IDX]
    def canCreateDb(self):
        return self._info[self.CAN_CREATE_DB]
    def canDropDb(self):
        return self._info[self.CAN_DROP_DB]
676 677 678 679
    def canCreateFixedSuperTable(self):
        return self._info[self.CAN_CREATE_FIXED_SUPER_TABLE]
    def canDropFixedSuperTable(self):
        return self._info[self.CAN_DROP_FIXED_SUPER_TABLE]
680 681 682 683 684 685 686 687 688 689 690
    def canAddData(self):
        return self._info[self.CAN_ADD_DATA]
    def canReadData(self):
        return self._info[self.CAN_READ_DATA]

    def assertAtMostOneSuccess(self, tasks, cls):
        sCnt = 0
        for task in tasks :
            if not isinstance(task, cls):
                continue
            if task.isSuccess():
S
Steven Li 已提交
691
                # task.logDebug("Task success found")
692 693 694 695 696 697 698 699 700 701 702 703 704 705 706 707 708 709 710 711 712 713 714 715 716 717 718 719 720 721 722 723 724 725 726
                sCnt += 1
                if ( sCnt >= 2 ):
                    raise RuntimeError("Unexpected more than 1 success with task: {}".format(cls))

    def assertIfExistThenSuccess(self, tasks, cls):
        sCnt = 0
        exists = False
        for task in tasks :
            if not isinstance(task, cls):
                continue
            exists = True # we have a valid instance
            if task.isSuccess():
                sCnt += 1
        if ( exists and sCnt <= 0 ):
            raise RuntimeError("Unexpected zero success for task: {}".format(cls))

    def assertNoTask(self, tasks, cls):
        for task in tasks :
            if isinstance(task, cls):
                raise CrashGenError("This task: {}, is not expected to be present, given the success/failure of others".format(cls.__name__))

    def assertNoSuccess(self, tasks, cls):
        for task in tasks :
            if isinstance(task, cls):
                if task.isSuccess():
                    raise RuntimeError("Unexpected successful task: {}".format(cls))

    def hasSuccess(self, tasks, cls):
        for task in tasks :
            if not isinstance(task, cls):
                continue
            if task.isSuccess():
                return True
        return False

S
Steven Li 已提交
727 728 729 730 731 732
    def hasTask(self, tasks, cls):
        for task in tasks :
            if isinstance(task, cls):
                return True
        return False

733 734 735 736 737 738 739 740 741 742 743 744 745 746 747 748 749 750 751 752
class StateInvalid(AnyState):
    def getInfo(self):
        return [
            self.STATE_INVALID,
            False, False, # can create/drop Db
            False, False, # can create/drop fixed table
            False, False, # can insert/read data with fixed table
        ]

    # def verifyTasksToState(self, tasks, newState):

class StateEmpty(AnyState):
    def getInfo(self):
        return [
            self.STATE_EMPTY,
            True, False, # can create/drop Db
            False, False, # can create/drop fixed table
            False, False, # can insert/read data with fixed table
        ]

S
Steven Li 已提交
753
    def verifyTasksToState(self, tasks, newState): 
754 755 756
        if ( self.hasSuccess(tasks, TaskCreateDb) ): # at EMPTY, if there's succes in creating DB
            if ( not self.hasTask(tasks, TaskDropDb) ) : # and no drop_db tasks
                self.assertAtMostOneSuccess(tasks, TaskCreateDb) # we must have at most one. TODO: compare numbers
757 758 759 760 761 762 763 764 765 766 767

class StateDbOnly(AnyState):
    def getInfo(self):
        return [
            self.STATE_DB_ONLY,
            False, True,
            True, False,
            False, False,
        ]

    def verifyTasksToState(self, tasks, newState):
768 769 770
        if ( not self.hasTask(tasks, TaskCreateDb) ):
            self.assertAtMostOneSuccess(tasks, TaskDropDb) # only if we don't create any more
        self.assertIfExistThenSuccess(tasks, TaskDropDb)
S
Steven Li 已提交
771
        # self.assertAtMostOneSuccess(tasks, CreateFixedTableTask) # not true in massively parrallel cases
772
        # Nothing to be said about adding data task
773
        # if ( self.hasSuccess(tasks, DropDbTask) ): # dropped the DB
774
            # self.assertHasTask(tasks, DropDbTask) # implied by hasSuccess
775
            # self.assertAtMostOneSuccess(tasks, DropDbTask)
776
            # self._state = self.STATE_EMPTY
777 778 779 780
        # if ( self.hasSuccess(tasks, TaskCreateSuperTable) ): # did not drop db, create table success
        #     # self.assertHasTask(tasks, CreateFixedTableTask) # tried to create table
        #     if ( not self.hasTask(tasks, TaskDropSuperTable) ): 
        #         self.assertAtMostOneSuccess(tasks, TaskCreateSuperTable) # at most 1 attempt is successful, if we don't drop anything
781
            # self.assertNoTask(tasks, DropDbTask) # should have have tried
782 783 784 785 786 787 788 789 790 791 792 793
            # if ( not self.hasSuccess(tasks, AddFixedDataTask) ): # just created table, no data yet
            #     # can't say there's add-data attempts, since they may all fail
            #     self._state = self.STATE_TABLE_ONLY
            # else:                    
            #     self._state = self.STATE_HAS_DATA
        # What about AddFixedData?
        # elif ( self.hasSuccess(tasks, AddFixedDataTask) ):
        #     self._state = self.STATE_HAS_DATA
        # else: # no success in dropping db tasks, no success in create fixed table? read data should also fail
        #     # raise RuntimeError("Unexpected no-success scenario")   # We might just landed all failure tasks, 
        #     self._state = self.STATE_DB_ONLY  # no change

794
class StateSuperTableOnly(AnyState):
795 796 797 798 799 800 801 802 803
    def getInfo(self):
        return [
            self.STATE_TABLE_ONLY,
            False, True,
            False, True,
            True, True,
        ]

    def verifyTasksToState(self, tasks, newState):
804
        if ( self.hasSuccess(tasks, TaskDropSuperTable) ): # we are able to drop the table
805 806 807
            #self.assertAtMostOneSuccess(tasks, TaskDropSuperTable)
            self.hasSuccess(tasks, TaskCreateSuperTable) # we must have had recreted it

808
            # self._state = self.STATE_DB_ONLY
S
Steven Li 已提交
809 810
        # elif ( self.hasSuccess(tasks, AddFixedDataTask) ): # no success dropping the table, but added data
        #     self.assertNoTask(tasks, DropFixedTableTask) # not true in massively parrallel cases
811
            # self._state = self.STATE_HAS_DATA
S
Steven Li 已提交
812 813 814
        # elif ( self.hasSuccess(tasks, ReadFixedDataTask) ): # no success in prev cases, but was able to read data
            # self.assertNoTask(tasks, DropFixedTableTask)
            # self.assertNoTask(tasks, AddFixedDataTask)
815
            # self._state = self.STATE_TABLE_ONLY # no change
S
Steven Li 已提交
816 817 818
        # else: # did not drop table, did not insert data, did not read successfully, that is impossible
        #     raise RuntimeError("Unexpected no-success scenarios")
        # TODO: need to revamp!!
819 820 821 822 823 824 825 826 827 828 829

class StateHasData(AnyState):
    def getInfo(self):
        return [
            self.STATE_HAS_DATA,
            False, True,
            False, True,
            True, True,
        ]

    def verifyTasksToState(self, tasks, newState):
S
Steven Li 已提交
830
        if ( newState.equals(AnyState.STATE_EMPTY) ):
831 832 833
            self.hasSuccess(tasks, TaskDropDb)
            if ( not self.hasTask(tasks, TaskCreateDb) ) : 
                self.assertAtMostOneSuccess(tasks, TaskDropDb) # TODO: dicy
S
Steven Li 已提交
834
        elif ( newState.equals(AnyState.STATE_DB_ONLY) ): # in DB only
835 836 837
            if ( not self.hasTask(tasks, TaskCreateDb)): # without a create_db task
                self.assertNoTask(tasks, TaskDropDb) # we must have drop_db task
            self.hasSuccess(tasks, TaskDropSuperTable)
838
            # self.assertAtMostOneSuccess(tasks, DropFixedSuperTableTask) # TODO: dicy
839 840 841 842
        # elif ( newState.equals(AnyState.STATE_TABLE_ONLY) ): # data deleted
            # self.assertNoTask(tasks, TaskDropDb)
            # self.assertNoTask(tasks, TaskDropSuperTable)
            # self.assertNoTask(tasks, TaskAddData)
S
Steven Li 已提交
843
            # self.hasSuccess(tasks, DeleteDataTasks)
844
        else: # should be STATE_HAS_DATA
845 846
            if (not self.hasTask(tasks, TaskCreateDb) ): # only if we didn't create one
                self.assertNoTask(tasks, TaskDropDb) # we shouldn't have dropped it
847 848
            if (not self.hasTask(tasks, TaskCreateSuperTable)) :  # if we didn't create the table
                self.assertNoTask(tasks, TaskDropSuperTable) # we should not have a task that drops it            
849
            # self.assertIfExistThenSuccess(tasks, ReadFixedDataTask)
S
Steven Li 已提交
850

851
class StateMechine:
852 853 854 855 856 857 858 859
    def __init__(self, dbConn):
        self._dbConn = dbConn
        self._curState = self._findCurrentState() # starting state
        self._stateWeights = [1,3,5,15] # transitition target probabilities, indexed with value of STATE_EMPTY, STATE_DB_ONLY, etc.
        
    def getCurrentState(self):
        return self._curState

860 861 862
    def hasDatabase(self):
        return self._curState.canDropDb()  # ha, can drop DB means it has one

863 864
    # May be slow, use cautionsly...
    def getTaskTypes(self): # those that can run (directly/indirectly) from the current state
865 866 867 868 869 870
        def typesToStrings(types):
            ss = []
            for t in types:
                ss.append(t.__name__)
            return ss

871 872 873 874 875 876 877 878 879 880 881 882 883 884 885 886 887 888
        allTaskClasses = StateTransitionTask.__subclasses__() # all state transition tasks
        firstTaskTypes = []
        for tc in allTaskClasses:
            # t = tc(self) # create task object            
            if tc.canBeginFrom(self._curState):
                firstTaskTypes.append(tc)
        # now we have all the tasks that can begin directly from the current state, let's figure out the INDIRECT ones
        taskTypes = firstTaskTypes.copy() # have to have these
        for task1 in firstTaskTypes: # each task type gathered so far
            endState = task1.getEndState() # figure the end state
            if endState == None: # does not change end state
                continue # no use, do nothing
            for tc in allTaskClasses: # what task can further begin from there?
                if tc.canBeginFrom(endState) and (tc not in firstTaskTypes):
                    taskTypes.append(tc) # gather it

        if len(taskTypes) <= 0:
            raise RuntimeError("No suitable task types found for state: {}".format(self._curState))   
889
        logger.debug("[OPS] Tasks found for state {}: {}".format(self._curState, typesToStrings(taskTypes)))     
890 891 892 893 894 895 896 897 898
        return taskTypes

    def _findCurrentState(self):
        dbc = self._dbConn
        ts = time.time() # we use this to debug how fast/slow it is to do the various queries to find the current DB state
        if dbc.query("show databases") == 0 : # no database?!
            # logger.debug("Found EMPTY state")
            logger.debug("[STT] empty database found, between {} and {}".format(ts, time.time()))
            return StateEmpty()
899
        dbc.execute("use db") # did not do this when openning connection, and this is NOT the worker thread, which does this on their own
900 901 902 903 904 905 906 907 908 909 910 911 912 913 914
        if dbc.query("show tables") == 0 : # no tables
            # logger.debug("Found DB ONLY state")
            logger.debug("[STT] DB_ONLY found, between {} and {}".format(ts, time.time()))
            return StateDbOnly()
        if dbc.query("SELECT * FROM db.{}".format(DbManager.getFixedSuperTableName()) ) == 0 : # no regular tables
            # logger.debug("Found TABLE_ONLY state")
            logger.debug("[STT] SUPER_TABLE_ONLY found, between {} and {}".format(ts, time.time()))
            return StateSuperTableOnly()
        else: # has actual tables
            # logger.debug("Found HAS_DATA state")
            logger.debug("[STT] HAS_DATA found, between {} and {}".format(ts, time.time()))
            return StateHasData()

    def transition(self, tasks):
        if ( len(tasks) == 0 ): # before 1st step, or otherwise empty
915
            logger.debug("[STT] Starting State: {}".format(self._curState))
916 917 918 919 920 921 922 923 924 925 926 927 928 929 930 931 932 933 934 935 936 937 938 939 940 941 942 943 944 945 946 947 948 949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 964 965 966
            return # do nothing

        self._dbConn.execute("show dnodes") # this should show up in the server log, separating steps

        # Generic Checks, first based on the start state
        if self._curState.canCreateDb():
            self._curState.assertIfExistThenSuccess(tasks, TaskCreateDb)
            # self.assertAtMostOneSuccess(tasks, CreateDbTask) # not really, in case of multiple creation and drops

        if self._curState.canDropDb():
            self._curState.assertIfExistThenSuccess(tasks, TaskDropDb)
            # self.assertAtMostOneSuccess(tasks, DropDbTask) # not really in case of drop-create-drop

        # if self._state.canCreateFixedTable():
            # self.assertIfExistThenSuccess(tasks, CreateFixedTableTask) # Not true, DB may be dropped
            # self.assertAtMostOneSuccess(tasks, CreateFixedTableTask) # not really, in case of create-drop-create

        # if self._state.canDropFixedTable():
            # self.assertIfExistThenSuccess(tasks, DropFixedTableTask) # Not True, the whole DB may be dropped
            # self.assertAtMostOneSuccess(tasks, DropFixedTableTask) # not really in case of drop-create-drop

        # if self._state.canAddData():
        #     self.assertIfExistThenSuccess(tasks, AddFixedDataTask)  # not true actually

        # if self._state.canReadData():
            # Nothing for sure

        newState = self._findCurrentState()
        logger.debug("[STT] New DB state determined: {}".format(newState))
        self._curState.verifyTasksToState(tasks, newState) # can old state move to new state through the tasks?
        self._curState = newState

    def pickTaskType(self):
        taskTypes = self.getTaskTypes() # all the task types we can choose from at curent state
        weights = []
        for tt in taskTypes:
            endState = tt.getEndState()
            if endState != None :
                weights.append(self._stateWeights[endState.getValIndex()]) # TODO: change to a method
            else:
                weights.append(10) # read data task, default to 10: TODO: change to a constant
        i = self._weighted_choice_sub(weights)
        # logger.debug(" (weighted random:{}/{}) ".format(i, len(taskTypes)))        
        return taskTypes[i]

    def _weighted_choice_sub(self, weights): # ref: https://eli.thegreenplace.net/2010/01/22/weighted-random-generation-in-python/
        rnd = random.random() * sum(weights) # TODO: use our dice to ensure it being determinstic?
        for i, w in enumerate(weights):
            rnd -= w
            if rnd < 0:
                return i
967

968
# Manager of the Database Data/Connection
969
class DbManager():    
970
    def __init__(self, resetDb = True):
S
Steven Li 已提交
971
        self.tableNumQueue = LinearQueue()
972
        self._lastTick = self.setupLastTick() # datetime.datetime(2019, 1, 1) # initial date time tick
973 974
        self._lastInt  = 0 # next one is initial integer 
        self._lock = threading.RLock()
975
        
976
        # self.openDbServerConnection()
977
        self._dbConn = DbConn.createNative() if (gConfig.connector_type=='native') else DbConn.createRest()
978 979 980 981
        try:
            self._dbConn.open() # may throw taos.error.ProgrammingError: disconnected
        except taos.error.ProgrammingError as err:
            # print("Error type: {}, msg: {}, value: {}".format(type(err), err.msg, err))
982
            if ( err.msg == 'client disconnected' ): # cannot open DB connection
983 984 985 986 987
                print("Cannot establish DB connection, please re-run script without parameter, and follow the instructions.")
                sys.exit()
            else:
                raise            
        except:
S
Steven Li 已提交
988
            print("[=] Unexpected exception")
989
            raise        
990 991 992

        if resetDb :
            self._dbConn.resetDb() # drop and recreate DB            
993

994 995
        self._stateMachine = StateMechine(self._dbConn) # Do this after dbConn is in proper shape
        
996 997 998
    def getDbConn(self):
        return self._dbConn

999
    def getStateMachine(self) -> StateMechine :
1000 1001 1002 1003
        return self._stateMachine

    # def getState(self):
    #     return self._stateMachine.getCurrentState()
1004 1005 1006 1007 1008 1009

    # We aim to create a starting time tick, such that, whenever we run our test here once
    # We should be able to safely create 100,000 records, which will not have any repeated time stamp
    # when we re-run the test in 3 minutes (180 seconds), basically we should expand time duration
    # by a factor of 500.
    # TODO: what if it goes beyond 10 years into the future
1010
    # TODO: fix the error as result of above: "tsdb timestamp is out of range"
1011
    def setupLastTick(self):
1012
        t1 = datetime.datetime(2020, 6, 1)
1013
        t2 = datetime.datetime.now()
1014 1015
        elSec = int(t2.timestamp() - t1.timestamp()) # maybe a very large number, takes 69 years to exceed Python int range
        elSec2 = (  elSec % (8 * 12 * 30 * 24 * 60 * 60 / 500 ) ) * 500 # a number representing seconds within 10 years
1016 1017
        # print("elSec = {}".format(elSec))
        t3 = datetime.datetime(2012, 1, 1) # default "keep" is 10 years
1018
        t4 = datetime.datetime.fromtimestamp( t3.timestamp() + elSec2) # see explanation above
1019 1020 1021
        logger.info("Setting up TICKS to start from: {}".format(t4))
        return t4

S
Steven Li 已提交
1022 1023 1024
    def pickAndAllocateTable(self): # pick any table, and "use" it
        return self.tableNumQueue.pickAndAllocate()

1025 1026 1027 1028 1029
    def addTable(self):
        with self._lock:
            tIndex = self.tableNumQueue.push()
        return tIndex

1030 1031
    @classmethod
    def getFixedSuperTableName(cls):
1032
        return "fs_table"
1033

S
Steven Li 已提交
1034 1035 1036
    def releaseTable(self, i): # return the table back, so others can use it
        self.tableNumQueue.release(i)

1037
    def getNextTick(self):
1038 1039 1040
        with self._lock: # prevent duplicate tick
            self._lastTick += datetime.timedelta(0, 1) # add one second to it
            return self._lastTick
1041 1042

    def getNextInt(self):
1043 1044 1045
        with self._lock:
            self._lastInt += 1
            return self._lastInt
1046 1047

    def getNextBinary(self):
1048
        return "Beijing_Shanghai_Los_Angeles_New_York_San_Francisco_Chicago_Beijing_Shanghai_Los_Angeles_New_York_San_Francisco_Chicago_{}".format(self.getNextInt())
1049 1050 1051

    def getNextFloat(self):
        return 0.9 + self.getNextInt()
1052
    
S
Steven Li 已提交
1053
    def getTableNameToDelete(self):
1054
        tblNum = self.tableNumQueue.pop() # TODO: race condition!
1055 1056 1057
        if ( not tblNum ): # maybe false
            return False
        
S
Steven Li 已提交
1058 1059
        return "table_{}".format(tblNum)

1060 1061 1062
    def cleanUp(self):
        self._dbConn.close()      

1063 1064 1065 1066
class TaskExecutor():
    def __init__(self, curStep):
        self._curStep = curStep

1067 1068 1069
    def getCurStep(self):
        return self._curStep

1070 1071
    def execute(self, task: Task, wt: WorkerThread): # execute a task on a thread
        task.execute(wt)
1072

1073 1074
    # def logInfo(self, msg):
    #     logger.info("    T[{}.x]: ".format(self._curStep) + msg)
1075

1076 1077
    # def logDebug(self, msg):
    #     logger.debug("    T[{}.x]: ".format(self._curStep) + msg)
1078

S
Steven Li 已提交
1079
class Task():
1080 1081 1082 1083
    taskSn = 100

    @classmethod
    def allocTaskNum(cls):
S
Steven Li 已提交
1084 1085 1086
        Task.taskSn += 1 # IMPORTANT: cannot use cls.taskSn, since each sub class will have a copy
        # logger.debug("Allocating taskSN: {}".format(Task.taskSn))
        return Task.taskSn
1087

1088
    def __init__(self, dbManager: DbManager, execStats: ExecutionStats):        
1089
        self._dbManager = dbManager
1090
        self._workerThread = None 
1091
        self._err = None
1092
        self._curStep = None
1093
        self._numRows = None # Number of rows affected
1094 1095 1096

        # Assign an incremental task serial number        
        self._taskNum = self.allocTaskNum()
S
Steven Li 已提交
1097
        # logger.debug("Creating new task {}...".format(self._taskNum))
1098

1099
        self._execStats = execStats
1100
        self._lastSql = "" # last SQL executed/attempted
1101

1102 1103
    def isSuccess(self):
        return self._err == None
1104

1105
    def clone(self): # TODO: why do we need this again?
1106
        newTask = self.__class__(self._dbManager, self._execStats)
1107 1108 1109
        return newTask

    def logDebug(self, msg):
S
Steven Li 已提交
1110
        self._workerThread.logDebug("Step[{}.{}] {}".format(self._curStep, self._taskNum, msg))
1111 1112

    def logInfo(self, msg):
S
Steven Li 已提交
1113
        self._workerThread.logInfo("Step[{}.{}] {}".format(self._curStep, self._taskNum, msg))
1114

1115
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1116
        raise RuntimeError("To be implemeted by child classes, class name: {}".format(self.__class__.__name__))
1117

1118 1119
    def execute(self, wt: WorkerThread):
        wt.verifyThreadSelf()
1120
        self._workerThread = wt # type: ignore
1121 1122

        te = wt.getTaskExecutor()
1123 1124
        self._curStep = te.getCurStep()
        self.logDebug("[-] executing task {}...".format(self.__class__.__name__))
1125 1126

        self._err = None
1127
        self._execStats.beginTaskType(self.__class__.__name__) # mark beginning
1128 1129 1130
        try:
            self._executeInternal(te, wt) # TODO: no return value?
        except taos.error.ProgrammingError as err:
1131 1132 1133 1134
            errno2 = err.errno if (err.errno > 0) else 0x80000000 + err.errno # correct error scheme
            if ( errno2 in [0x200, 0x360, 0x362, 0x36A, 0x36B, 0x36D, 0x381, 0x380, 0x383, 0x503, 0x600,
                1000 # REST catch-all error
                ]) : # allowed errors
1135
                self.logDebug("[=] Acceptable Taos library exception: errno=0x{:X}, msg: {}, SQL: {}".format(errno2, err, self._lastSql))
1136
                print("_", end="", flush=True)
1137 1138
                self._err = err  
            else:
1139 1140 1141 1142 1143
                errMsg = "[=] Unexpected Taos library exception: errno=0x{:X}, msg: {}, SQL: {}".format(errno2, err, self._lastSql)
                self.logDebug(errMsg)
                if gConfig.debug :
                    raise # so that we see full stack
                else: # non-debug
1144 1145
                    print("\n\n----------------------------\nProgram ABORTED Due to Unexpected TAOS Error: \n\n{}\n".format(errMsg) +
                        "----------------------------\n")
1146
                    sys.exit(-1)
1147
        except:
1148
            self.logDebug("[=] Unexpected exception, SQL: {}".format(self._lastSql))
1149
            raise
1150
        self._execStats.endTaskType(self.__class__.__name__, self.isSuccess())
1151
        
1152 1153
        self.logDebug("[X] task execution completed, {}, status: {}".format(self.__class__.__name__, "Success" if self.isSuccess() else "Failure"))        
        self._execStats.incExecCount(self.__class__.__name__, self.isSuccess()) # TODO: merge with above.
S
Steven Li 已提交
1154

1155
    def execSql(self, sql):
1156
        self._lastSql = sql
1157
        return self._dbManager.execute(sql)
1158

1159 1160 1161 1162 1163 1164 1165 1166 1167 1168 1169 1170
    def execWtSql(self, wt: WorkerThread, sql): # execute an SQL on the worker thread
        self._lastSql = sql
        return wt.execSql(sql)

    def queryWtSql(self, wt: WorkerThread, sql): # execute an SQL on the worker thread
        self._lastSql = sql
        return wt.querySql(sql)

    def getQueryResult(self, wt: WorkerThread): # execute an SQL on the worker thread
        return wt.getQueryResult()


1171
                  
1172
class ExecutionStats:
1173 1174 1175 1176 1177
    def __init__(self):
        self._execTimes: Dict[str, [int, int]] = {} # total/success times for a task
        self._tasksInProgress = 0
        self._lock = threading.Lock()
        self._firstTaskStartTime = None
1178 1179
        self._execStartTime = None
        self._elapsedTime = 0.0 # total elapsed time
1180 1181
        self._accRunTime = 0.0 # accumulated run time

1182 1183 1184 1185 1186 1187 1188 1189 1190
        self._failed = False
        self._failureReason = None

    def startExec(self):
        self._execStartTime = time.time()

    def endExec(self):
        self._elapsedTime = time.time() - self._execStartTime

1191 1192 1193 1194 1195 1196 1197 1198 1199 1200 1201 1202 1203 1204 1205 1206 1207 1208 1209 1210 1211
    def incExecCount(self, klassName, isSuccess): # TODO: add a lock here
        if klassName not in self._execTimes:
            self._execTimes[klassName] = [0, 0]
        t = self._execTimes[klassName] # tuple for the data
        t[0] += 1 # index 0 has the "total" execution times
        if isSuccess:
            t[1] += 1 # index 1 has the "success" execution times

    def beginTaskType(self, klassName):
        with self._lock:
            if self._tasksInProgress == 0 : # starting a new round
                self._firstTaskStartTime = time.time() # I am now the first task
            self._tasksInProgress += 1

    def endTaskType(self, klassName, isSuccess):
        with self._lock:
            self._tasksInProgress -= 1
            if self._tasksInProgress == 0 : # all tasks have stopped
                self._accRunTime += (time.time() - self._firstTaskStartTime)
                self._firstTaskStartTime = None

1212 1213 1214 1215
    def registerFailure(self, reason):
        self._failed = True
        self._failureReason = reason

1216
    def logStats(self):
1217 1218 1219 1220
        logger.info("----------------------------------------------------------------------")
        logger.info("| Crash_Gen test {}, with the following stats:".
            format("FAILED (reason: {})".format(self._failureReason) if self._failed else "SUCCEEDED"))
        logger.info("| Task Execution Times (success/total):")
1221 1222
        execTimesAny = 0
        for k, n in self._execTimes.items():            
1223
            execTimesAny += n[0]
1224
            logger.info("|    {0:<24}: {1}/{2}".format(k,n[1],n[0]))
1225
                
1226 1227 1228 1229 1230 1231 1232
        logger.info("| Total Tasks Executed (success or not): {} ".format(execTimesAny))
        logger.info("| Total Tasks In Progress at End: {}".format(self._tasksInProgress))
        logger.info("| Total Task Busy Time (elapsed time when any task is in progress): {:.3f} seconds".format(self._accRunTime))
        logger.info("| Average Per-Task Execution Time: {:.3f} seconds".format(self._accRunTime/execTimesAny))
        logger.info("| Total Elapsed Time (from wall clock): {:.3f} seconds".format(self._elapsedTime))
        logger.info("----------------------------------------------------------------------")
        
1233 1234 1235


class StateTransitionTask(Task):
1236 1237 1238 1239 1240
    LARGE_NUMBER_OF_TABLES = 35
    SMALL_NUMBER_OF_TABLES = 3
    LARGE_NUMBER_OF_RECORDS = 50
    SMALL_NUMBER_OF_RECORDS = 3

1241 1242 1243 1244
    @classmethod
    def getInfo(cls): # each sub class should supply their own information
        raise RuntimeError("Overriding method expected")

1245 1246 1247 1248 1249
    _endState = None 
    @classmethod
    def getEndState(cls): # TODO: optimize by calling it fewer times
        raise RuntimeError("Overriding method expected")

1250 1251 1252
    # @classmethod
    # def getBeginStates(cls):
    #     return cls.getInfo()[0]
1253

1254 1255 1256
    # @classmethod
    # def getEndState(cls): # returning the class name
    #     return cls.getInfo()[0]
1257 1258

    @classmethod
1259 1260 1261
    def canBeginFrom(cls, state: AnyState):
        # return state.getValue() in cls.getBeginStates()
        raise RuntimeError("must be overriden")
1262

1263 1264 1265 1266
    @classmethod
    def getRegTableName(cls, i):
        return "db.reg_table_{}".format(i)

1267 1268 1269
    def execute(self, wt: WorkerThread):
        super().execute(wt)
        
1270
class TaskCreateDb(StateTransitionTask):
1271
    @classmethod
1272 1273
    def getEndState(cls):
        return StateDbOnly() 
1274

1275 1276 1277 1278
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canCreateDb()

1279
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1280
        self.execWtSql(wt, "create database db")       
1281

1282
class TaskDropDb(StateTransitionTask):
1283
    @classmethod
1284 1285
    def getEndState(cls):
        return StateEmpty()
1286

1287 1288 1289 1290
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canDropDb()

1291
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1292
        self.execWtSql(wt, "drop database db")
S
Steven Li 已提交
1293
        logger.debug("[OPS] database dropped at {}".format(time.time()))
1294

1295
class TaskCreateSuperTable(StateTransitionTask):
1296
    @classmethod
1297 1298
    def getEndState(cls):
        return StateSuperTableOnly()
1299

1300 1301
    @classmethod
    def canBeginFrom(cls, state: AnyState):
1302
        return state.canCreateFixedSuperTable()
1303

1304
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1305 1306 1307 1308 1309 1310 1311
        if not wt.dbInUse(): # no DB yet, to the best of our knowledge
            logger.debug("Skipping task, no DB yet")
            return

        tblName = self._dbManager.getFixedSuperTableName()   
        # wt.execSql("use db")    # should always be in place
        self.execWtSql(wt, "create table db.{} (ts timestamp, speed int) tags (b binary(200), f float) ".format(tblName))
1312 1313
        # No need to create the regular tables, INSERT will do that automatically

S
Steven Li 已提交
1314

1315
class TaskReadData(StateTransitionTask):
1316
    @classmethod
1317 1318
    def getEndState(cls):
        return None # meaning doesn't affect state
1319

1320 1321 1322 1323
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canReadData()

1324
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1325
        sTbName = self._dbManager.getFixedSuperTableName()        
1326 1327
        self.queryWtSql(wt, "select TBNAME from db.{}".format(sTbName)) # TODO: analyze result set later

1328
        if random.randrange(5) == 0 : # 1 in 5 chance, simulate a broken connection. TODO: break connection in all situations
1329 1330
            wt.getDbConn().close()
            wt.getDbConn().open()
1331
        else:
1332
            rTables = self.getQueryResult(wt) # wt.getDbConn().getQueryResult()
1333 1334
            # print("rTables[0] = {}, type = {}".format(rTables[0], type(rTables[0])))
            for rTbName in rTables : # regular tables
1335
                self.execWtSql(wt, "select * from db.{}".format(rTbName[0]))
1336

1337 1338
        # tdSql.query(" cars where tbname in ('carzero', 'carone')")

1339
class TaskDropSuperTable(StateTransitionTask):
1340
    @classmethod
1341 1342
    def getEndState(cls):
        return StateDbOnly() 
1343

1344 1345
    @classmethod
    def canBeginFrom(cls, state: AnyState):
1346
        return state.canDropFixedSuperTable()
1347

1348
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1349 1350 1351 1352 1353
        # 1/2 chance, we'll drop the regular tables one by one, in a randomized sequence
        if Dice.throw(2) == 0 : 
            tblSeq = list(range(2 + (self.LARGE_NUMBER_OF_TABLES if gConfig.larger_data else self.SMALL_NUMBER_OF_TABLES))) 
            random.shuffle(tblSeq) 
            tickOutput = False # if we have spitted out a "d" character for "drop regular table"
1354
            isSuccess = True
1355
            for i in tblSeq: 
1356
                regTableName = self.getRegTableName(i); # "db.reg_table_{}".format(i)                  
1357
                try:
1358
                    self.execWtSql(wt, "drop table {}".format(regTableName)) # nRows always 0, like MySQL
1359 1360
                except taos.error.ProgrammingError as err:                    
                    errno2 = err.errno if (err.errno > 0) else 0x80000000 + err.errno # correcting for strange error number scheme
1361 1362
                    if ( errno2 in [0x362]) : # mnode invalid table name
                        isSuccess = False
1363
                        logger.debug("[DB] Acceptable error when dropping a table")
1364
                    continue # try to delete next regular table
1365 1366 1367

                if (not tickOutput):
                    tickOutput = True # Print only one time
1368
                    if isSuccess :
1369 1370
                        print("d", end="", flush=True)
                    else:
1371
                        print("f", end="", flush=True)                    
1372 1373 1374 1375

        # Drop the super table itself
        tblName = self._dbManager.getFixedSuperTableName()     
        self.execWtSql(wt, "drop table db.{}".format(tblName))
1376

1377 1378 1379 1380 1381 1382 1383 1384 1385 1386 1387 1388 1389
class TaskAlterTags(StateTransitionTask):
    @classmethod
    def getEndState(cls):
        return None # meaning doesn't affect state

    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canDropFixedSuperTable() # if we can drop it, we can alter tags

    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
        tblName = self._dbManager.getFixedSuperTableName()   
        dice = Dice.throw(4)
        if dice == 0 :
1390
            sql = "alter table db.{} add tag extraTag int".format(tblName)
1391
        elif dice == 1 :
1392
            sql = "alter table db.{} drop tag extraTag".format(tblName)
1393
        elif dice == 2 :
1394
            sql = "alter table db.{} drop tag newTag".format(tblName)
1395
        else: # dice == 3
1396 1397 1398
            sql = "alter table db.{} change tag extraTag newTag".format(tblName)

        self.execWtSql(wt, sql)
1399

1400
class TaskAddData(StateTransitionTask):
1401
    activeTable : Set[int] = set() # Track which table is being actively worked on
1402 1403 1404 1405 1406 1407 1408 1409 1410 1411 1412 1413 1414 1415

    # We use these two files to record operations to DB, useful for power-off tests
    fAddLogReady = None
    fAddLogDone = None

    @classmethod
    def prepToRecordOps(cls):
        if gConfig.record_ops :            
            if ( cls.fAddLogReady == None ):
                logger.info("Recording in a file operations to be performed...")
                cls.fAddLogReady = open("add_log_ready.txt", "w")
            if ( cls.fAddLogDone == None ):
                logger.info("Recording in a file operations completed...")
                cls.fAddLogDone = open("add_log_done.txt", "w")
1416

1417
    @classmethod
1418 1419
    def getEndState(cls):
        return StateHasData()
1420 1421 1422 1423

    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canAddData()
1424 1425
        
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1426
        ds = self._dbManager
1427
        # wt.execSql("use db") # TODO: seems to be an INSERT bug to require this
1428
        tblSeq = list(range(self.LARGE_NUMBER_OF_TABLES if gConfig.larger_data else self.SMALL_NUMBER_OF_TABLES)) 
1429 1430 1431 1432 1433 1434 1435 1436
        random.shuffle(tblSeq) 
        for i in tblSeq: 
            if ( i in self.activeTable ): # wow already active
                # logger.info("Concurrent data insertion into table: {}".format(i))      
                # print("ct({})".format(i), end="", flush=True) # Concurrent insertion into table
                print("x", end="", flush=True)
            else:
                self.activeTable.add(i) # marking it active
1437 1438
            # No need to shuffle data sequence, unless later we decide to do non-increment insertion      
            regTableName = self.getRegTableName(i); # "db.reg_table_{}".format(i)      
1439
            for j in range(self.LARGE_NUMBER_OF_RECORDS if gConfig.larger_data else self.SMALL_NUMBER_OF_RECORDS) : # number of records per table
1440
                nextInt = ds.getNextInt()                
1441 1442 1443 1444 1445 1446 1447
                if gConfig.record_ops:
                    self.prepToRecordOps()
                    self.fAddLogReady.write("Ready to write {} to {}\n".format(nextInt, regTableName))
                    self.fAddLogReady.flush()
                    os.fsync(self.fAddLogReady)
                sql = "insert into {} using {} tags ('{}', {}) values ('{}', {});".format(
                    regTableName, 
1448 1449
                    ds.getFixedSuperTableName(), 
                    ds.getNextBinary(), ds.getNextFloat(),
1450
                    ds.getNextTick(), nextInt)
1451
                self.execWtSql(wt, sql) 
1452 1453 1454 1455
                if gConfig.record_ops:
                    self.fAddLogDone.write("Wrote {} to {}\n".format(nextInt, regTableName))
                    self.fAddLogDone.flush()
                    os.fsync(self.fAddLogDone)
1456
            self.activeTable.discard(i) # not raising an error, unlike remove
1457 1458


S
Steven Li 已提交
1459 1460 1461 1462 1463 1464 1465 1466 1467 1468 1469 1470 1471 1472 1473 1474 1475 1476 1477 1478 1479 1480
# Deterministic random number generator
class Dice():
    seeded = False # static, uninitialized

    @classmethod
    def seed(cls, s): # static
        if (cls.seeded):
            raise RuntimeError("Cannot seed the random generator more than once")
        cls.verifyRNG()
        random.seed(s)
        cls.seeded = True  # TODO: protect against multi-threading

    @classmethod
    def verifyRNG(cls): # Verify that the RNG is determinstic
        random.seed(0)
        x1 = random.randrange(0, 1000)
        x2 = random.randrange(0, 1000)
        x3 = random.randrange(0, 1000)
        if ( x1 != 864 or x2!=394 or x3!=776 ):
            raise RuntimeError("System RNG is not deterministic")

    @classmethod
1481 1482
    def throw(cls, stop): # get 0 to stop-1
        return cls.throwRange(0, stop)
S
Steven Li 已提交
1483 1484

    @classmethod
1485
    def throwRange(cls, start, stop): # up to stop-1
S
Steven Li 已提交
1486 1487
        if ( not cls.seeded ):
            raise RuntimeError("Cannot throw dice before seeding it")
1488
        return random.randrange(start, stop)
S
Steven Li 已提交
1489 1490 1491


# Anyone needing to carry out work should simply come here
1492 1493 1494 1495 1496 1497 1498 1499 1500 1501 1502 1503 1504 1505 1506 1507 1508 1509 1510 1511 1512 1513
# class WorkDispatcher():
#     def __init__(self, dbState):
#         # self.totalNumMethods = 2
#         self.tasks = [
#             # CreateTableTask(dbState), # Obsolete
#             # DropTableTask(dbState),
#             # AddDataTask(dbState),
#         ]

#     def throwDice(self):
#         max = len(self.tasks) - 1 
#         dRes = random.randint(0, max)
#         # logger.debug("Threw the dice in range [{},{}], and got: {}".format(0,max,dRes))
#         return dRes

#     def pickTask(self):
#         dice = self.throwDice()
#         return self.tasks[dice]

#     def doWork(self, workerThread):
#         task = self.pickTask()
#         task.execute(workerThread)
S
Steven Li 已提交
1514

S
Steven Li 已提交
1515 1516
class LoggingFilter(logging.Filter):
    def filter(self, record: logging.LogRecord):
S
Steven Li 已提交
1517 1518 1519
        if ( record.levelno >= logging.INFO ) :
            return True # info or above always log

S
Steven Li 已提交
1520 1521 1522 1523
        # Commenting out below to adjust...

        # if msg.startswith("[TRD]"):
        #     return False
S
Steven Li 已提交
1524 1525
        return True

1526 1527 1528 1529 1530
class MyLoggingAdapter(logging.LoggerAdapter):    
    def process(self, msg, kwargs):
        return "[{}]{}".format(threading.get_ident() % 10000, msg), kwargs
        # return '[%s] %s' % (self.extra['connid'], msg), kwargs

1531 1532 1533 1534 1535 1536 1537 1538 1539
class MainExec:
    @classmethod
    def runClient(cls):
        # resetDb = False # DEBUG only
        # dbState = DbState(resetDb)  # DBEUG only!
        dbManager = DbManager() # Regular function
        Dice.seed(0) # initial seeding of dice
        thPool = ThreadPool(gConfig.num_threads, gConfig.max_steps)
        tc = ThreadCoordinator(thPool, dbManager)
S
Steven Li 已提交
1540
        
1541 1542 1543 1544 1545 1546 1547 1548 1549 1550 1551 1552 1553 1554 1555 1556 1557 1558 1559 1560 1561 1562 1563 1564 1565 1566 1567 1568 1569 1570 1571 1572 1573 1574 1575 1576 1577 1578 1579 1580 1581 1582 1583 1584 1585 1586 1587 1588 1589 1590 1591
        tc.run()
        tc.logStats()
        dbManager.cleanUp()    

    @classmethod
    def runService(cls):
        print("Running service...")

    @classmethod
    def runTemp(cls): # for debugging purposes
        # # Hack to exercise reading from disk, imcreasing coverage. TODO: fix
        # dbc = dbState.getDbConn()
        # sTbName = dbState.getFixedSuperTableName()   
        # dbc.execute("create database if not exists db")
        # if not dbState.getState().equals(StateEmpty()):
        #     dbc.execute("use db")     

        # rTables = None
        # try: # the super table may not exist
        #     sql = "select TBNAME from db.{}".format(sTbName)
        #     logger.info("Finding out tables in super table: {}".format(sql))
        #     dbc.query(sql) # TODO: analyze result set later
        #     logger.info("Fetching result")
        #     rTables = dbc.getQueryResult()
        #     logger.info("Result: {}".format(rTables))
        # except taos.error.ProgrammingError as err:
        #     logger.info("Initial Super table OPS error: {}".format(err))
        
        # # sys.exit()
        # if ( not rTables == None):
        #     # print("rTables[0] = {}, type = {}".format(rTables[0], type(rTables[0])))
        #     try:
        #         for rTbName in rTables : # regular tables
        #             ds = dbState
        #             logger.info("Inserting into table: {}".format(rTbName[0]))
        #             sql = "insert into db.{} values ('{}', {});".format(
        #                 rTbName[0],                    
        #                 ds.getNextTick(), ds.getNextInt())
        #             dbc.execute(sql)
        #         for rTbName in rTables : # regular tables        
        #             dbc.query("select * from db.{}".format(rTbName[0])) # TODO: check success failure
        #         logger.info("Initial READING operation is successful")       
        #     except taos.error.ProgrammingError as err:
        #         logger.info("Initial WRITE/READ error: {}".format(err))   
        
        # Sandbox testing code
        # dbc = dbState.getDbConn()
        # while True:
        #     rows = dbc.query("show databases") 
        #     print("Rows: {}, time={}".format(rows, time.time()))
        return 
S
Steven Li 已提交
1592

1593
def main():
1594
    # Super cool Python argument library: https://docs.python.org/3/library/argparse.html
1595 1596 1597 1598 1599 1600 1601 1602 1603
    parser = argparse.ArgumentParser(
        formatter_class=argparse.RawDescriptionHelpFormatter,
        description=textwrap.dedent('''\
            TDengine Auto Crash Generator (PLEASE NOTICE the Prerequisites Below)
            ---------------------------------------------------------------------
            1. You build TDengine in the top level ./build directory, as described in offical docs
            2. You run the server there before this script: ./build/bin/taosd -c test/cfg

            '''))
1604

1605 1606
    parser.add_argument('-c', '--connector-type', action='store', default='native', type=str,
                        help='Connector type to use: native, rest, or mixed (default: 10)')
1607 1608
    parser.add_argument('-d', '--debug', action='store_true',                        
                        help='Turn on DEBUG mode for more logging (default: false)')
1609 1610
    parser.add_argument('-e', '--run-tdengine', action='store_true',                        
                        help='Run TDengine service in foreground (default: false)')
1611 1612
    parser.add_argument('-l', '--larger-data', action='store_true',                        
                        help='Write larger amount of data during write operations (default: false)')
1613
    parser.add_argument('-p', '--per-thread-db-connection', action='store_true',                        
1614
                        help='Use a single shared db connection (default: false)')
1615 1616
    parser.add_argument('-r', '--record-ops', action='store_true',                        
                        help='Use a pair of always-fsynced fils to record operations performing + performed, for power-off tests (default: false)')                    
1617
    parser.add_argument('-s', '--max-steps', action='store', default=1000, type=int,
1618
                        help='Maximum number of steps to run (default: 100)')
1619
    parser.add_argument('-t', '--num-threads', action='store', default=5, type=int,
1620
                        help='Number of threads to run (default: 10)')
1621

1622
    global gConfig
1623
    gConfig = parser.parse_args()
1624

1625 1626 1627
    # if len(sys.argv) == 1:
    #     parser.print_help()
    #     sys.exit()
1628
 
1629
    # Logging Stuff
1630
    global logger
1631 1632 1633 1634 1635 1636 1637
    _logger = logging.getLogger('CrashGen') # real logger
    _logger.addFilter(LoggingFilter()) 
    ch = logging.StreamHandler()
    _logger.addHandler(ch)

    logger = MyLoggingAdapter(_logger, []) # Logging adapter, to be used as a logger

1638 1639
    if ( gConfig.debug ):
        logger.setLevel(logging.DEBUG) # default seems to be INFO        
S
Steven Li 已提交
1640 1641
    else:
        logger.setLevel(logging.INFO)
1642 1643
    
    # Run server or client
1644 1645 1646 1647
    if gConfig.run_tdengine : # run server
        MainExec.runService()
    else :
        MainExec.runClient()
1648

1649
    
S
Steven Li 已提交
1650
    # logger.info("Crash_Gen execution finished")
1651 1652 1653

if __name__ == "__main__":
    main()