crash_gen.py 84.7 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 609 610 611 612 613 614 615 616 617 618 619 620 621 622 623 624 625 626 627 628
    def queryScalar(self, sql) -> int :
        return self._queryAny(sql)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

        # Open connection
        self._tdSql = TDSql()
        self._tdSql.init(self._cursor)
        
629 630 631 632
    def close(self):
        if ( not self.isOpen ):
            raise RuntimeError("Cannot clean up database until connection is open")
        self._tdSql.close()
633
        logger.debug("[DB] Database connection closed")
634
        self.isOpen = False
S
Steven Li 已提交
635

636
    def execute(self, sql): 
637
        if ( not self.isOpen ):
638
            raise RuntimeError("Cannot execute database commands until connection is open")
639 640 641 642
        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 已提交
643

644
    def query(self, sql) :  # return rows affected
645 646
        if ( not self.isOpen ):
            raise RuntimeError("Cannot query database until connection is open")
647 648
        logger.debug("[SQL] Executing SQL: {}".format(sql))
        nRows = self._tdSql.query(sql)
649
        logger.debug("[SQL] Query Result, nRows = {}, SQL = {}".format(nRows, sql))
650
        return nRows
651
        # results are in: return self._tdSql.queryResult
652

653 654 655
    def getQueryResult(self):
        return self._tdSql.queryResult

656 657
    def getResultRows(self):
        return self._tdSql.queryRows
658

659 660
    def getResultCols(self):
        return self._tdSql.queryCols
661 662 663

    
class AnyState:
664
    STATE_INVALID    = -1
665 666 667 668
    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
669 670 671 672 673
    _stateNames = ["Invalid", "Empty", "DB_Only", "Table_Only", "Has_Data"]

    STATE_VAL_IDX = 0
    CAN_CREATE_DB = 1
    CAN_DROP_DB = 2
674 675
    CAN_CREATE_FIXED_SUPER_TABLE = 3
    CAN_DROP_FIXED_SUPER_TABLE = 4
676 677 678 679 680 681 682
    CAN_ADD_DATA = 5
    CAN_READ_DATA = 6

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

    def __str__(self):
S
Steven Li 已提交
683
        return self._stateNames[self._info[self.STATE_VAL_IDX] + 1] # -1 hack to accomodate the STATE_INVALID case
684 685 686 687

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

S
Steven Li 已提交
688 689 690 691 692 693 694 695
    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)))

696 697 698
    def verifyTasksToState(self, tasks, newState):
        raise RuntimeError("Must be overriden by child classes")

S
Steven Li 已提交
699 700 701
    def getValIndex(self):
        return self._info[self.STATE_VAL_IDX]

702 703 704 705 706 707
    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]
708 709 710 711
    def canCreateFixedSuperTable(self):
        return self._info[self.CAN_CREATE_FIXED_SUPER_TABLE]
    def canDropFixedSuperTable(self):
        return self._info[self.CAN_DROP_FIXED_SUPER_TABLE]
712 713 714 715 716 717 718 719 720 721 722
    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 已提交
723
                # task.logDebug("Task success found")
724 725 726 727 728 729 730 731 732 733 734 735 736 737 738 739 740 741 742 743 744 745 746 747 748 749 750 751 752 753 754 755 756 757 758
                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 已提交
759 760 761 762 763 764
    def hasTask(self, tasks, cls):
        for task in tasks :
            if isinstance(task, cls):
                return True
        return False

765 766 767 768 769 770 771 772 773 774 775 776 777 778 779 780 781 782 783 784
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 已提交
785
    def verifyTasksToState(self, tasks, newState): 
786 787 788
        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
789 790 791 792 793 794 795 796 797 798 799

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

    def verifyTasksToState(self, tasks, newState):
800 801 802
        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 已提交
803
        # self.assertAtMostOneSuccess(tasks, CreateFixedTableTask) # not true in massively parrallel cases
804
        # Nothing to be said about adding data task
805
        # if ( self.hasSuccess(tasks, DropDbTask) ): # dropped the DB
806
            # self.assertHasTask(tasks, DropDbTask) # implied by hasSuccess
807
            # self.assertAtMostOneSuccess(tasks, DropDbTask)
808
            # self._state = self.STATE_EMPTY
809 810 811 812
        # 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
813
            # self.assertNoTask(tasks, DropDbTask) # should have have tried
814 815 816 817 818 819 820 821 822 823 824 825
            # 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

