crash_gen.py 86.0 KB
Newer Older
S
Steven Li 已提交
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 19
import io
import signal
20
import traceback
21 22 23 24
# Require Python 3
if sys.version_info[0] < 3:
    raise Exception("Must be using Python 3")

S
Steven Li 已提交
25
import getopt
26
import argparse
27
import copy
S
Steven Li 已提交
28
import requests
S
Steven Li 已提交
29 30 31

import threading
import random
32
import time
S
Steven Li 已提交
33
import logging
34
import datetime
35
import textwrap
36 37
import requests
from requests.auth import HTTPBasicAuth
S
Steven Li 已提交
38

39
from typing import List
40
from typing import Dict
41
from typing import Set
42 43
from typing import IO
from queue import Queue, Empty
44

S
Steven Li 已提交
45 46 47 48 49
from util.log import *
from util.dnodes import *
from util.cases import *
from util.sql import *

50
import crash_gen
S
Steven Li 已提交
51 52
import taos

53
# Global variables, tried to keep a small number. 
54 55 56 57

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

60 61
def runThread(wt: WorkerThread):    
    wt.run()
62

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

84
        # Let us have a DB connection of our own
85
        if ( gConfig.per_thread_db_connection ): # type: ignore
86 87
            # print("connector_type = {}".format(gConfig.connector_type))
            self._dbConn = DbConn.createNative() if (gConfig.connector_type == 'native') else DbConn.createRest()
88

89 90
        self._dbInUse = False # if "use db" was executed already

91
    def logDebug(self, msg):
S
Steven Li 已提交
92
        logger.debug("    TRD[{}] {}".format(self._tid, msg))
93 94

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

97 98 99 100 101 102 103 104
    def dbInUse(self):
        return self._dbInUse

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

105 106
    def getTaskExecutor(self):
        return self._tc.getTaskExecutor()     
107

S
Steven Li 已提交
108
    def start(self):
109
        self._thread.start()  # AFTER the thread is recorded
S
Steven Li 已提交
110

111
    def run(self): 
S
Steven Li 已提交
112
        # initialization after thread starts, in the thread context
113
        # self.isSleeping = False
114 115
        logger.info("Starting to run thread: {}".format(self._tid))

116
        if ( gConfig.per_thread_db_connection ): # type: ignore
117
            logger.debug("Worker thread openning database connection")
118
            self._dbConn.open()
S
Steven Li 已提交
119

120 121
        self._doTaskLoop()       
        
122
        # clean up
123
        if ( gConfig.per_thread_db_connection ): # type: ignore 
124
            self._dbConn.close()
125

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

139
            # Fetch a task from the Thread Coordinator
S
Steven Li 已提交
140
            logger.debug("[TRD] Worker thread [{}] about to fetch task".format(self._tid))
141
            task = tc.fetchTask()
142 143

            # Execute such a task
S
Steven Li 已提交
144
            logger.debug("[TRD] Worker thread [{}] about to execute task: {}".format(self._tid, task.__class__.__name__))
145
            task.execute(self)
146
            tc.saveExecutedTask(task)
S
Steven Li 已提交
147
            logger.debug("[TRD] Worker thread [{}] finished executing task".format(self._tid))
148 149

            self._dbInUse = False # there may be changes between steps
150
  
S
Steven Li 已提交
151
    def verifyThreadSelf(self): # ensure we are called by this own thread
152
        if ( threading.get_ident() != self._thread.ident ): 
S
Steven Li 已提交
153 154 155 156 157 158 159
            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):
160
        if ( not self._thread.is_alive() ):
S
Steven Li 已提交
161 162
            raise RuntimeError("Unexpected dead thread")

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

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

183
    def execSql(self, sql): # TODO: expose DbConn directly
184 185 186
        if ( gConfig.per_thread_db_connection ):
            return self._dbConn.execute(sql)            
        else:
187
            return self._tc.getDbManager().getDbConn().execute(sql)
188

189 190 191 192 193 194 195 196 197 198 199 200
    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()

201 202 203 204
    def getDbConn(self):
        if ( gConfig.per_thread_db_connection ):
            return self._dbConn     
        else:
205
            return self._tc.getDbManager().getDbConn()
206

207 208 209 210 211
    # 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)
212

213
# The coordinator of all worker threads, mostly running in main thread
214
class ThreadCoordinator:
215
    def __init__(self, pool: ThreadPool, dbManager):
216 217
        self._curStep = -1 # first step is 0
        self._pool = pool
218
        # self._wd = wd
219
        self._te = None # prepare for every new step
220
        self._dbManager = dbManager
221 222
        self._executedTasks: List[Task] = [] # in a given step
        self._lock = threading.RLock() # sync access for a few things
S
Steven Li 已提交
223

224
        self._stepBarrier = threading.Barrier(self._pool.numThreads + 1) # one barrier for all threads
225
        self._execStats = ExecutionStats()
226
        self._runStatus = MainExec.STATUS_RUNNING
S
Steven Li 已提交
227

228 229 230
    def getTaskExecutor(self):
        return self._te

231 232
    def getDbManager(self) -> DbManager :
        return self._dbManager
233

234 235 236
    def crossStepBarrier(self):
        self._stepBarrier.wait()

237 238 239 240
    def requestToStop(self):
        self._runStatus = MainExec.STATUS_STOPPING
        self._execStats.registerFailure("User Interruption")

241 242
    def run(self):              
        self._pool.createAndStartThreads(self)
S
Steven Li 已提交
243 244

        # Coordinate all threads step by step
245 246
        self._curStep = -1 # not started yet
        maxSteps = gConfig.max_steps # type: ignore
247
        self._execStats.startExec() # start the stop watch
248 249 250 251 252 253 254
        transitionFailed = False
        hasAbortedTask = False
        while(self._curStep < maxSteps-1 and 
            (not transitionFailed) and 
            (self._runStatus==MainExec.STATUS_RUNNING) and
            (not hasAbortedTask)):  # maxStep==10, last curStep should be 9

S
Steven Li 已提交
255 256 257
            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")
258

259
            # Now main thread (that's us) is ready to enter a step
260 261 262 263
            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"
264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297
            # We use this period to do house keeping work, when all worker threads are QUIET.
            hasAbortedTask = False
            for task in self._executedTasks :
                if task.isAborted() :
                    print("Task aborted: {}".format(task))
                    hasAbortedTask = True
                    break

            if hasAbortedTask : # do transition only if tasks are error free
                self._execStats.registerFailure("Aborted Task Encountered")
            else: 
                try:
                    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")
                    # Due to limitation (or maybe not) of the Python library, we cannot share connections across threads
                    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
                except taos.error.ProgrammingError as err:
                    if ( err.msg == 'network unavailable' ): # broken DB connection
                        logger.info("DB connection broken, execution failed")
                        traceback.print_stack()
                        transitionFailed = 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
298
            
299
            self.resetExecutedTasks() # clear the tasks after we are done
300 301

            # Get ready for next step
S
Steven Li 已提交
302
            logger.debug("<-- Step {} finished".format(self._curStep))
303
            self._curStep += 1 # we are about to get into next step. TODO: race condition here!                
304
            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
305

306
            # A new TE for the new step
307
            if not transitionFailed: # only if not failed
308
                self._te = TaskExecutor(self._curStep)
309

S
Steven Li 已提交
310
            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            
311
            self.tapAllThreads() # Worker threads will wake up at this point, and each execute it's own task
S
Steven Li 已提交
312

313
        logger.debug("Main thread ready to finish up...")
314
        if not transitionFailed: # only in regular situations
315 316 317 318 319 320 321
            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

322 323
        logger.debug("Main thread joining all threads")
        self._pool.joinAll() # Get all threads to finish
