CCSDK-3531 improve cmd-exec returned err msg

Issue-ID: CCSDK-3531

Improve end-user CBA's Python scripts ability to return
error messages on failues.
See JIRA story for examples: https://jira.onap.org/browse/CCSDK-3531

adds functions send_response_err_msg(err_message)
and send_response_err_msg_and_exit(ret_err_msg, code=1)

Signed-off-by: Oleg Mitsura <oleg.mitsura@amdocs.com>
Change-Id: Ideda64dd108f987c3c4515c70daf9f7b6d2b1f2f

6 files changed, 222 insertions, 111 deletions

diff --git a/ms/command-executor/src/main/python/cds_utils/payload_coder.py b/ms/command-executor/src/main/python/cds_utils/payload_coder.py
index 951262172..eccd419d4 100644
--- a/ms/command-executor/src/main/python/cds_utils/payload_coder.py
+++ b/ms/command-executor/src/main/python/cds_utils/payload_coder.py
@@ -2,6 +2,8 @@ import json
 from email.mime import multipart

 from email.mime import text

 import email.parser

+import sys

+

 

 def send_response_data_payload(json_payload):

     m = multipart.MIMEMultipart("form-data")

@@ -10,4 +12,17 @@ def send_response_data_payload(json_payload):
     m.attach(data)

     print("BEGIN_EXTRA_PAYLOAD")

     print(m.as_string())

-    print("END_EXTRA_PAYLOAD")
\ No newline at end of file
+    print("END_EXTRA_PAYLOAD")

+

+

+def send_response_err_msg(ret_err_msg):

+    print("BEGIN_EXTRA_RET_ERR_MSG")

+    print(ret_err_msg)

+    print("END_EXTRA_RET_ERR_MSG")

+

+

+def send_response_err_msg_and_exit(ret_err_msg, code=1):

+    print("BEGIN_EXTRA_RET_ERR_MSG")

+    print(ret_err_msg)

+    print("END_EXTRA_RET_ERR_MSG")

+    sys.exit(code)

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 b6d644cba..d90feab31 100644
--- a/ms/command-executor/src/main/python/command_executor_handler.py
+++ b/ms/command-executor/src/main/python/command_executor_handler.py
@@ -22,7 +22,6 @@ import os
 import sys
 import re
 import subprocess
-import virtualenv
 import venv
 import utils
 import proto.CommandExecutor_pb2 as CommandExecutor_pb2
@@ -49,13 +48,13 @@ class CommandExecutorHandler():
         self.uuid = utils.get_blueprint_uuid(request)
         self.request_id = utils.get_blueprint_requestid(request)
         self.sub_request_id = utils.get_blueprint_subRequestId(request)
-        self.blueprint_name_version = utils.blueprint_name_version(request) # for legacy support
+        self.blueprint_name_version = utils.blueprint_name_version(request) #for legacy SR7 support
         self.blueprint_name_version_uuid = utils.blueprint_name_version_uuid(request)
         self.execution_timeout = utils.get_blueprint_timeout(request)
         # onap/blueprints/deploy will be ephemeral now
+        self.blueprint_dir = self.BLUEPRINTS_DEPLOY_DIR + self.blueprint_name_version_uuid
         # if the command matches “/opt/app/onap/blueprints/deploy/$cba_name/$cba_version/stuff_that_is_not_cba_uuid/”
         # then prepend the $cba_uuid before “stuff_that_is_not_cba_uuid”
-        self.blueprint_dir = self.BLUEPRINTS_DEPLOY_DIR + self.blueprint_name_version_uuid
         self.blueprint_tosca_meta_file = self.blueprint_dir + '/' + self.TOSCA_META_FILE
         self.extra = utils.getExtraLogData(request)
         self.installed = self.blueprint_dir + '/.installed'
@@ -120,7 +119,9 @@ class CommandExecutorHandler():
         start_time = time.time()
         archive_type = request.archiveType
         compressed_cba_stream = io.BytesIO(request.binData)
-        self.logger.info("uploadBlueprint request {}".format(request), extra=self.extra)
+        ### request_copy = request.pop("binData") # Do not show binData of the uploaded compressed CBA in the log
+        ### self.logger.info("uploadBlueprint request\n{}".format(request_copy), extra=self.extra)
+        self.logger.info("uploadBlueprint request\n{}".format(request), extra=self.extra)
         if not self.is_valid_archive_type(archive_type):
             self.prometheus_counter.labels(self.PROMETHEUS_METRICS_UPLOAD_CBA_LABEL, self.blueprint_name, self.blueprint_version, None).inc()
             return utils.build_grpc_blueprint_upload_response(self.request_id, self.sub_request_id, False, ["Archive type {} is not valid.".format(archive_type)])