826
class StateSuperTableOnly(AnyState):
827 828 829 830 831 832 833 834 835
    def getInfo(self):
        return [
            self.STATE_TABLE_ONLY,
            False, True,
            False, True,
            True, True,
        ]

    def verifyTasksToState(self, tasks, newState):
836
        if ( self.hasSuccess(tasks, TaskDropSuperTable) ): # we are able to drop the table
837 838 839
            #self.assertAtMostOneSuccess(tasks, TaskDropSuperTable)
            self.hasSuccess(tasks, TaskCreateSuperTable) # we must have had recreted it

840
            # self._state = self.STATE_DB_ONLY
S
Steven Li 已提交
841 842
        # elif ( self.hasSuccess(tasks, AddFixedDataTask) ): # no success dropping the table, but added data
        #     self.assertNoTask(tasks, DropFixedTableTask) # not true in massively parrallel cases
843
            # self._state = self.STATE_HAS_DATA
S
Steven Li 已提交
844 845 846
        # elif ( self.hasSuccess(tasks, ReadFixedDataTask) ): # no success in prev cases, but was able to read data
            # self.assertNoTask(tasks, DropFixedTableTask)
            # self.assertNoTask(tasks, AddFixedDataTask)
847
            # self._state = self.STATE_TABLE_ONLY # no change
S
Steven Li 已提交
848 849 850
        # 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!!
851 852 853 854 855 856 857 858 859 860 861

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 已提交
862
        if ( newState.equals(AnyState.STATE_EMPTY) ):
863 864 865
            self.hasSuccess(tasks, TaskDropDb)
            if ( not self.hasTask(tasks, TaskCreateDb) ) : 
                self.assertAtMostOneSuccess(tasks, TaskDropDb) # TODO: dicy
S
Steven Li 已提交
866
        elif ( newState.equals(AnyState.STATE_DB_ONLY) ): # in DB only
867 868 869
            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)
870
            # self.assertAtMostOneSuccess(tasks, DropFixedSuperTableTask) # TODO: dicy
871 872 873 874
        # elif ( newState.equals(AnyState.STATE_TABLE_ONLY) ): # data deleted
            # self.assertNoTask(tasks, TaskDropDb)
            # self.assertNoTask(tasks, TaskDropSuperTable)
            # self.assertNoTask(tasks, TaskAddData)
S
Steven Li 已提交
875
            # self.hasSuccess(tasks, DeleteDataTasks)
876
        else: # should be STATE_HAS_DATA
877 878
            if (not self.hasTask(tasks, TaskCreateDb) ): # only if we didn't create one
                self.assertNoTask(tasks, TaskDropDb) # we shouldn't have dropped it
879 880
            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            
881
            # self.assertIfExistThenSuccess(tasks, ReadFixedDataTask)
S
Steven Li 已提交
882

883
class StateMechine:
884 885 886 887 888 889 890 891
    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

892 893 894
    def hasDatabase(self):
        return self._curState.canDropDb()  # ha, can drop DB means it has one

895 896
    # May be slow, use cautionsly...
    def getTaskTypes(self): # those that can run (directly/indirectly) from the current state
897 898 899 900 901 902
        def typesToStrings(types):
            ss = []
            for t in types:
                ss.append(t.__name__)
            return ss

903 904 905 906 907 908 909 910 911 912 913 914 915 916 917 918 919 920
        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))   
921
        logger.debug("[OPS] Tasks found for state {}: {}".format(self._curState, typesToStrings(taskTypes)))     
922 923 924 925 926 927 928 929 930
        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()
931
        dbc.execute("use db") # did not do this when openning connection, and this is NOT the worker thread, which does this on their own
932 933 934 935 936 937 938 939 940 941 942 943 944 945 946
        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
947
            logger.debug("[STT] Starting State: {}".format(self._curState))
948 949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 964 965 966 967 968 969 970 971 972 973 974 975 976 977 978 979 980 981 982 983 984 985 986 987 988 989 990 991 992 993 994 995 996 997 998
            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
999

1000
# Manager of the Database Data/Connection
1001
class DbManager():    
1002
    def __init__(self, resetDb = True):
S
Steven Li 已提交
1003
        self.tableNumQueue = LinearQueue()
1004
        self._lastTick = self.setupLastTick() # datetime.datetime(2019, 1, 1) # initial date time tick
1005 1006
        self._lastInt  = 0 # next one is initial integer 
        self._lock = threading.RLock()
1007
        