324
        logger.info("\nAll worker threads finished")
325 326
        self._execStats.endExec()

327 328
    def printStats(self):
        self._execStats.printStats()
S
Steven Li 已提交
329

S
Steven Li 已提交
330 331 332 333 334 335
    def isFailed(self):
        return self._execStats.isFailed()

    def getExecStats(self):
        return self._execStats

S
Steven Li 已提交
336 337
    def tapAllThreads(self): # in a deterministic manner
        wakeSeq = []
338
        for i in range(self._pool.numThreads): # generate a random sequence
S
Steven Li 已提交
339 340 341 342
            if Dice.throw(2) == 1 :
                wakeSeq.append(i)
            else:
                wakeSeq.insert(0, i)
343
        logger.debug("[TRD] Main thread waking up worker threads: {}".format(str(wakeSeq)))
344
        # TODO: set dice seed to a deterministic value
S
Steven Li 已提交
345
        for i in wakeSeq:
346
            self._pool.threadList[i].tapStepGate() # TODO: maybe a bit too deep?!
S
Steven Li 已提交
347 348
            time.sleep(0) # yield

349 350 351 352 353 354
    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")
355 356
        # return self._wd.pickTask()
        # Alternatively, let's ask the DbState for the appropriate task
357 358 359 360 361 362 363
        # 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?
364
        taskType = self.getDbManager().getStateMachine().pickTaskType() # pick a task type for current state
365
        return taskType(self.getDbManager(), self._execStats) # create a task from it
366 367 368

    def resetExecutedTasks(self):
        self._executedTasks = [] # should be under single thread
369 370 371 372

    def saveExecutedTask(self, task):
        with self._lock:
            self._executedTasks.append(task)
373 374

# We define a class to run a number of threads in locking steps.
375
class ThreadPool:
376
    def __init__(self, numThreads, maxSteps):
377 378 379 380
        self.numThreads = numThreads
        self.maxSteps = maxSteps
        # Internal class variables
        self.curStep = 0
381
        self.threadList = [] # type: List[WorkerThread]
382 383
        
    # starting to run all the threads, in locking steps
384
    def createAndStartThreads(self, tc: ThreadCoordinator):
385
        for tid in range(0, self.numThreads): # Create the threads
386
            workerThread = WorkerThread(self, tid, tc)            
387 388 389 390 391 392 393 394
            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()

395 396
# A queue of continguous POSITIVE integers, used by DbManager to generate continuous numbers
# for new table names
S
Steven Li 已提交
397 398
class LinearQueue():
    def __init__(self):
399
        self.firstIndex = 1  # 1st ever element
S
Steven Li 已提交
400
        self.lastIndex = 0
401
        self._lock = threading.RLock() # our functions may call each other
402
        self.inUse = set() # the indexes that are in use right now
S
Steven Li 已提交
403

404 405 406 407 408 409 410 411 412
    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
413 414
            # Otherwise we have something
            self.lastIndex += 1
415 416
            self.allocate(self.lastIndex)
            # self.inUse.add(self.lastIndex) # mark it in use immediately
417
            return self.lastIndex
S
Steven Li 已提交
418 419

    def pop(self):
420
        with self._lock:
421
            if ( self.isEmpty() ): 
422 423 424
                # raise RuntimeError("Cannot pop an empty queue") 
                return False # TODO: None?
            
425
            index = self.firstIndex
426
            if ( index in self.inUse ):
427 428
                return False

429 430 431 432 433 434 435
            self.firstIndex += 1
            return index

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

    def popIfNotEmpty(self):
436
        with self._lock:
437 438 439 440
            if (self.isEmpty()):
                return 0
            return self.pop()

S
Steven Li 已提交
441
    def allocate(self, i):
442
        with self._lock:
443
            # logger.debug("LQ allocating item {}".format(i))
444 445 446 447
            if ( i in self.inUse ):
                raise RuntimeError("Cannot re-use same index in queue: {}".format(i))
            self.inUse.add(i)

S
Steven Li 已提交
448
    def release(self, i):
449
        with self._lock:
450 451
            # logger.debug("LQ releasing item {}".format(i))
            self.inUse.remove(i) # KeyError possible, TODO: why?
452 453 454 455

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

S
Steven Li 已提交
456
    def pickAndAllocate(self):
457 458 459
        if ( self.isEmpty() ):
            return None
        with self._lock:
460 461 462 463
            cnt = 0 # counting the interations
            while True:
                cnt += 1
                if ( cnt > self.size()*10 ): # 10x iteration already
464 465
                    # raise RuntimeError("Failed to allocate LinearQueue element")
                    return None
466 467
                ret = Dice.throwRange(self.firstIndex, self.lastIndex+1)
                if ( not ret in self.inUse ):
468 469 470 471
                    self.allocate(ret)
                    return ret

class DbConn:
472 473 474 475 476 477 478 479 480 481 482 483 484 485 486 487 488 489 490 491 492
    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)

493 494
    def __init__(self):
        self.isOpen = False
495 496 497
        self._type = self.TYPE_INVALID

    def open(self):
498 499 500
        if ( self.isOpen ):
            raise RuntimeError("Cannot re-open an existing DB connection")

501 502
        # below implemented by child classes
        self.openByType()
503

504
        logger.debug("[DB] data connection opened, type = {}".format(self._type))
505 506 507 508 509
        self.isOpen = True

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

512
        self.execute('drop database if exists db')
513 514
        logger.debug("Resetting DB, dropped database")
        # self._cursor.execute('create database db')
515
        # self._cursor.execute('use db')
516 517
        # tdSql.execute('show databases')

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 597 598 599 600 601 602 603 604 605 606 607 608
    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")
    
609 610 611 612 613 614 615 616 617 618 619 620 621 622 623 624 625 626 627 628 629 630 631 632 633 634 635 636 637 638 639 640 641 642 643 644 645 646 647 648 649
    # Duplicate code from TDMySQL, TODO: merge all this into DbConnNative
class MyTDSql:
    def __init__(self):
        self.queryRows = 0
        self.queryCols = 0
        self.affectedRows = 0

    def init(self, cursor, log=True):
        self.cursor = cursor
        # if (log):
        #     caller = inspect.getframeinfo(inspect.stack()[1][0])
        #     self.cursor.log(caller.filename + ".sql")

    def close(self):
        self.cursor.close()

    def query(self, sql):
        self.sql = sql
        try:
            self.cursor.execute(sql)
            self.queryResult = self.cursor.fetchall()
            self.queryRows = len(self.queryResult)
            self.queryCols = len(self.cursor.description)
        except Exception as e:
            # caller = inspect.getframeinfo(inspect.stack()[1][0])
            # args = (caller.filename, caller.lineno, sql, repr(e))
            # tdLog.exit("%s(%d) failed: sql:%s, %s" % args)
            raise
        return self.queryRows
    
    def execute(self, sql):
        self.sql = sql
        try:
            self.affectedRows = self.cursor.execute(sql)
        except Exception as e:
            # caller = inspect.getframeinfo(inspect.stack()[1][0])
            # args = (caller.filename, caller.lineno, sql, repr(e))
            # tdLog.exit("%s(%d) failed: sql:%s, %s" % args)
            raise
        return self.affectedRows

650 651 652 653 654 655 656 657 658 659 660 661 662 663 664 665 666
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
667
        self._tdSql = MyTDSql()
668 669
        self._tdSql.init(self._cursor)
        
670 671 672 673
    def close(self):
        if ( not self.isOpen ):
            raise RuntimeError("Cannot clean up database until connection is open")
        self._tdSql.close()
674
        logger.debug("[DB] Database connection closed")
675
        self.isOpen = False
S
Steven Li 已提交
676

677
    def execute(self, sql): 
678
        if ( not self.isOpen ):