@@ -177,12 +178,14 @@ class CommandExecutorHandler():
                 self.prometheus_counter.labels(self.PROMETHEUS_METRICS_PREP_ENV_LABEL, self.blueprint_name, self.blueprint_version, None).inc()
                 return self.err_exit("ERROR: failed to prepare environment for request {} due to error in creating virtual Python env. Original error {}".format(self.blueprint_name_version_uuid, create_venv_status[utils.ERR_MSG_KEY]))
 
-            activate_venv_status = self.activate_venv()
-            if not activate_venv_status[utils.CDS_IS_SUCCESSFUL_KEY]:
+            # Upgrade pip - venv comes with PIP 18.1, which is too old.
+            if not self.upgrade_pip(results_log):
                 self.prometheus_counter.labels(self.PROMETHEUS_METRICS_PREP_ENV_LABEL, self.blueprint_name, self.blueprint_version, None).inc()
-                return self.err_exit("ERROR: failed to prepare environment for request {} due Python venv_activation. Original error {}".format(self.blueprint_name_version_uuid, activate_venv_status[utils.ERR_MSG_KEY]))
+                err_msg = "ERROR: failed to prepare environment for request {} due to error in upgrading pip.".format(self.blueprint_name_version_uuid)
+                return utils.build_ret_data(False, results_log=results_log, error=err_msg)
 
             try:
+                # NOTE: pip or ansible selection is done later inside 'install_packages'
                 with open(self.installed, "w+") as f:
                     if not self.install_packages(request, CommandExecutor_pb2.pip, f, results_log):
                         self.prometheus_counter.labels(self.PROMETHEUS_METRICS_PREP_ENV_LABEL, self.blueprint_name, self.blueprint_version, None).inc()
@@ -201,6 +204,7 @@ class CommandExecutorHandler():
                 return utils.build_ret_data(False, error=err_msg)
         else:
             try:
+                self.logger.info(".installed file was found for request {}".format(self.blueprint_name_version_uuid), extra=self.extra)
                 with open(self.installed, "r") as f:
                     results_log.append(f.read())
             except Exception as ex:
@@ -218,6 +222,7 @@ class CommandExecutorHandler():
         results_log = []
         # encoded payload returned by the process
         result = {}
+        script_err_msg = []
 
         self.logger.info("execute_command request {}".format(request), extra=self.extra)
         # workaround for when packages are not specified, we may not want to go through the install step
@@ -231,11 +236,7 @@ class CommandExecutorHandler():
                     self.prometheus_counter.labels(self.PROMETHEUS_METRICS_EXEC_COMMAND_LABEL, self.blueprint_name, self.blueprint_version, request.command).inc()
                     err_msg = "{} - Failed to execute command during venv creation. Original error: {}".format(self.blueprint_name_version_uuid, create_venv_status[utils.ERR_MSG_KEY])
                     return utils.build_ret_data(False, error=err_msg)
-            activate_response = self.activate_venv()
-            if not activate_response[utils.CDS_IS_SUCCESSFUL_KEY]:
-                orig_error = activate_response[utils.ERR_MSG_KEY]
-                err_msg = "{} - Failed to execute command during environment activation. Original error: {}".format(self.blueprint_name_version_uuid, orig_error)
-                return utils.build_ret_data(False, error=err_msg)
+
             # touch blueprint dir to indicate this CBA was used recently
             os.utime(self.blueprint_dir)
 
@@ -246,39 +247,40 @@ class CommandExecutorHandler():
             if request.properties is not None and len(request.properties) > 0:
                 properties = " " + re.escape(MessageToJson(request.properties)).replace('"','\\"')
 
-            # compatibility hack
+            # SR7/SR10 compatibility hack
             # check if the path for the request.command does not contain UUID, then add it after cba_name/cba_version path.
             updated_request_command = request.command
             if self.blueprint_name_version in updated_request_command and self.blueprint_name_version_uuid not in updated_request_command:
                 updated_request_command = updated_request_command.replace(self.blueprint_name_version, self.blueprint_name_version_uuid)
 