1008
        # self.openDbServerConnection()
1009
        self._dbConn = DbConn.createNative() if (gConfig.connector_type=='native') else DbConn.createRest()
1010 1011 1012 1013
        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))
1014
            if ( err.msg == 'client disconnected' ): # cannot open DB connection
1015
                print("Cannot establish DB connection, please re-run script without parameter, and follow the instructions.")
S
Steven Li 已提交
1016
                sys.exit(2)
1017 1018 1019
            else:
                raise            
        except:
S
Steven Li 已提交
1020
            print("[=] Unexpected exception")
1021
            raise        
1022 1023 1024

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

1026 1027
        self._stateMachine = StateMechine(self._dbConn) # Do this after dbConn is in proper shape
        
1028 1029 1030
    def getDbConn(self):
        return self._dbConn

1031
    def getStateMachine(self) -> StateMechine :
1032 1033 1034 1035
        return self._stateMachine

    # def getState(self):
    #     return self._stateMachine.getCurrentState()
1036 1037 1038 1039 1040 1041

    # 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
1042
    # TODO: fix the error as result of above: "tsdb timestamp is out of range"
1043
    def setupLastTick(self):
1044
        t1 = datetime.datetime(2020, 6, 1)
1045
        t2 = datetime.datetime.now()
1046 1047
        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
1048 1049
        # print("elSec = {}".format(elSec))
        t3 = datetime.datetime(2012, 1, 1) # default "keep" is 10 years
1050
        t4 = datetime.datetime.fromtimestamp( t3.timestamp() + elSec2) # see explanation above
1051 1052 1053
        logger.info("Setting up TICKS to start from: {}".format(t4))
        return t4

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

1057 1058 1059 1060 1061
    def addTable(self):
        with self._lock:
            tIndex = self.tableNumQueue.push()
        return tIndex

1062 1063
    @classmethod
    def getFixedSuperTableName(cls):
1064
        return "fs_table"
1065

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

1069
    def getNextTick(self):
1070
        with self._lock: # prevent duplicate tick
S
Steven Li 已提交
1071 1072 1073 1074 1075
            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
1076 1077

    def getNextInt(self):
1078 1079 1080
        with self._lock:
            self._lastInt += 1
            return self._lastInt
1081 1082

    def getNextBinary(self):
1083
        return "Beijing_Shanghai_Los_Angeles_New_York_San_Francisco_Chicago_Beijing_Shanghai_Los_Angeles_New_York_San_Francisco_Chicago_{}".format(self.getNextInt())
1084 1085 1086

    def getNextFloat(self):
        return 0.9 + self.getNextInt()
1087
    
S
Steven Li 已提交
1088
    def getTableNameToDelete(self):
1089
        tblNum = self.tableNumQueue.pop() # TODO: race condition!
1090 1091 1092
        if ( not tblNum ): # maybe false
            return False
        
S
Steven Li 已提交
1093 1094
        return "table_{}".format(tblNum)

1095 1096 1097
    def cleanUp(self):
        self._dbConn.close()      

1098
class TaskExecutor():
1099 1100 1101 1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131 1132 1133 1134 1135
    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()

1136 1137 1138
    def __init__(self, curStep):
        self._curStep = curStep

1139 1140 1141 1142
    @classmethod
    def getBoundedList(cls):
        return cls._boundedList

1143 1144 1145
    def getCurStep(self):
        return self._curStep

1146 1147
    def execute(self, task: Task, wt: WorkerThread): # execute a task on a thread
        task.execute(wt)
1148

1149 1150 1151 1152
    def recordDataMark(self, n: int):
        # print("[{}]".format(n), end="", flush=True)
        self._boundedList.add(n)

1153 1154
    # def logInfo(self, msg):
    #     logger.info("    T[{}.x]: ".format(self._curStep) + msg)
1155

1156 1157
    # def logDebug(self, msg):
    #     logger.debug("    T[{}.x]: ".format(self._curStep) + msg)
1158

S
Steven Li 已提交
1159
class Task():
1160 1161 1162 1163
    taskSn = 100

    @classmethod
    def allocTaskNum(cls):
S
Steven Li 已提交
1164 1165 1166
        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
1167

1168
    def __init__(self, dbManager: DbManager, execStats: ExecutionStats):        
1169
        self._dbManager = dbManager
1170
        self._workerThread = None 
1171
        self._err = None
1172
        self._aborted = False
1173
        self._curStep = None
