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 __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 __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 wait(self,
poll_every_secs=1,
max_secs=None,
trace_every=False,
trace_first=True):
"""Wait until the status reaches a final state.
Args:
poll_every_secs: [float] Interval to refresh() from the proxy.
max_secs: [float] Most seconds to wait before giving up.
0 is a poll, None is unbounded. Otherwise, number of seconds.
trace_every: [bool] Whether or not to log every poll request.
trace_first: [bool] Whether to log the first poll request.
"""
if self.finished:
return
if max_secs is None:
max_secs = self.operation.max_wait_secs
if max_secs < 0 and max_secs is not None:
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(trace=trace_first)
self.__wait_helper(poll_every_secs, max_secs, trace_every)
context_relation = 'VALID' if self.finished_ok else 'INVALID'
finally:
JournalLogger.end_context(relation=context_relation)
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 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 _log_call_method_response(self, method, response):
# pylint: disable=unused-argument
JournalLogger.journal_or_log(
json.JSONEncoder(separators=(',', ': ')).encode(response),
_logger=self.logger,
_context='response',
format='json')
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()
self.__init_appengine_bindings()
self.__init_openstack_bindings()
self._do_init_bindings()
except:
logger = logging.getLogger(__name__)
logger.exception('Failed to initialize spinnaker agent.')
raise
finally:
JournalLogger.end_context()
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 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 __do_invoke_resource(self,
context,
method,
resource_type,
resource_id=None,
**kwargs):
"""Implements invoke_resource()."""
variables = self.resource_method_to_variables(method,
resource_type,
resource_id=resource_id,
**kwargs)
variables = context.eval(variables)
resource_obj = self.resource_type_to_resource_obj(resource_type)
logging.debug('Calling %s.%s', resource_type, method)
JournalLogger.journal_or_log(
'Requesting {type} {method} {vars}'.format(type=resource_type,
method=method,
vars=variables),
_logging=self.logger.name,
_context='request')
request = getattr(resource_obj(), method)(**variables)
response = request.execute()
JournalLogger.journal_or_log(
json.JSONEncoder(separators=(',', ': ')).encode(response),
_logger=self.logger,
_context='response',
format='json')
return response
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)
protocol = bindings['NETWORK_PROTOCOL']
base_url = '{protocol}://{netloc}'.format(protocol=protocol,
netloc=netloc)
logger.info('%s is available at %s. Using %s', name, netloc,
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 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 __log_delta_quota(self, before, after):
if before == after:
logging.info("No GCP quota impact.")
return
diff = {}
for region in after.keys():
before_quota = before.get(region, {})
after_quota = after.get(region, {})
if before_quota == after_quota:
continue
delta = {
metric: after_quota[metric] - before_quota[metric]
for metric in after_quota.keys()
if after_quota.get(metric) != before_quota.get(metric)
}
if delta:
diff[region] = delta
self.__update_running_quota(diff)
self.__to_log_path(
"--- QUOTA ---",
detail=json.JSONEncoder(indent=2,
separators=(",", ": ")).encode(diff),
indent=2,
)
JournalLogger.journal_or_log_detail("GCP Quota Impact",
str(diff),
format="json")
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 __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.debug('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(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.debug('Found total=%d %s', len(all_objects), resource_type)
return all_objects
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 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 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').contains_match(
[jp.DICT_SUBSET(image_entry) for image_entry in expect_images],
match_kwargs={
'strict': True,
'unique': True
}))
return st.OperationContract(NoOpOperation('List Available Images'),
contract=builder.build())
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 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 run(self, args, trace=True, output_scrubber=None):
"""Run the specified command.
Args:
args: The list of command-line arguments for self.__program.
trace: If True then we should trace the call/response.
Returns:
CliResponseType tuple containing program execution results.
"""
command = self._args_to_full_commandline(args)
log_msg = 'spawn {0} "{1}"'.format(command[0], '" "'.join(command[1:]))
JournalLogger.journal_or_log(log_msg,
_module=self.logger.name,
_alwayslog=trace,
_context='request')
process = subprocess.Popen(command,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
close_fds=True)
stdout, stderr = process.communicate()
scrubber = output_scrubber or self.__output_scrubber
if scrubber:
log_msg = 'Scrubbing output with {0}'.format(
scrubber.__class__.__name__)
JournalLogger.journal_or_log(log_msg,
_module=self.logger.name,
_alwayslog=trace)
stdout = scrubber(stdout)
# Strip leading/trailing eolns that program may add to errors and output.
stderr = stderr.strip()
stdout = stdout.strip()
code = process.returncode
# Always log to journal
if stdout and stderr:
which = 'both stdout and stderr'
output_json = {'stdout': stdout, 'stderr': stderr}
else:
which = 'stderr' if stderr else 'stdout'
output_json = stderr if stderr else stdout
if output_json:
JournalLogger.journal_or_log_detail('Result Code {0} / {1}'.format(
code, which),
output_json,
_module=self.logger.name,
_alwayslog=trace,
_context='response')
else:
JournalLogger.journal_or_log(
'Result Code {0} / no ouptut'.format(code),
_module=self.logger.name,
_alwayslog=trace,
_context='response')
return CliResponseType(code, stdout, stderr)
def new_native_instance(cls, name, status_factory, base_url, bindings):
"""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.
bindings: [dict] List of bindings to configure the endpoint
BEARER_AUTH_TOKEN: The token used to authenticate request to a
protected host.
IGNORE_SSL_CERT_VERIFICATION: If True, ignores SSL certificate
verification when making requests.
Returns:
A SpinnakerAgent connected to the specified instance port.
"""
bearer_auth_token = bindings.get("BEARER_AUTH_TOKEN", None)
ignore_ssl_cert_verification = bindings["IGNORE_SSL_CERT_VERIFICATION"]
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")
headers = {}
if bearer_auth_token:
headers["Authorization"] = "Bearer {}".format(bearer_auth_token)
deployed_config = scrape_spring_config(
env_url,
headers=headers,
ignore_ssl_cert_verification=ignore_ssl_cert_verification,
)
JournalLogger.journal_or_log_detail(
"{0} configuration".format(name), deployed_config
)
spinnaker_agent = cls(base_url, status_factory)
spinnaker_agent.ignore_ssl_cert_verification = ignore_ssl_cert_verification
spinnaker_agent.__deployed_config = deployed_config
if bearer_auth_token:
spinnaker_agent.add_header(
"Authorization", "Bearer {}".format(bearer_auth_token)
)
return spinnaker_agent
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 __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 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 list_resource(self,
context,
resource_type,
method_variant='list',
item_list_transform=None,
**kwargs):
"""List the contents of the specified resource.
Args:
resource_type: [string] The name of the resource to list.
method_variant: [string] The API method name to invoke.
item_list_transform: [lambda items] Converts the list of items into
a result list, or None for the identity.
kwargs: [kwargs] Additional parameters may be required depending
on the resource type (such as zone, etc).
Returns:
A list of resources.
"""
return JournalLogger.execute_in_context(
'List {}'.format(resource_type), lambda: self.__do_list_resource(
context,
resource_type,
method_variant=method_variant,
item_list_transform=item_list_transform,
**kwargs))
def invoke_resource(self,
context,
method,
resource_type,
resource_id=None,
**kwargs):
"""Invoke a method on a resource type or instance.
Args:
method: [string] The operation to perform as named under the
|resource_type| in the discovery document.
resource_type: [string] The type of the resource instance to operate on.
resource_id: [string] The id of the resource instance, or None to operate
on the resource type or collection.
kwargs: [kwargs] Additional parameters may be required depending
on the resource type and method.
"""
return JournalLogger.execute_in_context(
'Invoke "{method}" {type}'.format(method=method,
type=resource_type),
lambda: self.__do_invoke_resource(context,
method,
resource_type,
resource_id=resource_id,
**kwargs))
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 __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()
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)
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()
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 new_native_instance(cls, name, status_factory, base_url, bindings):
"""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.
bindings: [dict] List of bindings to configure the endpoint
BEARER_AUTH_TOKEN: The token used to authenticate request to a
protected host.
IGNORE_SSL_CERT_VERIFICATION: If True, ignores SSL certificate
verification when making requests.
Returns:
A SpinnakerAgent connected to the specified instance port.
"""
bearer_auth_token = bindings.get('BEARER_AUTH_TOKEN', None)
ignore_ssl_cert_verification = bindings['IGNORE_SSL_CERT_VERIFICATION']
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')
headers = {}
if bearer_auth_token:
headers['Authorization'] = 'Bearer {}'.format(bearer_auth_token)
deployed_config = scrape_spring_config(env_url, headers=headers, ignore_ssl_cert_verification=ignore_ssl_cert_verification)
JournalLogger.journal_or_log_detail(
'{0} configuration'.format(name), deployed_config)
spinnaker_agent = cls(base_url, status_factory)
spinnaker_agent.ignore_ssl_cert_verification = ignore_ssl_cert_verification
spinnaker_agent.__deployed_config = deployed_config
if bearer_auth_token:
spinnaker_agent.add_header('Authorization', 'Bearer {}'.format(bearer_auth_token))
return spinnaker_agent
def run(self, args, output_scrubber=None):
"""Run the specified command.
Args:
args: The list of command-line arguments for self.__program.
Returns:
CliResponseType tuple containing program execution results.
"""
command = self._args_to_full_commandline(args)
log_msg = 'spawn {0} "{1}"'.format(command[0], '" "'.join(command[1:]))
JournalLogger.journal_or_log(log_msg,
_logger=self.logger,
_context='request')
process = subprocess.Popen(
command,
stdout=subprocess.PIPE, stderr=subprocess.PIPE, close_fds=True)
stdout, stderr = process.communicate()
if stdout is not None:
stdout = bytes.decode(stdout)
if stderr is not None:
stderr = bytes.decode(stderr)
scrubber = output_scrubber or self.__output_scrubber
if scrubber:
log_msg = 'Scrubbing output with {0}'.format(scrubber.__class__.__name__)
JournalLogger.journal_or_log(log_msg, _logger=self.logger)
stdout = scrubber(stdout)
# Strip leading/trailing eolns that program may add to errors and output.
stderr = stderr.strip()
stdout = stdout.strip()
code = process.returncode
# Always log to journal
if stdout and stderr:
which = 'both stdout and stderr'
output_json = {'stdout':stdout, 'stderr':stderr}
else:
which = 'stderr' if stderr else 'stdout'
output_json = stderr if stderr else stdout
if output_json:
JournalLogger.journal_or_log_detail(
'Result Code {0} / {1}'.format(code, which), output_json,
_logger=self.logger, _context='response')
else:
JournalLogger.journal_or_log(
'Result Code {0} / no ouptut'.format(code),
_logger=self.logger,
_context='response')
return CliResponseType(code, stdout, stderr)
def pre_run_hook(self, test_case, context):
if not self.bindings.get('RECORD_GCP_RESOURCE_USAGE'):
return None
if self.__google_resource_analyzer is None:
from google_scenario_support import GcpResourceUsageAnalyzer
self.__google_resource_analyzer = GcpResourceUsageAnalyzer(self)
analyzer = self.__google_resource_analyzer
scanner = analyzer.make_gcp_api_scanner(
self.bindings.get('GOOGLE_ACCOUNT_PROJECT'),
self.bindings.get('GOOGLE_CREDENTIALS_PATH'),
include_apis=['compute'],
exclude_apis=['compute.*Operations'])
JournalLogger.begin_context('Capturing initial quota usage')
try:
usage = analyzer.collect_resource_usage(self.gcp_observer, scanner)
finally:
JournalLogger.end_context()
return (scanner, usage)
def pre_run_hook(self, test_case, context):
if not self.bindings.get('RECORD_GCP_RESOURCE_USAGE'):
return None
if self.__google_resource_analyzer is None:
from google_scenario_support import GcpResourceUsageAnalyzer
self.__google_resource_analyzer = GcpResourceUsageAnalyzer(self)
analyzer = self.__google_resource_analyzer
scanner = analyzer.make_gcp_api_scanner(
self.bindings.get('GOOGLE_ACCOUNT_PROJECT'),
self.bindings.get('GOOGLE_CREDENTIALS_PATH'),
include_apis=['compute'],
exclude_apis=['compute.*Operations'])
JournalLogger.begin_context('Capturing initial quota usage')
try:
usage = analyzer.collect_resource_usage(self.gcp_observer, scanner)
finally:
JournalLogger.end_context()
return (scanner, usage)
def verify(self, context):
"""Attempt to make an observation and verify it.
This call will repeatedly attempt to observe new data and verify it
until either the verification passes, or it times out base on
the retryable_for_secs specified in the constructor.
Args:
context: Runtime citest execution context may contain operation status
and other testing parameters used by downstream verifiers.
Returns:
ContractClauseVerifyResult with details.
"""
JournalLogger.begin_context(
'Verifying ContractClause: {0}'.format(self.__title))
context_relation = 'ERROR'
try:
JournalLogger.delegate("store", self, _title='Clause Specification')
result = self.__do_verify(context)
context_relation = 'VALID' if result else 'INVALID'
finally:
JournalLogger.end_context(relation=context_relation)
return result
def __do_invoke_resource(self, context, method, resource_type,
resource_id=None, **kwargs):
"""Implements invoke_resource()."""
variables = self.resource_method_to_variables(
method, resource_type, resource_id=resource_id, **kwargs)
variables = context.eval(variables)
resource_obj = self.resource_type_to_resource_obj(resource_type)
logging.debug('Calling %s.%s', resource_type, method)
JournalLogger.journal_or_log(
'Requesting {type} {method} {vars}'.format(
type=resource_type, method=method, vars=variables),
_logging=self.logger.name,
_context='request')
request = getattr(resource_obj(), method)(**variables)
response = request.execute()
JournalLogger.journal_or_log(
json.JSONEncoder(separators=(',', ': ')).encode(response),
_logger=self.logger, _context='response', format='json')
return response
def new_native_instance(cls, name, status_factory, base_url, bindings):
"""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.
bindings: [dict] List of bindings to configure the endpoint
BEARER_AUTH_TOKEN: The token used to authenticate request to a
protected host.
Returns:
A SpinnakerAgent connected to the specified instance port.
"""
bearer_auth_token = bindings.get('BEARER_AUTH_TOKEN', None)
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, headers={
'Authorization': 'Bearer {}'.format(bearer_auth_token)
})
JournalLogger.journal_or_log_detail(
'{0} configuration'.format(name), deployed_config)
spinnaker_agent = cls(base_url, status_factory)
spinnaker_agent.__deployed_config = deployed_config
if bearer_auth_token:
spinnaker_agent.add_header('Authorization', 'Bearer {}'.format(bearer_auth_token))
return spinnaker_agent
def __log_delta_quota(self, before, after):
if before == after:
logging.info('No GCP quota impact.')
return
diff = {}
for region in after.keys():
before_quota = before.get(region, {})
after_quota = after.get(region, {})
if before_quota == after_quota:
continue
delta = {metric: after_quota[metric] - before_quota[metric]
for metric in after_quota.keys()
if after_quota.get(metric) != before_quota.get(metric)}
if delta:
diff[region] = delta
self.__update_running_quota(diff)
self.__to_log_path(
'--- QUOTA ---',
detail=json.JSONEncoder(indent=2, separators=(',', ': ')).encode(diff),
indent=2)
JournalLogger.journal_or_log_detail('GCP Quota Impact',
str(diff), format='json')
def invoke_resource(self, context, method, resource_type,
resource_id=None, **kwargs):
"""Invoke a method on a resource type or instance.
Args:
method: [string] The operation to perform as named under the
|resource_type| in the discovery document.
resource_type: [string] The type of the resource instance to operate on.
resource_id: [string] The id of the resource instance, or None to operate
on the resource type or collection.
kwargs: [kwargs] Additional parameters may be required depending
on the resource type and method.
"""
return JournalLogger.execute_in_context(
'Invoke "{method}" {type}'.format(method=method, type=resource_type),
lambda: self.__do_invoke_resource(
context, method, resource_type,
resource_id=resource_id, **kwargs))
def list_resource(self, context, resource_type, method_variant='list',
item_list_transform=None, **kwargs):
"""List the contents of the specified resource.
Args:
resource_type: [string] The name of the resource to list.
method_variant: [string] The API method name to invoke.
item_list_transform: [lambda items] Converts the list of items into
a result list, or None for the identity.
kwargs: [kwargs] Additional parameters may be required depending
on the resource type (such as zone, etc).
Returns:
A list of resources.
"""
return JournalLogger.execute_in_context(
'List {}'.format(resource_type),
lambda: self.__do_list_resource(
context, resource_type, method_variant=method_variant,
item_list_transform=item_list_transform, **kwargs))
def test_context_logging(self):
offset = len(_journal_file.getvalue())
logger = JournalLogger('test_journal_logger')
logger.addHandler(JournalLogHandler(path=None))
citest_extra = {'foo':'bar'}
start_time = _journal_clock.last_time
JournalLogger.execute_in_context(
'The Test Context',
lambda: {logger.debug('Test Log Message')},
**citest_extra)
expect_sequence = [
{
'_title': 'The Test Context',
'_type': 'JournalContextControl',
'_timestamp': start_time + 1,
'_thread': current_thread().ident,
'control': 'BEGIN',
'foo': 'bar',
},
{
'_value': 'Test Log Message',
'_type': 'JournalMessage',
'_level': logging.DEBUG,
'_timestamp': start_time + 2,
'_thread': current_thread().ident,
'format': 'pre'
},
{
'_type': 'JournalContextControl',
'_timestamp': start_time + 3,
'_thread': current_thread().ident,
'control': 'END'
}
]
entry_str = _journal_file.getvalue()[offset:]
input_stream = RecordInputStream(BytesIO(entry_str))
for expect in expect_sequence:
json_str = next(input_stream)
json_dict = json_module.JSONDecoder().decode(json_str)
self.assertEqual(expect, json_dict)
def test_journal_logger(self):
offset = len(_journal_file.getvalue())
logger = JournalLogger('test_journal_logger')
logger.addHandler(JournalLogHandler(path=None))
citest_extra = {'foo':'bar', 'format':'FMT'}
logger.info('Hello, World!', extra={'citest_journal': citest_extra})
expect = {
'_value': 'Hello, World!',
'_type': 'JournalMessage',
'_level': logging.INFO,
'_timestamp': _journal_clock.last_time,
'_thread': current_thread().ident,
'foo': 'bar',
'format': 'FMT',
}
entry_str = _journal_file.getvalue()[offset:]
json_str = next(RecordInputStream(BytesIO(entry_str)))
json_dict = json_module.JSONDecoder().decode(json_str)
self.assertEqual(expect, json_dict)
def test_journal_logger_with_custom_message(self):
offset = len(_journal_file.getvalue())
logger = JournalLogger(__name__)
logger.addHandler(JournalLogHandler(path=None))
citest_extra = {'foo':'bar', '_journal_message':'HELLO, JOURNAL'}
logger.debug('Hello, World!', extra={'citest_journal': citest_extra})
expect = {
'_value': 'HELLO, JOURNAL',
'_type': 'JournalMessage',
'_level': logging.DEBUG,
'_timestamp': _journal_clock.last_time,
'_thread': current_thread().ident,
'foo': 'bar',
'format': 'pre'
}
entry_str = _journal_file.getvalue()[offset:]
json_str = next(RecordInputStream(BytesIO(entry_str)))
json_dict = json_module.JSONDecoder().decode(json_str)
self.assertEqual(expect, json_dict)
def _log_call_method_response(self, method, response):
JournalLogger.journal_or_log(
AwsJsonEncoder(separators=(',', ':')).encode(response),
_logger=self.logger, _context='response', format='json')
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.
poll_every_secs: [int] Number of seconds between wait polls. Default=1.
"""
if context is None:
context = ExecutionContext()
timeout_ok = kwargs.pop('timeout_ok', False)
max_retries = kwargs.pop('max_retries', 0)
retry_interval_secs = kwargs.pop('retry_interval_secs', 5)
poll_every_secs = kwargs.pop('poll_every_secs', 1)
full_trace = kwargs.pop('full_trace', False) # Deprecated
if kwargs:
raise TypeError('Unrecognized arguments {0}'.format(kwargs.keys()))
self.log_start_test(test_case.title)
if max_retries < 0:
raise ValueError(
'max_retries={max} cannot be negative'.format(max=max_retries))
if retry_interval_secs < 0:
raise ValueError(
'retry_interval_secs={secs} cannot be negative'.format(
secs=retry_interval_secs))
execution_trace = OperationContractExecutionTrace(test_case)
verify_results = None
final_status_ok = None
context_relation = None
attempt_info = None
status = None
try:
JournalLogger.begin_context('Test "{0}"'.format(test_case.title))
JournalLogger.delegate(
"store", test_case.operation,
_title='Operation "{0}" Specification'.format(
test_case.operation.title))
max_tries = 1 + max_retries
# We attempt the operation on the agent multiple times until the agent
# thinks that it succeeded. But we will only verify once the agent thinks
# it succeeded. We do not give multiple chances to satisfy the
# verification.
for i in range(max_tries):
context.clear_key('OperationStatus')
context.clear_key('AttemptInfo')
attempt_info = execution_trace.new_attempt()
status = None
status = test_case.operation.execute(agent=self.testing_agent)
status.wait(poll_every_secs=poll_every_secs)
summary = status.error or ('Operation status OK' if status.finished_ok
else 'Operation status Unknown')
# Write the status (and attempt_info) into the execution_context
# to make it available to contract verifiers. For example, to
# make specific details in the status (e.g. new resource names)
# available to downstream validators for their consideration.
context.set_internal('AttemptInfo', attempt_info)
context.set_internal('OperationStatus', status)
attempt_info.set_status(status, summary)
if test_case.status_extractor:
test_case.status_extractor(status, context)
if not status.exception_details:
execution_trace.set_operation_summary('Completed test.')
break
if max_tries - i > 1:
self.logger.warning(
'Got an exception: %s.\nTrying again in %r secs...',
status.exception_details, retry_interval_secs)
time.sleep(retry_interval_secs)
elif max_tries > 1:
execution_trace.set_operation_summary('Gave up retrying operation.')
self.logger.error('Giving up retrying test.')
# We're always going to verify the contract, even if the request itself
# failed. We set the verification on the attempt here, but do not assert
# anything. We'll assert below outside this try/catch handler.
verify_results = test_case.contract.verify(context)
execution_trace.set_verify_results(verify_results)
final_status_ok = self.verify_final_status_ok(
status, timeout_ok=timeout_ok,
final_attempt=attempt_info,
execution_trace=execution_trace)
context_relation = ('VALID' if (final_status_ok and verify_results)
else 'INVALID')
except BaseException as ex:
context_relation = 'ERROR'
execution_trace.set_exception(ex)
if attempt_info is None:
execution_trace.set_exception(ex, traceback_module.format_exc())
elif not attempt_info.completed:
# Exception happened during the attempt as opposed to during our
# verification afterwards.
attempt_info.set_exception(ex, traceback_module.format_exc())
try:
self.logger.error('Test failed with exception: %s', ex)
self.logger.error('Last status was:\n%s', str(status))
self.logger.debug('Exception was at:\n%s',
traceback_module.format_exc())
except BaseException as unexpected:
self.logger.error(
'Unexpected error %s\nHandling original exception %s',
unexpected, ex)
self.logger.debug('Unexpected exception was at:\n%s',
traceback_module.format_exc())
raise
finally:
try:
context.set_internal('ContractVerifyResults', verify_results)
self.log_end_test(test_case.title)
self.report(execution_trace)
if test_case.cleanup:
if 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:
JournalLogger.end_context(relation=context_relation)
if not final_status_ok:
self.raise_final_status_not_ok(status, attempt_info)
if verify_results is not None:
self.assertVerifyResults(verify_results)
def __send_http_request(self, path, http_type, data=None, headers=None):
"""Send an HTTP message.
Args:
path: [string] The URL path to send to (without network location)
http_type: [string] The HTTP message type (e.g. POST)
data: [string] Data payload to send, if any.
headers: [dict] Headers to write, if any.
Returns:
HttpResponseType
"""
if headers is None:
all_headers = self.__headers
else:
all_headers = self.__headers.copy()
all_headers.update(headers)
if path[0] == '/':
path = path[1:]
url = '{0}/{1}'.format(self.__base_url, path)
req = urllib2.Request(url=url, data=data, headers=all_headers)
req.get_method = lambda: http_type
scrubbed_url = self.__http_scrubber.scrub_url(url)
scrubbed_data = self.__http_scrubber.scrub_request(data)
if data is not None:
JournalLogger.journal_or_log_detail(
'{type} {url}'.format(type=http_type, url=scrubbed_url),
scrubbed_data,
_logger=self.logger,
_context='request')
else:
JournalLogger.journal_or_log(
'{type} {url}'.format(type=http_type, url=scrubbed_url),
_logger=self.logger,
_context='request')
code = None
output = None
exception = None
try:
response = urllib2.urlopen(req)
code = response.getcode()
output = response.read()
scrubbed_output = self.__http_scrubber.scrub_response(output)
JournalLogger.journal_or_log_detail(
'HTTP {code}'.format(code=code),
scrubbed_output,
_logger=self.logger,
_context='response')
except urllib2.HTTPError as ex:
code = ex.getcode()
output = ex.read()
scrubbed_error = self.__http_scrubber.scrub_response(output)
JournalLogger.journal_or_log_detail(
'HTTP {code}'.format(code=code), scrubbed_error,
_logger=self.logger,
_context='response')
except urllib2.URLError as ex:
JournalLogger.journal_or_log(
'Caught exception: {ex}\n{stack}'.format(
ex=ex, stack=traceback.format_exc()),
_logger=self.logger)
exception = ex
return HttpResponseType(code, output, exception)
def _log_call_method_response(self, method, response):
# pylint: disable=unused-argument
JournalLogger.journal_or_log(
json.JSONEncoder(separators=(',', ': ')).encode(response),
_logger=self.logger, _context='response', format='json')