-            ### TODO: replace with os.environ['VIRTUAL_ENV']?
             if "ansible-playbook" in updated_request_command:
                 cmd = cmd + "; " + updated_request_command + " -e 'ansible_python_interpreter=" + self.blueprint_dir + "/bin/python'"
             else:
                 cmd = cmd + "; " + updated_request_command + properties
 
             ### extract the original header request into sys-env variables
-            ### OriginatorID
+            # OriginatorID
             originator_id = request.originatorId
-            ### CorrelationID
+            # CorrelationID
             correlation_id = request.correlationId
             request_id_map = {'CDS_REQUEST_ID':self.request_id, 'CDS_SUBREQUEST_ID':self.sub_request_id, 'CDS_ORIGINATOR_ID': originator_id, 'CDS_CORRELATION_ID': correlation_id}
             updated_env =  { **os.environ, **request_id_map }
+            # Prepare PATH and VENV_HOME
+            updated_env['PATH'] = self.blueprint_dir + "/bin/:" + os.environ['PATH']
+            updated_env['VIRTUAL_ENV'] = self.blueprint_dir
             self.logger.info("Running blueprint {} with timeout: {}".format(self.blueprint_name_version_uuid, self.execution_timeout), extra=self.extra)
-
             with tempfile.TemporaryFile(mode="w+") as tmp:
                 try:
                     completed_subprocess = subprocess.run(cmd, stdout=tmp, stderr=subprocess.STDOUT, shell=True,
-                                                env=updated_env, timeout=self.execution_timeout)
-                except TimeoutExpired:
+                                                          env=updated_env, timeout=self.execution_timeout)
+                except TimeoutExpired as timeout_ex:
                     self.prometheus_counter.labels(self.PROMETHEUS_METRICS_EXEC_COMMAND_LABEL, self.blueprint_name, self.blueprint_version, request.command).inc()
                     timeout_err_msg = "Running command {} failed due to timeout of {} seconds.".format(self.blueprint_name_version_uuid, self.execution_timeout)
                     self.logger.error(timeout_err_msg, extra=self.extra)
-                    utils.parse_cmd_exec_output(tmp, self.logger, result, results_log, self.extra)
+                    # In the time-out case, we will never get CBA's script err msg string.
+                    utils.parse_cmd_exec_output(outputfile=tmp, logger=self.logger, payload_result=result, err_msg_result=script_err_msg, results_log=results_log, extra=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, self.extra)
+                utils.parse_cmd_exec_output(outputfile=tmp, logger=self.logger, payload_result=result, err_msg_result=script_err_msg, results_log=results_log, extra=self.extra)
                 rc = completed_subprocess.returncode
         except Exception as e:
             self.prometheus_counter.labels(self.PROMETHEUS_METRICS_EXEC_COMMAND_LABEL, self.blueprint_name, self.blueprint_version, request.command).inc()
@@ -286,10 +288,11 @@ class CommandExecutorHandler():
             result.update(utils.build_ret_data(False, results_log=results_log, error=err_msg))
             return result
 
-        # deactivate_venv(blueprint_id)
-        #Since return code is only used to check if it's zero (success), we can just return success flag instead.
+        # Since return code is only used to check if it's zero (success), we can just return success flag instead.
         is_execution_successful = rc == 0
-        result.update(utils.build_ret_data(is_execution_successful, results_log=results_log))
+        # Propagate error message in case rc is not 0
+        ret_err_msg = None if is_execution_successful or not script_err_msg else script_err_msg
+        result.update(utils.build_ret_data(is_execution_successful, results_log=results_log, error=ret_err_msg))
         self.prometheus_histogram.labels(self.PROMETHEUS_METRICS_EXEC_COMMAND_LABEL, self.blueprint_name, self.blueprint_version, request.command).observe(time.time() - start_time)
 
         return result
@@ -315,18 +318,41 @@ class CommandExecutorHandler():
                         return False
         return True
 