679
            raise RuntimeError("Cannot execute database commands until connection is open")
680 681 682 683
        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 已提交
684

685
    def query(self, sql) :  # return rows affected
686 687
        if ( not self.isOpen ):
            raise RuntimeError("Cannot query database until connection is open")
688 689
        logger.debug("[SQL] Executing SQL: {}".format(sql))
        nRows = self._tdSql.query(sql)
690
        logger.debug("[SQL] Query Result, nRows = {}, SQL = {}".format(nRows, sql))
691
        return nRows
692
        # results are in: return self._tdSql.queryResult
693

694 695 696
    def getQueryResult(self):
        return self._tdSql.queryResult

697 698
    def getResultRows(self):
        return self._tdSql.queryRows
699

700 701
    def getResultCols(self):
        return self._tdSql.queryCols
702 703 704

    
class AnyState:
705
    STATE_INVALID    = -1
706 707 708 709
    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
710 711 712 713 714
    _stateNames = ["Invalid", "Empty", "DB_Only", "Table_Only", "Has_Data"]

    STATE_VAL_IDX = 0
    CAN_CREATE_DB = 1
    CAN_DROP_DB = 2
715 716
    CAN_CREATE_FIXED_SUPER_TABLE = 3
    CAN_DROP_FIXED_SUPER_TABLE = 4
717 718 719 720 721 722 723
    CAN_ADD_DATA = 5
    CAN_READ_DATA = 6

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

    def __str__(self):
S
Steven Li 已提交
724
        return self._stateNames[self._info[self.STATE_VAL_IDX] + 1] # -1 hack to accomodate the STATE_INVALID case
725 726 727 728

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

S
Steven Li 已提交
729 730 731 732 733 734 735 736
    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)))

737 738 739
    def verifyTasksToState(self, tasks, newState):
        raise RuntimeError("Must be overriden by child classes")

S
Steven Li 已提交
740 741 742
    def getValIndex(self):
        return self._info[self.STATE_VAL_IDX]

743 744 745 746 747 748
    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]
749 750 751 752
    def canCreateFixedSuperTable(self):
        return self._info[self.CAN_CREATE_FIXED_SUPER_TABLE]
    def canDropFixedSuperTable(self):
        return self._info[self.CAN_DROP_FIXED_SUPER_TABLE]
753 754 755 756 757 758 759 760 761 762 763
    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 已提交
764
                # task.logDebug("Task success found")
765 766 767 768 769 770 771 772 773 774 775 776 777 778 779 780 781 782 783 784 785 786 787 788 789 790 791 792 793 794 795 796 797 798 799
                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 已提交
800 801 802 803 804 805
    def hasTask(self, tasks, cls):
        for task in tasks :
            if isinstance(task, cls):
                return True
        return False

806 807 808 809 810 811 812 813 814 815 816 817 818 819 820 821 822 823 824 825
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 已提交
826
    def verifyTasksToState(self, tasks, newState): 
827 828 829
        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
830 831 832 833 834 835 836 837 838 839 840

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

    def verifyTasksToState(self, tasks, newState):
841 842 843
        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 已提交
844
        # self.assertAtMostOneSuccess(tasks, CreateFixedTableTask) # not true in massively parrallel cases
845
        # Nothing to be said about adding data task
846
        # if ( self.hasSuccess(tasks, DropDbTask) ): # dropped the DB
847
            # self.assertHasTask(tasks, DropDbTask) # implied by hasSuccess
848
            # self.assertAtMostOneSuccess(tasks, DropDbTask)
849
            # self._state = self.STATE_EMPTY
850 851 852 853
        # 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
854
            # self.assertNoTask(tasks, DropDbTask) # should have have tried
855 856 857 858 859 860 861 862 863 864 865 866
            # 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

867
class StateSuperTableOnly(AnyState):
868 869 870 871 872 873 874 875 876
    def getInfo(self):
        return [
            self.STATE_TABLE_ONLY,
            False, True,
            False, True,
            True, True,
        ]

    def verifyTasksToState(self, tasks, newState):
877
        if ( self.hasSuccess(tasks, TaskDropSuperTable) ): # we are able to drop the table
878 879 880
            #self.assertAtMostOneSuccess(tasks, TaskDropSuperTable)
            self.hasSuccess(tasks, TaskCreateSuperTable) # we must have had recreted it

881
            # self._state = self.STATE_DB_ONLY
S
Steven Li 已提交
882 883
        # elif ( self.hasSuccess(tasks, AddFixedDataTask) ): # no success dropping the table, but added data
        #     self.assertNoTask(tasks, DropFixedTableTask) # not true in massively parrallel cases
884
            # self._state = self.STATE_HAS_DATA
S
Steven Li 已提交
885 886 887
        # elif ( self.hasSuccess(tasks, ReadFixedDataTask) ): # no success in prev cases, but was able to read data
            # self.assertNoTask(tasks, DropFixedTableTask)
            # self.assertNoTask(tasks, AddFixedDataTask)
888
            # self._state = self.STATE_TABLE_ONLY # no change
S
Steven Li 已提交
889 890 891
        # 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!!
892 893 894 895 896 897 898 899 900 901 902

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 已提交
903
        if ( newState.equals(AnyState.STATE_EMPTY) ):
904 905 906
            self.hasSuccess(tasks, TaskDropDb)
            if ( not self.hasTask(tasks, TaskCreateDb) ) : 
                self.assertAtMostOneSuccess(tasks, TaskDropDb) # TODO: dicy
S
Steven Li 已提交
907
        elif ( newState.equals(AnyState.STATE_DB_ONLY) ): # in DB only
908 909 910
            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)
911
            # self.assertAtMostOneSuccess(tasks, DropFixedSuperTableTask) # TODO: dicy
912 913 914 915
        # elif ( newState.equals(AnyState.STATE_TABLE_ONLY) ): # data deleted
            # self.assertNoTask(tasks, TaskDropDb)
            # self.assertNoTask(tasks, TaskDropSuperTable)
            # self.assertNoTask(tasks, TaskAddData)
S
Steven Li 已提交
916
            # self.hasSuccess(tasks, DeleteDataTasks)
917
        else: # should be STATE_HAS_DATA
918 919
            if (not self.hasTask(tasks, TaskCreateDb) ): # only if we didn't create one
                self.assertNoTask(tasks, TaskDropDb) # we shouldn't have dropped it
920 921
            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            
922
            # self.assertIfExistThenSuccess(tasks, ReadFixedDataTask)
S
Steven Li 已提交
923

924
class StateMechine:
925 926 927 928 929 930 931 932
    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

933 934 935
    def hasDatabase(self):
        return self._curState.canDropDb()  # ha, can drop DB means it has one

936 937
    # May be slow, use cautionsly...
    def getTaskTypes(self): # those that can run (directly/indirectly) from the current state
938 939 940 941 942 943
        def typesToStrings(types):
            ss = []
            for t in types:
                ss.append(t.__name__)
            return ss

944 945 946 947 948 949 950 951 952 953 954 955 956 957 958 959 960 961
        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))   
962
        logger.debug("[OPS] Tasks found for state {}: {}".format(self._curState, typesToStrings(taskTypes)))     
963 964 965 966 967 968 969 970 971
        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()
972
        dbc.execute("use db") # did not do this when openning connection, and this is NOT the worker thread, which does this on their own
973 974 975 976 977 978 979 980 981 982 983 984 985 986 987
        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
988
            logger.debug("[STT] Starting State: {}".format(self._curState))
989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036 1037 1038 1039
            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
1040

1041
# Manager of the Database Data/Connection
1042
class DbManager():    
1043
    def __init__(self, resetDb = True):
S
Steven Li 已提交
1044
        self.tableNumQueue = LinearQueue()
