diff options
12 files changed, 156 insertions, 80 deletions
diff --git a/components/model-catalog/proto-definition/proto/CommandExecutor.proto b/components/model-catalog/proto-definition/proto/CommandExecutor.proto index ac6921965..bad6a01c3 100644 --- a/components/model-catalog/proto-definition/proto/CommandExecutor.proto +++ b/components/model-catalog/proto-definition/proto/CommandExecutor.proto @@ -17,6 +17,8 @@ message ExecutionInput { google.protobuf.Struct properties = 6; // Request Time Stamp google.protobuf.Timestamp timestamp = 7; + string subRequestId = 8; + string originatorId = 9; } message PrepareEnvInput { @@ -28,6 +30,8 @@ message PrepareEnvInput { int32 timeOut = 5; google.protobuf.Struct properties = 6; google.protobuf.Timestamp timestamp = 7; + string subRequestId = 8; + string originatorId = 9; } message Identifiers { diff --git a/ms/blueprintsprocessor/application/src/main/resources/logback.xml b/ms/blueprintsprocessor/application/src/main/resources/logback.xml index aceea4327..b905b7da4 100644 --- a/ms/blueprintsprocessor/application/src/main/resources/logback.xml +++ b/ms/blueprintsprocessor/application/src/main/resources/logback.xml @@ -1,5 +1,6 @@ <!-- ~ Copyright © 2017-2018 AT&T Intellectual Property. + ~ Modifications Copyright © 2020 Bell Canada. ~ ~ Licensed under the Apache License, Version 2.0 (the "License"); ~ you may not use this file except in compliance with the License. @@ -18,7 +19,7 @@ <property name="localPattern" value="%d{HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n"/> <property name="defaultPattern" - value="%date{ISO8601,UTC}|%X{RequestID}|%X{InvocationID}|%thread|%X{ServiceName}|%X{ClientIPAddress}|%logger{50}| %msg%n"/> + value="%date{ISO8601,UTC}|%X{RequestID}|%X{SubRequestID}|%X{OriginatorID}|%X{InvocationID}|%thread|%X{ServiceName}|%X{ClientIPAddress}|%logger{50}|%msg%n"/> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>${defaultPattern}</pattern> diff --git a/ms/blueprintsprocessor/functions/python-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/python/executor/ComponentRemotePythonExecutor.kt b/ms/blueprintsprocessor/functions/python-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/python/executor/ComponentRemotePythonExecutor.kt index 9ed13c146..b06da3810 100644 --- a/ms/blueprintsprocessor/functions/python-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/python/executor/ComponentRemotePythonExecutor.kt +++ b/ms/blueprintsprocessor/functions/python-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/python/executor/ComponentRemotePythonExecutor.kt @@ -1,5 +1,6 @@ /* * Copyright © 2019 IBM. + * Modifications Copyright © 2020 Bell Canada. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -145,7 +146,9 @@ open class ComponentRemotePythonExecutor( // If packages are defined, then install in remote server if (packages != null) { val prepareEnvInput = PrepareRemoteEnvInput( + originatorId = executionServiceInput.commonHeader.originatorId, requestId = processId, + subRequestId = executionServiceInput.commonHeader.subRequestId, remoteIdentifier = RemoteIdentifier( blueprintName = blueprintName, blueprintVersion = blueprintVersion), @@ -195,7 +198,9 @@ open class ComponentRemotePythonExecutor( val properties = dynamicProperties?.returnNullIfMissing()?.rootFieldsToMap() ?: hashMapOf() val remoteExecutionInput = RemoteScriptExecutionInput( + originatorId = executionServiceInput.commonHeader.originatorId, requestId = processId, + subRequestId = executionServiceInput.commonHeader.subRequestId, remoteIdentifier = RemoteIdentifier(blueprintName = blueprintName, blueprintVersion = blueprintVersion), command = scriptCommand, properties = properties, diff --git a/ms/blueprintsprocessor/modules/blueprints/blueprint-core/src/main/kotlin/org/onap/ccsdk/cds/controllerblueprints/core/BluePrintConstants.kt b/ms/blueprintsprocessor/modules/blueprints/blueprint-core/src/main/kotlin/org/onap/ccsdk/cds/controllerblueprints/core/BluePrintConstants.kt index 76662d4ee..8290167cd 100644 --- a/ms/blueprintsprocessor/modules/blueprints/blueprint-core/src/main/kotlin/org/onap/ccsdk/cds/controllerblueprints/core/BluePrintConstants.kt +++ b/ms/blueprintsprocessor/modules/blueprints/blueprint-core/src/main/kotlin/org/onap/ccsdk/cds/controllerblueprints/core/BluePrintConstants.kt @@ -1,6 +1,6 @@ /* * Copyright © 2017-2018 AT&T Intellectual Property. - * Modifications Copyright © 2018 - 2019 IBM, Bell Canada + * Modifications Copyright © 2018 - 2020 IBM, Bell Canada * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -34,6 +34,8 @@ object BluePrintConstants { const val RESPONSE_HEADER_LATEST_VERSION: String = "X-LatestVersion" const val ONAP_REQUEST_ID = "X-ONAP-RequestID" + const val ONAP_SUBREQUEST_ID = "X-ONAP-SubRequestID" + const val ONAP_ORIGINATOR_ID = "X-ONAP-OriginatorID" const val ONAP_INVOCATION_ID = "X-ONAP-InvocationID" const val ONAP_PARTNER_NAME = "X-ONAP-PartnerName" diff --git a/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/api/data/BlueprintRemoteProcessorData.kt b/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/api/data/BlueprintRemoteProcessorData.kt index 628b65ea4..6baf261fb 100644 --- a/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/api/data/BlueprintRemoteProcessorData.kt +++ b/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/api/data/BlueprintRemoteProcessorData.kt @@ -1,5 +1,6 @@ /* * Copyright © 2019 IBM. + * Modifications Copyright © 2020 Bell Canada. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -29,7 +30,9 @@ data class RemoteIdentifier( ) data class RemoteScriptExecutionInput( + var originatorId: String, var requestId: String, + var subRequestId: String, var correlationId: String? = null, var remoteIdentifier: RemoteIdentifier? = null, var command: String, @@ -46,7 +49,9 @@ data class RemoteScriptExecutionOutput( ) data class PrepareRemoteEnvInput( + var originatorId: String, var requestId: String, + var subRequestId: String, var correlationId: String? = null, var remoteIdentifier: RemoteIdentifier? = null, var packages: JsonNode, diff --git a/ms/blueprintsprocessor/modules/commons/rest-lib/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/rest/service/RestLoggerService.kt b/ms/blueprintsprocessor/modules/commons/rest-lib/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/rest/service/RestLoggerService.kt index 846a94a09..dc45e3545 100644 --- a/ms/blueprintsprocessor/modules/commons/rest-lib/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/rest/service/RestLoggerService.kt +++ b/ms/blueprintsprocessor/modules/commons/rest-lib/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/rest/service/RestLoggerService.kt @@ -1,5 +1,6 @@ /* * Copyright © 2018-2019 AT&T Intellectual Property. + * Modifications Copyright © 2020 Bell Canada. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -30,8 +31,10 @@ import kotlinx.coroutines.withContext import org.apache.http.message.BasicHeader import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintConstants import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintConstants.ONAP_INVOCATION_ID +import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintConstants.ONAP_ORIGINATOR_ID import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintConstants.ONAP_PARTNER_NAME import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintConstants.ONAP_REQUEST_ID +import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintConstants.ONAP_SUBREQUEST_ID import org.onap.ccsdk.cds.controllerblueprints.core.MDCContext import org.onap.ccsdk.cds.controllerblueprints.core.defaultToEmpty import org.onap.ccsdk.cds.controllerblueprints.core.defaultToUUID @@ -68,10 +71,14 @@ class RestLoggerService { val localhost = InetAddress.getLocalHost() val headers = request.headers val requestID = headers.getFirst(ONAP_REQUEST_ID).defaultToUUID() + val subrequestID = headers.getFirst(ONAP_SUBREQUEST_ID).defaultToEmpty() + val originatorID = headers.getFirst(ONAP_ORIGINATOR_ID).defaultToEmpty() val invocationID = headers.getFirst(ONAP_INVOCATION_ID).defaultToUUID() val partnerName = headers.getFirst(ONAP_PARTNER_NAME).defaultToEmpty() MDC.put("InvokeTimestamp", ZonedDateTime.now(ZoneOffset.UTC).format(DateTimeFormatter.ISO_INSTANT)) MDC.put("RequestID", requestID) + MDC.put("SubRequestID", subrequestID) + MDC.put("OriginatorID", originatorID) MDC.put("InvocationID", invocationID) MDC.put("PartnerName", partnerName) MDC.put("ClientIPAddress", request.remoteAddress?.address?.hostAddress.defaultToEmpty()) @@ -86,6 +93,8 @@ class RestLoggerService { val reqHeaders = request.headers val resHeaders = response.headers resHeaders[ONAP_REQUEST_ID] = MDC.get("RequestID") + resHeaders[ONAP_SUBREQUEST_ID] = MDC.get("SubRequestID") + resHeaders[ONAP_ORIGINATOR_ID] = MDC.get("OriginatorID") resHeaders[ONAP_INVOCATION_ID] = MDC.get("InvocationID") resHeaders[ONAP_PARTNER_NAME] = BluePrintConstants.APP_NAME } catch (e: Exception) { diff --git a/ms/blueprintsprocessor/modules/services/execution-service/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/services/execution/RemoteScriptExecutionService.kt b/ms/blueprintsprocessor/modules/services/execution-service/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/services/execution/RemoteScriptExecutionService.kt index 861a95507..35f156707 100644 --- a/ms/blueprintsprocessor/modules/services/execution-service/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/services/execution/RemoteScriptExecutionService.kt +++ b/ms/blueprintsprocessor/modules/services/execution-service/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/services/execution/RemoteScriptExecutionService.kt @@ -1,5 +1,6 @@ /* * Copyright © 2019 IBM. + * Modifications Copyright © 2020 Bell Canada. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -129,6 +130,8 @@ class GrpcRemoteScriptExecutionService(private val bluePrintGrpcLibPropertyServi return PrepareEnvInput.newBuilder() .setIdentifiers(this.remoteIdentifier!!.asGrpcData()) .setRequestId(this.requestId) + .setSubRequestId(this.subRequestId) + .setOriginatorId(this.originatorId) .setCorrelationId(correlationId) .setTimeOut(this.timeOut.toInt()) .addAllPackages(packageList) @@ -140,6 +143,8 @@ class GrpcRemoteScriptExecutionService(private val bluePrintGrpcLibPropertyServi val correlationId = this.correlationId ?: this.requestId return ExecutionInput.newBuilder() .setRequestId(this.requestId) + .setSubRequestId(this.subRequestId) + .setOriginatorId(this.originatorId) .setCorrelationId(correlationId) .setIdentifiers(this.remoteIdentifier!!.asGrpcData()) .setCommand(this.command) diff --git a/ms/command-executor/src/main/python/command_executor_handler.py b/ms/command-executor/src/main/python/command_executor_handler.py index 06004b551..b7d3eec0d 100644 --- a/ms/command-executor/src/main/python/command_executor_handler.py +++ b/ms/command-executor/src/main/python/command_executor_handler.py @@ -1,5 +1,5 @@ # -# Copyright (C) 2019 Bell Canada. +# Copyright (C) 2019 - 2020 Bell Canada. # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. @@ -38,6 +38,7 @@ class CommandExecutorHandler(): self.execution_timeout = utils.get_blueprint_timeout(request) self.venv_home = '/opt/app/onap/blueprints/deploy/' + self.blueprint_id self.installed = self.venv_home + '/.installed' + self.extra = utils.getExtraLogData(request) def is_installed(self): return os.path.exists(self.installed) @@ -48,13 +49,13 @@ class CommandExecutorHandler(): create_venv_status = self.create_venv() if not create_venv_status[utils.CDS_IS_SUCCESSFUL_KEY]: err_msg = "ERROR: failed to prepare environment for request {} due to error in creating virtual Python env. Original error {}".format(self.blueprint_id, create_venv_status[utils.ERR_MSG_KEY]) - self.logger.error(err_msg) + self.logger.error(err_msg, extra=self.extra) return utils.build_ret_data(False, error=err_msg) activate_venv_status = self.activate_venv() if not activate_venv_status[utils.CDS_IS_SUCCESSFUL_KEY]: err_msg = "ERROR: failed to prepare environment for request {} due Python venv_activation. Original error {}".format(self.blueprint_id, activate_venv_status[utils.ERR_MSG_KEY]) - self.logger.error(err_msg) + self.logger.error(err_msg, extra=self.extra) return utils.build_ret_data(False, error=err_msg) try: with open(self.installed, "w+") as f: @@ -68,7 +69,7 @@ class CommandExecutorHandler(): return utils.build_ret_data(False, results_log=results_log, error=err_msg) except Exception as ex: err_msg = "ERROR: failed to prepare environment for request {} during installing packages. Exception: {}".format(self.blueprint_id, ex) - self.logger.error(err_msg) + self.logger.error(err_msg, extra=self.extra) return utils.build_ret_data(False, error=err_msg) else: try: @@ -119,10 +120,14 @@ class CommandExecutorHandler(): ### RequestID request_id = request.requestId ### Sub-requestID - subrequest_id = request.correlationId - request_id_map = {'CDS_REQUEST_ID':request_id, 'CDS_CORRELATION_ID':subrequest_id} + subrequest_id = request.subRequestId + ### OriginatorID + originator_id = request.originatorId + ### CorrelationID + correlation_id = request.correlationId + request_id_map = {'CDS_REQUEST_ID':request_id, 'CDS_SUBREQUEST_ID':subrequest_id, 'CDS_ORIGINATOR_ID': originator_id, 'CDS_CORRELATION_ID': correlation_id} updated_env = { **os.environ, **request_id_map } - self.logger.info("Running blueprint {} with timeout: {}".format(self.blueprint_id, self.execution_timeout)) + self.logger.info("Running blueprint {} with timeout: {}".format(self.blueprint_id, self.execution_timeout), extra=self.extra) with tempfile.TemporaryFile(mode="w+") as tmp: try: @@ -130,11 +135,11 @@ class CommandExecutorHandler(): env=updated_env, timeout=self.execution_timeout) except TimeoutExpired: timeout_err_msg = "Running command {} failed due to timeout of {} seconds.".format(self.blueprint_id, self.execution_timeout) - self.logger.error(timeout_err_msg) - utils.parse_cmd_exec_output(tmp, self.logger, result, results_log) + self.logger.error(timeout_err_msg, extra=self.extra) + utils.parse_cmd_exec_output(tmp, self.logger, result, results_log, self.extra) return utils.build_ret_data(False, results_log=results_log, error=timeout_err_msg) - utils.parse_cmd_exec_output(tmp, self.logger, result, results_log) + utils.parse_cmd_exec_output(tmp, self.logger, result, results_log, self.extra) rc = completed_subprocess.returncode except Exception as e: err_msg = "{} - Failed to execute command. Error: {}".format(self.blueprint_id, e) @@ -143,7 +148,7 @@ class CommandExecutorHandler(): # deactivate_venv(blueprint_id) #Since return code is only used to check if it's zero (success), we can just return success flag instead. - self.logger.debug("python return_code : {}".format(rc)) + self.logger.debug("python return_code : {}".format(rc), extra=self.extra) is_execution_successful = rc == 0 result.update(utils.build_ret_data(is_execution_successful, results_log=results_log)) return result @@ -168,7 +173,7 @@ class CommandExecutorHandler(): def install_python_packages(self, package, results): self.logger.info( - "{} - Install Python package({}) in Python Virtual Environment".format(self.blueprint_id, package)) + "{} - Install Python package({}) in Python Virtual Environment".format(self.blueprint_id, package), extra=self.extra) if REQUIREMENTS_TXT == package: command = ["pip", "install", "-r", self.venv_home + "/Environments/" + REQUIREMENTS_TXT] @@ -181,21 +186,21 @@ class CommandExecutorHandler(): env = dict(os.environ) if "https_proxy" in os.environ: env['https_proxy'] = os.environ['https_proxy'] - self.logger.info("Using https_proxy: ", env['https_proxy']) + self.logger.info("Using https_proxy: ", env['https_proxy'], extra=self.extra) try: results.append(subprocess.run(command, check=True, stdout=PIPE, stderr=PIPE, env=env).stdout.decode()) results.append("\n") - self.logger.info("install_python_packages {} succeeded".format(package)) + self.logger.info("install_python_packages {} succeeded".format(package), extra=self.extra) return True except CalledProcessError as e: results.append(e.stderr.decode()) - self.logger.error("install_python_packages {} failed".format(package)) + self.logger.error("install_python_packages {} failed".format(package), extra=self.extra) return False def install_ansible_packages(self, package, results): self.logger.info( - "{} - Install Ansible Role package({}) in Python Virtual Environment".format(self.blueprint_id, package)) + "{} - Install Ansible Role package({}) in Python Virtual Environment".format(self.blueprint_id, package), extra=self.extra) command = ["ansible-galaxy", "install", package, "-p", self.venv_home + "/Scripts/ansible/roles"] env = dict(os.environ) @@ -216,23 +221,23 @@ class CommandExecutorHandler(): # 'err_msg' indicates an error occurred. The presence of err_msg may not be fatal, # status should be set to False for fatal errors. def create_venv(self): - self.logger.info("{} - Create Python Virtual Environment".format(self.blueprint_id)) + self.logger.info("{} - Create Python Virtual Environment".format(self.blueprint_id), extra=self.extra) try: bin_dir = self.venv_home + "/bin" # venv doesn't populate the activate_this.py script, hence we use from virtualenv venv.create(self.venv_home, with_pip=True, system_site_packages=True) virtualenv.writefile(os.path.join(bin_dir, "activate_this.py"), virtualenv.ACTIVATE_THIS) - self.logger.info("{} - Creation of Python Virtual Environment finished.".format(self.blueprint_id)) + self.logger.info("{} - Creation of Python Virtual Environment finished.".format(self.blueprint_id), extra=self.extra) return utils.build_ret_data(True) except Exception as err: err_msg = "{} - Failed to provision Python Virtual Environment. Error: {}".format(self.blueprint_id, err) - self.logger.info(err_msg) + self.logger.info(err_msg, extra=self.extra) return utils.build_ret_data(False, error=err_msg) # return map cds_is_successful and err_msg. Status is True on success. err_msg may existence doesn't necessarily indicate fatal condition. # the 'status' should be set to False to indicate error. def activate_venv(self): - self.logger.info("{} - Activate Python Virtual Environment".format(self.blueprint_id)) + self.logger.info("{} - Activate Python Virtual Environment".format(self.blueprint_id), extra=self.extra) # Fix: The python generated activate_this.py script concatenates the env bin dir to PATH on every call # eventually this process PATH variable was so big (128Kb) that no child process could be spawn @@ -244,20 +249,20 @@ class CommandExecutorHandler(): with open(path) as activate_this_script: exec (activate_this_script.read(), {'__file__': path}) exec (fixpathenvvar) - self.logger.info("Running with PATH : {}".format(os.environ['PATH'])) + self.logger.info("Running with PATH : {}".format(os.environ['PATH']), extra=self.extra) return utils.build_ret_data(True) except Exception as err: err_msg ="{} - Failed to activate Python Virtual Environment. Error: {}".format(self.blueprint_id, err) - self.logger.info( err_msg) + self.logger.info( err_msg, extra=self.extra) return utils.build_ret_data(False, error=err_msg) def deactivate_venv(self): - self.logger.info("{} - Deactivate Python Virtual Environment".format(self.blueprint_id)) + self.logger.info("{} - Deactivate Python Virtual Environment".format(self.blueprint_id), extra=self.extra) command = ["deactivate"] try: subprocess.run(command, check=True) except Exception as err: self.logger.info( - "{} - Failed to deactivate Python Virtual Environment. Error: {}".format(self.blueprint_id, err)) + "{} - Failed to deactivate Python Virtual Environment. Error: {}".format(self.blueprint_id, err), extra=self.extra) diff --git a/ms/command-executor/src/main/python/command_executor_server.py b/ms/command-executor/src/main/python/command_executor_server.py index aa666ee24..175ddc7d3 100644 --- a/ms/command-executor/src/main/python/command_executor_server.py +++ b/ms/command-executor/src/main/python/command_executor_server.py @@ -1,7 +1,7 @@ #!/usr/bin/python # -# Copyright (C) 2019 Bell Canada. +# Copyright (C) 2019 - 2020 Bell Canada. # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. @@ -29,32 +29,34 @@ class CommandExecutorServer(CommandExecutor_pb2_grpc.CommandExecutorServiceServi def prepareEnv(self, request, context): blueprint_id = utils.get_blueprint_id(request) - self.logger.info("{} - Received prepareEnv request".format(blueprint_id)) - self.logger.info(request) + extra = utils.getExtraLogData(request) + self.logger.info("{} - Received prepareEnv request".format(blueprint_id), extra=extra) + self.logger.info(request, extra=extra) handler = CommandExecutorHandler(request) prepare_env_response = handler.prepare_env(request) if prepare_env_response[utils.CDS_IS_SUCCESSFUL_KEY]: - self.logger.info("{} - Package installation logs {}".format(blueprint_id, prepare_env_response[utils.RESULTS_LOG_KEY])) + self.logger.info("{} - Package installation logs {}".format(blueprint_id, prepare_env_response[utils.RESULTS_LOG_KEY]), extra=extra) else: - self.logger.info("{} - Failed to prepare python environment. {}".format(blueprint_id, prepare_env_response[utils.ERR_MSG_KEY])) - self.logger.info("Prepare Env Response returned : %s" % prepare_env_response) + self.logger.info("{} - Failed to prepare python environment. {}".format(blueprint_id, prepare_env_response[utils.ERR_MSG_KEY]), extra=extra) + self.logger.info("Prepare Env Response returned : %s" % prepare_env_response, extra=extra) return utils.build_grpc_response(request.requestId, prepare_env_response) def executeCommand(self, request, context): blueprint_id = utils.get_blueprint_id(request) - self.logger.info("{} - Received executeCommand request".format(blueprint_id)) + extra = utils.getExtraLogData(request) + self.logger.info("{} - Received executeCommand request".format(blueprint_id), extra=extra) if os.environ.get('CE_DEBUG','false') == "true": - self.logger.info(request) + self.logger.info(request, extra=extra) handler = CommandExecutorHandler(request) exec_cmd_response = handler.execute_command(request) if exec_cmd_response[utils.CDS_IS_SUCCESSFUL_KEY]: - self.logger.info("{} - Execution finished successfully.".format(blueprint_id)) + self.logger.info("{} - Execution finished successfully.".format(blueprint_id), extra=extra) else: - self.logger.info("{} - Failed to executeCommand. {}".format(blueprint_id, exec_cmd_response[utils.RESULTS_LOG_KEY])) + self.logger.info("{} - Failed to executeCommand. {}".format(blueprint_id, exec_cmd_response[utils.RESULTS_LOG_KEY]), extra=extra) ret = utils.build_grpc_response(request.requestId, exec_cmd_response) - self.logger.info("Payload returned : {}".format(exec_cmd_response)) + self.logger.info("Payload returned : {}".format(exec_cmd_response), extra=extra) return ret
\ No newline at end of file diff --git a/ms/command-executor/src/main/python/proto/CommandExecutor_pb2.py b/ms/command-executor/src/main/python/proto/CommandExecutor_pb2.py index 4edfc6cd5..5ee04927e 100644 --- a/ms/command-executor/src/main/python/proto/CommandExecutor_pb2.py +++ b/ms/command-executor/src/main/python/proto/CommandExecutor_pb2.py @@ -23,7 +23,7 @@ DESCRIPTOR = _descriptor.FileDescriptor( package='org.onap.ccsdk.cds.controllerblueprints.command.api', syntax='proto3', serialized_options=_b('P\001'), - serialized_pb=_b('\n\x15\x43ommandExecutor.proto\x12\x33org.onap.ccsdk.cds.controllerblueprints.command.api\x1a\x1cgoogle/protobuf/struct.proto\x1a\x1fgoogle/protobuf/timestamp.proto\"\x8f\x02\n\x0e\x45xecutionInput\x12\x11\n\trequestId\x18\x01 \x01(\t\x12\x15\n\rcorrelationId\x18\x02 \x01(\t\x12U\n\x0bidentifiers\x18\x03 \x01(\x0b\x32@.org.onap.ccsdk.cds.controllerblueprints.command.api.Identifiers\x12\x0f\n\x07\x63ommand\x18\x04 \x01(\t\x12\x0f\n\x07timeOut\x18\x05 \x01(\x05\x12+\n\nproperties\x18\x06 \x01(\x0b\x32\x17.google.protobuf.Struct\x12-\n\ttimestamp\x18\x07 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\"\xd0\x02\n\x0fPrepareEnvInput\x12U\n\x0bidentifiers\x18\x01 \x01(\x0b\x32@.org.onap.ccsdk.cds.controllerblueprints.command.api.Identifiers\x12\x11\n\trequestId\x18\x02 \x01(\t\x12\x15\n\rcorrelationId\x18\x03 \x01(\t\x12O\n\x08packages\x18\x04 \x03(\x0b\x32=.org.onap.ccsdk.cds.controllerblueprints.command.api.Packages\x12\x0f\n\x07timeOut\x18\x05 \x01(\x05\x12+\n\nproperties\x18\x06 \x01(\x0b\x32\x17.google.protobuf.Struct\x12-\n\ttimestamp\x18\x07 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\">\n\x0bIdentifiers\x12\x15\n\rblueprintName\x18\x01 \x01(\t\x12\x18\n\x10\x62lueprintVersion\x18\x02 \x01(\t\"\xcb\x01\n\x0f\x45xecutionOutput\x12\x11\n\trequestId\x18\x01 \x01(\t\x12\x10\n\x08response\x18\x02 \x03(\t\x12S\n\x06status\x18\x03 \x01(\x0e\x32\x43.org.onap.ccsdk.cds.controllerblueprints.command.api.ResponseStatus\x12-\n\ttimestamp\x18\x04 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\x12\x0f\n\x07payload\x18\x05 \x01(\t\"k\n\x08Packages\x12N\n\x04type\x18\x01 \x01(\x0e\x32@.org.onap.ccsdk.cds.controllerblueprints.command.api.PackageType\x12\x0f\n\x07package\x18\x02 \x03(\t**\n\x0eResponseStatus\x12\x0b\n\x07SUCCESS\x10\x00\x12\x0b\n\x07\x46\x41ILURE\x10\x01*9\n\x0bPackageType\x12\x07\n\x03pip\x10\x00\x12\x12\n\x0e\x61nsible_galaxy\x10\x01\x12\r\n\tutilities\x10\x02\x32\xd1\x02\n\x16\x43ommandExecutorService\x12\x98\x01\n\nprepareEnv\x12\x44.org.onap.ccsdk.cds.controllerblueprints.command.api.PrepareEnvInput\x1a\x44.org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionOutput\x12\x9b\x01\n\x0e\x65xecuteCommand\x12\x43.org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionInput\x1a\x44.org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionOutputB\x02P\x01\x62\x06proto3') + serialized_pb=_b('\n\x15\x43ommandExecutor.proto\x12\x33org.onap.ccsdk.cds.controllerblueprints.command.api\x1a\x1cgoogle/protobuf/struct.proto\x1a\x1fgoogle/protobuf/timestamp.proto\"\xbb\x02\n\x0e\x45xecutionInput\x12\x11\n\trequestId\x18\x01 \x01(\t\x12\x15\n\rcorrelationId\x18\x02 \x01(\t\x12U\n\x0bidentifiers\x18\x03 \x01(\x0b\x32@.org.onap.ccsdk.cds.controllerblueprints.command.api.Identifiers\x12\x0f\n\x07\x63ommand\x18\x04 \x01(\t\x12\x0f\n\x07timeOut\x18\x05 \x01(\x05\x12+\n\nproperties\x18\x06 \x01(\x0b\x32\x17.google.protobuf.Struct\x12-\n\ttimestamp\x18\x07 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\x12\x14\n\x0csubRequestId\x18\x08 \x01(\t\x12\x14\n\x0coriginatorId\x18\t \x01(\t\"\xfc\x02\n\x0fPrepareEnvInput\x12U\n\x0bidentifiers\x18\x01 \x01(\x0b\x32@.org.onap.ccsdk.cds.controllerblueprints.command.api.Identifiers\x12\x11\n\trequestId\x18\x02 \x01(\t\x12\x15\n\rcorrelationId\x18\x03 \x01(\t\x12O\n\x08packages\x18\x04 \x03(\x0b\x32=.org.onap.ccsdk.cds.controllerblueprints.command.api.Packages\x12\x0f\n\x07timeOut\x18\x05 \x01(\x05\x12+\n\nproperties\x18\x06 \x01(\x0b\x32\x17.google.protobuf.Struct\x12-\n\ttimestamp\x18\x07 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\x12\x14\n\x0csubRequestId\x18\x08 \x01(\t\x12\x14\n\x0coriginatorId\x18\t \x01(\t\">\n\x0bIdentifiers\x12\x15\n\rblueprintName\x18\x01 \x01(\t\x12\x18\n\x10\x62lueprintVersion\x18\x02 \x01(\t\"\xcb\x01\n\x0f\x45xecutionOutput\x12\x11\n\trequestId\x18\x01 \x01(\t\x12\x10\n\x08response\x18\x02 \x03(\t\x12S\n\x06status\x18\x03 \x01(\x0e\x32\x43.org.onap.ccsdk.cds.controllerblueprints.command.api.ResponseStatus\x12-\n\ttimestamp\x18\x04 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\x12\x0f\n\x07payload\x18\x05 \x01(\t\"k\n\x08Packages\x12N\n\x04type\x18\x01 \x01(\x0e\x32@.org.onap.ccsdk.cds.controllerblueprints.command.api.PackageType\x12\x0f\n\x07package\x18\x02 \x03(\t**\n\x0eResponseStatus\x12\x0b\n\x07SUCCESS\x10\x00\x12\x0b\n\x07\x46\x41ILURE\x10\x01*9\n\x0bPackageType\x12\x07\n\x03pip\x10\x00\x12\x12\n\x0e\x61nsible_galaxy\x10\x01\x12\r\n\tutilities\x10\x02\x32\xd1\x02\n\x16\x43ommandExecutorService\x12\x98\x01\n\nprepareEnv\x12\x44.org.onap.ccsdk.cds.controllerblueprints.command.api.PrepareEnvInput\x1a\x44.org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionOutput\x12\x9b\x01\n\x0e\x65xecuteCommand\x12\x43.org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionInput\x1a\x44.org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionOutputB\x02P\x01\x62\x06proto3') , dependencies=[google_dot_protobuf_dot_struct__pb2.DESCRIPTOR,google_dot_protobuf_dot_timestamp__pb2.DESCRIPTOR,]) @@ -44,8 +44,8 @@ _RESPONSESTATUS = _descriptor.EnumDescriptor( ], containing_type=None, serialized_options=None, - serialized_start=1133, - serialized_end=1175, + serialized_start=1221, + serialized_end=1263, ) _sym_db.RegisterEnumDescriptor(_RESPONSESTATUS) @@ -71,8 +71,8 @@ _PACKAGETYPE = _descriptor.EnumDescriptor( ], containing_type=None, serialized_options=None, - serialized_start=1177, - serialized_end=1234, + serialized_start=1265, + serialized_end=1322, ) _sym_db.RegisterEnumDescriptor(_PACKAGETYPE) @@ -141,6 +141,20 @@ _EXECUTIONINPUT = _descriptor.Descriptor( message_type=None, enum_type=None, containing_type=None, is_extension=False, extension_scope=None, serialized_options=None, file=DESCRIPTOR), + _descriptor.FieldDescriptor( + name='subRequestId', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionInput.subRequestId', index=7, + number=8, type=9, cpp_type=9, label=1, + has_default_value=False, default_value=_b("").decode('utf-8'), + message_type=None, enum_type=None, containing_type=None, + is_extension=False, extension_scope=None, + serialized_options=None, file=DESCRIPTOR), + _descriptor.FieldDescriptor( + name='originatorId', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionInput.originatorId', index=8, + number=9, type=9, cpp_type=9, label=1, + has_default_value=False, default_value=_b("").decode('utf-8'), + message_type=None, enum_type=None, containing_type=None, + is_extension=False, extension_scope=None, + serialized_options=None, file=DESCRIPTOR), ], extensions=[ ], @@ -154,7 +168,7 @@ _EXECUTIONINPUT = _descriptor.Descriptor( oneofs=[ ], serialized_start=142, - serialized_end=413, + serialized_end=457, ) @@ -214,6 +228,20 @@ _PREPAREENVINPUT = _descriptor.Descriptor( message_type=None, enum_type=None, containing_type=None, is_extension=False, extension_scope=None, serialized_options=None, file=DESCRIPTOR), + _descriptor.FieldDescriptor( + name='subRequestId', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.PrepareEnvInput.subRequestId', index=7, + number=8, type=9, cpp_type=9, label=1, + has_default_value=False, default_value=_b("").decode('utf-8'), + message_type=None, enum_type=None, containing_type=None, + is_extension=False, extension_scope=None, + serialized_options=None, file=DESCRIPTOR), + _descriptor.FieldDescriptor( + name='originatorId', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.PrepareEnvInput.originatorId', index=8, + number=9, type=9, cpp_type=9, label=1, + has_default_value=False, default_value=_b("").decode('utf-8'), + message_type=None, enum_type=None, containing_type=None, + is_extension=False, extension_scope=None, + serialized_options=None, file=DESCRIPTOR), ], extensions=[ ], @@ -226,8 +254,8 @@ _PREPAREENVINPUT = _descriptor.Descriptor( extension_ranges=[], oneofs=[ ], - serialized_start=416, - serialized_end=752, + serialized_start=460, + serialized_end=840, ) @@ -264,8 +292,8 @@ _IDENTIFIERS = _descriptor.Descriptor( extension_ranges=[], oneofs=[ ], - serialized_start=754, - serialized_end=816, + serialized_start=842, + serialized_end=904, ) @@ -323,8 +351,8 @@ _EXECUTIONOUTPUT = _descriptor.Descriptor( extension_ranges=[], oneofs=[ ], - serialized_start=819, - serialized_end=1022, + serialized_start=907, + serialized_end=1110, ) @@ -361,8 +389,8 @@ _PACKAGES = _descriptor.Descriptor( extension_ranges=[], oneofs=[ ], - serialized_start=1024, - serialized_end=1131, + serialized_start=1112, + serialized_end=1219, ) _EXECUTIONINPUT.fields_by_name['identifiers'].message_type = _IDENTIFIERS @@ -384,39 +412,39 @@ DESCRIPTOR.enum_types_by_name['ResponseStatus'] = _RESPONSESTATUS DESCRIPTOR.enum_types_by_name['PackageType'] = _PACKAGETYPE _sym_db.RegisterFileDescriptor(DESCRIPTOR) -ExecutionInput = _reflection.GeneratedProtocolMessageType('ExecutionInput', (_message.Message,), { - 'DESCRIPTOR' : _EXECUTIONINPUT, - '__module__' : 'CommandExecutor_pb2' +ExecutionInput = _reflection.GeneratedProtocolMessageType('ExecutionInput', (_message.Message,), dict( + DESCRIPTOR = _EXECUTIONINPUT, + __module__ = 'CommandExecutor_pb2' # @@protoc_insertion_point(class_scope:org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionInput) - }) + )) _sym_db.RegisterMessage(ExecutionInput) -PrepareEnvInput = _reflection.GeneratedProtocolMessageType('PrepareEnvInput', (_message.Message,), { - 'DESCRIPTOR' : _PREPAREENVINPUT, - '__module__' : 'CommandExecutor_pb2' +PrepareEnvInput = _reflection.GeneratedProtocolMessageType('PrepareEnvInput', (_message.Message,), dict( + DESCRIPTOR = _PREPAREENVINPUT, + __module__ = 'CommandExecutor_pb2' # @@protoc_insertion_point(class_scope:org.onap.ccsdk.cds.controllerblueprints.command.api.PrepareEnvInput) - }) + )) _sym_db.RegisterMessage(PrepareEnvInput) -Identifiers = _reflection.GeneratedProtocolMessageType('Identifiers', (_message.Message,), { - 'DESCRIPTOR' : _IDENTIFIERS, - '__module__' : 'CommandExecutor_pb2' +Identifiers = _reflection.GeneratedProtocolMessageType('Identifiers', (_message.Message,), dict( + DESCRIPTOR = _IDENTIFIERS, + __module__ = 'CommandExecutor_pb2' # @@protoc_insertion_point(class_scope:org.onap.ccsdk.cds.controllerblueprints.command.api.Identifiers) - }) + )) _sym_db.RegisterMessage(Identifiers) -ExecutionOutput = _reflection.GeneratedProtocolMessageType('ExecutionOutput', (_message.Message,), { - 'DESCRIPTOR' : _EXECUTIONOUTPUT, - '__module__' : 'CommandExecutor_pb2' +ExecutionOutput = _reflection.GeneratedProtocolMessageType('ExecutionOutput', (_message.Message,), dict( + DESCRIPTOR = _EXECUTIONOUTPUT, + __module__ = 'CommandExecutor_pb2' # @@protoc_insertion_point(class_scope:org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionOutput) - }) + )) _sym_db.RegisterMessage(ExecutionOutput) -Packages = _reflection.GeneratedProtocolMessageType('Packages', (_message.Message,), { - 'DESCRIPTOR' : _PACKAGES, - '__module__' : 'CommandExecutor_pb2' +Packages = _reflection.GeneratedProtocolMessageType('Packages', (_message.Message,), dict( + DESCRIPTOR = _PACKAGES, + __module__ = 'CommandExecutor_pb2' # @@protoc_insertion_point(class_scope:org.onap.ccsdk.cds.controllerblueprints.command.api.Packages) - }) + )) _sym_db.RegisterMessage(Packages) @@ -428,8 +456,8 @@ _COMMANDEXECUTORSERVICE = _descriptor.ServiceDescriptor( file=DESCRIPTOR, index=0, serialized_options=None, - serialized_start=1237, - serialized_end=1574, + serialized_start=1325, + serialized_end=1662, methods=[ _descriptor.MethodDescriptor( name='prepareEnv', @@ -454,4 +482,4 @@ _sym_db.RegisterServiceDescriptor(_COMMANDEXECUTORSERVICE) DESCRIPTOR.services_by_name['CommandExecutorService'] = _COMMANDEXECUTORSERVICE -# @@protoc_insertion_point(module_scope) +# @@protoc_insertion_point(module_scope)
\ No newline at end of file diff --git a/ms/command-executor/src/main/python/server.py b/ms/command-executor/src/main/python/server.py index c136bd8cc..d506d096b 100644 --- a/ms/command-executor/src/main/python/server.py +++ b/ms/command-executor/src/main/python/server.py @@ -2,7 +2,7 @@ #!/usr/bin/python # -# Copyright (C) 2019 Bell Canada. +# Copyright (C) 2019 - 2020 Bell Canada. # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. @@ -21,6 +21,7 @@ from concurrent import futures import logging import time import sys +import utils import grpc @@ -52,7 +53,7 @@ def serve(): server.add_insecure_port('[::]:' + port) server.start() - logger.info("Command Executor Server started on %s" % port) + logger.info("Command Executor Server started on %s" % port, extra=utils.getExtraLogData()) try: while True: @@ -62,7 +63,7 @@ def serve(): if __name__ == '__main__': - logging_formater = '%(asctime)s - %(name)s - %(threadName)s - %(levelname)s - %(message)s' + logging_formater = '%(asctime)s|%(request_id)s|%(subrequest_id)s|%(originator_id)s|%(threadName)s|%(name)s|%(levelname)s|%(message)s' logging.basicConfig(filename='/opt/app/onap/logs/application.log', level=logging.DEBUG, format=logging_formater) console = logging.StreamHandler() diff --git a/ms/command-executor/src/main/python/utils.py b/ms/command-executor/src/main/python/utils.py index 54c5ceafa..c624a3d2e 100644 --- a/ms/command-executor/src/main/python/utils.py +++ b/ms/command-executor/src/main/python/utils.py @@ -1,5 +1,5 @@ # -# Copyright (C) 2019 Bell Canada. +# Copyright (C) 2019 - 2020 Bell Canada. # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. @@ -79,7 +79,7 @@ def truncate_execution_output(execution_output): # Read temp file 'outputfile' into results_log and split out the returned payload into payload_result -def parse_cmd_exec_output(outputfile, logger, payload_result, results_log): +def parse_cmd_exec_output(outputfile, logger, payload_result, results_log, extra): payload_section = [] is_payload_section = False outputfile.seek(0) @@ -98,8 +98,17 @@ def parse_cmd_exec_output(outputfile, logger, payload_result, results_log): for part in msg.get_payload(): payload_result.update(json.loads(part.get_payload())) if output and not is_payload_section: - logger.info(output.strip()) + logger.info(output.strip(), extra=extra) results_log.append(output.strip()) else: payload_section.append(output.strip()) +def getExtraLogData(request=None): + extra = {'request_id' : '', 'subrequest_id' : '', 'originator_id': ''} + if request is not None: + extra = { + 'request_id' : request.requestId, + 'subrequest_id' : request.subRequestId, + 'originator_id': request.originatorId + } + return extra
\ No newline at end of file |