+    def upgrade_pip(self, results):
+        self.logger.info("{} - updating PIP (venv supplied pip is too old...)".format(self.blueprint_name_version_uuid), extra=self.extra)
+        full_path_to_pip = self.blueprint_dir + "/bin/pip"
+        command = [full_path_to_pip,"install","--upgrade","pip"]
+        env = dict(os.environ)
+        if "https_proxy" in os.environ:
+            env['https_proxy'] = os.environ['https_proxy']
+            self.logger.info("Using https_proxy: {}".format(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("upgrade_pip succeeded", extra=self.extra)
+            return True
+        except CalledProcessError as e:
+            results.append(e.stderr.decode())
+            self.logger.error("upgrade_pip failed", extra=self.extra)
+            return False
+
     def install_python_packages(self, package, results):
-        self.logger.info(
-            "{} - Install Python package({}) in Python Virtual Environment".format(self.blueprint_name_version_uuid, package), extra=self.extra)
+        self.logger.info( "{} - Install Python package({}) in Python Virtual Environment".format(self.blueprint_name_version_uuid, package), extra=self.extra)
+        pip_install_user_flag = 'PIP_INSTALL_USER_FLAG' in os.environ
+
+        if pip_install_user_flag:
+            self.logger.info("Note: PIP_INSTALL_USER_FLAG is set, 'pip install' will use '--user' flag.", extra=self.extra)
 
         if REQUIREMENTS_TXT == package:
-            command = ["pip", "install", "--user", "-r", self.blueprint_dir + "/Environments/" + REQUIREMENTS_TXT]
+            full_path_to_pip = self.blueprint_dir + "/bin/pip"
+            full_path_to_requirements_txt = self.blueprint_dir + "/Environments/" + REQUIREMENTS_TXT
+            command = [full_path_to_pip, "install", "--user", "-r", full_path_to_requirements_txt] if pip_install_user_flag else [full_path_to_pip, "install", "-r", full_path_to_requirements_txt]
         elif package == 'UTILITY':
             py_ver_maj = sys.version_info.major
             py_ver_min = sys.version_info.minor
             command = ["cp", "-r", "./cds_utils", "{}/lib/python{}.{}/site-packages/".format(self.blueprint_dir, py_ver_maj,py_ver_min)]
         else:
-            command = ["pip", "install", "--user", package]
+            command = ["pip", "install", "--user", package] if pip_install_user_flag else ["pip", "install", package]
 
         env = dict(os.environ)
         if "https_proxy" in os.environ:
@@ -343,8 +369,7 @@ class CommandExecutorHandler():
             return False
 
     def install_ansible_packages(self, package, results):
-        self.logger.info(
-            "{} - Install Ansible Role package({}) in Python Virtual Environment".format(self.blueprint_name_version_uuid, package), extra=self.extra)
+        self.logger.info( "{} - Install Ansible Role package({}) in Python Virtual Environment".format(self.blueprint_name_version_uuid, package), extra=self.extra)
         command = ["ansible-galaxy", "install", package, "-p", self.blueprint_dir + "/Scripts/ansible/roles"]
 
         env = dict(os.environ)
@@ -367,45 +392,14 @@ class CommandExecutorHandler():
         self.logger.info("{} - Create Python Virtual Environment".format(self.blueprint_name_version_uuid), extra=self.extra)
         try:
             bin_dir = self.blueprint_dir + "/bin"
-            # venv doesn't populate the activate_this.py script, hence we use from virtualenv
-            venv.create(self.blueprint_dir, with_pip=True, system_site_packages=True)
-            virtualenv.writefile(os.path.join(bin_dir, "activate_this.py"), virtualenv.ACTIVATE_THIS)
+            # check if CREATE_VENV_DISABLE_SITE_PACKAGES is set
+            venv_system_site_packages_disabled = 'CREATE_VENV_DISABLE_SITE_PACKAGES' in os.environ
+            if (venv_system_site_packages_disabled):
+                self.logger.info("Note: CREATE_VENV_DISABLE_SITE_PACKAGES env var is set - environment creation will have site packages disabled.", extra=self.extra)
+            venv.create(self.blueprint_dir, with_pip=True, system_site_packages=not venv_system_site_packages_disabled)
             self.logger.info("{} - Creation of Python Virtual Environment finished.".format(self.blueprint_name_version_uuid), 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_name_version_uuid, err)
             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_name_version_uuid), 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
-        #      This script will remove all duplicates; while keeping the order of the PATH folders
-        fixpathenvvar = "os.environ['PATH']=os.pathsep.join(list(dict.fromkeys(os.environ['PATH'].split(':'))))"
-
-        path = "%s/bin/activate_this.py" % self.blueprint_dir
-        try:
-            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']), 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_name_version_uuid, err)
-            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_name_version_uuid), 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_name_version_uuid, 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 057214306..7a9a4fde3 100644
--- a/ms/command-executor/src/main/python/command_executor_server.py
+++ b/ms/command-executor/src/main/python/command_executor_server.py
@@ -62,7 +62,8 @@ class CommandExecutorServer(CommandExecutor_pb2_grpc.CommandExecutorServiceServi
         if exec_cmd_response[utils.CDS_IS_SUCCESSFUL_KEY]:
             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]), extra=extra)