1174
        self._numRows = None # Number of rows affected
1175 1176 1177

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

1180
        self._execStats = execStats
1181
        self._lastSql = "" # last SQL executed/attempted
1182

1183 1184
    def isSuccess(self):
        return self._err == None
1185

1186 1187 1188
    def isAborted(self):
        return self._aborted

1189
    def clone(self): # TODO: why do we need this again?
1190
        newTask = self.__class__(self._dbManager, self._execStats)
1191 1192 1193
        return newTask

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

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

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

1202 1203
    def execute(self, wt: WorkerThread):
        wt.verifyThreadSelf()
1204
        self._workerThread = wt # type: ignore
1205 1206

        te = wt.getTaskExecutor()
1207 1208
        self._curStep = te.getCurStep()
        self.logDebug("[-] executing task {}...".format(self.__class__.__name__))
1209 1210

        self._err = None
1211
        self._execStats.beginTaskType(self.__class__.__name__) # mark beginning
1212 1213 1214
        try:
            self._executeInternal(te, wt) # TODO: no return value?
        except taos.error.ProgrammingError as err:
1215
            errno2 = err.errno if (err.errno > 0) else 0x80000000 + err.errno # correct error scheme
1216 1217 1218 1219 1220
            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,
1221 1222
                1000 # REST catch-all error
                ]) : # allowed errors
1223
                self.logDebug("[=] Acceptable Taos library exception: errno=0x{:X}, msg: {}, SQL: {}".format(errno2, err, self._lastSql))
1224
                print("_", end="", flush=True)
1225 1226
                self._err = err  
            else:
1227 1228 1229
                errMsg = "[=] Unexpected Taos library exception: errno=0x{:X}, msg: {}, SQL: {}".format(errno2, err, self._lastSql)
                self.logDebug(errMsg)
                if gConfig.debug :
1230 1231 1232 1233 1234 1235 1236
                    # 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 已提交
1237 1238 1239 1240
        except Exception as e :
            self.logInfo("Non-TAOS exception encountered")
            self._err = e 
            self._aborted = True
1241 1242 1243 1244 1245
            traceback.print_exc()
        except BaseException as e :
            self.logInfo("Python base exception encountered")
            self._err = e 
            self._aborted = True
S
Steven Li 已提交
1246 1247
            traceback.print_exc()
        except :
1248
            self.logDebug("[=] Unexpected exception, SQL: {}".format(self._lastSql))
1249
            raise
1250
        self._execStats.endTaskType(self.__class__.__name__, self.isSuccess())
1251
        
1252 1253
        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 已提交
1254

1255
    def execSql(self, sql):
1256
        self._lastSql = sql
1257
        return self._dbManager.execute(sql)
1258

1259 1260 1261 1262 1263 1264 1265 1266 1267 1268 1269 1270
    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()


1271
                  
1272
class ExecutionStats:
1273 1274 1275 1276 1277
    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
1278 1279
        self._execStartTime = None
        self._elapsedTime = 0.0 # total elapsed time
1280 1281
        self._accRunTime = 0.0 # accumulated run time

1282 1283 1284
        self._failed = False
        self._failureReason = None

S
Steven Li 已提交
1285 1286 1287 1288 1289 1290
    def __str__(self):
        return "[ExecStats: _failed={}, _failureReason={}".format(self._failed, self._failureReason)

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

1291 1292 1293 1294 1295 1296
    def startExec(self):
        self._execStartTime = time.time()

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

1297 1298 1299 1300 1301 1302 1303 1304 1305 1306 1307 1308 1309 1310 1311 1312 1313 1314 1315 1316 1317
    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

1318 1319 1320 1321
    def registerFailure(self, reason):
        self._failed = True
        self._failureReason = reason

1322
    def printStats(self):
1323 1324 1325 1326
        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):")
1327 1328
        execTimesAny = 0
        for k, n in self._execTimes.items():            
1329
            execTimesAny += n[0]
1330
            logger.info("|    {0:<24}: {1}/{2}".format(k,n[1],n[0]))
1331
                
1332 1333 1334 1335 1336
        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))
1337
        logger.info("| Top numbers written: {}".format(TaskExecutor.getBoundedList()))
1338 1339
        logger.info("----------------------------------------------------------------------")
        
1340 1341 1342


class StateTransitionTask(Task):
1343 1344 1345 1346 1347
    LARGE_NUMBER_OF_TABLES = 35
    SMALL_NUMBER_OF_TABLES = 3
    LARGE_NUMBER_OF_RECORDS = 50
    SMALL_NUMBER_OF_RECORDS = 3

