refactor pytest framework to include lineno in log

tests/pytest/stream/parser.py

@@ -20,10 +20,6 @@ from util.sql import tdSql
 
 
 class TDTestCase:
-    def sleep(self, duration):
-        tdLog.info("sleeping %f seconds" % duration)
-        time.sleep(duration)
-
     def init(self, conn, logSql):
         tdLog.debug("start to execute %s" % __file__)
         tdSql.init(conn.cursor(), logSql)
@@ -55,20 +51,15 @@ class TDTestCase:
         tdSql.execute("create table tb2 using mt tags(2)");
         tdSql.execute("create table strm as select count(*), avg(c1), sum(c2), max(c1), min(c2),first(c1), last(c2) from mt interval(4s) sliding(2s)")
         #tdSql.execute("create table strm as select count(*), avg(c1), sum(c2), max(c1), min(c2), first(c1) from mt interval(4s) sliding(2s)")
-        self.sleep(10)
+        tdLog.sleep(10)
         tdSql.execute("insert into tb2 values(now, 1, 1)");
         tdSql.execute("insert into tb1 values(now, 1, 1)");
-        self.sleep(4)
+        tdLog.sleep(4)
         tdSql.query("select * from mt")
         tdSql.query("select * from strm")
         tdSql.execute("drop table tb1")
 
-        tdLog.info("retrieve data from strm")
+        tdSql.waitedQuery("select * from strm", 1, 100)
-        for i in range(100):
-            time.sleep(1)
-            tdSql.query("select * from strm")
-            if tdSql.queryRows > 0:
-                break
         if tdSql.queryRows < 1 or tdSql.queryRows > 2:
             tdLog.exit("rows should be 1 or 2")
 
@@ -88,12 +79,7 @@ class TDTestCase:
         tdSql.execute("insert into tb1 values (now,1)")
         tdSql.execute("insert into tb2 values (now,2)")
 
-        tdLog.info("retrieve data from strm")
+        tdSql.waitedQuery("select * from strm", 1, 100)
-        for i in range(100):
-            time.sleep(1)
-            tdSql.query("select * from strm")
-            if tdSql.queryRows > 0:
-                break
         if tdSql.queryRows < 1 or tdSql.queryRows > 2:
             tdLog.exit("rows should be 1 or 2")
 
@@ -104,7 +90,7 @@ class TDTestCase:
         tdSql.execute("insert into tb1 values (now,1)")
         tdSql.query("select * from strm")
         tdSql.execute("alter table mt304 add tag t2 int")
-        self.sleep(1)
+        tdLog.sleep(1)
         tdSql.query("select * from strm")
 
     def wildcardFilterOnTags(self):
@@ -118,20 +104,14 @@ class TDTestCase:
         tdSql.query("describe strm")
         tdSql.checkRows(4)
 
-        self.sleep(1)
+        tdLog.sleep(1)
         tdSql.execute("insert into tb1 values (now, 0, 'tb1')")
-        self.sleep(4)
+        tdLog.sleep(4)
         tdSql.execute("insert into tb2 values (now, 2, 'tb2')")
-        self.sleep(4)
+        tdLog.sleep(4)
         tdSql.execute("insert into tb3 values (now, 0, 'tb3')")
 
-        tdLog.info("retrieve data from strm")
+        tdSql.waitedQuery("select * from strm", 4, 60)
-        for i in range(60):
-            time.sleep(1)
-            tdSql.query("select * from strm")
-            if tdSql.queryRows == 4:
-                break
-
         tdSql.checkRows(4)
         tdSql.checkData(0, 2, 0.000000000)
         if tdSql.getData(0, 3) == 'tb2':
@@ -149,28 +129,18 @@ class TDTestCase:
         # commented out the case below to save running time
         tdSql.execute("create table tb4 using stb tags('a4')")
         tdSql.execute("insert into tb4 values(now, 4, 'tb4')")
-        tdLog.info("retrieve data from strm order by ts desc")
+        tdSql.waitedQuery("select * from strm order by ts desc", 6, 60)
-        for i in range(60):
-            time.sleep(1)
-            tdSql.query("select * from strm order by ts desc")
-            if tdSql.queryRows == 6:
-                break
         tdSql.checkRows(6)
         tdSql.checkData(0, 2, 4)
         tdSql.checkData(0, 3, "tb4")
 
         tdLog.info("change tag values to see if stream still works correctly")
         tdSql.execute("alter table tb4 set tag t1='b4'")