1045
        self._lastTick = self.setupLastTick() # datetime.datetime(2019, 1, 1) # initial date time tick
1046 1047
        self._lastInt  = 0 # next one is initial integer 
        self._lock = threading.RLock()
1048
        
1049
        # self.openDbServerConnection()
1050
        self._dbConn = DbConn.createNative() if (gConfig.connector_type=='native') else DbConn.createRest()
1051 1052 1053 1054
        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))
1055
            if ( err.msg == 'client disconnected' ): # cannot open DB connection
1056
                print("Cannot establish DB connection, please re-run script without parameter, and follow the instructions.")
S
Steven Li 已提交
1057
                sys.exit(2)
1058 1059 1060
            else:
                raise            
        except:
S
Steven Li 已提交
1061
            print("[=] Unexpected exception")
1062
            raise        
1063 1064 1065

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

1067 1068
        self._stateMachine = StateMechine(self._dbConn) # Do this after dbConn is in proper shape
        
1069 1070 1071
    def getDbConn(self):
        return self._dbConn

1072
    def getStateMachine(self) -> StateMechine :
1073 1074 1075 1076
        return self._stateMachine

    # def getState(self):
    #     return self._stateMachine.getCurrentState()
1077 1078 1079 1080 1081 1082

    # 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
1083
    # TODO: fix the error as result of above: "tsdb timestamp is out of range"
1084
    def setupLastTick(self):
1085
        t1 = datetime.datetime(2020, 6, 1)
1086
        t2 = datetime.datetime.now()
1087 1088
        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
1089 1090
        # print("elSec = {}".format(elSec))
        t3 = datetime.datetime(2012, 1, 1) # default "keep" is 10 years
1091
        t4 = datetime.datetime.fromtimestamp( t3.timestamp() + elSec2) # see explanation above
1092 1093 1094
        logger.info("Setting up TICKS to start from: {}".format(t4))
        return t4

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

1098 1099 1100 1101 1102
    def addTable(self):
        with self._lock:
            tIndex = self.tableNumQueue.push()
        return tIndex

1103 1104
    @classmethod
    def getFixedSuperTableName(cls):
1105
        return "fs_table"
1106

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

1110
    def getNextTick(self):
1111
        with self._lock: # prevent duplicate tick
S
Steven Li 已提交
1112 1113 1114 1115 1116
            if Dice.throw(10) == 0 : # 1 in 10 chance
                return self._lastTick + datetime.timedelta(0, -100)
            else: # regular
                self._lastTick += datetime.timedelta(0, 1) # add one second to it
                return self._lastTick
1117 1118

    def getNextInt(self):
1119 1120 1121
        with self._lock:
            self._lastInt += 1
            return self._lastInt
1122 1123

    def getNextBinary(self):
1124
        return "Beijing_Shanghai_Los_Angeles_New_York_San_Francisco_Chicago_Beijing_Shanghai_Los_Angeles_New_York_San_Francisco_Chicago_{}".format(self.getNextInt())
1125 1126 1127

    def getNextFloat(self):
        return 0.9 + self.getNextInt()
1128
    
S
Steven Li 已提交
1129
    def getTableNameToDelete(self):
1130
        tblNum = self.tableNumQueue.pop() # TODO: race condition!
1131 1132 1133
        if ( not tblNum ): # maybe false
            return False
        
S
Steven Li 已提交
1134 1135
        return "table_{}".format(tblNum)

1136 1137 1138
    def cleanUp(self):
        self._dbConn.close()      

1139
class TaskExecutor():
1140 1141 1142 1143 1144 1145 1146 1147 1148 1149 1150 1151 1152 1153 1154 1155 1156 1157 1158 1159 1160 1161 1162 1163 1164 1165 1166 1167 1168 1169 1170 1171 1172 1173 1174 1175 1176
    class BoundedList:
        def __init__(self, size = 10):
            self._size = size
            self._list = []

        def add(self, n: int) :
            if not self._list: # empty
                self._list.append(n)
                return
            # now we should insert
            nItems = len(self._list)
            insPos = 0
            for i in range(nItems):
                insPos = i
                if n <= self._list[i] : # smaller than this item, time to insert
                    break # found the insertion point
                insPos += 1 # insert to the right

            if insPos == 0 : # except for the 1st item, # TODO: elimiate first item as gating item
                return # do nothing

            # print("Inserting at postion {}, value: {}".format(insPos, n))
            self._list.insert(insPos, n) # insert
            
            newLen = len(self._list)
            if newLen <= self._size :
                return # do nothing
            elif newLen == (self._size + 1) :                
                del self._list[0] # remove the first item
            else :
                raise RuntimeError("Corrupt Bounded List")

        def __str__(self):
            return repr(self._list)

    _boundedList = BoundedList()

1177 1178 1179
    def __init__(self, curStep):
        self._curStep = curStep

1180 1181 1182 1183
    @classmethod
    def getBoundedList(cls):
        return cls._boundedList

1184 1185 1186
    def getCurStep(self):
        return self._curStep

1187 1188
    def execute(self, task: Task, wt: WorkerThread): # execute a task on a thread
        task.execute(wt)
1189

1190 1191 1192 1193
    def recordDataMark(self, n: int):
        # print("[{}]".format(n), end="", flush=True)
        self._boundedList.add(n)

1194 1195
    # def logInfo(self, msg):
    #     logger.info("    T[{}.x]: ".format(self._curStep) + msg)
1196

1197 1198
    # def logDebug(self, msg):
    #     logger.debug("    T[{}.x]: ".format(self._curStep) + msg)
1199

S
Steven Li 已提交
1200
class Task():
1201 1202 1203 1204
    taskSn = 100

    @classmethod
    def allocTaskNum(cls):
S
Steven Li 已提交
1205 1206 1207
        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
1208

1209
    def __init__(self, dbManager: DbManager, execStats: ExecutionStats):        
1210
        self._dbManager = dbManager
1211
        self._workerThread = None 
1212
        self._err = None
1213
        self._aborted = False
1214
        self._curStep = None
1215
        self._numRows = None # Number of rows affected
1216 1217 1218

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

1221
        self._execStats = execStats
1222
        self._lastSql = "" # last SQL executed/attempted
1223

1224 1225
    def isSuccess(self):
        return self._err == None
1226

1227 1228 1229
    def isAborted(self):
        return self._aborted

1230
    def clone(self): # TODO: why do we need this again?
1231
        newTask = self.__class__(self._dbManager, self._execStats)
1232 1233 1234
        return newTask

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

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

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

1243 1244
    def execute(self, wt: WorkerThread):
        wt.verifyThreadSelf()
1245
        self._workerThread = wt # type: ignore
1246 1247

        te = wt.getTaskExecutor()
1248 1249
        self._curStep = te.getCurStep()
        self.logDebug("[-] executing task {}...".format(self.__class__.__name__))
1250 1251

        self._err = None
1252
        self._execStats.beginTaskType(self.__class__.__name__) # mark beginning
1253 1254 1255
        try:
            self._executeInternal(te, wt) # TODO: no return value?
        except taos.error.ProgrammingError as err:
1256
            errno2 = err.errno if (err.errno > 0) else 0x80000000 + err.errno # correct error scheme
1257 1258 1259 1260 1261
            if ( errno2 in [
                0x05, # TSDB_CODE_RPC_NOT_READY
                0x200, 0x360, 0x362, 0x36A, 0x36B, 0x36D, 0x381, 0x380, 0x383, 0x503, 
                0x510, # vnode not in ready state
                0x600,
1262 1263
                1000 # REST catch-all error
                ]) : # allowed errors
1264
                self.logDebug("[=] Acceptable Taos library exception: errno=0x{:X}, msg: {}, SQL: {}".format(errno2, err, self._lastSql))