+            script_err_msg = "Error returned: {}".format(exec_cmd_response[utils.ERR_MSG_KEY]) if utils.ERR_MSG_KEY in exec_cmd_response else ""
+            self.logger.info("{} - Failed to executeCommand. {} {}" .format(blueprint_id, exec_cmd_response[utils.RESULTS_LOG_KEY], script_err_msg), extra=extra)
 
         ret = utils.build_grpc_response(request.requestId, exec_cmd_response)
         self.logger.info("Payload returned : {}".format(exec_cmd_response), extra=extra)
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 3e9773c6c..7516b7830 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\"\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\"\xa9\x02\n\x14UploadBlueprintInput\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\x14\n\x0csubRequestId\x18\x03 \x01(\t\x12\x14\n\x0coriginatorId\x18\x04 \x01(\t\x12\x15\n\rcorrelationId\x18\x05 \x01(\t\x12\x0f\n\x07timeOut\x18\x06 \x01(\x05\x12\x13\n\x0b\x61rchiveType\x18\x07 \x01(\t\x12-\n\ttimestamp\x18\x08 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\x12\x0f\n\x07\x62inData\x18\t \x01(\x0c\"\xd5\x01\n\x15UploadBlueprintOutput\x12\x11\n\trequestId\x18\x01 \x01(\t\x12\x14\n\x0csubRequestId\x18\x02 \x01(\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\"\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\"U\n\x0bIdentifiers\x12\x15\n\rblueprintName\x18\x01 \x01(\t\x12\x18\n\x10\x62lueprintVersion\x18\x02 \x01(\t\x12\x15\n\rblueprintUUID\x18\x03 \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\xfc\x03\n\x16\x43ommandExecutorService\x12\xa8\x01\n\x0fuploadBlueprint\x12I.org.onap.ccsdk.cds.controllerblueprints.command.api.UploadBlueprintInput\x1aJ.org.onap.ccsdk.cds.controllerblueprints.command.api.UploadBlueprintOutput\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\"\xd9\x01\n\x19\x42lueprintValidationOutput\x12\x11\n\trequestId\x18\x01 \x01(\t\x12\x14\n\x0csubRequestId\x18\x02 \x01(\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\x07\x63\x62\x61UUID\x18\x05 \x01(\t\"\xa9\x02\n\x14UploadBlueprintInput\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\x14\n\x0csubRequestId\x18\x03 \x01(\t\x12\x14\n\x0coriginatorId\x18\x04 \x01(\t\x12\x15\n\rcorrelationId\x18\x05 \x01(\t\x12\x0f\n\x07timeOut\x18\x06 \x01(\x05\x12\x13\n\x0b\x61rchiveType\x18\x07 \x01(\t\x12-\n\ttimestamp\x18\x08 \x01(\x0b\x32\x1a.google.protobuf.Timestamp\x12\x0f\n\x07\x62inData\x18\t \x01(\x0c\"\xd5\x01\n\x15UploadBlueprintOutput\x12\x11\n\trequestId\x18\x01 \x01(\t\x12\x14\n\x0csubRequestId\x18\x02 \x01(\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\"\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\"U\n\x0bIdentifiers\x12\x15\n\rblueprintName\x18\x01 \x01(\t\x12\x18\n\x10\x62lueprintVersion\x18\x02 \x01(\t\x12\x15\n\rblueprintUUID\x18\x03 \x01(\t\"\xdb\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\x12\x0e\n\x06\x65rrMsg\x18\x06 \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\xfc\x03\n\x16\x43ommandExecutorService\x12\xa8\x01\n\x0fuploadBlueprint\x12I.org.onap.ccsdk.cds.controllerblueprints.command.api.UploadBlueprintInput\x1aJ.org.onap.ccsdk.cds.controllerblueprints.command.api.UploadBlueprintOutput\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=1760,
-  serialized_end=1802,
+  serialized_start=1996,
+  serialized_end=2038,
 )
 _sym_db.RegisterEnumDescriptor(_RESPONSESTATUS)
 