-        self.sleep(3)
+        tdLog.sleep(3)
         tdSql.execute("insert into tb1 values (now, 1, 'tb1_a1')")
-        self.sleep(4)
+        tdLog.sleep(4)
         tdSql.execute("insert into tb4 values (now, -4, 'tb4_b4')")
-        tdLog.info("retrieve data from strm order by ts desc")
+        tdSql.waitedQuery("select * from strm order by ts desc", 8, 100)
-        for i in range(100):
-            time.sleep(1)
-            tdSql.query("select * from strm order by ts desc")
-            if tdSql.queryRows == 8:
-                break
         tdSql.checkRows(8)
         tdSql.checkData(0, 2, 1)
         tdSql.checkData(0, 3, "tb1_a1")
@@ -187,24 +157,14 @@ class TDTestCase:
 
         tdSql.execute("create table strm0 as select count(ts), count(c1), max(c2), min(c4), first(c5), last(c6) from stb where ts < now + 30s interval(4s) sliding(2s)")
         #tdSql.execute("create table strm0 as select count(ts), count(c1), max(c2), min(c4), first(c5) from stb where ts < now + 30s interval(4s) sliding(2s)")
-        self.sleep(1)
+        tdLog.sleep(1)
         tdSql.execute("insert into tb0 values (now, 0, 0, 0, 0, 'binary0', '涛思0', true) tb1 values (now, 1, 1, 1, 1, 'binary1', '涛思1', false) tb2 values (now, 2, 2, 2, 2, 'binary2', '涛思2', true) tb3 values (now, 3, 3, 3, 3, 'binary3', '涛思3', false) tb4 values (now, 4, 4, 4, 4, 'binary4', '涛思4', true) ")
 
-        tdLog.info("retrieve data from strm0")
+        tdSql.waitedQuery("select * from strm0 order by ts desc", 2, 60)
-        for i in range(60):
-            time.sleep(1)
-            tdSql.query("select * from strm0 order by ts desc")
-            if tdSql.queryRows == 2:
-                break
         tdSql.checkRows(2)
 
         tdSql.execute("insert into tb0 values (now, 10, 10, 10, 10, 'binary0', '涛思0', true) tb1 values (now, 11, 11, 11, 11, 'binary1', '涛思1', false) tb2 values (now, 12, 12, 12, 12, 'binary2', '涛思2', true) tb3 values (now, 13, 13, 13, 13, 'binary3', '涛思3', false) tb4 values (now, 14, 14, 14, 14, 'binary4', '涛思4', true) ")
-        tdLog.info("retrieve data from strm0 again")
+        tdSql.waitedQuery("select * from strm0 order by ts desc", 4, 60)
-        for i in range(60):
-            time.sleep(1)
-            tdSql.query("select * from strm0 order by ts desc")
-            if tdSql.queryRows == 4:
-                break
         tdSql.checkRows(4)
 
     def run(self):

tests/pytest/stream/stream1.py

@@ -55,10 +55,7 @@ class TDTestCase:
         tdSql.checkRows(tbNum + 1)
 
         tdLog.info("===== step3 =====")
-        tdLog.info("sleeping 120 seconds")
+        tdSql.waitedQuery("select * from s0", 1, 120)
-        time.sleep(120)
-        tdSql.query("select * from s0")
-
         try:
             tdSql.checkData(0, 1, rowNum)
             tdSql.checkData(0, 2, rowNum)
@@ -82,10 +79,7 @@ class TDTestCase:
         tdSql.checkRows(tbNum + 1)
 
         tdLog.info("===== step7 =====")
-        tdLog.info("sleeping 120 seconds")
+        tdSql.waitedQuery("select * from s0", 1, 120)
-        time.sleep(120)
-
-        tdSql.query("select * from s0")
         try:
             tdSql.checkData(0, 1, rowNum)
             tdSql.checkData(0, 2, rowNum)