1265
                print("_", end="", flush=True)
1266 1267
                self._err = err  
            else:
1268 1269 1270
                errMsg = "[=] Unexpected Taos library exception: errno=0x{:X}, msg: {}, SQL: {}".format(errno2, err, self._lastSql)
                self.logDebug(errMsg)
                if gConfig.debug :
1271 1272 1273 1274 1275 1276 1277
                    # raise # so that we see full stack
                    traceback.print_exc()
                print("\n\n----------------------------\nProgram ABORTED Due to Unexpected TAOS Error: \n\n{}\n".format(errMsg) +
                    "----------------------------\n")
                # sys.exit(-1)
                self._err = err
                self._aborted = True
S
Steven Li 已提交
1278 1279 1280 1281
        except Exception as e :
            self.logInfo("Non-TAOS exception encountered")
            self._err = e 
            self._aborted = True
1282 1283 1284 1285 1286
            traceback.print_exc()
        except BaseException as e :
            self.logInfo("Python base exception encountered")
            self._err = e 
            self._aborted = True
S
Steven Li 已提交
1287 1288
            traceback.print_exc()
        except :
1289
            self.logDebug("[=] Unexpected exception, SQL: {}".format(self._lastSql))
1290
            raise
1291
        self._execStats.endTaskType(self.__class__.__name__, self.isSuccess())
1292
        
1293 1294
        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 已提交
1295

1296
    def execSql(self, sql):
1297
        self._lastSql = sql
1298
        return self._dbManager.execute(sql)
1299

1300 1301 1302 1303 1304 1305 1306 1307 1308 1309 1310 1311
    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()


1312
                  
1313
class ExecutionStats:
1314 1315 1316 1317 1318
    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
1319 1320
        self._execStartTime = None
        self._elapsedTime = 0.0 # total elapsed time
1321 1322
        self._accRunTime = 0.0 # accumulated run time

1323 1324 1325
        self._failed = False
        self._failureReason = None

S
Steven Li 已提交
1326 1327 1328 1329 1330 1331
    def __str__(self):
        return "[ExecStats: _failed={}, _failureReason={}".format(self._failed, self._failureReason)

    def isFailed(self):
        return self._failed == True

1332 1333 1334 1335 1336 1337
    def startExec(self):
        self._execStartTime = time.time()

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

1338 1339 1340 1341 1342 1343 1344 1345 1346 1347 1348 1349 1350 1351 1352 1353 1354 1355 1356 1357 1358
    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

1359 1360 1361 1362
    def registerFailure(self, reason):
        self._failed = True
        self._failureReason = reason

1363
    def printStats(self):
1364 1365 1366 1367
        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):")
1368 1369
        execTimesAny = 0
        for k, n in self._execTimes.items():            
1370
            execTimesAny += n[0]
1371
            logger.info("|    {0:<24}: {1}/{2}".format(k,n[1],n[0]))
1372
                
1373 1374 1375 1376 1377
        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))
1378
        logger.info("| Top numbers written: {}".format(TaskExecutor.getBoundedList()))
1379 1380
        logger.info("----------------------------------------------------------------------")
        
1381 1382 1383


class StateTransitionTask(Task):
1384 1385 1386 1387 1388
    LARGE_NUMBER_OF_TABLES = 35
    SMALL_NUMBER_OF_TABLES = 3
    LARGE_NUMBER_OF_RECORDS = 50
    SMALL_NUMBER_OF_RECORDS = 3

1389 1390 1391 1392
    @classmethod
    def getInfo(cls): # each sub class should supply their own information
        raise RuntimeError("Overriding method expected")

1393 1394 1395 1396 1397
    _endState = None 
    @classmethod
    def getEndState(cls): # TODO: optimize by calling it fewer times
        raise RuntimeError("Overriding method expected")

1398 1399 1400
    # @classmethod
    # def getBeginStates(cls):
    #     return cls.getInfo()[0]
1401

1402 1403 1404
    # @classmethod
    # def getEndState(cls): # returning the class name
    #     return cls.getInfo()[0]
1405 1406

    @classmethod
1407 1408 1409
    def canBeginFrom(cls, state: AnyState):
        # return state.getValue() in cls.getBeginStates()
        raise RuntimeError("must be overriden")
1410

1411 1412 1413 1414
    @classmethod
    def getRegTableName(cls, i):
        return "db.reg_table_{}".format(i)

1415 1416 1417
    def execute(self, wt: WorkerThread):
        super().execute(wt)
        
1418
class TaskCreateDb(StateTransitionTask):
1419
    @classmethod
1420 1421
    def getEndState(cls):
        return StateDbOnly() 
1422

1423 1424 1425 1426
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canCreateDb()

1427
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1428
        self.execWtSql(wt, "create database db")       
1429

1430
class TaskDropDb(StateTransitionTask):
1431
    @classmethod
1432 1433
    def getEndState(cls):
        return StateEmpty()
1434

1435 1436 1437 1438
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canDropDb()

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

1443
class TaskCreateSuperTable(StateTransitionTask):
1444
    @classmethod
1445 1446
    def getEndState(cls):
        return StateSuperTableOnly()
1447

1448 1449
    @classmethod
    def canBeginFrom(cls, state: AnyState):
1450
        return state.canCreateFixedSuperTable()
1451

1452
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1453 1454 1455 1456 1457 1458 1459
        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))
1460 1461
        # No need to create the regular tables, INSERT will do that automatically

S
Steven Li 已提交
1462

1463
class TaskReadData(StateTransitionTask):
1464
    @classmethod
1465 1466
    def getEndState(cls):
        return None # meaning doesn't affect state
1467

1468 1469 1470 1471
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canReadData()

1472
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1473
        sTbName = self._dbManager.getFixedSuperTableName()        
1474 1475
        self.queryWtSql(wt, "select TBNAME from db.{}".format(sTbName)) # TODO: analyze result set later

1476
        if random.randrange(5) == 0 : # 1 in 5 chance, simulate a broken connection. TODO: break connection in all situations
1477 1478
            wt.getDbConn().close()
            wt.getDbConn().open()
1479
        else:
1480
            rTables = self.getQueryResult(wt) # wt.getDbConn().getQueryResult()
1481 1482
            # print("rTables[0] = {}, type = {}".format(rTables[0], type(rTables[0])))
            for rTbName in rTables : # regular tables
1483
                self.execWtSql(wt, "select * from db.{}".format(rTbName[0]))
1484

1485 1486
        # tdSql.query(" cars where tbname in ('carzero', 'carone')")

1487
class TaskDropSuperTable(StateTransitionTask):
1488
    @classmethod
1489 1490
    def getEndState(cls):
        return StateDbOnly() 
1491

1492 1493
    @classmethod
    def canBeginFrom(cls, state: AnyState):
1494
        return state.canDropFixedSuperTable()
1495

1496
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1497 1498 1499 1500 1501
        # 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"
1502
            isSuccess = True
1503
            for i in tblSeq: 
1504
                regTableName = self.getRegTableName(i); # "db.reg_table_{}".format(i)                  
1505
                try:
1506
                    self.execWtSql(wt, "drop table {}".format(regTableName)) # nRows always 0, like MySQL
1507 1508
                except taos.error.ProgrammingError as err:                    
                    errno2 = err.errno if (err.errno > 0) else 0x80000000 + err.errno # correcting for strange error number scheme
1509 1510
                    if ( errno2 in [0x362]) : # mnode invalid table name
                        isSuccess = False
1511
                        logger.debug("[DB] Acceptable error when dropping a table")
1512
                    continue # try to delete next regular table
1513 1514 1515

                if (not tickOutput):
                    tickOutput = True # Print only one time
1516
                    if isSuccess :
