def exception_log(request): logger = loggers.ClassLogger(for_exception=True, log_file=DATAFILE)._get_logger( "test_module", "test_class", "test_function") request.addfinalizer(lambda: remove_logger(logger)) return logger
class TestSSHLogger(object): """This suite demonstrates autolog and sshlog fixtures usage. """ log = loggers.ClassLogger() def test_case_one(self): self.log.info("I'm in TC one.") # For this command output the new file test_case_one_<PID>__id_<lhost id>_type_<lhost type>.log has to be created. def test_case_one_two(self): # This test function doesn't use env fixture, so ssh logging configuration has to be omitted. self.log.info("TC with no env fixture.") def test_case_three(self): # The same as the first test function, but new file for ssh logs has to be created. self.log.info("I'm in TC tree.")
def introspection_log(request): logger = loggers.ClassLogger(introspection=False, log_file=DATAFILE)._get_logger( request.cls.__module__) request.addfinalizer(lambda: remove_logger(logger)) return logger
def file_log(request): logger = loggers.ClassLogger(log_file=DATAFILE)._get_logger( request.cls.__module__, request.cls.__name__) request.addfinalizer(lambda: remove_logger(logger)) return logger
class CommandCollector(object): """Thread safe collector for server command queue. """ class_logger = loggers.ClassLogger() def __init__(self): """Initialize CommandCollector class. """ self._lock = RLock() self.queue = [] @log_exception(msg="failed to add command") def add(self, cmd): """Add command to collector. Args: cmd(dict): Command Returns: bool: Status Examples:: command = {'client': "client-name-with-pid-1111", 'build': 'cool-software-v.0.0.0.1-pre-alfa', 'close': True, 'duration': 15} command_collector.add(command) """ with self._lock: self.queue.append(cmd) self.class_logger.info("Command added successfully. CMD keys: %s", list(cmd.keys())) return True def pop(self): """Pop the first item. Returns: dict: command Note: See also get() method. """ with self._lock: try: return self.queue.pop(FIRST_ITEM_IN_QUEUE) except IndexError: return None def get(self): """Same as pop but does not remove item. Returns: dict: command Note: See pop() method description. """ with self._lock: try: return self.queue[FIRST_ITEM_IN_QUEUE] except IndexError: return None def drop(self, index): """Remove item by index. Args: index(int): Index of item in queue list. Returns: dict|str: Command or Error message. """ with self._lock: try: return self.queue.pop(index) except IndexError: message = "ERROR: No item with such index: {0}".format(index) self.class_logger.error(message) return message except Exception as err: message = "ERROR: {0}".format(err) self.class_logger.error(message) return message def len(self): """Return command queue length. Returns: int: command queue length. """ with self._lock: return len(self.queue) def list(self): """Return list of all items. Returns: list[dict]: All commands list. """ with self._lock: return self.queue
def simple_log(request): logger = loggers.ClassLogger()._get_logger(request.cls.__module__, request.cls.__name__) request.addfinalizer(lambda: remove_logger(logger)) return logger
class XMLReportingServer(xmlrpc.XMLRPC): """Root reporting server handler. Note: This handler receive all test execution information and with command_processor process it to reports. """ NAME = "XMLReportingServer" class_logger = loggers.ClassLogger() # Last operation timestamp last_operation_time = None last_cmdprocess_time = None last_cmdprocess_status = None # Client collector clients = None # commands queue queue = None watchdog = None watchdog_thr = None # list of reports. {'type1': {<dict of instances>}, } _reports = {} # list of connectors. {'name': {<dict of instance>}, } _connectors = {} # To avoid process termination by buildbot we have to send keepalive messages to console keep_alive_interval = 3600 keep_alive_last = time.time() def xmlrpc_ping(self): """Return self.NAME. """ return self.NAME def setup(self, opts): """Create WRTM proxy instance and set necessary attributes. Args: opts(OptionParse): cli options (OptionParse parsed options). Returns: None """ self.last_operation_time = time.time() self.clients = ClientCollector() self.queue = CommandCollector() self._reports = {} self._connectors = {} self.init_connectors() # Start queue processing self.watchdog = True self.start_queue_watchdog() # Multiuser self.multiuser = opts.multiuser # pylint: disable=attribute-defined-outside-init def xmlrpc_shutdown(self, trycount=0, lasttry=0): """Store shutdown server command. Args: trycount(int): attempts count. lasttry(int): time of last attempt. """ if self.multiuser: message = "Multiuser mode On. Shutdown command canceled." self.class_logger.info(message) return message self.class_logger.info("Shutdown command received.") cmd = {'shutdown': trycount, 'lasttry': lasttry} self.queue.add(cmd) return "Shutdown command is added to queue." # TODO: Implement correct reactor stop def shutdown(self): """Shutdown xmlrpc server. """ qlen = self.queue.len() cinprocess = self.clients.inprocess() idle = False # Check if qlen == 1 because 1 command is shutdown itself. if qlen == 1 and len(cinprocess) == 0: idle = True if idle: self.watchdog = False self.watchdog_thr.join() pid = os.getpid() os.kill(pid, signal.SIGTERM) return "Server {0} ready to shut down.".format(self.NAME) else: return "Server {0} still processing queries... Cancel operation...".format( self.NAME) @update_timestamp def xmlrpc_open(self, client_id): """Store connected client information. Args: client_id(str): Unique client name. Returns: bool: True if command successfully processed. Examples:: xs = xmlrpclib.ServerProxy("http://localhost:18080") xs.reports.open("py.test-user-1234", "CoolSoftware-0.0.0.1234-1") """ self.class_logger.info("New client %s has connected to %s.", client_id, self.NAME) self.clients.update(client_id, ClientCollector.STATUSES[0]) return True @update_timestamp def xmlrpc_close(self, client_id): """Free client information. Args: client_id(str): Unique client name. Returns: bool: True if command successfully processed. Note: Set Inactive status to client and set session duration. Examples:: xs = xmlrpclib.ServerProxy("http://localhost:18080") xs.reports.close("py.test-user-1234", "CoolSoftware-0.0.0.1234-1") """ self.class_logger.info("Client %s has disconnected from %s.", client_id, self.NAME) connect_time = self.clients.get(client_id, "connect_time") if connect_time is not None: duration = time.time() - connect_time else: duration = 0 self.class_logger.info("Client %s session duration = %s.", client_id, duration) cmd = {'client': client_id, 'close': True, 'duration': duration} self.queue.add(cmd) self.clients.update(client_id, ClientCollector.STATUSES[1]) return True @update_timestamp def xmlrpc_reportadd(self, client_id, report_type): """Append client report attribute with report_type. Args: client_id(str): Unique client name. report_type(str): Report typr. E.g. "xml", "html" or "wrtm". Returns: bool True if command successfully processed. Examples:: xs = xmlrpclib.ServerProxy("http://localhost:18080") xs.reports.reportadd("py.test-user-1234", "CoolSoftware-0.0.0.1234-1", "xml") """ self.class_logger.info("Add %s report type for client %s.", report_type, client_id) self.clients.addreport(client_id, report_type) self.check_report_instance(report_type, client_id) return True @update_timestamp def xmlrpc_reportdel(self, client_id, report_type): """Remove report type from client report attribute. Args: client_id(str): Unique client name. report_type(str): Report typr. E.g. "xml", "html" or "wrtm". Returns: bool: True if command successfully processed. Examples:: xs = xmlrpclib.ServerProxy("http://localhost:18080") xs.reports.delreport("py.test-user-1234", "CoolSoftware-0.0.0.1234-1", "xml") """ self.class_logger.info("Remove %s report type from client %s.", report_type, client_id) self.clients.delreport(client_id, report_type) return True @update_timestamp def xmlrpc_reportconfig(self, client_id, report_type, cfgname, value): """Config XML RPC reports. Args: client_id(str): Unique client name. report_type(str): Report typr. E.g. "xml", "html" or "wrtm". cfgname(str): Report attribute. value(Depends on attribute): Attribute value. Returns: Depends on report. Note: Set report attributes. Examples:: xs = xmlrpclib.ServerProxy("http://localhost:18080") xs.reports.reportconfig("py.test-user-1234", "CoolSoftware-0.0.0.1234-1", "xml", "logfile", "/path/where/to/store/log") """ # if not hasattr(self, "{0}_report_cfg".format(report_type)): # return "WARNING: There is no method to configure report of the {0} type.".format(report_type) # return getattr(self, "{0}_report_cfg".format(report_type))(client_id, build, cfgname, value) self.check_report_instance(report_type, client_id) if cfgname == "options" and value: for i in value: setattr(self._reports[report_type.upper()][client_id], i[0], i[1]) setattr(self._reports[report_type.upper()][client_id], cfgname, value) if cfgname in ["", None]: return "ERROR: cfgname must be defined." try: setattr(self._reports[report_type.upper()][client_id], cfgname, value) except Exception as err: self.class_logger.error( "Setattr %s = %s failed for report '%s'. Exception occurred: %s", cfgname, value, report_type, err) return err else: self.class_logger.info("Setattr %s = %s is OK for report %s.", cfgname, value, report_type) return True def xmlrpc_idletime(self): """Return idle time. Returns: int: time elapsed from last processed xmlrpc query (int). """ return int(time.time() - self.last_operation_time) def xmlrpc_queueidletime(self): """Return queue idle time. Returns: int: time elapsed from last processed command (int). """ return int(time.time() - self.last_cmdprocess_time) def xmlrpc_queuelastcmdstatus(self): """Get last queue command process status. Returns: bool: last queue command process status """ return self.last_cmdprocess_status def xmlrpc_queuelen(self): """Get command queue length. Returns: int: command queue length """ return self.queue.len() def xmlrpc_queuelist(self): """Get command queue list. Returns: list[dict]: command queue list """ return self.queue.list() def xmlrpc_queuedropcmd(self, index): """Remove command from queue by index. Args: index(int): Index of command in queue. Returns: dict: Command. Note: It's recommended to stop queue processing first (see cmdprocdisable method) and check queuelist. """ return self.queue.drop(index) def xmlrpc_clientlist(self, ltype="active"): """Get list of active clients. Args: ltype(str): 'all'|'active' Returns: list: list of active clients """ if ltype == "all": return self.clients.all() elif ltype == "active": return self.clients.active() else: return "Unknown ltype option." def xmlrpc_clientfullinfo(self, client): """Return full client info. Args: client(tuple(str)): Tuple of ClientID and build. Returns: dict: Full client dictionary with all attributes. """ return str(self.clients.getall(client)) def xmlrpc_reportslist(self, r_type=None): """List of all report instances. Args: r_type(str): Report type to list. Returns: dict: dict of dict {<type>: {<build>: {<client>: <value>}}} Values are dicts of report specific values. (dict of dict) """ r_dict = {} if r_type is None: report_type_list = list(self._reports.keys()) else: report_type_list = [ _rt for _rt in self._reports if r_type.upper() in _rt ] for t_key in report_type_list: r_dict[t_key] = {} for b_key in self._reports[t_key]: r_dict[t_key][b_key] = self._reports[t_key][b_key].info() return r_dict def xmlrpc_reportmethod(self, report_type, client, method, params=None): """Call report class method. Args: report_type(str): Report type. client(tuple(str)): Tuple of ClientID and build. method(str): method name. params(list): method params. Returns: Query execution status if one. """ # ctime = self.clients.get((client, build), "connect_time") # if ctime is None: # ctime = 0 # duration = time.time() - ctime params = [] if params is None else params return getattr(self._reports[report_type.upper()][client], method)(*params) def xmlrpc_cmdprocdisable(self): """Disabling and stopping queue command processing. Returns: bool: Query execution status. """ self.watchdog = False self.class_logger.debug("cmdproc is disable") return not self.watchdog def xmlrpc_cmdprocenable(self): """Enabling queue command processing. Returns: bool: Query execution status. """ self.watchdog = True self.class_logger.debug("cmdproc is enable") return self.watchdog def xmlrpc_cmdprocstart(self): """Starting queue command processing. Returns: bool: Query execution status. """ return self.start_queue_watchdog() def xmlrpc_cmdproccheck(self): """Return queue command processing status. Returns: str: Query execution status. """ return "Watchdog is %s and cmdproc is %s" % ( self.watchdog, self.watchdog_thr.is_alive()) def xmlrpc_checklocks(self): """Get CommandCollector and ClientCollector lock statuses. Returns: dict{bool}: CommandCollector and ClientCollector lock statuses. """ return { "ClientCollector": self.clients._lock._is_owned(), # pylint: disable=protected-access "CommandCollector": self.queue._lock._is_owned() } # pylint: disable=protected-access @update_timestamp def xmlrpc_post(self, client, build, suite, tc, status, report=None, info=None, build_info=None, **kwargs): """Post TC run result. Args: client(tuple(str)): Tuple of ClientID and build. build(str): Build name. suite(str): Suite class name). tc(str): TC function name. status(str): TC status string ('Run', 'Passed', 'Failed'). report(dict): TC run duration, longreport, retval. Returns: bool: Query execution status. Examples:: xs = xmlrpclib.ServerProxy("http://localhost:18080") xs.reports.post("py.test-user-1234", "0.0.0.1234-1/CoolSoftware", "feature_tests.Feature1Test", "test_same_behaviour", "Run") """ self.class_logger.debug("Kwargs: %s", kwargs) if info is None: info = {} cmd = { 'client': client, 'build': build, 'suite': suite, 'tc': tc, 'status': status, 'report': report, 'info': info, 'build_info': build_info } with contextlib.suppress(Exception): self.queue.add(cmd) return True return False def queue_watchdog(self): """Send commands from queue to command processor in loop. Raises: Exception: exception while processing command. """ while self.watchdog: # Send keep_alive message _cur_time = time.time() if (self.keep_alive_last + self.keep_alive_interval) <= _cur_time: sys.stdout.write("Keep alive message. Time stamp: %s\n" % (_cur_time, )) sys.stdout.flush() self.keep_alive_last = _cur_time cmd = self.queue.get() if cmd is not None: try: self.last_cmdprocess_time = time.time() self.command_processor(cmd) self.class_logger.debug("Command processed.") self.queue.pop() self.class_logger.debug("Command removed from queue.") self.last_cmdprocess_status = True except Exception: self.last_cmdprocess_status = False exc_type, exc_value, exc_traceback = sys.exc_info() traceback_message = traceback.format_exception( exc_type, exc_value, exc_traceback) self.class_logger.error( "Exception while processing command: %s", cmd) self.class_logger.error("Traceback:\n%s", "".join(traceback_message)) raise else: time.sleep(0.5) self.class_logger.info("Exiting command processor.") return False def start_queue_watchdog(self): """Start watchdog in thread. """ def start_thr(): """Launching queue_watchdog in thread. """ self.watchdog_thr = Thread(target=self.queue_watchdog) self.watchdog_thr.daemon = True self.watchdog_thr.start() self.class_logger.info("Starting queue processing.") if not self.watchdog: self.class_logger.info( "Queue processing start canceled. Reason - it is disabled.") return False if self.watchdog_thr is None: # First start self.class_logger.info("Command processor first start.") start_thr() elif self.watchdog_thr.is_alive(): self.class_logger.info("Command processor is already running.") else: # Thread is dead # Try to stop current thread self.class_logger.info( "Command processor has been started but dead.") self.class_logger.info("Try to wait while thread terminates.") self.watchdog_thr.join(10) if self.watchdog_thr.is_alive(): self.class_logger.warning( "watchdog_thr didn't terminate after 10 sec.") self.class_logger.warning( "Thread object will be deleted and new one created.") # Try to restart self.class_logger.info( "Command processor has been started but dead.") start_thr() return True def command_processor(self, cmd): """Processing command from queue. Args: cmd(dict): Command. Returns: None """ # Truncating command for log message cmd1 = {k: v for k, v in cmd.items() if k not in ['report']} self.class_logger.info("Start processing command: %s.", cmd1) # Processing shutdown command. if "shutdown" in cmd: # Perform shutdown only if 30s have passed after previous try. if time.time() - cmd['lasttry'] >= 30: reactor.callFromThread(self.shutdown) # pylint: disable=no-member # Wait until shutdown time.sleep(1) # Put command again to queue if shutdown is canceled. # Cancel shutdown if 3 attempts are failed. if cmd['shutdown'] < 3: self.class_logger.info("Shutdown command is postponed.") self.queue.add({ 'shutdown': cmd['shutdown'] + 1, 'lasttry': time.time() }) else: self.class_logger.error( "Shutdown command is canceled after 3 failed attempts.") return for r_type in self.clients.get(cmd['client'], "reports"): self.class_logger.debug("Processing %s command.", r_type) try: self._reports[r_type.upper()][cmd['client']].process_cmd(cmd) if "close" in cmd: self.class_logger.info("Closing %s report.", r_type) self.clients.closereport(cmd['client'], r_type) except Exception as err: self.class_logger.error( "Error while processing command: %s. ERROR: %s", cmd, err) exc_type, exc_value, exc_traceback = sys.exc_info() traceback_message = traceback.format_exception( exc_type, exc_value, exc_traceback) self.class_logger.error("Traceback:\n%s", "".join(traceback_message)) def is_idle(self): """Command processor idle status. Returns: bool: True if command queue is empty and all clients are in closed state """ self.class_logger.info("Last operation time: %s", self.last_operation_time) qlen = self.queue.len() self.class_logger.info("Command queue length: %s", qlen) cinprocess = self.clients.inprocess() self.class_logger.info("Clients in process: %s", cinprocess) return qlen == 0 and len(cinprocess) == 0 def check_report_instance(self, r_type, client_id): """Create report instance if any for given client_id and build. Args: r_type(str): report type. client_id(str): Unique client name. Returns: None """ r_type = r_type.upper() if r_type not in self._reports: self._reports[r_type] = {} # if not build in self._reports[r_type]: # self._reports[r_type][build] = {} if client_id not in self._reports[r_type]: self._reports[r_type][client_id] = getattr( getattr(MODULES['reports.{0}'.format(r_type)], r_type), r_type)(connectors=self._connectors) def init_connectors(self): """Initializing connectors. """ for mod in MODULES: if mod.startswith('connectors.'): arr = mod.split('.') self._connectors[arr[1]] = getattr( getattr(MODULES[mod], arr[1].upper()), arr[1].upper())()
class ClientCollector(object): """Thread safe object for collecting clients dictionaries. """ # Allowed client statuses. STATUSES = ["Active", "Inactive"] class_logger = loggers.ClassLogger() def __init__(self): """Initialize ClientCollector class. """ self._lock = RLock() self.clients = {} def update(self, client, status): """Update status of the client. Args: client(tuple(str)): Tuple of ClientID and build. status(str): Available values are listed in STATUSES constant. Raises: ValueError: status not in self.STATUSES Returns: None Examples:: client_id = "py.test-user-1234" build = "0.0.0.0.pre-alfa" client_collector.update((client_id, build), ClientCollector.STATUSES[0]) """ with self._lock: if status not in self.STATUSES: raise ValueError( "Invalid status - {0}. Acceptable values: {1}.".format( status, self.STATUSES)) if client not in self.clients: self.clients[client] = {} self.clients[client]['status'] = status self.clients[client]['connect_time'] = time.time() if "reports" not in self.clients[client]: self.clients[client]['reports'] = {} def addreport(self, client, report_type): """Add and open report type. Args: client(tuple(str)): Tuple of ClientID and build. report_type(str): "html", "xml" or "wrtm". Raises: KeyError: client not in self.clients Returns: None Examples:: client = ("py.test-user-1234", "v.0.0.0.0.0.1") report_type = "html" client_collector.addreport(client, report_type) """ with self._lock: if client not in self.clients: raise KeyError("Unknown client: {0}.".format(client)) self.clients[client]['reports'][report_type] = True self.clients[client]['reports'] = OrderedDict( sorted(list(self.clients[client]['reports'].items()), key=lambda t: t[0])) def closereport(self, client, report_type): """Close report type (set False for existing opened report). Args: client( tuple(str)): Tuple of ClientID and build report_type(str): "html", "xml" or "wrtm". Raises: KeyError: client not in self.clients Returns: None """ with self._lock: if client not in self.clients: raise KeyError("Unknown client: {0}.".format(client)) self.clients[client]['reports'][report_type] = False self.class_logger.info("Report type - %s of client - %s closed", report_type, client) def delreport(self, client, report_type): """Remove report type (disabling collecting info for report). Args: client(tuple(str)): Tuple of ClientID and build. report_type(str): "html", "xml" or "wrtm". Raises: KeyError: client not in self.clients Returns: None """ with self._lock: if client not in self.clients: raise KeyError("Unknown client: {0}.".format(client)) try: del self.clients[client]['reports'][report_type.lower()] except KeyError: pass @log_exception(msg="failed to get client's attribute") def get(self, client, attr): """Return client's attribute. Args: client(tuple(str)): Tuple of ClientID and build. attr(str): Client attribute - key of client dict. Returns: Client's attribute (return type depends on attribute type). Examples:: client = ("py.test-user-1234", "v.0.0.0.0.0.1") client_collector.get(client, "connect_time") client_collector.get(client, "reports") """ with self._lock: if client in self.clients and attr in self.clients[client]: return self.clients[client][attr] else: return None def getall(self, client): """Return all client attributes. Args: client(str): Tuple of ClientID and build. Returns: dict: client dict. """ with self._lock: if client in self.clients: return self.clients[client] else: return None def active(self): """List of active clients. Returns: list[dict]: list of clients. Note: There are can be commands from client in queue when client is disconnected (see inprocess() method). """ with self._lock: active = [ _x for _x in list(self.clients.keys()) if self.clients[_x]['status'] == self.STATUSES[0] ] return active def inprocess(self): """List of clients with unprocessed close command. Returns: list[dict]: list of clients. Note: On close command server should close (and dump) client's reports. """ with self._lock: active = [ _x for _x in list(self.clients.keys()) if True in list(self.clients[_x]['reports'].values()) ] return active def all(self): """All connected/disconnected client. Returns: list[dict]: @return: list of clients. """ with self._lock: try: return list(self.clients.keys()) except IndexError: return None
# distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. """``pytest_helpers.py`` `pytest specific helpers functions` """ import inspect import re from testlib import loggers class_logger = loggers.ClassLogger() def get_tcname(report): """Return TC name from pytest report object. Args: report(pytest.report): pytest report object Returns: str: test case name Note: This function allows to get proper name without parameters string from normal and parametrized TCs. """
class ReportingServer(object): """Logging xmlrpc server class. """ REPORTINGSRV_PATH = "reporting_server.py" UNDEFINED_BUILD = "Undefined" class_logger = loggers.ClassLogger() def __init__(self, opts): """Initialize ReportingServer class. """ self._opts = opts self.rs_port = opts.rs_port self._tc2id_map = {} self.xmlproxy = XMLRPCProxy("http://localhost:{0}".format( self.rs_port), allow_none=True) # _sessionstart launch status flag # _sessionstart should be launched only ones at the first runtest_call self._init_session = False # Setting build name : This is a test. # Setting build name self._buildname = None self.post_queue = [] # duration of Test Case since pytest_setup to longrepr self.detailed_duration = dict() self.platform = 'undetermined' self.build = 'undetermined' # Get os username try: self.os_username = os.environ['SUDO_USER'] except KeyError: self.os_username = os.environ['USER'] self.self_name = "py.test-{0}-{1}".format(self.os_username, os.getpid()) def buildname(self, env_prop=None): """Return buildname for current session. Args: env_prop(dict): environment information e.g. build, name, etc. Returns: str: buildname """ if self._buildname is not None: return self._buildname try: platform, build = env_prop['chipName'], env_prop['switchppVersion'] except (KeyError, TypeError): message = 'Cannot determine build name' self.class_logger.warning(message) self._buildname = self.UNDEFINED_BUILD else: self.platform = platform self.build = build name_iter = ( MODULES[_var].ReportingServerConfig._get_build_name(self._opts) for _var in # pylint: disable=protected-access MODULES if 'reports_conf.' in _var) with suppress(StopIteration): # retain build name from env_prop build = next(name for name in name_iter if name is not None) self._buildname = '{0}-{1}'.format(build, platform) # WORKAROUND to add 'sanity' suffix to buildname if 'sanity' in self._opts.markexpr and self._buildname is not None: self._buildname += "-sanity" # WORKAROUND END return self._buildname def shutdown_server(self): """Send xmlrpc request to shutdown xmlrpc server. """ try: ans = self.xmlproxy.shutdown() except socket_error as err: self.class_logger.info( "xmlrpc shutdown complete. (DEBUG: {0})".format(err)) except XmlrpcProtocolError as err: self.class_logger.info( "xmlrpc shutdown complete. (DEBUG: {0})".format(err)) except Exception as err: self.class_logger.info( "xmlrpc shutdown expected error: {0} - {1}".format( type(err), err)) else: self.class_logger.info("xmlrpc shutdown query answer: %s" % (ans, )) # except socket.error, err: # if err[0] == 111: # print "!"*100 # print "ERR '{0}' handled".format(err) # else: # raise REPORTINGSRV_TIMEOUT = 30 def launch_server(self, port=None): """Launch xmlrpc server. Args: port(int): port to launch xmlrpc server """ def wait_rc(popen, timeout=30): """Wait until popen finish execution. """ stop = False end_time = time.time() + timeout rc = None while not stop: rc = popen.poll() if time.time() > end_time: stop = True return rc if rc is not None: stop = True return rc else: time.sleep(0.5) logdir = self._opts.logdir if self._opts.logdir is not None else os.curdir # server_path = os.path.join(os.path.dirname(__file__), self.REPORTINGSRV_PATH) server_path = os.path.abspath( os.path.join(os.path.dirname(__file__), '../../reporting', self.REPORTINGSRV_PATH)) cmd = [ sys.executable, server_path, "--logdir={0}".format(logdir), "--loglevel={0}".format(self._opts.loglevel), "--silent", "--logprefix={0}".format( os.path.splitext(self.REPORTINGSRV_PATH)[0]), ] if port: cmd.append("--port={0}".format(port)) popen = Popen(cmd) self.class_logger.debug( "reporting server parent process PID - {0}".format(popen.pid)) rc = wait_rc(popen) if rc != 0: message = "Failed to start XMLRPC server with command: {0}. Return code: {1}".format( " ".join(cmd), rc) self.class_logger.error(message) raise Exception(message) retry = 0 _vr_path = os.path.join("/tmp", "{0}.pid".format(popen.pid)) while port is None and retry < self.REPORTINGSRV_TIMEOUT: try: with open(_vr_path, "r") as _vr: # Read server port number from file port = int(_vr.read()) except IOError as err: if err.errno == errno.ENOENT: self.class_logger.warning("Sleeping until %s exists", _vr_path) retry += 1 time.sleep(1) except Exception as err: self.class_logger.error( "Cannot determinate reporting server port.") self.class_logger.error( "Failed to open pid/port file {0}. Error:\n{1}".format( _vr_path, err)) raise self.class_logger.info( "Reporting server is listening on port {0}".format(port)) self.rs_port = port self.xmlproxy = XMLRPCProxy("http://localhost:{0}".format( self.rs_port), allow_none=True) # Wait until xmlrpc server starts processing requests if not self.check_server(timeout=60): message = "XMLRPC Server does not respond." self.class_logger.error(message) raise Exception(message) def check_server(self, timeout=1): """Check if xmlrpc server is alive. Args: timeout(int): timeout for server verification """ ans = None end_time = time.time() + timeout while time.time() <= end_time: try: ans = self.xmlproxy.ping() except socket_error: time.sleep(1) except Exception as err: self.class_logger.warning( "Unexpected type of error while checking xmlrpc server - {0} - {1}" .format(type(err), err)) time.sleep(1) else: if ans == "XMLReportingServer": return True else: message = "Unknown xmlrpc server is running on localhost:18080" self.class_logger.error(message) raise Exception(message) return False def server_cmd(self, cmd, args, retry=3): """Send XML query to server with retry and exception handling. Args: cmd(str): command name args(list): command arguments retry(int): retry count """ success = False _i = 1 try: while not success and _i <= retry: _i += 1 try: getattr(self.xmlproxy, cmd)(*args) except socket_error: self.class_logger.info( "XMLRPC query {0}({1}) failed on {2} retry.".format( cmd, str(args), _i)) time.sleep(2 * _i) except KeyboardInterrupt: self.class_logger.debug( "Caught KeyboardInterrupt on server_cmd.") self.pytest_sessionfinish(session=self) else: success = True except Exception as err: self.class_logger.error( "XMLRPC query {0}({1}) failed on {2} retry. Unexpected error type {3}: {4}" .format(cmd, str(args), _i, type(err), err)) if not success: self.class_logger.warning("XMLRPC query {0}({1}) failed.".format( cmd, str(args))) def _send_post_request(self, item): """Send post request to reporting server or add it to queue. Args: item(pytest.Item): test case item """ tc_name = get_tcname(item) try: env_prop = item.config.env.env_prop except AttributeError: buildname = self.UNDEFINED_BUILD else: buildname = self.buildname(env_prop) suite_name = get_suite_name(item.nodeid) info = { "brief": get_brief(item, tc_name), "description": get_steps(item, tc_name) } if self.post_queue: self._send_post_queue(item, buildname) self.server_cmd("post", [ self.self_name, buildname, suite_name, tc_name, "Run", "", info, self._get_build_info(item) ]) def pytest_runtest_setup(self, item): """Add info about test case start time. Args: item(pytest.Item): test case item """ if not item.config.option.tc_duration: self.detailed_duration[item.nodeid] = dict() self.detailed_duration[item.nodeid]['setup'] = time.time() if self._buildname is not None: self._send_post_request(item) @pytest.mark.tryfirst def pytest_runtest_call(self, item): """Create TC instance and send it to the Reporting Server. Args: item(pytest.Item): test case item """ if not item.config.option.tc_duration: self.detailed_duration[item.nodeid]['call'] = time.time() if self._buildname is None: self.buildname(item.config.env.env_prop) if self._buildname is not None and not self._init_session: self._sessionstart(item) self._init_session = True self._send_post_request(item) def _send_post_queue(self, item=None, buildname=None, sanity=False): """Send info about test execution to the Reporting Server. Args: item(pytest.Item): test case item buildname(str): buildname sanity(bool): True if sanity test """ if buildname is None: buildname = 'undetermined' if sanity: buildname += "-sanity" self.server_cmd("post", [ self.self_name, buildname, "", "", "Run", "", "", self._get_build_info(item) ]) for post_req in self.post_queue: post_req[1] = buildname # Add empty description and brief. In synapsert new TC won't create post_req.append(('', '')) post_req.append(self._get_build_info(item)) self.server_cmd("post", post_req) self.post_queue[:] = [] def _get_build_info(self, item=None): """Get info about build. Args: item(pytest.Item): test case item Returns: dict{"platform": str, "build": str}: build info """ if item is not None and item.config and hasattr(item.config, 'env')\ and item.config.env and "chipName" in item.config.env.env_prop \ and "switchppVersion" in item.config.env.env_prop and self.platform == 'undetermined': self.platform = item.config.env.env_prop["chipName"] self.build = item.config.env.env_prop["switchppVersion"] return {'platform': self.platform, 'build': self.build} def pytest_runtest_logreport(self, report): """Send update TC run status to the Reporting Server. Args: report(pytest.BaseReport): pytets report """ status = None if report.passed: # ignore setup/teardown if report.when == "call": status = "Passed" elif report.failed: if report.when in ["setup", "teardown"]: status = "Error" else: status = "Failed" elif report.skipped: status = "Skipped" # status = "Blocked" if not status and hasattr(report, 'monitor'): status = "Monitor" if status is not None: _report = {} _report['longrepr'] = "" _report['when'] = report.when if hasattr(report, "longrepr"): # Remove all bash escape sequences _report['longrepr'] = xml_escape( re_sub(r"\x1b.*?m", "", str(report.longrepr))) # longrepr = xml_unescape(re_sub(r"\x1b.*?m", "", report['longrepr'])) if hasattr(report, "keywords") and "xfail" in report.keywords: _report['keywords'] = {} # TODO: check xfail in keywords because now it's number _report['keywords']['xfail'] = report.keywords['xfail'] if hasattr(report, "sections"): _report['sections'] = [] for i in range(len(report.sections)): if isinstance(report.sections[i], str): _report['sections'].append( xml_escape(report.sections[i])) # _report['sections'] = report.sections if hasattr(report, "duration"): if not self._opts.tc_duration and self.detailed_duration.get( report.nodeid) and self.detailed_duration.get( report.nodeid).get('call'): _report['detailed_duration'] = dict() _report['detailed_duration']['setup'] = \ self.detailed_duration.get(report.nodeid).get('call') - self.detailed_duration.get(report.nodeid).get('setup') _report['detailed_duration']['longrepr'] = time.time( ) - self.detailed_duration.get( report.nodeid).get('call') - report.duration _report['duration'] = report.duration if hasattr(report, "retval"): _report['retval'] = report.retval if hasattr(report, "monitor"): _report['monitor'] = report.monitor tc_name = get_tcname(report) suite_name = get_suite_name(report.nodeid) if self.buildname() is not None: self.server_cmd("post", [ self.self_name, self.buildname(), suite_name, tc_name, status, _report, "", self._get_build_info() ]) else: self.post_queue.append([ self.self_name, self.buildname(), suite_name, tc_name, status, _report ]) def _sessionstart(self, item): """Tell to XMLRPC Server that we are going to interact with it. Args: item(pytest.Item): test case item """ self.class_logger.info("Configuring reporting server...") self.server_cmd("open", [self.self_name]) for _var in MODULES: if "reports_conf." in _var: commands = MODULES[_var].ReportingServerConfig._sessionstart( # pylint: disable=protected-access self.class_logger, item, self.self_name, self.buildname(item.config.env.env_prop)) for comm in commands: self.server_cmd(*comm) # Order TM reporting to server. # Order and configure XML report to server. def pytest_sessionfinish(self, session): """Tell to XMLRPC Server that we have finished interaction. Args: session(pytest.Session): test session """ _buildname = self.buildname() if _buildname is None: if not self._init_session: self._sessionstart(session) if self.post_queue: if 'sanity' in self._opts.markexpr: self._send_post_queue(session, sanity=True) else: self._send_post_queue(session) self.class_logger.warning( "Cannot determinate buildname. Probably test setup is failed. Skipping report.close step." ) self.server_cmd("close", [self.self_name]) def pytest_keyboard_interrupt(self, excinfo): """Handle KeyboardInterrupt. Args: excinfo(py.code.ExceptionInfo): exception info """ self.class_logger.debug("Caught KeyboardInterrupt on pytest_hook.") self.pytest_sessionfinish(session=self)
class SystemLog(object): """Syslog object class. """ class_logger = loggers.ClassLogger() def __init__(self, host=None, user=None, pasw=None, log_path=None): """Initialize SystemLog class. Args: host(str): Host IP address user(str): Host user pasw(str): Host password log_path(str): Path to logs """ self.host = host self.user = user self.pasw = pasw self.log_path = log_path self.ssh = clissh.CLISSH(self.host) def __del__(self): """Try to close CLI connection on object destroy. """ self.ssh.close() def get_checkpoint(self): """Get syslog checkpoint. Notes: Checkpoint it's an integer value which can be used for log reading from checkpoint till the end. Returns: int: checkpoint Examples:: syslog_1 = syslog.SystemLog("1.1.1.1", "usr", "PaSsWd", "/some/path") cp = syslog_1.get_checkpoint() # cp = 57899427 """ try: sftp = self.ssh.client.open_sftp() self.class_logger.debug('SSH session is active.') except (AttributeError, SSHException): self.class_logger.debug('No active SSH. Connecting...') self.ssh.login(self.user, self.pasw) sftp = self.ssh.client.open_sftp() # get remote logfile: remote_log_file = sftp.open(self.log_path) # go to end of remote log file: remote_log_file.seek(0, 2) # get end position for logfile checkpoint = remote_log_file.tell() remote_log_file.close() sftp.close() # return end position for logfile return checkpoint def get_log(self, checkpoint=None, timeout=60): """Read log from remote host. Args: checkpoint(int): Log file checkpoint timeout(int): Get log timeout Raises: SysLogException: syslog timeout exceeded Returns: tuple: log_list (list), new_checkpoint (integer) Notes: If checkpoint present read from checkpoint till the end, if not read full file. Examples:: log_list, checkpoint = get_log(34134654, 30) """ log_list = [] checkpoint_temp = 0 try: check_alive_ssh = self.ssh.client.open_sftp() check_alive_ssh.close() self.class_logger.debug('SSH session is active.') except Exception: self.class_logger.debug('ERROR: No active SSH.') self.class_logger.debug('Connecting...') self.ssh.login(self.user, self.pasw) sftp = self.ssh.client.open_sftp() remote_log_file = sftp.open(self.log_path, bufsize=50000) if checkpoint is None: self.class_logger.debug( 'No checkpoint value. Full log file will be download it can take a while.' ) # when no checkpoint parameter, read full file and return new checkpoint log_list = remote_log_file.readlines() checkpoint_new = remote_log_file.tell() else: # wait until new records appear; compare checkpoint with temp_checkpoint end_time = time.time() + timeout while checkpoint >= checkpoint_temp: if time.time() >= end_time: self.ssh.close() message = "Syslog Timeout exceeded. No Syslog messages in %s second" % ( timeout, ) raise SysLogException(message) # move in end of file remote_log_file.seek(0, 2) # get end possition checkpoint_temp = remote_log_file.tell() # wait 0.5 sec to repeat operation time.sleep(0.5) # move to checkpoint possition remote_log_file.seek(checkpoint) # read remote log file: log_list = remote_log_file.readlines() # get new_checkpoint - log file end possition: checkpoint_new = remote_log_file.tell() self.class_logger.debug('log file is successfully readed.') remote_log_file.close() sftp.close() # return logfile and end possition for logfile return log_list, checkpoint_new def search(self, log_list, paterntuple): """Find command records in log file. Args: log_list(list): logfiles paterntuple(tuple): commands part what function should find in loglist Returns: list: find_list_result Examples:: \>>> test_command = 'sshd', '', 'Accepted password' \>>> syslog_1.search(test_log, test_command) ['Aug 10 08:54:03 <platform> sshd[13275]: Accepted password for root from 127.0.0.1 port 59212 ssh2\n', 'Aug 10 08:54:03 <platform> sshd[13275]: Accepted password for root from 127.0.0.1 port 59212 ssh2\n'] """ # create empty list for search result: find_list_result = [] # backslashed input commands from paterntuple: # Compile a regular expression pattern into a regular expression object, patern consist from findlist elements: log_regexp = re.compile( r"(%s.*?%s.*?%s.*?\n)" % (re.escape(paterntuple[0]), re.escape( paterntuple[1]), re.escape(paterntuple[2]))) # applied regular expression object to input list and if result not empty append it to find_list_result list: find_list_result = [x for x in log_list if log_regexp.findall(x)] return find_list_result def find_duplicated_records(self, log_list): """Find duplicated records in log file. Args: log_list(list): logfiles Returns: list: None or list of duplicated records """ # compare list length: if len(set(log_list)) == len(log_list): return None # if present duplicate records, find and return list with duplicated records: log_duplicate = [] for index, row in enumerate(log_list): if row in log_list[:index]: log_duplicate.append(row) return log_duplicate