granicus.if.org Git - esp-idf/blob - tools/tiny-test-fw/DUT.py

   1 # Copyright 2015-2017 Espressif Systems (Shanghai) PTE LTD
   2 #
   3 # Licensed under the Apache License, Version 2.0 (the "License");
   4 # you may not use this file except in compliance with the License.
   5 # You may obtain a copy of the License at
   6 #
   7 #     http:#www.apache.org/licenses/LICENSE-2.0
   8 #
   9 # Unless required by applicable law or agreed to in writing, software
  10 # distributed under the License is distributed on an "AS IS" BASIS,
  11 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  12 # See the License for the specific language governing permissions and
  13 # limitations under the License.
  14
  15 """
  16 DUT provides 3 major groups of features:
  17
  18 * DUT port feature, provide basic open/close/read/write features
  19 * DUT tools, provide extra methods to control the device, like download and start app
  20 * DUT expect method, provide features for users to check DUT outputs
  21
  22 The current design of DUT have 3 classes for one DUT: BaseDUT, DUTPort, DUTTool.
  23
  24 * BaseDUT class:
  25     * defines methods DUT port and DUT tool need to overwrite
  26     * provide the expect methods and some other methods based on DUTPort
  27 * DUTPort class:
  28     * inherent from BaseDUT class
  29     * implements the port features by overwriting port methods defined in BaseDUT
  30 * DUTTool class:
  31     * inherent from one of the DUTPort class
  32     * implements the tools features by overwriting tool methods defined in BaseDUT
  33     * could add some new methods provided by the tool
  34
  35 This module implements the BaseDUT class and one of the port class SerialDUT.
  36 User should implement their DUTTool classes.
  37 If they using different port then need to implement their DUTPort class as well.
  38 """
  39
  40 from __future__ import print_function
  41 import time
  42 import re
  43 import threading
  44 import copy
  45 import sys
  46 import functools
  47
  48 import serial
  49 from serial.tools import list_ports
  50
  51 import Utility
  52
  53 if sys.version_info[0] == 2:
  54     import Queue as _queue
  55 else:
  56     import queue as _queue
  57
  58
  59 class ExpectTimeout(ValueError):
  60     """ timeout for expect method """
  61     pass
  62
  63
  64 class UnsupportedExpectItem(ValueError):
  65     """ expect item not supported by the expect method """
  66     pass
  67
  68
  69 def _expect_lock(func):
  70     @functools.wraps(func)
  71     def handler(self, *args, **kwargs):
  72         with self.expect_lock:
  73             ret = func(self, *args, **kwargs)
  74         return ret
  75     return handler
  76
  77
  78 def _decode_data(data):
  79     """ for python3, if the data is bytes, then decode it to string """
  80     if isinstance(data, bytes):
  81         # convert bytes to string
  82         try:
  83             data = data.decode("utf-8", "ignore")
  84         except UnicodeDecodeError:
  85             data = data.decode("iso8859-1", )
  86     return data
  87
  88
  89 def _pattern_to_string(pattern):
  90     try:
  91         ret = "RegEx: " + pattern.pattern
  92     except AttributeError:
  93         ret = pattern
  94     return ret
  95
  96
  97 class _DataCache(_queue.Queue):
  98     """
  99     Data cache based on Queue. Allow users to process data cache based on bytes instead of Queue."
 100     """
 101
 102     def __init__(self, maxsize=0):
 103         _queue.Queue.__init__(self, maxsize=maxsize)
 104         self.data_cache = str()
 105
 106     def _move_from_queue_to_cache(self):
 107         """
 108         move all of the available data in the queue to cache
 109
 110         :return: True if moved any item from queue to data cache, else False
 111         """
 112         ret = False
 113         while True:
 114             try:
 115                 self.data_cache += _decode_data(self.get(0))
 116                 ret = True
 117             except _queue.Empty:
 118                 break
 119         return ret
 120
 121     def get_data(self, timeout=0.0):
 122         """
 123         get a copy of data from cache.
 124
 125         :param timeout: timeout for waiting new queue item
 126         :return: copy of data cache
 127         """
 128         # make sure timeout is non-negative
 129         if timeout < 0:
 130             timeout = 0
 131
 132         ret = self._move_from_queue_to_cache()
 133
 134         if not ret:
 135             # we only wait for new data if we can't provide a new data_cache
 136             try:
 137                 data = self.get(timeout=timeout)
 138                 self.data_cache += _decode_data(data)
 139             except _queue.Empty:
 140                 # don't do anything when on update for cache
 141                 pass
 142         return copy.deepcopy(self.data_cache)
 143
 144     def flush(self, index=0xFFFFFFFF):
 145         """
 146         flush data from cache.
 147
 148         :param index: if < 0 then don't do flush, otherwise flush data before index
 149         :return: None
 150         """
 151         # first add data in queue to cache
 152         self.get_data()
 153
 154         if index > 0:
 155             self.data_cache = self.data_cache[index:]
 156
 157
 158 class _LogThread(threading.Thread, _queue.Queue):
 159     """
 160     We found some SD card on Raspberry Pi could have very bad performance.
 161     It could take seconds to save small amount of data.
 162     If the DUT receives data and save it as log, then it stops receiving data until log is saved.
 163     This could lead to expect timeout.
 164     As an workaround to this issue, ``BaseDUT`` class will create a thread to save logs.
 165     Then data will be passed to ``expect`` as soon as received.
 166     """
 167     def __init__(self):
 168         threading.Thread.__init__(self, name="LogThread")
 169         _queue.Queue.__init__(self, maxsize=0)
 170         self.setDaemon(True)
 171         self.flush_lock = threading.Lock()
 172
 173     def save_log(self, filename, data):
 174         """
 175         :param filename: log file name
 176         :param data: log data. Must be ``bytes``.
 177         """
 178         self.put({"filename": filename, "data": data})
 179
 180     def flush_data(self):
 181         with self.flush_lock:
 182             data_cache = dict()
 183             while True:
 184                 # move all data from queue to data cache
 185                 try:
 186                     log = self.get_nowait()
 187                     try:
 188                         data_cache[log["filename"]] += log["data"]
 189                     except KeyError:
 190                         data_cache[log["filename"]] = log["data"]
 191                 except _queue.Empty:
 192                     break
 193             # flush data
 194             for filename in data_cache:
 195                 with open(filename, "ab+") as f:
 196                     f.write(data_cache[filename])
 197
 198     def run(self):
 199         while True:
 200             time.sleep(1)
 201             self.flush_data()
 202
 203
 204 class _RecvThread(threading.Thread):
 205
 206     PERFORMANCE_PATTERN = re.compile(r"\[Performance]\[(\w+)]: ([^\r\n]+)\r?\n")
 207
 208     def __init__(self, read, data_cache):
 209         super(_RecvThread, self).__init__()
 210         self.exit_event = threading.Event()
 211         self.setDaemon(True)
 212         self.read = read
 213         self.data_cache = data_cache
 214         # cache the last line of recv data for collecting performance
 215         self._line_cache = str()
 216
 217     def collect_performance(self, data):
 218         """ collect performance """
 219         if data:
 220             decoded_data = _decode_data(data)
 221
 222             matches = self.PERFORMANCE_PATTERN.findall(self._line_cache + decoded_data)
 223             for match in matches:
 224                 Utility.console_log("[Performance][{}]: {}".format(match[0], match[1]),
 225                                     color="orange")
 226
 227             # cache incomplete line to later process
 228             lines = decoded_data.splitlines(True)
 229             last_line = lines[-1]
 230
 231             if last_line[-1] != "\n":
 232                 if len(lines) == 1:
 233                     # only one line and the line is not finished, then append this to cache
 234                     self._line_cache += lines[-1]
 235                 else:
 236                     # more than one line and not finished, replace line cache
 237                     self._line_cache = lines[-1]
 238             else:
 239                 # line finishes, flush cache
 240                 self._line_cache = str()
 241
 242     def run(self):
 243         while not self.exit_event.isSet():
 244             data = self.read(1000)
 245             if data:
 246                 self.data_cache.put(data)
 247                 self.collect_performance(data)
 248
 249     def exit(self):
 250         self.exit_event.set()
 251         self.join()
 252
 253
 254 class BaseDUT(object):
 255     """
 256     :param name: application defined name for port
 257     :param port: comport name, used to create DUT port
 258     :param log_file: log file name
 259     :param app: test app instance
 260     :param kwargs: extra args for DUT to create ports
 261     """
 262
 263     DEFAULT_EXPECT_TIMEOUT = 10
 264     MAX_EXPECT_FAILURES_TO_SAVED = 10
 265
 266     LOG_THREAD = _LogThread()
 267     LOG_THREAD.start()
 268
 269     def __init__(self, name, port, log_file, app, **kwargs):
 270
 271         self.expect_lock = threading.Lock()
 272         self.name = name
 273         self.port = port
 274         self.log_file = log_file
 275         self.app = app
 276         self.data_cache = _DataCache()
 277         self.receive_thread = None
 278         self.expect_failures = []
 279         # open and start during init
 280         self.open()
 281
 282     def __str__(self):
 283         return "DUT({}: {})".format(self.name, str(self.port))
 284
 285     def _save_expect_failure(self, pattern, data, start_time):
 286         """
 287         Save expect failure. If the test fails, then it will print the expect failures.
 288         In some cases, user will handle expect exceptions.
 289         The expect failures could be false alarm, and test case might generate a lot of such failures.
 290         Therefore, we don't print the failure immediately and limit the max size of failure list.
 291         """
 292         self.expect_failures.insert(0, {"pattern": pattern, "data": data,
 293                                         "start": start_time, "end": time.time()})
 294         self.expect_failures = self.expect_failures[:self.MAX_EXPECT_FAILURES_TO_SAVED]
 295
 296     def _save_dut_log(self, data):
 297         """
 298         Save DUT log into file using another thread.
 299         This is a workaround for some devices takes long time for file system operations.
 300
 301         See descriptions in ``_LogThread`` for details.
 302         """
 303         self.LOG_THREAD.save_log(self.log_file, data)
 304
 305     # define for methods need to be overwritten by Port
 306     @classmethod
 307     def list_available_ports(cls):
 308         """
 309         list all available ports.
 310
 311         subclass (port) must overwrite this method.
 312
 313         :return: list of available comports
 314         """
 315         pass
 316
 317     def _port_open(self):
 318         """
 319         open the port.
 320
 321         subclass (port) must overwrite this method.
 322
 323         :return: None
 324         """
 325         pass
 326
 327     def _port_read(self, size=1):
 328         """
 329         read form port. This method should not blocking for long time, otherwise receive thread can not exit.
 330
 331         subclass (port) must overwrite this method.
 332
 333         :param size: max size to read.
 334         :return: read data.
 335         """
 336         pass
 337
 338     def _port_write(self, data):
 339         """
 340         write to port.
 341
 342         subclass (port) must overwrite this method.
 343
 344         :param data: data to write
 345         :return: None
 346         """
 347         pass
 348
 349     def _port_close(self):
 350         """
 351         close port.
 352
 353         subclass (port) must overwrite this method.
 354
 355         :return: None
 356         """
 357         pass
 358
 359     # methods that need to be overwritten by Tool
 360     @classmethod
 361     def confirm_dut(cls, port, app, **kwargs):
 362         """
 363         confirm if it's a DUT, usually used by auto detecting DUT in by Env config.
 364
 365         subclass (tool) must overwrite this method.
 366
 367         :param port: comport
 368         :param app: app instance
 369         :return: True or False
 370         """
 371         pass
 372
 373     def start_app(self):
 374         """
 375         usually after we got DUT, we need to do some extra works to let App start.
 376         For example, we need to reset->download->reset to let IDF application start on DUT.
 377
 378         subclass (tool) must overwrite this method.
 379
 380         :return: None
 381         """
 382         pass
 383
 384     # methods that features raw port methods
 385     def open(self):
 386         """
 387         open port and create thread to receive data.
 388
 389         :return: None
 390         """
 391         self._port_open()
 392         self.receive_thread = _RecvThread(self._port_read, self.data_cache)
 393         self.receive_thread.start()
 394
 395     def close(self):
 396         """
 397         close receive thread and then close port.
 398
 399         :return: None
 400         """
 401         if self.receive_thread:
 402             self.receive_thread.exit()
 403         self._port_close()
 404         self.LOG_THREAD.flush_data()
 405
 406     @staticmethod
 407     def u_to_bytearray(data):
 408         """
 409         if data is not bytearray then it tries to convert it
 410
 411         :param data: data which needs to be checked and maybe transformed
 412         """
 413         if type(data) is type(u''):
 414             try:
 415                 data = data.encode('utf-8')
 416             except:
 417                 print(u'Cannot encode {} of type {}'.format(data, type(data)))
 418                 raise
 419         return data
 420
 421     def write(self, data, eol="\r\n", flush=True):
 422         """
 423         :param data: data
 424         :param eol: end of line pattern.
 425         :param flush: if need to flush received data cache before write data.
 426                       usually we need to flush data before write,
 427                       make sure processing outputs generated by wrote.
 428         :return: None
 429         """
 430         # do flush before write
 431         if flush:
 432             self.data_cache.flush()
 433         # do write if cache
 434         if data is not None:
 435             self._port_write(self.u_to_bytearray(data) + self.u_to_bytearray(eol) if eol else self.u_to_bytearray(data))
 436
 437     @_expect_lock
 438     def read(self, size=0xFFFFFFFF):
 439         """
 440         read(size=0xFFFFFFFF)
 441         read raw data. NOT suggested to use this method.
 442         Only use it if expect method doesn't meet your requirement.
 443
 444         :param size: read size. default read all data
 445         :return: read data
 446         """
 447         data = self.data_cache.get_data(0)[:size]
 448         self.data_cache.flush(size)
 449         return data
 450
 451     # expect related methods
 452
 453     @staticmethod
 454     def _expect_str(data, pattern):
 455         """
 456         protected method. check if string is matched in data cache.
 457
 458         :param data: data to process
 459         :param pattern: string
 460         :return: pattern if match succeed otherwise None
 461         """
 462         index = data.find(pattern)
 463         if index != -1:
 464             ret = pattern
 465             index += len(pattern)
 466         else:
 467             ret = None
 468         return ret, index
 469
 470     @staticmethod
 471     def _expect_re(data, pattern):
 472         """
 473         protected method. check if re pattern is matched in data cache
 474
 475         :param data: data to process
 476         :param pattern: compiled RegEx pattern
 477         :return: match groups if match succeed otherwise None
 478         """
 479         ret = None
 480         if type(pattern.pattern) is type(u''):
 481             pattern = re.compile(BaseDUT.u_to_bytearray(pattern.pattern))
 482         if type(data) is type(u''):
 483             data = BaseDUT.u_to_bytearray(data)
 484         match = pattern.search(data)
 485         if match:
 486             ret = tuple(x.decode() for x in match.groups())
 487             index = match.end()
 488         else:
 489             index = -1
 490         return ret, index
 491
 492     EXPECT_METHOD = [
 493         [type(re.compile("")), "_expect_re"],
 494         [type(b''), "_expect_str"], # Python 2 & 3 hook to work without 'from builtins import str' from future
 495         [type(u''), "_expect_str"],
 496     ]
 497
 498     def _get_expect_method(self, pattern):
 499         """
 500         protected method. get expect method according to pattern type.
 501
 502         :param pattern: expect pattern, string or compiled RegEx
 503         :return: ``_expect_str`` or ``_expect_re``
 504         """
 505         for expect_method in self.EXPECT_METHOD:
 506             if isinstance(pattern, expect_method[0]):
 507                 method = expect_method[1]
 508                 break
 509         else:
 510             raise UnsupportedExpectItem()
 511         return self.__getattribute__(method)
 512
 513     @_expect_lock
 514     def expect(self, pattern, timeout=DEFAULT_EXPECT_TIMEOUT):
 515         """
 516         expect(pattern, timeout=DEFAULT_EXPECT_TIMEOUT)
 517         expect received data on DUT match the pattern. will raise exception when expect timeout.
 518
 519         :raise ExpectTimeout: failed to find the pattern before timeout
 520         :raise UnsupportedExpectItem: pattern is not string or compiled RegEx
 521
 522         :param pattern: string or compiled RegEx(string pattern)
 523         :param timeout: timeout for expect
 524         :return: string if pattern is string; matched groups if pattern is RegEx
 525         """
 526         method = self._get_expect_method(pattern)
 527
 528         # non-blocking get data for first time
 529         data = self.data_cache.get_data(0)
 530         start_time = time.time()
 531         while True:
 532             ret, index = method(data, pattern)
 533             if ret is not None:
 534                 self.data_cache.flush(index)
 535                 break
 536             time_remaining = start_time + timeout - time.time()
 537             if time_remaining < 0:
 538                 break
 539             # wait for new data from cache
 540             data = self.data_cache.get_data(time_remaining)
 541
 542         if ret is None:
 543             pattern = _pattern_to_string(pattern)
 544             self._save_expect_failure(pattern, data, start_time)
 545             raise ExpectTimeout(self.name + ": " + pattern)
 546         return ret
 547
 548     def _expect_multi(self, expect_all, expect_item_list, timeout):
 549         """
 550         protected method. internal logical for expect multi.
 551
 552         :param expect_all: True or False, expect all items in the list or any in the list
 553         :param expect_item_list: expect item list
 554         :param timeout: timeout
 555         :return: None
 556         """
 557         def process_expected_item(item_raw):
 558             # convert item raw data to standard dict
 559             item = {
 560                 "pattern": item_raw[0] if isinstance(item_raw, tuple) else item_raw,
 561                 "method": self._get_expect_method(item_raw[0] if isinstance(item_raw, tuple)
 562                                                   else item_raw),
 563                 "callback": item_raw[1] if isinstance(item_raw, tuple) else None,
 564                 "index": -1,
 565                 "ret": None,
 566             }
 567             return item
 568
 569         expect_items = [process_expected_item(x) for x in expect_item_list]
 570
 571         # non-blocking get data for first time
 572         data = self.data_cache.get_data(0)
 573
 574         start_time = time.time()
 575         matched_expect_items = list()
 576         while True:
 577             for expect_item in expect_items:
 578                 if expect_item not in matched_expect_items:
 579                     # exclude those already matched
 580                     expect_item["ret"], expect_item["index"] = \
 581                         expect_item["method"](data, expect_item["pattern"])
 582                     if expect_item["ret"] is not None:
 583                         # match succeed for one item
 584                         matched_expect_items.append(expect_item)
 585
 586             # if expect all, then all items need to be matched,
 587             # else only one item need to matched
 588             if expect_all:
 589                 match_succeed = len(matched_expect_items) == len(expect_items)
 590             else:
 591                 match_succeed = True if matched_expect_items else False
 592
 593             time_remaining = start_time + timeout - time.time()
 594             if time_remaining < 0 or match_succeed:
 595                 break
 596             else:
 597                 data = self.data_cache.get_data(time_remaining)
 598
 599         if match_succeed:
 600             # sort matched items according to order of appearance in the input data,
 601             # so that the callbacks are invoked in correct order
 602             matched_expect_items = sorted(matched_expect_items, key=lambda it: it["index"])
 603             # invoke callbacks and flush matched data cache
 604             slice_index = -1
 605             for expect_item in matched_expect_items:
 606                 # trigger callback
 607                 if expect_item["callback"]:
 608                     expect_item["callback"](expect_item["ret"])
 609                 slice_index = max(slice_index, expect_item["index"])
 610             # flush already matched data
 611             self.data_cache.flush(slice_index)
 612         else:
 613             pattern = str([_pattern_to_string(x["pattern"]) for x in expect_items])
 614             self._save_expect_failure(pattern, data, start_time)
 615             raise ExpectTimeout(self.name + ": " + pattern)
 616
 617     @_expect_lock
 618     def expect_any(self, *expect_items, **timeout):
 619         """
 620         expect_any(*expect_items, timeout=DEFAULT_TIMEOUT)
 621         expect any of the patterns.
 622         will call callback (if provided) if pattern match succeed and then return.
 623         will pass match result to the callback.
 624
 625         :raise ExpectTimeout: failed to match any one of the expect items before timeout
 626         :raise UnsupportedExpectItem: pattern in expect_item is not string or compiled RegEx
 627
 628         :arg expect_items: one or more expect items.
 629                            string, compiled RegEx pattern or (string or RegEx(string pattern), callback)
 630         :keyword timeout: timeout for expect
 631         :return: None
 632         """
 633         # to be compatible with python2
 634         # in python3 we can write f(self, *expect_items, timeout=DEFAULT_TIMEOUT)
 635         if "timeout" not in timeout:
 636             timeout["timeout"] = self.DEFAULT_EXPECT_TIMEOUT
 637         return self._expect_multi(False, expect_items, **timeout)
 638
 639     @_expect_lock
 640     def expect_all(self, *expect_items, **timeout):
 641         """
 642         expect_all(*expect_items, timeout=DEFAULT_TIMEOUT)
 643         expect all of the patterns.
 644         will call callback (if provided) if all pattern match succeed and then return.
 645         will pass match result to the callback.
 646
 647         :raise ExpectTimeout: failed to match all of the expect items before timeout
 648         :raise UnsupportedExpectItem: pattern in expect_item is not string or compiled RegEx
 649
 650         :arg expect_items: one or more expect items.
 651                            string, compiled RegEx pattern or (string or RegEx(string pattern), callback)
 652         :keyword timeout: timeout for expect
 653         :return: None
 654         """
 655         # to be compatible with python2
 656         # in python3 we can write f(self, *expect_items, timeout=DEFAULT_TIMEOUT)
 657         if "timeout" not in timeout:
 658             timeout["timeout"] = self.DEFAULT_EXPECT_TIMEOUT
 659         return self._expect_multi(True, expect_items, **timeout)
 660
 661     @staticmethod
 662     def _format_ts(ts):
 663         return "{}:{}".format(time.strftime("%m-%d %H:%M:%S", time.localtime(ts)), str(ts % 1)[2:5])
 664
 665     def print_debug_info(self):
 666         """
 667         Print debug info of current DUT. Currently we will print debug info for expect failures.
 668         """
 669         Utility.console_log("DUT debug info for DUT: {}:".format(self.name), color="orange")
 670
 671         for failure in self.expect_failures:
 672             Utility.console_log(u"\t[pattern]: {}\r\n\t[data]: {}\r\n\t[time]: {} - {}\r\n"
 673                                 .format(failure["pattern"], failure["data"],
 674                                         self._format_ts(failure["start"]), self._format_ts(failure["end"])),
 675                                 color="orange")
 676
 677
 678 class SerialDUT(BaseDUT):
 679     """ serial with logging received data feature """
 680
 681     DEFAULT_UART_CONFIG = {
 682         "baudrate": 115200,
 683         "bytesize": serial.EIGHTBITS,
 684         "parity": serial.PARITY_NONE,
 685         "stopbits": serial.STOPBITS_ONE,
 686         "timeout": 0.05,
 687         "xonxoff": False,
 688         "rtscts": False,
 689     }
 690
 691     def __init__(self, name, port, log_file, app, **kwargs):
 692         self.port_inst = None
 693         self.serial_configs = self.DEFAULT_UART_CONFIG.copy()
 694         self.serial_configs.update(kwargs)
 695         super(SerialDUT, self).__init__(name, port, log_file, app, **kwargs)
 696
 697     def _format_data(self, data):
 698         """
 699         format data for logging. do decode and add timestamp.
 700
 701         :param data: raw data from read
 702         :return: formatted data (str)
 703         """
 704         timestamp = "[{}]".format(self._format_ts(time.time()))
 705         formatted_data = timestamp.encode() + b"\r\n" + data + b"\r\n"
 706         return formatted_data
 707
 708     def _port_open(self):
 709         self.port_inst = serial.Serial(self.port, **self.serial_configs)
 710
 711     def _port_close(self):
 712         self.port_inst.close()
 713
 714     def _port_read(self, size=1):
 715         data = self.port_inst.read(size)
 716         if data:
 717             self._save_dut_log(self._format_data(data))
 718         return data
 719
 720     def _port_write(self, data):
 721         if isinstance(data, str):
 722             data = data.encode()
 723         self.port_inst.write(data)
 724
 725     @classmethod
 726     def list_available_ports(cls):
 727         return [x.device for x in list_ports.comports()]