@@ -108,10 +102,7 @@ class TDTestCase:
         tdSql.checkRows(tbNum + 2)
 
         tdLog.info("===== step9 =====")
-        tdLog.info("sleeping 120 seconds")
+        tdSql.waitedQuery("select * from s1", 1, 120)
-        time.sleep(120)
-
-        tdSql.query("select * from s1")
         try:
             tdSql.checkData(0, 1, rowNum * tbNum)
             tdSql.checkData(0, 2, rowNum * tbNum)
@@ -134,9 +125,7 @@ class TDTestCase:
         tdSql.checkRows(tbNum + 2)
 
         tdLog.info("===== step13 =====")
-        tdLog.info("sleeping 120 seconds")
+        tdSql.waitedQuery("select * from s1", 1, 120)
-        time.sleep(120)
-        tdSql.query("select * from s1")
         try:
             tdSql.checkData(0, 1, rowNum * tbNum)
             tdSql.checkData(0, 2, rowNum * tbNum)

tests/pytest/stream/stream2.py

@@ -53,8 +53,7 @@ class TDTestCase:
         tdSql.checkRows(tbNum + 1)
 
         tdLog.info("===== step3 =====")
-        time.sleep(120)
+        tdSql.waitedQuery("select * from s0", 1, 120)
-        tdSql.query("select * from s0")
         try:
             tdSql.checkData(0, 1, rowNum)
         except Exception as e:
@@ -81,8 +80,7 @@ class TDTestCase:
             tdLog.info(repr(e))
 
         tdLog.info("===== step7 =====")
-        time.sleep(120)
+        tdSql.waitedQuery("select * from s0", 1, 120)
-        tdSql.query("select * from s0")
         try:
             tdSql.checkData(0, 1, rowNum)
             tdSql.checkData(0, 2, rowNum)
@@ -107,8 +105,7 @@ class TDTestCase:
         tdSql.checkRows(tbNum + 2)
 
         tdLog.info("===== step9 =====")
-        time.sleep(120)
+        tdSql.waitedQuery("select * from s1", 1, 120)
-        tdSql.query("select * from s1")
         try:
             tdSql.checkData(0, 1, totalNum)
             tdSql.checkData(0, 2, totalNum)
@@ -137,8 +134,7 @@ class TDTestCase:
             tdLog.info(repr(e))
 
         tdLog.info("===== step13 =====")
-        time.sleep(120)
+        tdSql.waitedQuery("select * from s1", 1, 120)
-        tdSql.query("select * from s1")
         try:
             tdSql.checkData(0, 1, totalNum)
             #tdSql.checkData(0, 2, None)

tests/pytest/util/sql.py

@@ -29,10 +29,8 @@ class TDSql:
         self.cursor = cursor
 
         if (log):
-            frame = inspect.stack()[1]
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
-            callerModule = inspect.getmodule(frame[0])
+            self.cursor.log(caller.filename + ".sql")
-            callerFilename = callerModule.__file__
-            self.cursor.log(callerFilename + ".sql")
 
     def close(self):
         self.cursor.close()
@@ -55,12 +53,8 @@ class TDSql:
         except BaseException:
             expectErrNotOccured = False
         if expectErrNotOccured:
-            frame = inspect.stack()[1]
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
-            callerModule = inspect.getmodule(frame[0])
+            tdLog.exit("%s(%d) failed: sql:%s, expect error not occured" % (caller.filename, caller.lineno, sql))
-            callerFilename = callerModule.__file__
-            tdLog.exit(
-                "%s failed: sql:%s, expect error not occured" %
-                (callerFilename, sql))
         else:
             self.queryRows = 0
             self.queryCols = 0
@@ -69,75 +63,68 @@ class TDSql:
 
     def query(self, sql):
         self.sql = sql