1348 1349 1350 1351
    @classmethod
    def getInfo(cls): # each sub class should supply their own information
        raise RuntimeError("Overriding method expected")

1352 1353 1354 1355 1356
    _endState = None 
    @classmethod
    def getEndState(cls): # TODO: optimize by calling it fewer times
        raise RuntimeError("Overriding method expected")

1357 1358 1359
    # @classmethod
    # def getBeginStates(cls):
    #     return cls.getInfo()[0]
1360

1361 1362 1363
    # @classmethod
    # def getEndState(cls): # returning the class name
    #     return cls.getInfo()[0]
1364 1365

    @classmethod
1366 1367 1368
    def canBeginFrom(cls, state: AnyState):
        # return state.getValue() in cls.getBeginStates()
        raise RuntimeError("must be overriden")
1369

1370 1371 1372 1373
    @classmethod
    def getRegTableName(cls, i):
        return "db.reg_table_{}".format(i)

1374 1375 1376
    def execute(self, wt: WorkerThread):
        super().execute(wt)
        
1377
class TaskCreateDb(StateTransitionTask):
1378
    @classmethod
1379 1380
    def getEndState(cls):
        return StateDbOnly() 
1381

1382 1383 1384 1385
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canCreateDb()

1386
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1387
        self.execWtSql(wt, "create database db")       
1388

1389
class TaskDropDb(StateTransitionTask):
1390
    @classmethod
1391 1392
    def getEndState(cls):
        return StateEmpty()
1393

1394 1395 1396 1397
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canDropDb()

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

1402
class TaskCreateSuperTable(StateTransitionTask):
1403
    @classmethod
1404 1405
    def getEndState(cls):
        return StateSuperTableOnly()
1406

1407 1408
    @classmethod
    def canBeginFrom(cls, state: AnyState):
1409
        return state.canCreateFixedSuperTable()
1410

1411
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1412 1413 1414 1415 1416 1417 1418
        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))
1419 1420
        # No need to create the regular tables, INSERT will do that automatically

S
Steven Li 已提交
1421

1422
class TaskReadData(StateTransitionTask):
1423
    @classmethod
1424 1425
    def getEndState(cls):
        return None # meaning doesn't affect state
1426

1427 1428 1429 1430
    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canReadData()

1431
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1432
        sTbName = self._dbManager.getFixedSuperTableName()        
1433 1434
        self.queryWtSql(wt, "select TBNAME from db.{}".format(sTbName)) # TODO: analyze result set later

1435
        if random.randrange(5) == 0 : # 1 in 5 chance, simulate a broken connection. TODO: break connection in all situations
1436 1437
            wt.getDbConn().close()
            wt.getDbConn().open()
1438
        else:
1439
            rTables = self.getQueryResult(wt) # wt.getDbConn().getQueryResult()
1440 1441
            # print("rTables[0] = {}, type = {}".format(rTables[0], type(rTables[0])))
            for rTbName in rTables : # regular tables
1442
                self.execWtSql(wt, "select * from db.{}".format(rTbName[0]))
1443

1444 1445
        # tdSql.query(" cars where tbname in ('carzero', 'carone')")

1446
class TaskDropSuperTable(StateTransitionTask):
1447
    @classmethod
1448 1449
    def getEndState(cls):
        return StateDbOnly() 
1450

1451 1452
    @classmethod
    def canBeginFrom(cls, state: AnyState):
1453
        return state.canDropFixedSuperTable()
1454

1455
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1456 1457 1458 1459 1460
        # 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"
1461
            isSuccess = True
1462
            for i in tblSeq: 
1463
                regTableName = self.getRegTableName(i); # "db.reg_table_{}".format(i)                  
1464
                try:
1465
                    self.execWtSql(wt, "drop table {}".format(regTableName)) # nRows always 0, like MySQL
1466 1467
                except taos.error.ProgrammingError as err:                    
                    errno2 = err.errno if (err.errno > 0) else 0x80000000 + err.errno # correcting for strange error number scheme
1468 1469
                    if ( errno2 in [0x362]) : # mnode invalid table name
                        isSuccess = False
1470
                        logger.debug("[DB] Acceptable error when dropping a table")
1471
                    continue # try to delete next regular table
1472 1473 1474

                if (not tickOutput):
                    tickOutput = True # Print only one time
1475
                    if isSuccess :
