Explicit error message in command-executor when script is failing
[ccsdk/cds.git] / ms / command-executor / src / main / python / command_executor_handler.py
1 #
2 # Copyright (C) 2019 Bell Canada.
3 #
4 # Licensed under the Apache License, Version 2.0 (the "License");
5 # you may not use this file except in compliance with the License.
6 # You may obtain a copy of the License at
7 #
8 #      http://www.apache.org/licenses/LICENSE-2.0
9 #
10 # Unless required by applicable law or agreed to in writing, software
11 # distributed under the License is distributed on an "AS IS" BASIS,
12 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 # See the License for the specific language governing permissions and
14 # limitations under the License.
15 #
16 from builtins import Exception, open, dict
17 from subprocess import CalledProcessError, PIPE
18 from google.protobuf.json_format import MessageToJson
19
20 import logging
21 import os
22 import re
23 import subprocess
24 import virtualenv
25 import venv
26 import utils
27 import proto.CommandExecutor_pb2 as CommandExecutor_pb2
28 import email.parser
29 import json
30
31 REQUIREMENTS_TXT = "requirements.txt"
32
33
34 class CommandExecutorHandler():
35
36     def __init__(self, request):
37         self.request = request
38         self.logger = logging.getLogger(self.__class__.__name__)
39         self.blueprint_id = utils.get_blueprint_id(request)
40         self.venv_home = '/opt/app/onap/blueprints/deploy/' + self.blueprint_id
41         self.installed = self.venv_home + '/.installed'
42
43     def is_installed(self):
44         return os.path.exists(self.installed)
45
46     def prepare_env(self, request):
47         results_log = []
48         if not self.is_installed():
49             create_venv_status = self.create_venv()
50             if not create_venv_status[utils.CDS_IS_SUCCESSFUL_KEY]:
51                 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])
52                 self.logger.error(err_msg)
53                 return utils.build_ret_data(False, error=err_msg)
54
55             activate_venv_status = self.activate_venv()
56             if not activate_venv_status[utils.CDS_IS_SUCCESSFUL_KEY]:
57                 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])
58                 self.logger.error(err_msg)
59                 return utils.build_ret_data(False, error=err_msg)
60             try:
61                 with open(self.installed, "w+") as f:
62                     if not self.install_packages(request, CommandExecutor_pb2.pip, f, results_log):
63                         err_msg = "ERROR: failed to prepare environment for request {} during pip package install.".format(self.blueprint_id)
64                         return utils.build_ret_data(False, results_log=results_log, error=err_msg)
65                     f.write("\r\n") # TODO: is \r needed?
66                     results_log.append("\n")
67                     if not self.install_packages(request, CommandExecutor_pb2.ansible_galaxy, f, results_log):
68                         err_msg = "ERROR: failed to prepare environment for request {} during Ansible install.".format(self.blueprint_id)
69                         return utils.build_ret_data(False, results_log=results_log, error=err_msg)
70             except Exception as ex:
71                 err_msg = "ERROR: failed to prepare environment for request {} during installing packages. Exception: {}".format(self.blueprint_id, ex)
72                 self.logger.error(err_msg)
73                 return utils.build_ret_data(False, error=err_msg)
74         else:
75             try:
76                 with open(self.installed, "r") as f:
77                     results_log.append(f.read())
78             except Exception as ex:
79                 err_msg="ERROR: failed to prepare environment during reading 'installed' file {}. Exception: {}".format(self.installed, ex)
80                 return utils.build_ret_data(False, error=err_msg)
81
82         # deactivate_venv(blueprint_id)
83         return utils.build_ret_data(True, results_log=results_log)
84
85     def execute_command(self, request):
86         results_log = []
87         result = {}
88         # workaround for when packages are not specified, we may not want to go through the install step
89         # can just call create_venv from here.
90         if not self.is_installed():
91             self.create_venv()
92         try:
93             if not self.is_installed():
94                 create_venv_status = self.create_venv
95                 if not create_venv_status[utils.CDS_IS_SUCCESSFUL_KEY]:
96                     err_msg = "{} - Failed to execute command during venv creation. Original error: {}".format(self.blueprint_id, create_venv_status[utils.ERR_MSG_KEY])
97                     return utils.build_ret_data(False, error=err_msg)
98             activate_response = self.activate_venv()
99             if not activate_response[utils.CDS_IS_SUCCESSFUL_KEY]:
100                 orig_error = activate_response[utils.ERR_MSG_KEY]
101                 err_msg = "{} - Failed to execute command during environment activation. Original error: {}".format(self.blueprint_id, orig_error)
102                 return utils.build_ret_data(False, error=err_msg)
103
104             cmd = "cd " + self.venv_home
105
106             ### TODO: replace with os.environ['VIRTUAL_ENV']?
107             if "ansible-playbook" in request.command:
108                 cmd = cmd + "; " + request.command + " -e 'ansible_python_interpreter=" + self.venv_home + "/bin/python'"
109             else:
110                 cmd = cmd + "; " + request.command + " " + re.escape(MessageToJson(request.properties))
111             payload_section = []
112             is_payload_section = False
113
114             ### extract the original header request into sys-env variables
115             ### RequestID
116             request_id = request.requestId
117             ### Sub-requestID
118             subrequest_id = request.correlationId
119             request_id_map = {'CDS_REQUEST_ID':request_id, 'CDS_CORRELATION_ID':subrequest_id}
120             updated_env =  { **os.environ, **request_id_map }
121
122             with subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT,
123                                   shell=True, bufsize=1, universal_newlines=True, env=updated_env) as newProcess:
124                 while True:
125                     output = newProcess.stdout.readline()
126                     if output == '' and newProcess.poll() is not None:
127                         break
128                     if output.startswith('BEGIN_EXTRA_PAYLOAD'):
129                         is_payload_section = True
130                         output = newProcess.stdout.readline()
131                     if output.startswith('END_EXTRA_PAYLOAD'):
132                         is_payload_section = False
133                         output = ''
134                         payload = '\n'.join(payload_section)
135                         msg = email.parser.Parser().parsestr(payload)
136                         for part in msg.get_payload():
137                             result = json.loads(part.get_payload())
138                     if output and not is_payload_section:
139                         self.logger.info(output.strip())
140                         results_log.append(output.strip())
141                     else:
142                         payload_section.append(output.strip())
143                 rc = newProcess.poll()
144         except Exception as e:
145             err_msg = "{} - Failed to execute command. Error: {}".format(self.blueprint_id, e)
146             return utils.build_ret_data(False, results=result, results_log=results_log, error=err_msg)
147
148         # deactivate_venv(blueprint_id)
149         #Since return code is only used to check if it's zero (success), we can just return success flag instead.
150         self.logger.debug("python return_code : {}".format(rc))
151         if rc == 0:
152             return utils.build_ret_data(True, results=result, results_log=results_log)
153         else:
154             err_msg = ""
155             if len(results_log) > 0:
156                 # get exception message
157                 err_msg = "{} - {}".format(self.blueprint_id, results_log[-1:][0])
158             else:
159                 err_msg = "{} - Process exited with return code {}".format(self.blueprint_id, rc)
160             return utils.build_ret_data(False, results=result, results_log=results_log, error=err_msg)
161
162     def install_packages(self, request, type, f, results):
163         success = self.install_python_packages('UTILITY', results)
164
165         for package in request.packages:
166             if package.type == type:
167                 f.write("Installed %s packages:\r\n" % CommandExecutor_pb2.PackageType.Name(type))
168                 for p in package.package:
169                     f.write("   %s\r\n" % p)
170                     if package.type == CommandExecutor_pb2.pip:
171                         success = self.install_python_packages(p, results)
172                     else:
173                         success = self.install_ansible_packages(p, results)
174                     if not success:
175                         f.close()
176                         os.remove(self.installed)
177                         return False
178         return True
179
180     def install_python_packages(self, package, results):
181         self.logger.info(
182             "{} - Install Python package({}) in Python Virtual Environment".format(self.blueprint_id, package))
183
184         if REQUIREMENTS_TXT == package:
185             command = ["pip", "install", "-r", self.venv_home + "/Environments/" + REQUIREMENTS_TXT]
186         elif package == 'UTILITY':
187             command = ["cp", "-r", "./cds_utils", self.venv_home + "/lib/python3.6/site-packages/"]
188         else:
189             command = ["pip", "install", package]
190
191         env = dict(os.environ)
192         if "https_proxy" in os.environ:
193             env['https_proxy'] = os.environ['https_proxy']
194             self.logger.info("Using https_proxy: ", env['https_proxy'])
195
196         try:
197             results.append(subprocess.run(command, check=True, stdout=PIPE, stderr=PIPE, env=env).stdout.decode())
198             results.append("\n")
199             self.logger.info("install_python_packages {} succeeded".format(package))
200             return True
201         except CalledProcessError as e:
202             results.append(e.stderr.decode())
203             self.logger.error("install_python_packages {} failed".format(package))
204             return False
205
206     def install_ansible_packages(self, package, results):
207         self.logger.info(
208             "{} - Install Ansible Role package({}) in Python Virtual Environment".format(self.blueprint_id, package))
209         command = ["ansible-galaxy", "install", package, "-p", self.venv_home + "/Scripts/ansible/roles"]
210
211         env = dict(os.environ)
212         if "http_proxy" in os.environ:
213             # ansible galaxy uses https_proxy environment variable, but requires it to be set with http proxy value.
214             env['https_proxy'] = os.environ['http_proxy']
215
216         try:
217             results.append(subprocess.run(command, check=True, stdout=PIPE, stderr=PIPE, env=env).stdout.decode())
218             results.append("\n")
219             return True
220         except CalledProcessError as e:
221             results.append(e.stderr.decode())
222             return False
223
224     # Returns a map with 'status' and 'err_msg'.
225     # 'status' True indicates success.
226     # 'err_msg' indicates an error occurred. The presence of err_msg may not be fatal,
227     # status should be set to False for fatal errors.
228     def create_venv(self):
229         self.logger.info("{} - Create Python Virtual Environment".format(self.blueprint_id))
230         try:
231             bin_dir = self.venv_home + "/bin"
232             # venv doesn't populate the activate_this.py script, hence we use from virtualenv
233             venv.create(self.venv_home, with_pip=True, system_site_packages=True)
234             virtualenv.writefile(os.path.join(bin_dir, "activate_this.py"), virtualenv.ACTIVATE_THIS)
235             self.logger.info("{} - Creation of Python Virtual Environment finished.".format(self.blueprint_id))
236             return utils.build_ret_data(True, "")
237         except Exception as err:
238             err_msg = "{} - Failed to provision Python Virtual Environment. Error: {}".format(self.blueprint_id, err)
239             self.logger.info(err_msg)
240             return utils.build_ret_data(False, err_msg)
241
242     # return map cds_is_successful and err_msg. Status is True on success. err_msg may existence doesn't necessarily indicate fatal condition.
243     # the 'status' should be set to False to indicate error.
244     def activate_venv(self):
245         self.logger.info("{} - Activate Python Virtual Environment".format(self.blueprint_id))
246
247         # Fix: The python generated activate_this.py script concatenates the env bin dir to PATH on every call
248         #      eventually this process PATH variable was so big (128Kb) that no child process could be spawn
249         #      This script will remove all duplicates; while keeping the order of the PATH folders
250         fixpathenvvar = "os.environ['PATH']=os.pathsep.join(list(dict.fromkeys(os.environ['PATH'].split(':'))))"
251
252         path = "%s/bin/activate_this.py" % self.venv_home
253         try:
254             with open(path) as activate_this_script:
255                 exec (activate_this_script.read(), {'__file__': path})
256             exec (fixpathenvvar)
257             self.logger.info("Running with PATH : {}".format(os.environ['PATH']))
258             return utils.build_ret_data(True, "")
259         except Exception as err:
260             err_msg ="{} - Failed to activate Python Virtual Environment. Error: {}".format(self.blueprint_id, err)
261             self.logger.info( err_msg)
262             return utils.build_ret_data(False, err_msg)
263
264     def deactivate_venv(self):
265         self.logger.info("{} - Deactivate Python Virtual Environment".format(self.blueprint_id))
266         command = ["deactivate"]
267         try:
268             subprocess.run(command, check=True)
269         except Exception as err:
270             self.logger.info(
271                 "{} - Failed to deactivate Python Virtual Environment. Error: {}".format(self.blueprint_id, err))