Managed Resources for Software Release Tests

Introduce new "Managed Resources" and assorted fixes accompanying nexedi/slapos!840 

Also respect meaning of verbose (more output in the console) and debug (drop in debugger on errors and keep things around for inspection)

See merge request nexedi/slapos.core!259

slapos/testing/testcase.py

@@ -46,6 +46,7 @@ except ImportError:
   subprocess  # pyflakes
 
 from .utils import getPortFromPath
+from .utils import ManagedResource
 
 from ..slap.standalone import StandaloneSlapOS
 from ..slap.standalone import SlapOSNodeCommandError
@@ -54,7 +55,8 @@ from ..grid.utils import md5digest
 from ..util import mkdir_p
 
 try:
-  from typing import Iterable, Tuple, Callable, Type, Dict, List, Optional
+  from typing import Iterable, Tuple, Callable, Type, Dict, List, Optional, TypeVar
+  ManagedResourceType = TypeVar("ManagedResourceType", bound=ManagedResource)
 except ImportError:
   pass
 
@@ -127,7 +129,7 @@ def makeModuleSetUpAndTestCaseClass(
   logger = logging.getLogger()
   console_handler = logging.StreamHandler()
   console_handler.setLevel(
-      logging.DEBUG if (verbose or debug) else logging.WARNING)
+      logging.DEBUG if verbose else logging.WARNING)
   logger.addHandler(console_handler)
 
   if debug:
@@ -412,7 +414,7 @@ def installSoftwareUrlList(cls, software_url_list, max_retry=10, debug=False):
       cls._copySnapshot(path, name)
 
   try:
-    cls.logger.debug("Starting")
+    cls.logger.debug("Starting SlapOS")
     cls.slap.start()
     for software_url in software_url_list:
       cls.logger.debug("Supplying %s", software_url)
@@ -484,6 +486,11 @@ class SlapOSInstanceTestCase(unittest.TestCase):
   _ipv4_address = ""
   _ipv6_address = ""
 
+  _resources = {} # type: Dict[str, ManagedResource]
+  _instance_parameter_dict = None # type: Dict
+  computer_partition = None # type: ComputerPartition
+  computer_partition_root_path = None # type: str
+
   # a short name of that software URL.
   # eg. helloworld instead of
   # https://lab.nexedi.com/nexedi/slapos/raw/software/helloworld/software.cfg
@@ -503,6 +510,29 @@ class SlapOSInstanceTestCase(unittest.TestCase):
       'etc/',
   )
 
+  @classmethod
+  def getManagedResource(cls, resource_name, resource_class):
+    # type: (str, Type[ManagedResourceType]) -> ManagedResourceType
+    """Get the managed resource for this name.
+
+    If resouce was not created yet, it is created and `open`. The
+    resource will automatically be `close` at the end of the test
+    class.
+    """
+    try:
+      existing_resource = cls._resources[resource_name]
+    except KeyError:
+      resource = resource_class(cls, resource_name)
+      cls._resources[resource_name] = resource
+      resource.open()
+      return resource
+    else:
+      if not isinstance(existing_resource, resource_class):
+        raise ValueError(
+            "Resource %s is of unexpected class %s" %
+            (resource_name, existing_resource), )
+      return existing_resource
+
   # Methods to be defined by subclasses.
   @classmethod
   def getSoftwareURL(cls):
@@ -540,7 +570,7 @@ class SlapOSInstanceTestCase(unittest.TestCase):
     snapshot_name = "{}.{}.setUpClass".format(cls.__module__, cls.__name__)
 
     try:
-      cls.logger.debug("Starting")
+      cls.logger.debug("Starting setUpClass %s", cls)
       cls.slap.start()
       cls.logger.debug(
           "Formatting to remove old partitions XXX should not be needed because we delete ..."
@@ -692,6 +722,12 @@ class SlapOSInstanceTestCase(unittest.TestCase):
     """Destroy all instances and stop subsystem.
     Catches and log all exceptions and take snapshot named `snapshot_name` + the failing step.
     """
+    for resource_name in list(cls._resources):
+      cls.logger.debug("closing resource %s", resource_name)
+      try:
+        cls._resources.pop(resource_name).close()
+      except:
+        cls.logger.exception("Error closing resource %s", resource_name)
     try:
       if hasattr(cls, '_instance_parameter_dict'):
         cls.requestDefaultInstance(state='destroyed')
@@ -700,8 +736,16 @@ class SlapOSInstanceTestCase(unittest.TestCase):
       cls._storeSystemSnapshot(
           "{}._cleanup request destroy".format(snapshot_name))
     try:
+      # To make debug usable, we tolerate report_max_retry-1 errors and
+      # only debug the last.
       for _ in range(3):
-        cls.slap.waitForReport(max_retry=cls.report_max_retry, debug=cls._debug)
+        if cls._debug and cls.report_max_retry:
+          try:
+            cls.slap.waitForReport(max_retry=cls.report_max_retry - 1)
+          except SlapOSNodeCommandError:
+            cls.slap.waitForReport(debug=True)
+        else:
+          cls.slap.waitForReport(max_retry=cls.report_max_retry, debug=cls._debug)
     except:
       cls.logger.exception("Error during actual destruction")
       cls._storeSystemSnapshot(
@@ -732,8 +776,16 @@ class SlapOSInstanceTestCase(unittest.TestCase):
               "{}._cleanup leaked_partitions request destruction".format(
                   snapshot_name))
       try:
+        # To make debug usable, we tolerate report_max_retry-1 errors and
+        # only debug the last.
         for _ in range(3):
-          cls.slap.waitForReport(max_retry=cls.report_max_retry, debug=cls._debug)
+          if cls._debug and cls.report_max_retry:
+            try:
+              cls.slap.waitForReport(max_retry=cls.report_max_retry - 1)
+            except SlapOSNodeCommandError:
+              cls.slap.waitForReport(debug=True)
+          else:
+            cls.slap.waitForReport(max_retry=cls.report_max_retry, debug=cls._debug)
       except:
         cls.logger.exception(
             "Error during leaked partitions actual destruction")

slapos/testing/utils.py

@@ -30,15 +30,22 @@ import socket
 import hashlib
 import unittest
 import os
+import logging
+import multiprocessing
+import shutil
 import subprocess
+import tempfile
 import sys
 import json
 from contextlib import closing
+from six.moves import BaseHTTPServer
+from six.moves import urllib_parse
 
 try:
   import typing
   if typing.TYPE_CHECKING:
     from PIL import Image # pylint:disable=unused-import
+    from .testcase import SlapOSInstanceTestCase
 except ImportError:
   pass
 
@@ -84,8 +91,111 @@ print(json.dumps(extra_config_dict))
   return json.loads(extra_config_dict_json)
 
 
+class ManagedResource(object):
+  """A resource that will be available for the lifetime of test.
+  """
+  def __init__(self, slapos_instance_testcase_class, resource_name):
+    # type: (typing.Type[SlapOSInstanceTestCase], str) -> None
+    self._cls = slapos_instance_testcase_class
+    self._name = resource_name
+  def open(self):
+    NotImplemented
+  def close(self):
+    NotImplemented
+
+
+class ManagedHTTPServer(ManagedResource):
+  """Simple HTTP Server for testing.
+  """
+  # Request Handler, needs to be defined by subclasses.
+  RequestHandler = None # type: typing.Type[BaseHTTPServer.BaseHTTPRequestHandler]
+
+  proto = 'http'
+  # hostname to listen to, default to ipv4 address of the current test
+  hostname = None # type: str
+  # port to listen to, default
+  port = None # type: int
+
+  @property
+  def url(self):
+    # type: () -> str
+    return '{self.proto}://{self.hostname}:{self.port}'.format(self=self)
+
+  @property
+  def netloc(self):
+    # type: () -> str
+    return urllib_parse.urlparse(self.url).netloc
+
+  def _makeServer(self):
+    # type: () -> BaseHTTPServer.HTTPServer
+    """build the server class.
+
+    This is a method to make it possible to subclass to add https support.
+    """
+    logger = self._cls.logger
+
+    class ErrorLoggingHTTPServer(BaseHTTPServer.HTTPServer):
+      def handle_error(self, request , client_addr):
+        # redirect errors to log
+        logger.info("Error processing request from %s", client_addr, exc_info=True)
+
+    logger.debug(
+        "starting %s (%s) on %s:%s",
+        self.__class__.__name__,
+        self._name,
+        self.hostname,
+        self.port,
+    )
+    server = ErrorLoggingHTTPServer(
+        (self.hostname, self.port),
+        self.RequestHandler,
+    )
+
+    return server
+
+  def open(self):
+    # type: () -> None
+    if not self.hostname:
+      self.hostname = self._cls._ipv4_address
+    if not self.port:
+      self.port = findFreeTCPPort(self.hostname)
+
+    server = self._makeServer()
+    self._process = multiprocessing.Process(
+        target=server.serve_forever,
+        name=self._name,
+    )
+    self._process.start()
+
+  def close(self):
+    # type: () -> None
+    self._process.terminate()
+    self._process.join()
+
+
+class ManagedHTTPSServer(ManagedHTTPServer):
+  """An HTTPS Server
+  """
+  proto = 'https'
+  certificate_file = None # type: str
+
+  def _makeServer(self):
+    # type: () -> BaseHTTPServer.HTTPServer
+    server = super(ManagedHTTPSServer, self)._makeServer()
+    raise NotImplementedError("TODO")
+    return server
+
+class ManagedTemporaryDirectory(ManagedResource):
+  path = None # type: str
+  def open(self):
+    self.path = tempfile.mkdtemp()
+  def close(self):
+    shutil.rmtree(self.path)
+
+
 class CrontabMixin(object):
   computer_partition_root_path = None # type: str
+  logger = None # type: logging.Logger
   def _getCrontabCommand(self, crontab_name):
     # type: (str) -> str
     """Read a crontab and return the command that is executed.
@@ -108,10 +218,12 @@ class CrontabMixin(object):
     be a relative time.
     """
     crontab_command =  self._getCrontabCommand(crontab_name)
-    subprocess.check_call(
-        "faketime {date} bash -o pipefail -e -c '{crontab_command}'".format(**locals()),
+    crontab_output = subprocess.check_output(
+        # XXX we unset PYTHONPATH set by `setup.py test`
+        "env PYTHONPATH= faketime {date} bash -o pipefail -e -c '{crontab_command}'".format(**locals()),
         shell=True,
     )
+    self.logger.debug("crontab %s output: %s", crontab_command, crontab_output)
 
 
 class ImageComparisonTestCase(unittest.TestCase):