1476 1477
                        print("d", end="", flush=True)
                    else:
1478
                        print("f", end="", flush=True)                    
1479 1480 1481 1482

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

1484 1485 1486 1487 1488 1489 1490 1491 1492 1493 1494 1495 1496
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 :
1497
            sql = "alter table db.{} add tag extraTag int".format(tblName)
1498
        elif dice == 1 :
1499
            sql = "alter table db.{} drop tag extraTag".format(tblName)
1500
        elif dice == 2 :
1501
            sql = "alter table db.{} drop tag newTag".format(tblName)
1502
        else: # dice == 3
1503 1504 1505
            sql = "alter table db.{} change tag extraTag newTag".format(tblName)

        self.execWtSql(wt, sql)
1506

1507
class TaskAddData(StateTransitionTask):
1508
    activeTable : Set[int] = set() # Track which table is being actively worked on
1509 1510 1511 1512 1513 1514 1515 1516 1517 1518 1519 1520 1521 1522

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

1524
    @classmethod
1525 1526
    def getEndState(cls):
        return StateHasData()
1527 1528 1529 1530

    @classmethod
    def canBeginFrom(cls, state: AnyState):
        return state.canAddData()
1531 1532
        
    def _executeInternal(self, te: TaskExecutor, wt: WorkerThread):
1533
        ds = self._dbManager
1534
        # wt.execSql("use db") # TODO: seems to be an INSERT bug to require this
1535
        tblSeq = list(range(self.LARGE_NUMBER_OF_TABLES if gConfig.larger_data else self.SMALL_NUMBER_OF_TABLES)) 
1536 1537 1538 1539 1540 1541 1542 1543
        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
1544 1545
            # No need to shuffle data sequence, unless later we decide to do non-increment insertion      
            regTableName = self.getRegTableName(i); # "db.reg_table_{}".format(i)      
1546
            for j in range(self.LARGE_NUMBER_OF_RECORDS if gConfig.larger_data else self.SMALL_NUMBER_OF_RECORDS) : # number of records per table
1547
                nextInt = ds.getNextInt()                
1548 1549 1550 1551 1552 1553 1554
                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, 
1555 1556
                    ds.getFixedSuperTableName(), 
                    ds.getNextBinary(), ds.getNextFloat(),
1557
                    ds.getNextTick(), nextInt)
1558
                self.execWtSql(wt, sql) 
1559 1560
                # Successfully wrote the data into the DB, let's record it somehow
                te.recordDataMark(nextInt)
1561 1562 1563 1564
                if gConfig.record_ops:
                    self.fAddLogDone.write("Wrote {} to {}\n".format(nextInt, regTableName))
                    self.fAddLogDone.flush()
                    os.fsync(self.fAddLogDone)
1565
            self.activeTable.discard(i) # not raising an error, unlike remove
1566 1567


S
Steven Li 已提交
1568 1569 1570 1571 1572 1573 1574 1575 1576 1577 1578 1579 1580 1581 1582 1583 1584 1585 1586 1587 1588 1589
# 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
1590 1591
    def throw(cls, stop): # get 0 to stop-1
        return cls.throwRange(0, stop)
S
Steven Li 已提交
1592 1593

    @classmethod
1594
    def throwRange(cls, start, stop): # up to stop-1
S
Steven Li 已提交
1595 1596
        if ( not cls.seeded ):
            raise RuntimeError("Cannot throw dice before seeding it")
1597
        return random.randrange(start, stop)
S
Steven Li 已提交
1598

S
Steven Li 已提交
1599 1600
class LoggingFilter(logging.Filter):
    def filter(self, record: logging.LogRecord):
S
Steven Li 已提交
1601 1602 1603
        if ( record.levelno >= logging.INFO ) :
            return True # info or above always log

S
Steven Li 已提交
1604 1605 1606 1607
        # Commenting out below to adjust...

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

1610 1611 1612 1613 1614
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

1615 1616
class SvcManager:    
    def __init__(self):
1617
        print("Starting TDengine Service Manager")
1618
        signal.signal(signal.SIGTERM, self.sigIntHandler)
1619 1620 1621 1622 1623 1624
        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
1625

1626 1627 1628 1629 1630 1631 1632 1633 1634 1635 1636 1637 1638 1639 1640 1641 1642 1643 1644 1645 1646
    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")
1647
        if self.inSigHandler : # already
1648
            print("Ignoring repeated SIG...")