1517 1518
                        print("d", end="", flush=True)
                    else:
1519
                        print("f", end="", flush=True)                    
1520 1521 1522 1523

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

1525 1526 1527 1528 1529 1530 1531 1532 1533 1534 1535 1536 1537
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 :
1538
            sql = "alter table db.{} add tag extraTag int".format(tblName)
1539
        elif dice == 1 :
1540
            sql = "alter table db.{} drop tag extraTag".format(tblName)
1541
        elif dice == 2 :
1542
            sql = "alter table db.{} drop tag newTag".format(tblName)
1543
        else: # dice == 3
1544 1545 1546
            sql = "alter table db.{} change tag extraTag newTag".format(tblName)

        self.execWtSql(wt, sql)
1547

1548
class TaskAddData(StateTransitionTask):
1549
    activeTable : Set[int] = set() # Track which table is being actively worked on
1550 1551 1552 1553 1554 1555 1556 1557 1558 1559 1560 1561 1562 1563

    # 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")
1564

1565
    @classmethod
1566 1567
    def getEndState(cls):
        return StateHasData()
1568 1569 1570 1571

    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canAddData()
1572 1573
        
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1574
        ds = self._dbManager
1575
        # wt.execSql("use db") # TODO: seems to be an INSERT bug to require this
1576
        tblSeq = list(range(self.LARGE_NUMBER_OF_TABLES if gConfig.larger_data else self.SMALL_NUMBER_OF_TABLES)) 
1577 1578 1579 1580 1581 1582 1583 1584
        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
1585 1586
            # No need to shuffle data sequence, unless later we decide to do non-increment insertion      
            regTableName = self.getRegTableName(i); # "db.reg_table_{}".format(i)      
1587
            for j in range(self.LARGE_NUMBER_OF_RECORDS if gConfig.larger_data else self.SMALL_NUMBER_OF_RECORDS) : # number of records per table
1588
                nextInt = ds.getNextInt()                
1589 1590 1591 1592 1593 1594 1595
                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, 
1596 1597
                    ds.getFixedSuperTableName(), 
                    ds.getNextBinary(), ds.getNextFloat(),
1598
                    ds.getNextTick(), nextInt)
1599
                self.execWtSql(wt, sql) 
1600 1601
                # Successfully wrote the data into the DB, let's record it somehow
                te.recordDataMark(nextInt)
1602 1603 1604 1605
                if gConfig.record_ops:
                    self.fAddLogDone.write("Wrote {} to {}\n".format(nextInt, regTableName))
                    self.fAddLogDone.flush()
                    os.fsync(self.fAddLogDone)
1606
            self.activeTable.discard(i) # not raising an error, unlike remove
1607 1608


S
Steven Li 已提交
1609 1610 1611 1612 1613 1614 1615 1616 1617 1618 1619 1620 1621 1622 1623 1624 1625 1626 1627 1628 1629 1630
# 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
1631 1632
    def throw(cls, stop): # get 0 to stop-1
        return cls.throwRange(0, stop)
S
Steven Li 已提交
1633 1634

    @classmethod
1635
    def throwRange(cls, start, stop): # up to stop-1
S
Steven Li 已提交
1636 1637
        if ( not cls.seeded ):
            raise RuntimeError("Cannot throw dice before seeding it")
1638
        return random.randrange(start, stop)
S
Steven Li 已提交
1639

S
Steven Li 已提交
1640 1641
class LoggingFilter(logging.Filter):
    def filter(self, record: logging.LogRecord):
S
Steven Li 已提交
1642 1643 1644
        if ( record.levelno >= logging.INFO ) :
            return True # info or above always log

S
Steven Li 已提交
1645 1646 1647 1648
        # Commenting out below to adjust...

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

1651 1652 1653 1654 1655
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

1656 1657
class SvcManager:    
    def __init__(self):
1658
        print("Starting TDengine Service Manager")
1659
        signal.signal(signal.SIGTERM, self.sigIntHandler)
1660 1661 1662 1663 1664 1665
        signal.signal(signal.SIGINT,  self.sigIntHandler)
        signal.signal(signal.SIGUSR1, self.sigUsrHandler) # different handler!
        
        self.inSigHandler = False
        # self._status = MainExec.STATUS_RUNNING # set inside _startTaosService()
        self.svcMgrThread = None
1666

1667 1668 1669 1670 1671 1672 1673 1674 1675 1676 1677 1678 1679 1680 1681 1682 1683 1684 1685 1686 1687
    def _doMenu(self):
        choice = ""
        while True:
            print("\nInterrupting Service Program, Choose an Action: ")
            print("1: Resume")
            print("2: Terminate")
            print("3: Restart")
            # Remember to update the if range below
            # print("Enter Choice: ", end="", flush=True)            
            while choice == "":
                choice = input("Enter Choice: ")
                if choice != "":
                    break # done with reading repeated input
            if choice in ["1", "2", "3"]: 
                break # we are done with whole method
            print("Invalid choice, please try again.")
            choice = "" # reset
        return choice

    def sigUsrHandler(self, signalNumber, frame) :
        print("Interrupting main thread execution upon SIGUSR1")
1688
        if self.inSigHandler : # already
1689
            print("Ignoring repeated SIG...")
1690
            return # do nothing if it's already not running
1691
        self.inSigHandler = True
1692 1693 1694 1695 1696

        choice = self._doMenu()
        if choice == "1" :
            self.sigHandlerResume() # TODO: can the sub-process be blocked due to us not reading from queue?
        elif choice == "2" :
1697
            self.stopTaosService()
1698
        elif choice == "3" :
1699 1700
            self.stopTaosService()
            self.startTaosService()
1701 1702
        else:
            raise RuntimeError("Invalid menu choice: {}".format(choice))
1703

1704 1705
        self.inSigHandler = False

1706 1707
    def sigIntHandler(self, signalNumber, frame):
        print("Sig INT Handler starting...")
1708
        if self.inSigHandler :
1709 1710
            print("Ignoring repeated SIG_INT...")
            return
1711 1712
        self.inSigHandler = True
 
1713
        self.stopTaosService()  
1714
        print("INT signal handler returning...")  
1715
        self.inSigHandler = False
1716 1717 1718

    def sigHandlerResume(self) :
        print("Resuming TDengine service manager thread (main thread)...\n\n")
1719 1720 1721 1722 1723 1724 1725 1726 1727 1728 1729 1730 1731 1732 1733 1734 1735 1736 1737 1738 1739 1740 1741 1742 1743 1744 1745 1746 1747 1748 1749 1750 1751 1752 1753 1754 1755 1756 1757 1758 1759 1760 1761 1762 1763 1764 1765 1766 1767 1768 1769 1770 1771 1772 1773 1774 1775 1776 1777 1778 1779 1780 1781 1782 1783 1784 1785 1786 1787 1788 1789 1790 1791 1792 1793 1794 1795 1796 1797 1798 1799 1800 1801 1802 1803 1804 1805 1806 1807 1808 1809 1810 1811 1812 1813 1814 1815 1816 1817 1818 1819 1820 1821 1822 1823
    
    def _checkServiceManagerThread(self):
        if self.svcMgrThread: # valid svc mgr thread
            if self.svcMgrThread.isStopped(): # done?
                self.svcMgrThread.procIpcBatch() # one last time. TODO: appropriate?
                self.svcMgrThread = None # no more

    def _procIpcAll(self):
        while self.svcMgrThread : # for as long as the svc mgr thread is still here
            self.svcMgrThread.procIpcBatch() # regular processing,
            time.sleep(0.5) # pause, before next round
            self._checkServiceManagerThread()            
        print("Service Manager Thread (with subprocess) has ended, main thread now exiting...")

    def startTaosService(self):        
        if self.svcMgrThread:
            raise RuntimeError("Cannot start TAOS service when one may already be running")
        self.svcMgrThread = ServiceManagerThread() # create the object
        self.svcMgrThread.start()
        print("TAOS service started, printing out output...")
        self.svcMgrThread.procIpcBatch(trimToTarget=10, forceOutput=True) # for printing 10 lines
        print("TAOS service started")
        
    def stopTaosService(self, outputLines = 20):
        print("Terminating Service Manager Thread (SMT) execution...")
        if not self.svcMgrThread:
            raise RuntimeError("Unexpected empty svc mgr thread")
        self.svcMgrThread.stop()
        if self.svcMgrThread.isStopped():
            self.svcMgrThread.procIpcBatch(outputLines) # one last time
            self.svcMgrThread = None 
            print("----- End of TDengine Service Output -----\n")
            print("SMT execution terminated")
        else:
            print("WARNING: SMT did not terminate as expected")

    def run(self):
        self.startTaosService()
        self._procIpcAll() # pump/process all the messages
        if self.svcMgrThread: # if sig handler hasn't destroyed it by now
            self.stopTaosService() # should have started already
        
