Python base.JournalLogger类代码示例

  def __log_api_diff(self, api_diff):
    text_list = []
    for api, diff in api_diff.items():
      added = diff.to_instances_added()
      removed = diff.to_instances_removed()
      if not (added or removed):
        continue
      text_list.append(api + ' Changes:')
      if added:
        text_list.append('+ ADDED:')
        for resource, instances in added.items():
          text_list.append('  %s' % resource)
          text_list.extend(['  - {!r}'.format(name) for name in instances])

      if removed:
        text_list.append('- REMOVED:')
        for resource, instances in removed.items():
          text_list.append('  %s' % resource)
          text_list.extend(['  - {!r}'.format(name) for name in instances])

    self.__to_log_path('--- RESOURCES ---',
                       detail='\n'.join(text_list) if text_list else 'None',
                       indent=2)

    if text_list:
      JournalLogger.journal_or_log_detail(
          'GCP Resource Impact', '\n'.join(text_list), format='pre')
    else:
      logging.info('No GCP resource impact')

def verify_quota(title, gcp_agent, project_quota, regions):
  """Verify that the observed GCP project has sufficient quota.

  Args:
    title: [string] What the quota is for, for logging purposes only.
    gcp_agent: [GcpAgent] Observation agent on the desired project.
    project_quota: [dict] Minimum desired values keyed by quota metric for
       the observed project.
    regions: [array of (name, dict) tuple]: A list of regions and their
       individual quotas to check.

  Returns:
    json_contract.ContractVerifyResult against the quota check.
  """
  execution_context = ExecutionContext()
  contract = make_quota_contract(gcp_agent, project_quota, regions)
  verify_results = None
  context_relation = 'ERROR'

  try:
    JournalLogger.begin_context(title)
    verify_results = contract.verify(execution_context)
    context_relation = 'VALID' if verify_results else 'INVALID'
  finally:
    if verify_results is not None:
      journal = get_global_journal()
      if journal is not None:
        journal.store(verify_results)
    JournalLogger.end_context(relation=context_relation)

  return verify_results

  def wait(self, poll_every_secs=None, max_secs=None):
    """Wait until the status reaches a final state.

    Args:
      poll_every_secs: [float] Interval to refresh() from the proxy.
         This could also be a function taking an attempt number and
         returning number of seconds for that attempt.
         The default is default_wait_time_func.

      max_secs: [float] Most seconds to wait before giving up.
          0 is a poll, None is unbounded. Otherwise, number of seconds.
    """
    if self.finished:
      return

    if max_secs is None:
      max_secs = self.operation.max_wait_secs
    if max_secs is not None and max_secs < 0:
      raise ValueError()

    message = 'Wait on id={0}, max_secs={1}'.format(self.id, max_secs)
    JournalLogger.begin_context(message)
    context_relation = 'ERROR'
    try:
      self.refresh()
      self.__wait_helper(poll_every_secs, max_secs)
      context_relation = 'VALID' if self.finished_ok else 'INVALID'
    finally:
      JournalLogger.end_context(relation=context_relation)

  def new_native_instance(cls, name, status_factory, base_url):
    """Create a new Spinnaker HttpAgent talking to the specified server port.

    Args:
      name: [string] The name of agent we are creating for reporting only.
      status_factory: [SpinnakerStatus (SpinnakerAgent, HttpResponseType)]
         Factory method for creating specialized SpinnakerStatus instances.
      base_url: [string] The service base URL to send messages to.

    Returns:
      A SpinnakerAgent connected to the specified instance port.
    """
    logger = logging.getLogger(__name__)
    logger.info('Locating %s...', name)
    if not base_url:
      logger.error('Could not locate %s.', name)
      return None

    logger.info('%s is available at %s', name, base_url)
    env_url = os.path.join(base_url, 'resolvedEnv')
    deployed_config = scrape_spring_config(env_url)
    JournalLogger.journal_or_log_detail(
        '{0} configuration'.format(name), deployed_config)

    spinnaker_agent = cls(base_url, status_factory)
    spinnaker_agent.__deployed_config = deployed_config

    return spinnaker_agent

  def new_gce_instance_from_bindings(
      cls, name, status_factory, bindings, port):
    """Create a new Spinnaker HttpAgent talking to the specified server port.

    Args:
      name: [string] The name of agent we are creating for reporting only.
      status_factory: [SpinnakerStatus (SpinnakerAgent, HttpResponseType)]
         Factory method for creating specialized SpinnakerStatus instances.
      bindings: [dict] List of bindings to configure the endpoint
          GCE_PROJECT: The GCE project ID that the endpoint is in.
          GCE_ZONE: The GCE zone that the endpoint is in.
          GCE_INSTANCE: The GCE instance that the endpoint is in.
          GCE_SSH_PASSPHRASE_FILE: If not empty, the SSH passphrase key
              for tunneling if needed to connect through a GCE firewall.
          GCE_SERVICE_ACCOUNT: If not empty, the GCE service account to use
              when interacting with the GCE instance.
      port: [int] The port of the endpoint we want to connect to.
    Returns:
      A SpinnakerAgent connected to the specified instance port.
    """
    project = bindings['GCE_PROJECT']
    zone = bindings['GCE_ZONE']
    instance = bindings['GCE_INSTANCE']
    ssh_passphrase_file = bindings.get('GCE_SSH_PASSPHRASE_FILE', None)
    service_account = bindings.get('GCE_SERVICE_ACCOUNT', None)

    logger = logging.getLogger(__name__)
    JournalLogger.begin_context('Locating {0}...'.format(name))
    context_relation = 'ERROR'
    try:
      gcloud = gcp.GCloudAgent(
          project=project, zone=zone, service_account=service_account,
          ssh_passphrase_file=ssh_passphrase_file)
      netloc = gce_util.establish_network_connectivity(
          gcloud=gcloud, instance=instance, target_port=port)
      if not netloc:
        error = 'Could not locate {0}.'.format(name)
        logger.error(error)
        context_relation = 'INVALID'
        raise RuntimeError(error)

      approx_config = cls.__get_deployed_local_yaml_bindings(gcloud,
                                                             instance)
      protocol = approx_config.get('services.default.protocol', 'http')
      base_url = '{protocol}://{netloc}'.format(protocol=protocol,
                                                netloc=netloc)
      logger.info('%s is available at %s', name, base_url)
      deployed_config = scrape_spring_config(
          os.path.join(base_url, 'resolvedEnv'))
      spinnaker_agent = cls(base_url, status_factory)
      spinnaker_agent.__deployed_config = deployed_config
      context_relation = 'VALID'
    except:
      logger.exception('Failed to create spinnaker agent.')
      raise
    finally:
      JournalLogger.end_context(relation=context_relation)

    return spinnaker_agent

  def run_test_case(self, test_case, context=None, **kwargs):
    """Run the specified test operation from start to finish.

    Args:
      test_case: [OperationContract] To test.
      context: [ExecutionContext] The citest execution context to run in.
      timeout_ok: [bool] Whether an AgentOperationStatus timeout implies
          a test failure. If it is ok to timeout, then we'll still verify the
          contracts, but skip the final status check if there is no final
          status yet.
      max_retries: [int] Number of independent retries permitted on
          individual operations if the operation status fails. A value of 0
          indicates that a test should only be given a single attempt.
      retry_interval_secs: [int] The number of seconds to wait between retries.
      max_wait_secs: [int] How long to wait for status completion.
          Default=Determined by operation in the test case.
    """
    if context is None:
      context = ExecutionContext()

    # This is complicated because of all the individual parts
    # that we want to ensure excute, so we'll break it up into
    # helper functions based on scope and use the context to
    # pass back some shared state variables since they make sense
    # to communicate in the context anyway.
    #
    # This particular method is responsible for the logging context
    # and the post-execution cleanup, if any.
    #
    # It will delegate to a helper function for the execution and
    # pre/post hooks
    #
    # To get the context relation, we'll peek inside the execution
    # context to see how the status and validation turned out.
    JournalLogger.begin_context('Test "{0}"'.format(test_case.title))
    try:
      self._do_run_test_case_with_hooks(test_case, context, **kwargs)
    finally:
      try:
        if test_case.cleanup:
          attempt_info = context.get(self.CONTEXT_KEY_ATTEMPT_INFO, None)
          if attempt_info is None or attempt_info.status is None:
            self.logger.info('Skipping operation cleanup because'
                             ' operation could not be performed at all.')
          else:
            self.logger.info('Invoking injected operation cleanup.')
            test_case.cleanup(context)
      finally:
        verify_results = context.get(
            self.CONTEXT_KEY_CONTRACT_VERIFY_RESULTS, None)
        if verify_results is None:
          context_relation = 'ERROR'
        else:
          final_status_ok = context.get(self.CONTEXT_KEY_FINAL_STATUS_OK, False)
          context_relation = ('VALID' if (final_status_ok and verify_results)
                              else 'INVALID')
        JournalLogger.end_context(relation=context_relation)

  def __do_verify(self, context):
    """Helper function that implements the clause verification policy.

    We will periodically attempt to verify the clause until we succeed
    or give up trying. Each individual iteration attempt is performed
    by the verify_once method.

    Args:
      context: Runtime citest execution context.
    Returns:
      VerifyClauseResult specifying the final outcome.
    """

    # self.logger.debug('Verifying Contract: %s', self.__title)
    start_time = time.time()
    end_time = start_time + self.__retryable_for_secs

    while True:
      clause_result = self.verify_once(context)
      if clause_result:
        break

      now = time.time()
      if end_time <= now:
        if end_time > start_time:
          self.logger.debug(
              'Giving up verifying %s after %r of %r secs.',
              self.__title, end_time - start_time, self.__retryable_for_secs)
        break

      secs_remaining = end_time - now

      # This could be a bounded exponential backoff, but we probably
      # want to have an idea of when it actually becomes available so keep low.
      # But if we are going to wait a long time, then dont poll very frequently.
      # The numbers here are arbitrary otherwise.
      #
      # 1/10 total time or 5 seconds if that is pretty long,
      # but no less than 1 second unless there is less than 1 second left.
      sleep = min(secs_remaining, min(5, max(1, self.__retryable_for_secs / 10)))
      self.logger.debug(
          '%s not yet satisfied with secs_remaining=%r. Retry in %r\n%s',
          self.__title, secs_remaining, sleep, clause_result)
      time.sleep(sleep)

    summary = clause_result.enumerated_summary_message
    ok_str = 'OK' if clause_result else 'FAILED'
    JournalLogger.delegate(
        "store", clause_result,
        _title='Validation Analysis of "{0}"'.format(self.__title))
    self.logger.debug('ContractClause %s: %s\n%s',
                      ok_str, self.__title, summary)
    return clause_result

  def post_run_hook(self, info, test_case, context):
    if not info:
      return

    scanner, before_usage = info
    analyzer = self.__google_resource_analyzer
    JournalLogger.begin_context('Capturing final quota usage')
    try:
      after_usage = analyzer.collect_resource_usage(self.gcp_observer, scanner)
    finally:
      JournalLogger.end_context()
    analyzer.log_delta_resource_usage(
        test_case, scanner, before_usage, after_usage)

  def list_available_images(self):
    """Creates a test that confirms expected available images.

    Returns:
      st.OperationContract
    """
    logger = logging.getLogger(__name__)

    # Get the list of images available (to the service account we are using).
    context = citest.base.ExecutionContext()
    gcp_agent = self.gcp_observer
    JournalLogger.begin_context('Collecting expected available images')
    relation_context = 'ERROR'
    try:
      logger.debug('Looking up available images.')

      json_doc = gcp_agent.list_resource(context, 'images')
      for project in GCP_STANDARD_IMAGES.keys():
        logger.info('Looking for images from project=%s', project)
        found = gcp_agent.list_resource(context, 'images', project=project)
        for image in found:
          if not image.get('deprecated', None):
            json_doc.append(image)

      # Produce the list of images that we expect to receive from spinnaker
      # (visible to the primary service account).
      spinnaker_account = self.bindings['SPINNAKER_GOOGLE_ACCOUNT']

      logger.debug('Configured with Spinnaker account "%s"', spinnaker_account)
      expect_images = [{'account': spinnaker_account, 'imageName': image['name']}
                       for image in json_doc]
      expect_images = sorted(expect_images, key=lambda k: k['imageName'])
      relation_context = 'VALID'
    finally:
      JournalLogger.end_context(relation=relation_context)

    # pylint: disable=bad-continuation
    builder = HttpContractBuilder(self.agent)
    (builder.new_clause_builder('Has Expected Images')
       .get_url_path('/gce/images/find')
       .EXPECT(
           ov_factory.value_list_matches(
               [jp.DICT_SUBSET(image_entry) for image_entry in expect_images],
               strict=True,
               unique=True)))

    return st.OperationContract(
        NoOpOperation('List Available Images'),
        contract=builder.build())

  def call_method(self, method, context, *pos_args, **kwargs):
    """Invokes method and returns result.

    This is a wrapper around calling the method that will log the
    call and result.

    Args:
      method: callable method to invoke with *pos_args and **kwargs.
      context: [ExecutionContext]
      pos_args: [list]  positional arguments to pass to method.
      kwargs: [kwargs]to pass to method.
      _citest_log
    Raises:
      Exceptions thrown by method
    Returns:
      result of method
    """
    if hasattr(method, 'im_class'):
      method_name = '{0}.{1}'.format(method.im_class.__name__,
                                     method.im_func.__name__)
    else:
      method_name = str(method)

    return JournalLogger.execute_in_context(
        'Call {0}'.format(method_name),
        lambda: self.__do_call_method(
            method_name, method, context, *pos_args, **kwargs))

  def __do_call_method(self, method_name, method, context, *pos_args, **kwargs):
    """Helper function implementing call_method()."""
    eval_pos_args = context.eval(pos_args)
    eval_kwargs = context.eval(kwargs)

    arg_text_list = [repr(arg) for arg in eval_pos_args]
    arg_text_list.extend(['{0}={1!r}'.format(key, value)
                          for key, value in eval_kwargs.items()])
    arg_text = ','.join(arg_text_list)

    JournalLogger.journal_or_log(
        '{0}({1})'.format(method_name, arg_text),
        _logger=self.logger, _context='request')
    response = method(*eval_pos_args, **eval_kwargs)
    self._log_call_method_response(method, response)
    return response

  def list_available_images(self):
    """Creates a test that confirms expected available images.

    Returns:
      st.OperationContract
    """
    logger = logging.getLogger(__name__)

    # Get the list of images available (to the service account we are using).
    context = citest.base.ExecutionContext()
    gcp_agent = self.gcp_observer
    JournalLogger.begin_context('Collecting expected available images')
    relation_context = 'ERROR'
    try:
      logger.debug('Looking up available images.')

      json_doc = gcp_agent.list_resource(context, 'images')
      for project in GCP_STANDARD_IMAGES.keys():
        logger.info('Looking for images from project=%s', project)
        found = gcp_agent.list_resource(context, 'images', project=project)
        for image in found:
          if not image.get('deprecated', None):
            json_doc.append(image)

      # Produce the list of images that we expect to receive from spinnaker
      # (visible to the primary service account).
      spinnaker_account = self.agent.deployed_config.get(
          'providers.google.primaryCredentials.name')

      logger.debug('Configured with Spinnaker account "%s"', spinnaker_account)
      expect_images = [{'account': spinnaker_account, 'imageName': image['name']}
                       for image in json_doc]
      expect_images = sorted(expect_images, key=lambda k: k['imageName'])
      relation_context = 'VALID'
    finally:
      JournalLogger.end_context(relation=relation_context)

    # pylint: disable=bad-continuation
    builder = HttpContractBuilder(self.agent)
    (builder.new_clause_builder('Has Expected Images')
       .get_url_path('/gce/images/find')
       .add_constraint(jp.PathPredicate(jp.DONT_ENUMERATE_TERMINAL,
                                        jp.EQUIVALENT(expect_images))))

    return st.OperationContract(
        NoOpOperation('List Available Images'),
        contract=builder.build())

  def __do_list_resource(self, context, resource_type, method_variant='list',
                         item_list_transform=None, **kwargs):
    """Helper function implementing list_resource()."""
    resource_obj = self.resource_type_to_resource_obj(resource_type)
    method_container = resource_obj()
    variables = self.resource_method_to_variables(
        method_variant, resource_type, **kwargs)
    variables = context.eval(variables)
    request = getattr(method_container, method_variant)(**variables)

    all_objects = []
    more = ''
    while request:
      logging.info('Calling %s.%s', resource_type, method_variant,
                   extra={'citest_journal':{'nojournal':True}})
      JournalLogger.journal_or_log(
          'Listing {0}{1}'.format(more, resource_type),
          _logger=self.logger, _context='request')
      response = request.execute()
      JournalLogger.journal_or_log(
          json.JSONEncoder(
              encoding='utf-8', separators=(',', ': ')).encode(response),
          _logger=self.logger, _context='response', format='json')

      response_items = response.get('items', None)
      if response_items is None:
        # Assume item reponse is named by the type being listed.
        response_items = response.get(resource_type.split('.')[-1], [])

      all_items = (item_list_transform(response_items)
                   if item_list_transform
                   else response_items)
      if not isinstance(all_items, list):
        all_items = [all_items]
      all_objects.extend(all_items)
      try:
        request = method_container.list_next(request, response)
        if request:
          logging.debug('Iterate over another page of %s', resource_type,
                        extra={'citest_journal':{'nojournal':True}})
      except AttributeError:
        request = None
      more = ' more '

    self.logger.info('Found total=%d %s', len(all_objects), resource_type)
    return all_objects

  def __init__(self, bindings, agent=None):
    """Constructor

    Args:
      bindings: [dict] The parameter bindings for overriding the test
         scenario configuration.
      agent: [SpinnakerAgent] The Spinnaker agent to bind to the scenario.
    """
    super(SpinnakerTestScenario, self).__init__(bindings, agent)
    agent = self.agent
    self.__update_bindings_with_subsystem_configuration(agent)
    JournalLogger.begin_context('Configure Cloud Bindings')
    try:
      self.__init_google_bindings()
      self.__init_aws_bindings()
      self.__init_kubernetes_bindings()
    finally:
      JournalLogger.end_context()

  def __init__(self, bindings, agent=None):
    """Constructor

    Args:
      bindings: [dict] The parameter bindings for overriding the test
         scenario configuration.
      agent: [SpinnakerAgent] The Spinnaker agent to bind to the scenario.
    """
    super(SpinnakerTestScenario, self).__init__(bindings, agent)
    self.__google_resource_analyzer = None
    agent = self.agent
    bindings = self.bindings

    # For read-only tests that don't make mutating calls to Spinnaker,
    # there is nothing to update in the bindings, e.g. GCP quota test.
    if agent is not None:
      for key, value in agent.runtime_config.items():
        try:
          if bindings[key]:
            continue  # keep existing value already set within citest
        except KeyError:
          pass
        bindings[key] = value  # use value from agent's configuration

    JournalLogger.begin_context('Configure Scenario Bindings')
    self.__platform_support = {}
    for klas in PLATFORM_SUPPORT_CLASSES:
      try:
        support = klas(self)
        self.__platform_support[support.platform_name] = support
      except:
        logger = logging.getLogger(__name__)

        logger.exception('Failed to initialize support class %s:\n%s',
                         str(klas), traceback.format_exc())

    try:
      self._do_init_bindings()
    except:
      logger = logging.getLogger(__name__)
      logger.exception('Failed to initialize spinnaker agent.')
      raise
    finally:
      JournalLogger.end_context()