1649
            return # do nothing if it's already not running
1650
        self.inSigHandler = True
1651 1652 1653 1654 1655

        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" :
1656
            self.stopTaosService()
1657
        elif choice == "3" :
1658 1659
            self.stopTaosService()
            self.startTaosService()
1660 1661
        else:
            raise RuntimeError("Invalid menu choice: {}".format(choice))
1662

1663 1664
        self.inSigHandler = False

1665 1666
    def sigIntHandler(self, signalNumber, frame):
        print("Sig INT Handler starting...")
1667
        if self.inSigHandler :
1668 1669
            print("Ignoring repeated SIG_INT...")
            return
1670 1671
        self.inSigHandler = True
 
1672
        self.stopTaosService()  
1673
        print("INT signal handler returning...")  
1674
        self.inSigHandler = False
1675 1676 1677

    def sigHandlerResume(self) :
        print("Resuming TDengine service manager thread (main thread)...\n\n")
1678 1679 1680 1681 1682 1683 1684 1685 1686 1687 1688 1689 1690 1691 1692 1693 1694 1695 1696 1697 1698 1699 1700 1701 1702 1703 1704 1705 1706 1707 1708 1709 1710 1711 1712 1713 1714 1715 1716 1717 1718 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
    
    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")
1783

1784 1785 1786 1787 1788 1789 1790 1791 1792 1793 1794 1795 1796 1797 1798 1799 1800 1801
        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
1802 1803
        else :
            print("Joining empty thread, doing nothing")
1804 1805 1806 1807 1808 1809 1810 1811 1812 1813 1814 1815 1816 1817 1818

    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    
1819
    
1820
    TD_READY_MSG = "TDengine is initialized successfully"
1821 1822
    def procIpcBatch(self, trimToTarget = 0, forceOutput = False):
        self._trimQueue(trimToTarget) # trim if necessary
1823
        # Process all the output generated by the underlying sub process, managed by IO thread
1824 1825
        print("<", end="", flush=True)
        while True :            
1826
            try:  
1827 1828
                line = self._ipcQueue.get_nowait() # getting output at fast speed   
                self._printProgress("_o")
1829 1830 1831
            except Empty:
                # time.sleep(2.3) # wait only if there's no output
                # no more output
1832
                print(".>", end="", flush=True)
1833
                return # we are done with THIS BATCH
1834 1835 1836 1837 1838 1839 1840 1841 1842 1843 1844 1845 1846
            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)
1847

1848 1849 1850 1851 1852 1853 1854 1855 1856 1857 1858 1859 1860 1861 1862 1863 1864 1865 1866 1867 1868 1869 1870 1871 1872 1873 1874 1875 1876 1877 1878
    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
1879

1880 1881
    def isRunning(self):
        return self.subProcess != None
1882

1883
    def start(self):
1884 1885 1886
        ON_POSIX = 'posix' in sys.builtin_module_names
        svcCmd = ['../../build/build/bin/taosd', '-c', '../../build/test/cfg']
        # svcCmd = ['vmstat', '1']
1887 1888 1889 1890 1891 1892 1893
        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
1894
            close_fds=ON_POSIX) # had text=True, which interferred with reading EOF        
1895

1896 1897 1898
    def stop(self):
        if not self.subProcess:
            print("Sub process already stopped")
1899 1900 1901 1902 1903 1904
            return

        retCode = self.subProcess.poll()
        if retCode : # valid return code, process ended
            self.subProcess = None
        else: # process still alive, let's interrupt it
1905
            print("Sub process is running, sending SIG_INT and waiting for it to terminate...")
1906 1907 1908 1909 1910 1911
            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:
1912
                print("TDengine service process terminated successfully from SIG_INT")
1913 1914
                self.subProcess = None

1915 1916 1917 1918 1919 1920
class ClientManager:
    def __init__(self):
        print("Starting service manager")
        signal.signal(signal.SIGTERM, self.sigIntHandler)
        signal.signal(signal.SIGINT, self.sigIntHandler)

1921
        self._status = MainExec.STATUS_RUNNING
1922 1923 1924
        self.tc = None

    def sigIntHandler(self, signalNumber, frame):
1925
        if self._status != MainExec.STATUS_RUNNING :
1926 1927
            print("Ignoring repeated SIGINT...")
            return # do nothing if it's already not running
1928
        self._status = MainExec.STATUS_STOPPING # immediately set our status
1929 1930 1931 1932 1933 1934 1935 1936 1937

        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 已提交