class ServiceManagerThread:
    MAX_QUEUE_SIZE = 10000

    def __init__(self):
        self._tdeSubProcess = None
        self._thread = None        
        self._status = None

    def getStatus(self):
        return self._status

    def isRunning(self):
        # return self._thread and self._thread.is_alive()
        return self._status == MainExec.STATUS_RUNNING

    def isStopping(self):
        return self._status == MainExec.STATUS_STOPPING

    def isStopped(self):
        return self._status == MainExec.STATUS_STOPPED

    # Start the thread (with sub process), and wait for the sub service
    # to become fully operational
    def start(self):        
        if self._thread :
            raise RuntimeError("Unexpected _thread")
        if self._tdeSubProcess :
            raise RuntimeError("TDengine sub process already created/running")

        self._status = MainExec.STATUS_STARTING

        self._tdeSubProcess = TdeSubProcess()        
        self._tdeSubProcess.start()

        self._ipcQueue = Queue()
        self._thread = threading.Thread(
            target=self.svcOutputReader, 
            args=(self._tdeSubProcess.getStdOut(), self._ipcQueue))
        self._thread.daemon = True # thread dies with the program
        self._thread.start()

        # wait for service to start
        for i in range(0, 10) :
            time.sleep(1.0)
            # self.procIpcBatch() # don't pump message during start up
            print("_zz_", end="", flush=True)
            if self._status == MainExec.STATUS_RUNNING :
                logger.info("[] TDengine service READY to process requests")
                return # now we've started
        raise RuntimeError("TDengine service did not start successfully") # TODO: handle this better?

    def stop(self):
        # can be called from both main thread or signal handler
        print("Terminating TDengine service running as the sub process...")
        if self.isStopped():
            print("Service already stopped")
            return            
        if self.isStopping():
            print("Service is already being stopped")
            return
        # Linux will send Control-C generated SIGINT to the TDengine process already, ref: https://unix.stackexchange.com/questions/176235/fork-and-how-signals-are-delivered-to-processes
        if not self._tdeSubProcess :
            raise RuntimeError("sub process object missing")
1824

1825 1826 1827 1828 1829 1830 1831 1832 1833 1834 1835 1836 1837 1838 1839 1840 1841 1842
        self._status = MainExec.STATUS_STOPPING
        self._tdeSubProcess.stop()

        if self._tdeSubProcess.isRunning(): # still running
            print("FAILED to stop sub process, it is still running... pid = {}".format(self.subProcess.pid))
        else:
            self._tdeSubProcess = None # not running any more
            self.join() # stop the thread, change the status, etc.
            
    def join(self):
        # TODO: sanity check
        if not self.isStopping():
            raise RuntimeError("Unexpected status when ending svc mgr thread: {}".format(self._status))

        if self._thread :
            self._thread.join()
            self._thread = None   
            self._status = MainExec.STATUS_STOPPED
1843 1844
        else :
            print("Joining empty thread, doing nothing")
1845 1846 1847 1848 1849 1850 1851 1852 1853 1854 1855 1856 1857 1858 1859

    def _trimQueue(self, targetSize):
        if targetSize <= 0:
            return # do nothing
        q = self._ipcQueue
        if (q.qsize() <= targetSize ) : # no need to trim
            return

        logger.debug("Triming IPC queue to target size: {}".format(targetSize))
        itemsToTrim = q.qsize() - targetSize
        for i in range(0, itemsToTrim) :
            try:
                q.get_nowait()
            except Empty:
                break # break out of for loop, no more trimming    
1860
    
1861
    TD_READY_MSG = "TDengine is initialized successfully"
1862 1863
    def procIpcBatch(self, trimToTarget = 0, forceOutput = False):
        self._trimQueue(trimToTarget) # trim if necessary
1864
        # Process all the output generated by the underlying sub process, managed by IO thread
1865 1866
        print("<", end="", flush=True)
        while True :            
1867
            try:  
1868 1869
                line = self._ipcQueue.get_nowait() # getting output at fast speed   
                self._printProgress("_o")
1870 1871 1872
            except Empty:
                # time.sleep(2.3) # wait only if there's no output
                # no more output
1873
                print(".>", end="", flush=True)
1874
                return # we are done with THIS BATCH
1875 1876 1877 1878 1879 1880 1881 1882 1883 1884 1885 1886 1887
            else: # got line, printing out
                if forceOutput:
                    logger.info(line)
                else:
                    logger.debug(line)
        print(">", end="", flush=True)

    _ProgressBars = ["--", "//", "||", "\\\\"]
    def _printProgress(self, msg): # TODO: assuming 2 chars
        print(msg, end="", flush=True) 
        pBar = self._ProgressBars[Dice.throw(4)]
        print(pBar, end="", flush=True)
        print('\b\b\b\b', end="", flush=True)
1888