@@ -71,8 +71,8 @@ _PACKAGETYPE = _descriptor.EnumDescriptor(
   ],
   containing_type=None,
   serialized_options=None,
-  serialized_start=1804,
-  serialized_end=1861,
+  serialized_start=2040,
+  serialized_end=2097,
 )
 _sym_db.RegisterEnumDescriptor(_PACKAGETYPE)
 
@@ -172,6 +172,65 @@ _EXECUTIONINPUT = _descriptor.Descriptor(
 )
 
 
+_BLUEPRINTVALIDATIONOUTPUT = _descriptor.Descriptor(
+  name='BlueprintValidationOutput',
+  full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.BlueprintValidationOutput',
+  filename=None,
+  file=DESCRIPTOR,
+  containing_type=None,
+  fields=[
+    _descriptor.FieldDescriptor(
+      name='requestId', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.BlueprintValidationOutput.requestId', index=0,
+      number=1, 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='subRequestId', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.BlueprintValidationOutput.subRequestId', index=1,
+      number=2, 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='status', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.BlueprintValidationOutput.status', index=2,
+      number=3, type=14, cpp_type=8, label=1,
+      has_default_value=False, default_value=0,
+      message_type=None, enum_type=None, containing_type=None,
+      is_extension=False, extension_scope=None,
+      serialized_options=None, file=DESCRIPTOR),
+    _descriptor.FieldDescriptor(
+      name='timestamp', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.BlueprintValidationOutput.timestamp', index=3,
+      number=4, type=11, cpp_type=10, label=1,
+      has_default_value=False, default_value=None,
+      message_type=None, enum_type=None, containing_type=None,
+      is_extension=False, extension_scope=None,
+      serialized_options=None, file=DESCRIPTOR),
+    _descriptor.FieldDescriptor(
+      name='cbaUUID', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.BlueprintValidationOutput.cbaUUID', index=4,
+      number=5, 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=[
+  ],
+  nested_types=[],
+  enum_types=[
+  ],
+  serialized_options=None,
+  is_extendable=False,
+  syntax='proto3',
+  extension_ranges=[],
+  oneofs=[
+  ],
+  serialized_start=460,
+  serialized_end=677,
+)
+
+
 _UPLOADBLUEPRINTINPUT = _descriptor.Descriptor(
   name='UploadBlueprintInput',
   full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.UploadBlueprintInput',
@@ -254,8 +313,8 @@ _UPLOADBLUEPRINTINPUT = _descriptor.Descriptor(
   extension_ranges=[],
   oneofs=[
   ],
-  serialized_start=460,
-  serialized_end=757,
+  serialized_start=680,
+  serialized_end=977,
 )
 
 
@@ -313,8 +372,8 @@ _UPLOADBLUEPRINTOUTPUT = _descriptor.Descriptor(
   extension_ranges=[],
   oneofs=[
   ],
-  serialized_start=760,
-  serialized_end=973,
+  serialized_start=980,
+  serialized_end=1193,
 )
 
 
@@ -400,8 +459,8 @@ _PREPAREENVINPUT = _descriptor.Descriptor(
   extension_ranges=[],
   oneofs=[
   ],
-  serialized_start=976,
-  serialized_end=1356,
+  serialized_start=1196,
+  serialized_end=1576,
 )
 
 
@@ -445,8 +504,8 @@ _IDENTIFIERS = _descriptor.Descriptor(
   extension_ranges=[],
   oneofs=[
   ],
-  serialized_start=1358,
-  serialized_end=1443,
+  serialized_start=1578,
+  serialized_end=1663,
 )
 
 
@@ -492,6 +551,13 @@ _EXECUTIONOUTPUT = _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='errMsg', full_name='org.onap.ccsdk.cds.controllerblueprints.command.api.ExecutionOutput.errMsg', index=5,
+      number=6, 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=[
   ],
@@ -504,8 +570,8 @@ _EXECUTIONOUTPUT = _descriptor.Descriptor(
   extension_ranges=[],
   oneofs=[
   ],
-  serialized_start=1446,
-  serialized_end=1649,
+  serialized_start=1666,
+  serialized_end=1885,
 )
 
 
@@ -542,13 +608,15 @@ _PACKAGES = _descriptor.Descriptor(
   extension_ranges=[],
   oneofs=[
   ],
-  serialized_start=1651,
-  serialized_end=1758,
+  serialized_start=1887,
+  serialized_end=1994,
 )
 
 _EXECUTIONINPUT.fields_by_name['identifiers'].message_type = _IDENTIFIERS
 _EXECUTIONINPUT.fields_by_name['properties'].message_type = google_dot_protobuf_dot_struct__pb2._STRUCT
 _EXECUTIONINPUT.fields_by_name['timestamp'].message_type = google_dot_protobuf_dot_timestamp__pb2._TIMESTAMP
+_BLUEPRINTVALIDATIONOUTPUT.fields_by_name['status'].enum_type = _RESPONSESTATUS
+_BLUEPRINTVALIDATIONOUTPUT.fields_by_name['timestamp'].message_type = google_dot_protobuf_dot_timestamp__pb2._TIMESTAMP
 _UPLOADBLUEPRINTINPUT.fields_by_name['identifiers'].message_type = _IDENTIFIERS
 _UPLOADBLUEPRINTINPUT.fields_by_name['timestamp'].message_type = google_dot_protobuf_dot_timestamp__pb2._TIMESTAMP
 _UPLOADBLUEPRINTOUTPUT.fields_by_name['status'].enum_type = _RESPONSESTATUS
@@ -561,6 +629,7 @@ _EXECUTIONOUTPUT.fields_by_name['status'].enum_type = _RESPONSESTATUS
 _EXECUTIONOUTPUT.fields_by_name['timestamp'].message_type = google_dot_protobuf_dot_timestamp__pb2._TIMESTAMP
 _PACKAGES.fields_by_name['type'].enum_type = _PACKAGETYPE
 DESCRIPTOR.message_types_by_name['ExecutionInput'] = _EXECUTIONINPUT
+DESCRIPTOR.message_types_by_name['BlueprintValidationOutput'] = _BLUEPRINTVALIDATIONOUTPUT
 DESCRIPTOR.message_types_by_name['UploadBlueprintInput'] = _UPLOADBLUEPRINTINPUT
 DESCRIPTOR.message_types_by_name['UploadBlueprintOutput'] = _UPLOADBLUEPRINTOUTPUT
 DESCRIPTOR.message_types_by_name['PrepareEnvInput'] = _PREPAREENVINPUT
@@ -578,6 +647,13 @@ ExecutionInput = _reflection.GeneratedProtocolMessageType('ExecutionInput', (_me
   ))
 _sym_db.RegisterMessage(ExecutionInput)
 
+BlueprintValidationOutput = _reflection.GeneratedProtocolMessageType('BlueprintValidationOutput', (_message.Message,), dict(
+  DESCRIPTOR = _BLUEPRINTVALIDATIONOUTPUT,
+  __module__ = 'CommandExecutor_pb2'
+  # @@protoc_insertion_point(class_scope:org.onap.ccsdk.cds.controllerblueprints.command.api.BlueprintValidationOutput)
+  ))
+_sym_db.RegisterMessage(BlueprintValidationOutput)
+
 UploadBlueprintInput = _reflection.GeneratedProtocolMessageType('UploadBlueprintInput', (_message.Message,), dict(
   DESCRIPTOR = _UPLOADBLUEPRINTINPUT,
   __module__ = 'CommandExecutor_pb2'
@@ -629,8 +705,8 @@ _COMMANDEXECUTORSERVICE = _descriptor.ServiceDescriptor(
   file=DESCRIPTOR,
   index=0,
   serialized_options=None,
-  serialized_start=1864,
-  serialized_end=2372,
+  serialized_start=2100,
+  serialized_end=2608,
   methods=[
   _descriptor.MethodDescriptor(
     name='uploadBlueprint',
diff --git a/ms/command-executor/src/main/python/server.py b/ms/command-executor/src/main/python/server.py
index d506d096b..f2f239660 100644
--- a/ms/command-executor/src/main/python/server.py
+++ b/ms/command-executor/src/main/python/server.py
@@ -64,11 +64,5 @@ def serve():
 
 if __name__ == '__main__':
     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()
-    console.setLevel(logging.INFO)
-    formatter = logging.Formatter(logging_formater)
-    console.setFormatter(formatter)
-    logging.getLogger('').addHandler(console)
+    logging.basicConfig(level=logging.INFO, format=logging_formater)
     serve()
diff --git a/ms/command-executor/src/main/python/utils.py b/ms/command-executor/src/main/python/utils.py
index d59f8cc47..a4b6b2c79 100644
--- a/ms/command-executor/src/main/python/utils.py
+++ b/ms/command-executor/src/main/python/utils.py
@@ -30,7 +30,7 @@ RESPONSE_MAX_SIZE = 4 * 1024 * 1024  # 4Mb
 def blueprint_name_version_uuid(request):
   return get_blueprint_name(request) + '/' + get_blueprint_version(request) + '/' + get_blueprint_uuid(request)
 
-# return blueprint_name and version part of the path (needed for legacy cmd-exec support
+# return blueprint_name and version part of the path (needed for legacy SR7 cmd-exec support
 def blueprint_name_version(request):
   return get_blueprint_name(request) + '/' + get_blueprint_version(request)
 
@@ -62,7 +62,11 @@ def build_grpc_response(request_id, response):
   response.pop(CDS_IS_SUCCESSFUL_KEY)
   logs = response.pop(RESULTS_LOG_KEY)
 
-  # Payload should only contains response data returned from the executed script and/or the error message
+  errorMessage = ""
+  if ERR_MSG_KEY in response:
+    errorMessage = '\n'.join(response.pop(ERR_MSG_KEY))
+
+  # Payload should only contain response data returned from the executed script and/or the error message
   payload = json.dumps(response)
 
   timestamp = Timestamp()
@@ -72,15 +76,28 @@ def build_grpc_response(request_id, response):
                                                          response=logs,
                                                          status=status,
                                                          payload=payload,
-                                                         timestamp=timestamp)
+                                                         timestamp=timestamp,
+                                                         errMsg=errorMessage)
 
   return truncate_execution_output(execution_output)
 
+
+# return the status of validate blueprint UUID call rpc
+def build_grpc_blueprint_validation_response(request_id, subrequest_id,
+    cba_uuid, success=True):
+  timestamp = Timestamp()
+  timestamp.GetCurrentTime()
+  return CommandExecutor_pb2.BlueprintValidationOutput(requestId=request_id,
+                                                subRequestId=subrequest_id,
+                                                status=CommandExecutor_pb2.SUCCESS if success else CommandExecutor_pb2.FAILURE,
+                                                cbaUUID=cba_uuid,
+                                                timestamp=timestamp)
+
 def build_grpc_blueprint_upload_response(request_id, subrequest_id, success=True, payload=[]):
   timestamp = Timestamp()
   timestamp.GetCurrentTime()
   return CommandExecutor_pb2.UploadBlueprintOutput(requestId=request_id,
-    subRequestId=subrequest_id, 
+    subRequestId=subrequest_id,
     status=CommandExecutor_pb2.SUCCESS if success else CommandExecutor_pb2.FAILURE,
     timestamp=timestamp,
     payload=json.dumps(payload))
@@ -112,30 +129,44 @@ 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, err_msg_result, results_log,
     extra):
   payload_section = []
+  ret_err_msg_section = []
   is_payload_section = False
+  is_user_script_err_msg = False
   outputfile.seek(0)
   while True:
-    output = outputfile.readline()
-    if output == '':
+    line = outputfile.readline()
+    if line == '':
       break
-    if output.startswith('BEGIN_EXTRA_PAYLOAD'):
+    # Read the user-supplied (script) return payload.
+    if line.startswith('BEGIN_EXTRA_PAYLOAD'):
       is_payload_section = True
-      output = outputfile.readline()
-    if output.startswith('END_EXTRA_PAYLOAD'):
+      line = outputfile.readline()
+    if line.startswith('END_EXTRA_PAYLOAD'):
       is_payload_section = False
-      output = ''
+      line = ''
       payload = '\n'.join(payload_section)
       msg = email.parser.Parser().parsestr(payload)
       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(), extra=extra)
-      results_log.append(output.strip())
-    else:
-      payload_section.append(output.strip())
+
+    # Read the user-supplied (script) error message string
+    if line.startswith('BEGIN_EXTRA_RET_ERR_MSG'):
+      is_user_script_err_msg = True
+      line = outputfile.readline()
+    if line.startswith('END_EXTRA_RET_ERR_MSG'):
+      is_user_script_err_msg = False
+      line = ''
+      err_msg_result.append('\n'.join(ret_err_msg_section))
+    if is_payload_section:
+      payload_section.append(line.strip())
+    elif is_user_script_err_msg:
+      ret_err_msg_section.append(line.strip())
+    elif line:
+      logger.info(line.strip(), extra=extra)
+      results_log.append(line.strip())
 
 
 def getExtraLogData(request=None):