diff --git a/armada/api/controller/tiller.py b/armada/api/controller/tiller.py index a38eb86a..366a8a95 100644 --- a/armada/api/controller/tiller.py +++ b/armada/api/controller/tiller.py @@ -16,12 +16,14 @@ import json import falcon from oslo_config import cfg +from oslo_log import log as logging from armada import api from armada.common import policy from armada.handlers.tiller import Tiller CONF = cfg.CONF +LOG = logging.getLogger(__name__) class Status(api.BaseResource): @@ -38,6 +40,10 @@ class Status(api.BaseResource): tiller_namespace=req.get_param( 'tiller_namespace', default=CONF.tiller_namespace)) + LOG.debug('Tiller (Status) at: %s:%s, namespace=%s, ' + 'timeout=%s', tiller.tiller_host, tiller.tiller_port, + tiller.tiller_namespace, tiller.timeout) + message = { 'tiller': { 'state': tiller.tiller_status(), @@ -69,6 +75,10 @@ class Release(api.BaseResource): tiller_namespace=req.get_param( 'tiller_namespace', default=CONF.tiller_namespace)) + LOG.debug('Tiller (Release) at: %s:%s, namespace=%s, ' + 'timeout=%s', tiller.tiller_host, tiller.tiller_port, + tiller.tiller_namespace, tiller.timeout) + releases = {} for release in tiller.list_releases(): releases.setdefault(release.namespace, []) diff --git a/armada/api/middleware.py b/armada/api/middleware.py index 41b440a4..b3e48c00 100644 --- a/armada/api/middleware.py +++ b/armada/api/middleware.py @@ -12,6 +12,8 @@ # See the License for the specific language governing permissions and # limitations under the License. +import re + from uuid import UUID from oslo_config import cfg @@ -97,7 +99,24 @@ class LoggingMiddleware(object): def __init__(self): self.logger = logging.getLogger(__name__) + # don't log any headers beginning with X-* + hdr_exclude = re.compile('x-.*', re.IGNORECASE) + + def process_request(self, req, resp): + """ Set up values to be logged across the request + """ + ctx = req.context + extra = { + 'user': ctx.user, + 'req_id': ctx.request_id, + 'external_ctx': ctx.external_marker, + } + self.logger.info("Request %s %s" % (req.method, req.url), extra=extra) + self._log_headers(req.headers) + def process_response(self, req, resp, resource, req_succeeded): + """ Log the response information + """ ctx = req.context extra = { 'user': ctx.user, @@ -105,4 +124,13 @@ class LoggingMiddleware(object): 'external_ctx': ctx.external_marker, } resp.append_header('X-Armada-Req', ctx.request_id) - self.logger.info("%s - %s" % (req.uri, resp.status), extra=extra) + self.logger.info("%s %s - %s" % (req.method, req.uri, resp.status), + extra=extra) + self.logger.debug("Response body:%s", resp.body) + + def _log_headers(self, headers): + """ Log request headers, while scrubbing sensitive values + """ + for header, header_value in headers.items(): + if not LoggingMiddleware.hdr_exclude.match(header): + self.logger.debug("Header %s: %s", header, header_value) diff --git a/armada/api/server.py b/armada/api/server.py index 052ce548..fe7308aa 100644 --- a/armada/api/server.py +++ b/armada/api/server.py @@ -36,7 +36,7 @@ CONF = cfg.CONF def create(enable_middleware=CONF.middleware): - """Entry point for intializing Armada server. + """Entry point for initializing Armada server. :param enable_middleware: Whether to enable middleware. :type enable_middleware: bool @@ -47,8 +47,8 @@ def create(enable_middleware=CONF.middleware): request_type=ArmadaRequest, middleware=[ AuthMiddleware(), + ContextMiddleware(), LoggingMiddleware(), - ContextMiddleware() ]) else: api = falcon.API(request_type=ArmadaRequest) diff --git a/armada/common/policies/service.py b/armada/common/policies/service.py index 4b8bffd4..63488d64 100644 --- a/armada/common/policies/service.py +++ b/armada/common/policies/service.py @@ -19,22 +19,22 @@ armada_policies = [ policy.DocumentedRuleDefault( name=base.ARMADA % 'create_endpoints', check_str=base.RULE_ADMIN_REQUIRED, - description='install manifest charts', + description='Install manifest charts', operations=[{'path': '/api/v1.0/apply/', 'method': 'POST'}]), policy.DocumentedRuleDefault( name=base.ARMADA % 'validate_manifest', check_str=base.RULE_ADMIN_REQUIRED, - description='validate installed manifest', + description='Validate manifest', operations=[{'path': '/api/v1.0/validatedesign/', 'method': 'POST'}]), policy.DocumentedRuleDefault( name=base.ARMADA % 'test_release', check_str=base.RULE_ADMIN_REQUIRED, - description='validate install manifest', + description='Test release', operations=[{'path': '/api/v1.0/test/{release}', 'method': 'GET'}]), policy.DocumentedRuleDefault( name=base.ARMADA % 'test_manifest', check_str=base.RULE_ADMIN_REQUIRED, - description='validate install manifest', + description='Test manifest', operations=[{'path': '/api/v1.0/tests/', 'method': 'POST'}]), ] diff --git a/armada/common/session.py b/armada/common/session.py index 502ea727..d1db8daa 100644 --- a/armada/common/session.py +++ b/armada/common/session.py @@ -73,9 +73,13 @@ class ArmadaSession(object): :return: A requests.Response object """ api_url = '{}{}'.format(self.base_url, endpoint) + req_timeout = self._timeout(timeout) + + self.logger.debug("Sending armada_client session GET %s with " + "params=[%s], headers=[%s], timeout=[%s]", + api_url, query, headers, req_timeout) resp = self._session.get( - api_url, params=query, headers=headers, - timeout=self._timeout(timeout)) + api_url, params=query, headers=headers, timeout=req_timeout) return resp @@ -95,22 +99,25 @@ class ArmadaSession(object): :return: A requests.Response object """ api_url = '{}{}'.format(self.base_url, endpoint) + req_timeout = self._timeout(timeout) - self.logger.debug("Sending POST with armada_client session") + self.logger.debug("Sending armada_client session POST %s with " + "params=[%s], headers=[%s], timeout=[%s]", + api_url, query, headers, req_timeout) if body is not None: self.logger.debug("Sending POST with explicit body: \n%s" % body) resp = self._session.post(api_url, params=query, data=body, headers=headers, - timeout=self._timeout(timeout)) + timeout=req_timeout) else: self.logger.debug("Sending POST with JSON body: \n%s" % str(data)) resp = self._session.post(api_url, params=query, json=data, headers=headers, - timeout=self._timeout(timeout)) + timeout=req_timeout) return resp diff --git a/armada/errors.py b/armada/errors.py index 1aeb5012..5fba2e3d 100644 --- a/armada/errors.py +++ b/armada/errors.py @@ -22,7 +22,6 @@ from oslo_log import log as logging LOG = logging.getLogger(__name__) -DEFAULT_TIMEOUT = 3600 CONF = cfg.CONF @@ -153,7 +152,7 @@ def default_error_serializer(req, resp, exception): def default_exception_handler(ex, req, resp, params): """ - Catch-all execption handler for standardized output. + Catch-all exception handler for standardized output. If this is a standard falcon HTTPError, rethrow it for handling """ if isinstance(ex, falcon.HTTPError): @@ -219,7 +218,7 @@ class AppError(Exception): @staticmethod def _gen_ex_message(title, description): ttl = title or 'Exception' - dsc = description or 'No additional decsription' + dsc = description or 'No additional description' return '{} : {}'.format(ttl, dsc) @staticmethod diff --git a/armada/exceptions/base_exception.py b/armada/exceptions/base_exception.py index d345dd32..c57348ab 100644 --- a/armada/exceptions/base_exception.py +++ b/armada/exceptions/base_exception.py @@ -19,8 +19,6 @@ from oslo_log import log as logging from armada.common.i18n import _ LOG = logging.getLogger(__name__) - -DEFAULT_TIMEOUT = 3600 CONF = cfg.CONF diff --git a/armada/handlers/document.py b/armada/handlers/document.py index a546c090..d16a6f81 100644 --- a/armada/handlers/document.py +++ b/armada/handlers/document.py @@ -26,7 +26,7 @@ LOG = logging.getLogger(__name__) class ReferenceResolver(object): - """Class for handling different data references to resolve them data.""" + """Class for handling different data references to resolve the data.""" @classmethod def resolve_reference(cls, design_ref): @@ -36,6 +36,7 @@ class ReferenceResolver(object): and use that handler to get the data referenced. :param design_ref: A list of URI-formatted reference to a data entity + :returns: A list of byte arrays """ data = [] diff --git a/armada/handlers/k8s.py b/armada/handlers/k8s.py index 428ac1fb..51e373f2 100644 --- a/armada/handlers/k8s.py +++ b/armada/handlers/k8s.py @@ -306,8 +306,8 @@ class K8s(object): LOG.debug('Pod %s is ready!', pod_name) else: pod_ready = False - LOG.debug('Pod %s not ready: conditions=[%s] ' - 'container_statuses=[%s] ', pod_name, + LOG.debug('Pod %s not ready: conditions:\n%s\n' + 'container_statuses:\n%s', pod_name, status.conditions, status.container_statuses) ready_pods[pod_name] = pod_ready diff --git a/armada/handlers/tiller.py b/armada/handlers/tiller.py index acdc7bd6..b1cceffb 100644 --- a/armada/handlers/tiller.py +++ b/armada/handlers/tiller.py @@ -65,7 +65,7 @@ class Tiller(object): # init k8s connectivity self.k8s = K8s() - # init tiller channel + # init Tiller channel self.channel = self.get_channel() # init timeout for all requests @@ -73,20 +73,29 @@ class Tiller(object): # be fed at runtime as an override self.timeout = TILLER_TIMEOUT + LOG.debug('Armada is using Tiller at: %s:%s, namespace=%s, timeout=%s', + self.tiller_host, self.tiller_port, self.tiller_namespace, + self.timeout) + @property def metadata(self): ''' - Return tiller metadata for requests + Return Tiller metadata for requests ''' return [(b'x-helm-api-client', TILLER_VERSION)] def get_channel(self): ''' - Return a tiller channel + Return a Tiller channel ''' tiller_ip = self._get_tiller_ip() tiller_port = self._get_tiller_port() try: + LOG.debug('Tiller getting gRPC insecure channel at %s:%s ' + 'with options: [grpc.max_send_message_length=%s, ' + 'grpc.max_receive_message_length=%s]', + tiller_ip, tiller_port, + MAX_MESSAGE_LENGTH, MAX_MESSAGE_LENGTH) return grpc.insecure_channel( '%s:%s' % (tiller_ip, tiller_port), options=[ @@ -99,49 +108,56 @@ class Tiller(object): def _get_tiller_pod(self): ''' - Returns tiller pod using the tiller pod labels specified in the Armada + Returns Tiller pod using the Tiller pod labels specified in the Armada config ''' pods = None namespace = self._get_tiller_namespace() pods = self.k8s.get_namespace_pod(namespace, CONF.tiller_pod_labels).items - # No tiller pods found + # No Tiller pods found if not pods: raise ex.TillerPodNotFoundException(CONF.tiller_pod_labels) - # Return first tiller pod in running state + # Return first Tiller pod in running state for pod in pods: if pod.status.phase == 'Running': + LOG.debug('Found at least one Running Tiller pod.') return pod - # No tiller pod found in running state + # No Tiller pod found in running state raise ex.TillerPodNotRunningException() def _get_tiller_ip(self): ''' - Returns the tiller pod's IP address by searching all namespaces + Returns the Tiller pod's IP address by searching all namespaces ''' if self.tiller_host: + LOG.debug('Using Tiller host IP: %s', self.tiller_host) return self.tiller_host else: pod = self._get_tiller_pod() + LOG.debug('Using Tiller pod IP: %s', pod.status.pod_ip) return pod.status.pod_ip def _get_tiller_port(self): '''Stub method to support arbitrary ports in the future''' + LOG.debug('Using Tiller host port: %s', self.tiller_port) return self.tiller_port def _get_tiller_namespace(self): + LOG.debug('Using Tiller namespace: %s', self.tiller_namespace) return self.tiller_namespace def tiller_status(self): ''' - return if tiller exist or not + return if Tiller exist or not ''' if self._get_tiller_ip(): + LOG.debug('Getting Tiller Status: Tiller exists') return True + LOG.debug('Getting Tiller Status: Tiller does not exist') return False def list_releases(self): @@ -155,10 +171,13 @@ class Tiller(object): STATUS_FAILED], sort_by='LAST_RELEASED', sort_order='DESC') + + LOG.debug('Tiller ListReleases() with timeout=%s', self.timeout) release_list = stub.ListReleases(req, self.timeout, metadata=self.metadata) for y in release_list: + LOG.debug('Found release: %s', y.releases) releases.extend(y.releases) return releases @@ -206,7 +225,7 @@ class Tiller(object): name, release_name, namespace, labels, action_type, chart, disable_hooks, values) except Exception: - LOG.debug("Pre: Could not update anything, please check yaml") + LOG.warn("Pre: Could not update anything, please check yaml") try: for action in actions.get('delete', []): @@ -217,7 +236,7 @@ class Tiller(object): self.delete_resources( release_name, name, action_type, labels, namespace) except Exception: - LOG.debug("PRE: Could not delete anything, please check yaml") + LOG.warn("PRE: Could not delete anything, please check yaml") raise ex.PreUpdateJobDeleteException(name, namespace) try: @@ -230,7 +249,7 @@ class Tiller(object): self.k8s.create_job_action(name, action_type) continue except Exception: - LOG.debug("PRE: Could not create anything, please check yaml") + LOG.warn("PRE: Could not create anything, please check yaml") raise ex.PreUpdateJobCreateException(name, namespace) def _post_update_actions(self, actions, namespace): @@ -244,7 +263,7 @@ class Tiller(object): self.k8s.create_job_action(name, action_type) continue except Exception: - LOG.debug("POST: Could not create anything, please check yaml") + LOG.warn("POST: Could not create anything, please check yaml") raise ex.PreUpdateJobCreateException(name, namespace) def list_charts(self): @@ -264,6 +283,7 @@ class Tiller(object): latest_release.info.status.code))) except IndexError: continue + LOG.debug('List of Helm Charts from Latest Releases: %s', charts) return charts def update_release(self, chart, release, namespace, @@ -280,8 +300,9 @@ class Tiller(object): rel_timeout = self.timeout if not timeout else timeout - LOG.debug("wait: %s", wait) - LOG.debug("timeout: %s", timeout) + LOG.debug('Helm update release%s: wait=%s, timeout=%s', + (' (dry run)' if dry_run else ''), + wait, timeout) if values is None: values = Config(raw='') @@ -323,7 +344,9 @@ class Tiller(object): rel_timeout = self.timeout if not timeout else timeout - LOG.info("Wait: %s, Timeout: %s", wait, timeout) + LOG.debug('Helm install release%s: wait=%s, timeout=%s', + (' (dry run)' if dry_run else ''), + wait, timeout) if values is None: values = Config(raw='') @@ -356,9 +379,10 @@ class Tiller(object): :param cleanup - removes testing pod created :returns - results of test pod - ''' + LOG.debug("Helm test release %s, timeout=%s", release, timeout) + try: stub = ReleaseServiceStub(self.channel) @@ -391,16 +415,20 @@ class Tiller(object): ''' :param release - name of release to test :param version - version of release status - ''' + LOG.debug('Helm getting release status for release=%s, version=%s', + release, version) try: stub = ReleaseServiceStub(self.channel) status_request = GetReleaseStatusRequest( name=release, version=version) + LOG.debug('GetReleaseStatusRequest= %s', status_request) - return stub.GetReleaseStatus( + release_status = stub.GetReleaseStatus( status_request, self.timeout, metadata=self.metadata) + LOG.debug('GetReleaseStatus= %s', release_status) + return release_status except Exception: raise ex.GetReleaseStatusException(release, version) @@ -409,42 +437,51 @@ class Tiller(object): ''' :param release - name of release to test :param version - version of release status - ''' + LOG.debug('Helm getting release content for release=%s, version=%s', + release, version) try: stub = ReleaseServiceStub(self.channel) status_request = GetReleaseContentRequest( name=release, version=version) + LOG.debug('GetReleaseContentRequest= %s', status_request) - return stub.GetReleaseContent( + release_content = stub.GetReleaseContent( status_request, self.timeout, metadata=self.metadata) + LOG.debug('GetReleaseContent= %s', release_content) + return release_content except Exception: raise ex.GetReleaseContentException(release, version) def tiller_version(self): ''' - :returns - tiller version + :returns - Tiller version ''' try: stub = ReleaseServiceStub(self.channel) release_request = GetVersionRequest() + LOG.debug('Getting Tiller version, with timeout=%s', self.timeout) tiller_version = stub.GetVersion( release_request, self.timeout, metadata=self.metadata) + LOG.debug('Got Tiller version response: %s', tiller_version) - return getattr(tiller_version.Version, 'sem_ver', None) + tiller_version = getattr(tiller_version.Version, 'sem_ver', None) + LOG.debug('Got Tiller version %s', tiller_version) + return tiller_version except Exception: + LOG.debug('Failed to get Tiller version') raise ex.TillerVersionException() def uninstall_release(self, release, disable_hooks=False, purge=True): ''' - :params - release - helm chart release name + :params - release - Helm chart release name :params - purge - deep delete of chart - deletes a helm chart from tiller + deletes a Helm chart from Tiller ''' # build release install request diff --git a/armada/tests/unit/api/test_tiller_controller.py b/armada/tests/unit/api/test_tiller_controller.py index f3c25703..bb5ee46e 100644 --- a/armada/tests/unit/api/test_tiller_controller.py +++ b/armada/tests/unit/api/test_tiller_controller.py @@ -33,11 +33,11 @@ class TillerControllerTest(base.BaseControllerTest): self.policy.set_rules(rules) mock_tiller.return_value.tiller_status.return_value = 'fake_status' - mock_tiller.return_value.tiller_version.return_value = 'fake_verson' + mock_tiller.return_value.tiller_version.return_value = 'fake_version' result = self.app.simulate_get('/api/v1.0/status') expected = { - 'tiller': {'version': 'fake_verson', 'state': 'fake_status'} + 'tiller': {'version': 'fake_version', 'state': 'fake_status'} } self.assertEqual(expected, result.json) @@ -53,7 +53,7 @@ class TillerControllerTest(base.BaseControllerTest): self.policy.set_rules(rules) mock_tiller.return_value.tiller_status.return_value = 'fake_status' - mock_tiller.return_value.tiller_version.return_value = 'fake_verson' + mock_tiller.return_value.tiller_version.return_value = 'fake_version' result = self.app.simulate_get('/api/v1.0/status', params_csv=False, @@ -61,7 +61,7 @@ class TillerControllerTest(base.BaseControllerTest): 'tiller_port': '98765', 'tiller_namespace': 'fake_ns'}) expected = { - 'tiller': {'version': 'fake_verson', 'state': 'fake_status'} + 'tiller': {'version': 'fake_version', 'state': 'fake_status'} } self.assertEqual(expected, result.json) diff --git a/armada/tests/unit/common/test_session.py b/armada/tests/unit/common/test_session.py index 1bd8a5ef..4b849c72 100644 --- a/armada/tests/unit/common/test_session.py +++ b/armada/tests/unit/common/test_session.py @@ -12,7 +12,6 @@ # See the License for the specific language governing permissions and # limitations under the License. -# import mock import testtools import responses diff --git a/armada/utils/validate.py b/armada/utils/validate.py index c7604a09..e05b20e2 100644 --- a/armada/utils/validate.py +++ b/armada/utils/validate.py @@ -56,7 +56,7 @@ def _validate_armada_manifest(manifest): :class:`armada.handlers.manifest.Manifest`. This will do business logic validation after the input - files have be syntatically validated via jsonschema. + files have be syntactically validated via jsonschema. :param dict manifest: The manifest to validate. @@ -97,7 +97,7 @@ def _validate_armada_manifest(manifest): def validate_armada_manifests(documents): - """Validate each Aramada manifest found in the document set. + """Validate each Armada manifest found in the document set. :param documents: List of Armada documents to validate :type documents: :func: `list[dict]`. @@ -170,7 +170,7 @@ def validate_armada_document(document): def validate_armada_documents(documents): """Validates multiple Armada documents. - :param documents: List of Armada maanifests to validate. + :param documents: List of Armada manifests to validate. :type documents: :func:`list[dict]`. :returns: A tuple of bool, list[dict] where the first value is whether diff --git a/requirements.txt b/requirements.txt index 47794127..3fffd1d4 100644 --- a/requirements.txt +++ b/requirements.txt @@ -1,6 +1,6 @@ gitpython -grpcio==1.6.0rc1 -grpcio-tools==1.6.0rc1 +grpcio>=1.6.0 +grpcio-tools>=1.6.0 keystoneauth1==2.21.0 keystonemiddleware==4.9.1 kubernetes>=1.0.0