1889 1890 1891 1892 1893 1894 1895 1896 1897 1898 1899 1900 1901 1902 1903 1904 1905 1906 1907 1908 1909 1910 1911 1912 1913 1914 1915 1916 1917 1918 1919
    def svcOutputReader(self, out: IO, queue):
        # Important Reference: https://stackoverflow.com/questions/375427/non-blocking-read-on-a-subprocess-pipe-in-python
        # print("This is the svcOutput Reader...")
        # for line in out : 
        for line in iter(out.readline, b''):
            # print("Finished reading a line: {}".format(line))
            # print("Adding item to queue...")
            line = line.decode("utf-8").rstrip()
            queue.put(line) # This might block, and then causing "out" buffer to block            
            self._printProgress("_i")

            if self._status == MainExec.STATUS_STARTING : # we are starting, let's see if we have started
                if line.find(self.TD_READY_MSG) != -1 : # found
                    self._status = MainExec.STATUS_RUNNING                              

            # Trim the queue if necessary: TODO: try this 1 out of 10 times
            self._trimQueue(self.MAX_QUEUE_SIZE * 9 // 10) # trim to 90% size

            if self.isStopping() : # TODO: use thread status instead
                print("_w", end="", flush=True) # WAITING for stopping sub process to finish its outptu

            # queue.put(line)
        print("\nNo more output from IO thread managing TDengine service") # meaning sub process must have died
        out.close()

class TdeSubProcess:    
    def __init__(self):
        self.subProcess = None

    def getStdOut(self):
        return self.subProcess.stdout
1920

1921 1922
    def isRunning(self):
        return self.subProcess != None
1923

1924
    def start(self):
1925 1926 1927
        ON_POSIX = 'posix' in sys.builtin_module_names
        svcCmd = ['../../build/build/bin/taosd', '-c', '../../build/test/cfg']
        # svcCmd = ['vmstat', '1']
1928 1929 1930 1931 1932 1933 1934
        if self.subProcess : # already there
            raise RuntimeError("Corrupt process state")

        self.subProcess = subprocess.Popen(
            svcCmd, 
            stdout=subprocess.PIPE, 
            # bufsize=1, # not supported in binary mode
1935
            close_fds=ON_POSIX) # had text=True, which interferred with reading EOF        
1936

1937 1938 1939
    def stop(self):
        if not self.subProcess:
            print("Sub process already stopped")
1940 1941 1942 1943 1944 1945
            return

        retCode = self.subProcess.poll()
        if retCode : # valid return code, process ended
            self.subProcess = None
        else: # process still alive, let's interrupt it
1946
            print("Sub process is running, sending SIG_INT and waiting for it to terminate...")
1947 1948 1949 1950 1951 1952
            self.subProcess.send_signal(signal.SIGINT) # sub process should end, then IPC queue should end, causing IO thread to end
            try :
                self.subProcess.wait(10)
            except subprocess.TimeoutExpired as err:
                print("Time out waiting for TDengine service process to exit")
            else:
1953
                print("TDengine service process terminated successfully from SIG_INT")
1954 1955
                self.subProcess = None

1956 1957 1958 1959 1960 1961
class ClientManager:
    def __init__(self):
        print("Starting service manager")
        signal.signal(signal.SIGTERM, self.sigIntHandler)
        signal.signal(signal.SIGINT, self.sigIntHandler)

1962
        self._status = MainExec.STATUS_RUNNING
1963 1964 1965
        self.tc = None

    def sigIntHandler(self, signalNumber, frame):
1966
        if self._status != MainExec.STATUS_RUNNING :
1967 1968
            print("Ignoring repeated SIGINT...")
            return # do nothing if it's already not running
1969
        self._status = MainExec.STATUS_STOPPING # immediately set our status
1970 1971 1972 1973 1974 1975 1976 1977 1978

        print("Terminating program...")
        self.tc.requestToStop()

    def _printLastNumbers(self): # to verify data durability
        dbManager = DbManager(resetDb=False)
        dbc = dbManager.getDbConn()
        if dbc.query("show databases") == 0 : # no databae
            return
S
Steven Li 已提交
1979 1980
        if dbc.query("show tables") == 0 : # no tables
            return
1981 1982 1983 1984 1985 1986 1987 1988 1989 1990 1991 1992 1993 1994 1995 1996 1997 1998 1999 2000 2001 2002 2003 2004 2005

        dbc.execute("use db")
        sTbName = dbManager.getFixedSuperTableName()        

        # get all regular tables
        dbc.query("select TBNAME from db.{}".format(sTbName)) # TODO: analyze result set later
        rTables = dbc.getQueryResult()

        bList = TaskExecutor.BoundedList()
        for rTbName in rTables : # regular tables
            dbc.query("select speed from db.{}".format(rTbName[0]))
            numbers = dbc.getQueryResult()
            for row in numbers :                
                # print("<{}>".format(n), end="", flush=True)
                bList.add(row[0])

        print("Top numbers in DB right now: {}".format(bList))
        print("TDengine client execution is about to start in 2 seconds...")
        time.sleep(2.0)
        dbManager = None # release?

    def prepare(self):
        self._printLastNumbers()

    def run(self):
2006 2007 2008 2009
        if gConfig.auto_start_service :
            svcMgr = SvcManager()
            svcMgr.startTaosService()

2010 2011
        self._printLastNumbers()

2012 2013
        dbManager = DbManager() # Regular function
        thPool = ThreadPool(gConfig.num_threads, gConfig.max_steps)
2014
        self.tc = ThreadCoordinator(thPool, dbManager)
S
Steven Li 已提交
2015
        
2016
        self.tc.run()
S
Steven Li 已提交
2017
        # print("exec stats: {}".format(self.tc.getExecStats()))
2018
        # print("TC failed = {}".format(self.tc.isFailed()))        
2019 2020
        if gConfig.auto_start_service :
            svcMgr.stopTaosService()
2021 2022
        # Print exec status, etc., AFTER showing messages from the server
        self.conclude()
S
Steven Li 已提交
2023 2024
        # print("TC failed (2) = {}".format(self.tc.isFailed()))
        return 1 if self.tc.isFailed() else 0 # Linux return code: ref https://shapeshed.com/unix-exit-codes/
2025 2026 2027 2028 2029 2030 2031

    def conclude(self):
        self.tc.printStats()
        self.tc.getDbManager().cleanUp()    


class MainExec:
2032
    STATUS_STARTING = 1
2033
    STATUS_RUNNING  = 2
2034
    STATUS_STOPPING = 3
2035
    STATUS_STOPPED  = 4
2036 2037 2038 2039

    @classmethod
    def runClient(cls):
        clientManager = ClientManager()
S
Steven Li 已提交
2040
        return clientManager.run()
2041 2042 2043

    @classmethod
    def runService(cls):
2044 2045
        svcManager = SvcManager()
        svcManager.run()
2046 2047 2048 2049 2050 2051 2052 2053 2054 2055 2056 2057 2058 2059 2060 2061 2062 2063 2064 2065 2066 2067 2068 2069 2070 2071 2072 2073 2074 2075 2076 2077 2078 2079 2080 2081 2082 2083 2084 2085 2086 2087 2088 2089

    @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 已提交
2090

2091
def main():
2092
    # Super cool Python argument library: https://docs.python.org/3/library/argparse.html
2093 2094 2095 2096 2097 2098 2099 2100 2101
    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

            '''))
2102

2103 2104
    parser.add_argument('-a', '--auto-start-service', action='store_true',                        
                        help='Automatically start/stop the TDengine service (default: false)')
2105 2106
    parser.add_argument('-c', '--connector-type', action='store', default='native', type=str,
                        help='Connector type to use: native, rest, or mixed (default: 10)')
2107 2108
    parser.add_argument('-d', '--debug', action='store_true',                        
                        help='Turn on DEBUG mode for more logging (default: false)')
2109 2110
    parser.add_argument('-e', '--run-tdengine', action='store_true',                        
                        help='Run TDengine service in foreground (default: false)')
2111 2112
    parser.add_argument('-l', '--larger-data', action='store_true',                        
                        help='Write larger amount of data during write operations (default: false)')
2113
    parser.add_argument('-p', '--per-thread-db-connection', action='store_true',                        
2114
                        help='Use a single shared db connection (default: false)')
2115 2116
    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)')                    
2117
    parser.add_argument('-s', '--max-steps', action='store', default=1000, type=int,
2118
                        help='Maximum number of steps to run (default: 100)')
2119
    parser.add_argument('-t', '--num-threads', action='store', default=5, type=int,
2120
                        help='Number of threads to run (default: 10)')
2121

2122
    global gConfig
2123
    gConfig = parser.parse_args()
2124
 
2125
    # Logging Stuff
2126
    global logger
2127 2128 2129 2130 2131 2132 2133
    _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

2134 2135
    if ( gConfig.debug ):
        logger.setLevel(logging.DEBUG) # default seems to be INFO        
S
Steven Li 已提交
2136 2137
    else:
        logger.setLevel(logging.INFO)
2138
    
2139 2140
    Dice.seed(0) # initial seeding of dice
        
2141
    # Run server or client
2142 2143 2144
    if gConfig.run_tdengine : # run server
        MainExec.runService()
    else :
S
Steven Li 已提交
2145
        return MainExec.runClient()
2146

2147
if __name__ == "__main__":
S
Steven Li 已提交
2148 2149 2150
    exitCode = main()
    # print("Exiting with code: {}".format(exitCode))
    sys.exit(exitCode)