1938 1939
        if dbc.query("show tables") == 0 : # no tables
            return
1940 1941 1942 1943 1944 1945 1946 1947 1948 1949 1950 1951 1952 1953 1954 1955 1956 1957 1958 1959 1960 1961 1962 1963 1964

        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):
1965 1966 1967 1968
        if gConfig.auto_start_service :
            svcMgr = SvcManager()
            svcMgr.startTaosService()

1969 1970
        self._printLastNumbers()

1971 1972
        dbManager = DbManager() # Regular function
        thPool = ThreadPool(gConfig.num_threads, gConfig.max_steps)
1973
        self.tc = ThreadCoordinator(thPool, dbManager)
S
Steven Li 已提交
1974
        
1975
        self.tc.run()
S
Steven Li 已提交
1976
        # print("exec stats: {}".format(self.tc.getExecStats()))
1977
        # print("TC failed = {}".format(self.tc.isFailed()))        
1978 1979
        if gConfig.auto_start_service :
            svcMgr.stopTaosService()
1980 1981
        # Print exec status, etc., AFTER showing messages from the server
        self.conclude()
S
Steven Li 已提交
1982 1983
        # 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/
1984 1985 1986 1987 1988 1989 1990

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


class MainExec:
1991
    STATUS_STARTING = 1
1992
    STATUS_RUNNING  = 2
1993
    STATUS_STOPPING = 3
1994
    STATUS_STOPPED  = 4
1995 1996 1997 1998

    @classmethod
    def runClient(cls):
        clientManager = ClientManager()
S
Steven Li 已提交
1999
        return clientManager.run()
2000 2001 2002

    @classmethod
    def runService(cls):
2003 2004
        svcManager = SvcManager()
        svcManager.run()
2005 2006 2007 2008 2009 2010 2011 2012 2013 2014 2015 2016 2017 2018 2019 2020 2021 2022 2023 2024 2025 2026 2027 2028 2029 2030 2031 2032 2033 2034 2035 2036 2037 2038 2039 2040 2041 2042 2043 2044 2045 2046 2047 2048

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

2050
def main():
2051
    # Super cool Python argument library: https://docs.python.org/3/library/argparse.html
2052 2053 2054 2055 2056 2057 2058 2059 2060
    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

            '''))
2061

2062 2063
    parser.add_argument('-a', '--auto-start-service', action='store_true',                        
                        help='Automatically start/stop the TDengine service (default: false)')
2064 2065
    parser.add_argument('-c', '--connector-type', action='store', default='native', type=str,
                        help='Connector type to use: native, rest, or mixed (default: 10)')
2066 2067
    parser.add_argument('-d', '--debug', action='store_true',                        
                        help='Turn on DEBUG mode for more logging (default: false)')
2068 2069
    parser.add_argument('-e', '--run-tdengine', action='store_true',                        
                        help='Run TDengine service in foreground (default: false)')
2070 2071
    parser.add_argument('-l', '--larger-data', action='store_true',                        
                        help='Write larger amount of data during write operations (default: false)')
2072
    parser.add_argument('-p', '--per-thread-db-connection', action='store_true',                        
2073
                        help='Use a single shared db connection (default: false)')
2074 2075
    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)')                    
2076
    parser.add_argument('-s', '--max-steps', action='store', default=1000, type=int,
2077
                        help='Maximum number of steps to run (default: 100)')
2078
    parser.add_argument('-t', '--num-threads', action='store', default=5, type=int,
2079
                        help='Number of threads to run (default: 10)')
2080

2081
    global gConfig
2082
    gConfig = parser.parse_args()
2083
 
2084
    # Logging Stuff
2085
    global logger
2086 2087 2088 2089 2090 2091 2092
    _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

2093 2094
    if ( gConfig.debug ):
        logger.setLevel(logging.DEBUG) # default seems to be INFO        
S
Steven Li 已提交
2095 2096
    else:
        logger.setLevel(logging.INFO)
2097
    
2098 2099
    Dice.seed(0) # initial seeding of dice
        
2100
    # Run server or client
2101 2102 2103
    if gConfig.run_tdengine : # run server
        MainExec.runService()
    else :
S
Steven Li 已提交
2104
        return MainExec.runClient()
2105

2106
if __name__ == "__main__":
S
Steven Li 已提交
2107 2108 2109
    exitCode = main()
    # print("Exiting with code: {}".format(exitCode))
    sys.exit(exitCode)