-        self.cursor.execute(sql)
+        try:
-        self.queryResult = self.cursor.fetchall()
+            self.cursor.execute(sql)
-        self.queryRows = len(self.queryResult)
+            self.queryResult = self.cursor.fetchall()
-        self.queryCols = len(self.cursor.description)
+            self.queryRows = len(self.queryResult)
-        # if self.queryRows == 1 and self.queryCols == 1:
+            self.queryCols = len(self.cursor.description)
-        #	tdLog.info("sql:%s, rows:%d cols:%d data:%s" % (self.sql, self.queryRows, self.queryCols, self.queryResult[0][0]))
+        except Exception as e:
-        # else:
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
-        #	tdLog.info("sql:%s, rows:%d cols:%d" % (self.sql, self.queryRows, self.queryCols))
+            args = (caller.filename, caller.lineno, sql, repr(e))
+            tdLog.exit("%s(%d) failed: sql:%s, %s" % args)
         return self.queryRows
 
+    def waitedQuery(self, sql, expectRows, timeout):
+        tdLog.info("sql: %s, try to retrieve %d rows in %d seconds" % (sql, expectRows, timeout))
+        self.sql = sql
+        try:
+            for i in range(timeout):
+                self.cursor.execute(sql)
+                self.queryResult = self.cursor.fetchall()
+                self.queryRows = len(self.queryResult)
+                self.queryCols = len(self.cursor.description)
+                if self.queryRows >= expectRows:
+                    return (self.queryRows, i)
+                time.sleep(1)
+        except Exception as e:
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
+            args = (caller.filename, caller.lineno, sql, repr(e))
+            tdLog.exit("%s(%d) failed: sql:%s, %s" % args)
+        return (self.queryRows, timeout)
+
     def checkRows(self, expectRows):
-        if self.queryRows != expectRows:
+        if self.queryRows == expectRows:
-            frame = inspect.stack()[1]
+            tdLog.info("sql:%s, queryRows:%d == expect:%d" % (self.sql, self.queryRows, expectRows))
-            callerModule = inspect.getmodule(frame[0])
+        else:
-            callerFilename = callerModule.__file__
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
-            tdLog.exit(
+            args = (caller.filename, caller.lineno, self.sql, self.queryRows, expectRows)
-                "%s failed: sql:%s, queryRows:%d != expect:%d" %
+            tdLog.exit("%s(%d) failed: sql:%s, queryRows:%d != expect:%d" % args)
-                (callerFilename, self.sql, self.queryRows, expectRows))
+
-        tdLog.info("sql:%s, queryRows:%d == expect:%d" %
+    def checkRowCol(self, row, col):
-                   (self.sql, self.queryRows, expectRows))
+        caller = inspect.getframeinfo(inspect.stack()[2][0])
+        if row < 0:
+            args = (caller.filename, caller.lineno, self.sql, row)
+            tdLog.exit("%s(%d) failed: sql:%s, row:%d is smaller than zero" % args)
+        if col < 0:
+            args = (caller.filename, caller.lineno, self.sql, row)
+            tdLog.exit("%s(%d) failed: sql:%s, col:%d is smaller than zero" % args)
+        if row > self.queryRows:
+            args = (caller.filename, caller.lineno, self.sql, row, self.queryRows)
+            tdLog.exit("%s(%d) failed: sql:%s, row:%d is larger than queryRows:%d" % args)
+        if col > self.queryCols:
+            args = (caller.filename, caller.lineno, self.sql, col, self.queryCols)
+            tdLog.exit("%s(%d) failed: sql:%s, col:%d is larger than queryCols:%d" % args)
 
     def checkDataType(self, row, col, dataType):
-        frame = inspect.stack()[1]
+        self.checkRowCol(row, col)
-        callerModule = inspect.getmodule(frame[0])
-        callerFilename = callerModule.__file__
-
-        if row < 0:
-            tdLog.exit(
-                "%s failed: sql:%s, row:%d is smaller than zero" %
-                (callerFilename, self.sql, row))
-        if col < 0:
-            tdLog.exit(
-                "%s failed: sql:%s, col:%d is smaller than zero" %
-                (callerFilename, self.sql, col))
-        if row > self.queryRows:
-            tdLog.exit(
-                "%s failed: sql:%s, row:%d is larger than queryRows:%d" %
-                (callerFilename, self.sql, row, self.queryRows))
-        if col > self.queryCols:
-            tdLog.exit(
-                "%s failed: sql:%s, col:%d is larger than queryCols:%d" %
-                (callerFilename, self.sql, col, self.queryCols))
-
         return self.cursor.istype(col, dataType)
 
     def checkData(self, row, col, data):
-        frame = inspect.stack()[1]
+        self.checkRowCol(row, col)
-        callerModule = inspect.getmodule(frame[0])
-        callerFilename = callerModule.__file__
-
-        if row < 0:
-            tdLog.exit(
-                "%s failed: sql:%s, row:%d is smaller than zero" %
-                (callerFilename, self.sql, row))
-        if col < 0:
-            tdLog.exit(
-                "%s failed: sql:%s, col:%d is smaller than zero" %
-                (callerFilename, self.sql, col))
-        if row > self.queryRows:
-            tdLog.exit(
-                "%s failed: sql:%s, row:%d is larger than queryRows:%d" %
-                (callerFilename, self.sql, row, self.queryRows))
-        if col > self.queryCols:
-            tdLog.exit(
-                "%s failed: sql:%s, col:%d is larger than queryCols:%d" %
-                (callerFilename, self.sql, col, self.queryCols))
         if self.queryResult[row][col] != data:
-            tdLog.exit("%s failed: sql:%s row:%d col:%d data:%s != expect:%s" % (
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
-                callerFilename, self.sql, row, col, self.queryResult[row][col], data))
+            args = (caller.filename, caller.lineno, self.sql, row, col, self.queryResult[row][col], data)
+            tdLog.exit("%s(%d) failed: sql:%s row:%d col:%d data:%s != expect:%s" % args)
 
         if data is None:
             tdLog.info("sql:%s, row:%d col:%d data:%s == expect:%s" %
@@ -153,26 +140,7 @@ class TDSql:
                        (self.sql, row, col, self.queryResult[row][col], data))
 
     def getData(self, row, col):
-        frame = inspect.stack()[1]
+        self.checkRowCol(row, col)
-        callerModule = inspect.getmodule(frame[0])
-        callerFilename = callerModule.__file__
-
-        if row < 0:
-            tdLog.exit(
-                "%s failed: sql:%s, row:%d is smaller than zero" %
-                (callerFilename, self.sql, row))
-        if col < 0:
-            tdLog.exit(
-                "%s failed: sql:%s, col:%d is smaller than zero" %
-                (callerFilename, self.sql, col))
-        if row > self.queryRows:
-            tdLog.exit(
-                "%s failed: sql:%s, row:%d is larger than queryRows:%d" %
-                (callerFilename, self.sql, row, self.queryRows))
-        if col > self.queryCols:
-            tdLog.exit(
-                "%s failed: sql:%s, col:%d is larger than queryCols:%d" %
-                (callerFilename, self.sql, col, self.queryCols))
         return self.queryResult[row][col]
 
     def executeTimes(self, sql, times):
@@ -185,20 +153,21 @@ class TDSql:
 
     def execute(self, sql):
         self.sql = sql
-        self.affectedRows = self.cursor.execute(sql)
+        try:
+            self.affectedRows = self.cursor.execute(sql)
+        except Exception as e:
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
+            args = (caller.filename, caller.lineno, sql, repr(e))
+            tdLog.exit("%s(%d) failed: sql:%s, %s" % args)
         return self.affectedRows
 
     def checkAffectedRows(self, expectAffectedRows):
         if self.affectedRows != expectAffectedRows:
-            frame = inspect.stack()[1]
+            caller = inspect.getframeinfo(inspect.stack()[1][0])
-            callerModule = inspect.getmodule(frame[0])
+            args = (caller.filename, caller.lineno, self.sql, self.affectedRows, expectAffectedRows)
-            callerFilename = callerModule.__file__
+            tdLog.exit("%s(%d) failed: sql:%s, affectedRows:%d != expect:%d" % args)
 
-            tdLog.exit(
+        tdLog.info("sql:%s, affectedRows:%d == expect:%d" % (self.sql, self.affectedRows, expectAffectedRows))
-                "%s failed: sql:%s, affectedRows:%d != expect:%d" %
-                (callerFilename, self.sql, self.affectedRows, expectAffectedRows))
-        tdLog.info("sql:%s, affectedRows:%d == expect:%d" %
-                   (self.sql, self.affectedRows, expectAffectedRows))
 
 
 tdSql = TDSql()