Command Executor : Invalid response_data when executed script fails
[ccsdk/cds.git] / ms / blueprintsprocessor / functions / python-executor / src / main / kotlin / org / onap / ccsdk / cds / blueprintsprocessor / functions / python / executor / ComponentRemotePythonExecutor.kt
1 /*
2  *  Copyright Â© 2019 IBM.
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
17 package org.onap.ccsdk.cds.blueprintsprocessor.functions.python.executor
18
19 import com.fasterxml.jackson.databind.JsonNode
20 import kotlinx.coroutines.GlobalScope
21 import kotlinx.coroutines.TimeoutCancellationException
22 import kotlinx.coroutines.async
23 import kotlinx.coroutines.withTimeout
24 import org.onap.ccsdk.cds.blueprintsprocessor.core.BluePrintPropertiesService
25 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.ExecutionServiceInput
26 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.PrepareRemoteEnvInput
27 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.RemoteIdentifier
28 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.RemoteScriptExecutionInput
29 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.StatusType
30 import org.onap.ccsdk.cds.blueprintsprocessor.services.execution.AbstractComponentFunction
31 import org.onap.ccsdk.cds.blueprintsprocessor.services.execution.ExecutionServiceConstant
32 import org.onap.ccsdk.cds.blueprintsprocessor.services.execution.RemoteScriptExecutionService
33 import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintProcessorException
34 import org.onap.ccsdk.cds.controllerblueprints.core.asJsonPrimitive
35 import org.onap.ccsdk.cds.controllerblueprints.core.checkFileExists
36 import org.onap.ccsdk.cds.controllerblueprints.core.checkNotBlank
37 import org.onap.ccsdk.cds.controllerblueprints.core.data.OperationAssignment
38 import org.onap.ccsdk.cds.controllerblueprints.core.normalizedFile
39 import org.onap.ccsdk.cds.controllerblueprints.core.returnNullIfMissing
40 import org.onap.ccsdk.cds.controllerblueprints.core.rootFieldsToMap
41 import org.onap.ccsdk.cds.controllerblueprints.core.utils.JacksonUtils
42 import org.slf4j.LoggerFactory
43 import org.springframework.beans.factory.config.ConfigurableBeanFactory
44 import org.springframework.boot.autoconfigure.condition.ConditionalOnBean
45 import org.springframework.context.annotation.Scope
46 import org.springframework.stereotype.Component
47
48 @ConditionalOnBean(name = [ExecutionServiceConstant.SERVICE_GRPC_REMOTE_SCRIPT_EXECUTION])
49 @Component("component-remote-python-executor")
50 @Scope(value = ConfigurableBeanFactory.SCOPE_PROTOTYPE)
51 open class ComponentRemotePythonExecutor(
52     private val remoteScriptExecutionService: RemoteScriptExecutionService,
53     private var bluePrintPropertiesService: BluePrintPropertiesService
54 ) : AbstractComponentFunction() {
55
56     private val log = LoggerFactory.getLogger(ComponentRemotePythonExecutor::class.java)!!
57
58     companion object {
59         const val SELECTOR_CMD_EXEC = "blueprintsprocessor.remote-script-command"
60         const val INPUT_ENDPOINT_SELECTOR = "endpoint-selector"
61         const val INPUT_DYNAMIC_PROPERTIES = "dynamic-properties"
62         const val INPUT_ARGUMENT_PROPERTIES = "argument-properties"
63
64         const val INPUT_COMMAND = "command"
65         const val INPUT_PACKAGES = "packages"
66         const val DEFAULT_SELECTOR = "remote-python"
67         const val INPUT_ENV_PREPARE_TIMEOUT = "env-prepare-timeout"
68         const val INPUT_EXECUTE_TIMEOUT = "execution-timeout"
69
70         const val STEP_PREPARE_ENV = "prepare-env"
71         const val STEP_EXEC_CMD = "execute-command"
72         const val ATTRIBUTE_EXEC_CMD_STATUS = "status"
73         const val ATTRIBUTE_PREPARE_ENV_LOG = "prepare-environment-logs"
74         const val ATTRIBUTE_EXEC_CMD_LOG = "execute-command-logs"
75         const val ATTRIBUTE_RESPONSE_DATA = "response-data"
76         const val DEFAULT_ENV_PREPARE_TIMEOUT_IN_SEC = 120
77         const val DEFAULT_EXECUTE_TIMEOUT_IN_SEC = 180
78     }
79
80     override suspend fun processNB(executionRequest: ExecutionServiceInput) {
81
82         log.debug("Processing : $operationInputs")
83
84         val isLogResponseEnabled = bluePrintPropertiesService.propertyBeanType("$SELECTOR_CMD_EXEC.response.log.enabled", Boolean::class.java)
85
86         val bluePrintContext = bluePrintRuntimeService.bluePrintContext()
87         val blueprintName = bluePrintContext.name()
88         val blueprintVersion = bluePrintContext.version()
89
90         val operationAssignment: OperationAssignment = bluePrintContext
91             .nodeTemplateInterfaceOperation(nodeTemplateName, interfaceName, operationName)
92
93         val artifactName: String = operationAssignment.implementation?.primary
94             ?: throw BluePrintProcessorException("missing primary field to get artifact name for node template ($nodeTemplateName)")
95
96         val artifactDefinition =
97             bluePrintRuntimeService.resolveNodeTemplateArtifactDefinition(nodeTemplateName, artifactName)
98
99         checkNotBlank(artifactDefinition.file) { "couldn't get python script path($artifactName)" }
100
101         val pythonScript = normalizedFile(bluePrintContext.rootPath, artifactDefinition.file)
102
103         checkFileExists(pythonScript) { "python script(${pythonScript.absolutePath}) doesn't exists" }
104
105         val endPointSelector = getOperationInput(INPUT_ENDPOINT_SELECTOR)
106         val dynamicProperties = getOptionalOperationInput(INPUT_DYNAMIC_PROPERTIES)
107         val packages = getOptionalOperationInput(INPUT_PACKAGES)?.returnNullIfMissing()
108
109         val argsNode = getOptionalOperationInput(INPUT_ARGUMENT_PROPERTIES)?.returnNullIfMissing()
110
111         // This prevents unescaping values, as well as quoting the each parameter, in order to allow for spaces in values
112         val args = getOptionalOperationInput(INPUT_ARGUMENT_PROPERTIES)?.returnNullIfMissing()
113             ?.rootFieldsToMap()?.toSortedMap()?.values?.joinToString(" ") { formatNestedJsonNode(it) }
114
115         val command = getOperationInput(INPUT_COMMAND).asText()
116
117         /**
118          * Timeouts that are specific to the command executor.
119          * Note: the interface->input->timeout is the component level timeout.
120          */
121         val envPrepTimeout = getOptionalOperationInput(INPUT_ENV_PREPARE_TIMEOUT)?.asInt()
122             ?: DEFAULT_ENV_PREPARE_TIMEOUT_IN_SEC
123         val executionTimeout = getOptionalOperationInput(INPUT_EXECUTE_TIMEOUT)?.asInt()
124             ?: DEFAULT_EXECUTE_TIMEOUT_IN_SEC
125
126         // component level timeout should be => env_prep_timeout + execution_timeout
127         val timeout = implementation.timeout
128
129         var scriptCommand = command.replace(pythonScript.name, pythonScript.absolutePath)
130         if (args != null && args.isNotEmpty()) {
131             scriptCommand = scriptCommand.plus(" ").plus(args)
132         }
133
134         try {
135             // Open GRPC Connection
136             if (DEFAULT_SELECTOR == endPointSelector.asText()) {
137                 remoteScriptExecutionService.init(endPointSelector.asText())
138             } else {
139                 // Get endpoint from DSL
140                 val endPointSelectorJson = bluePrintRuntimeService.resolveDSLExpression(endPointSelector.asText())
141                 remoteScriptExecutionService.init(endPointSelectorJson)
142             }
143
144             // If packages are defined, then install in remote server
145             if (packages != null) {
146                 val prepareEnvInput = PrepareRemoteEnvInput(
147                     requestId = processId,
148                     remoteIdentifier = RemoteIdentifier(
149                         blueprintName = blueprintName,
150                         blueprintVersion = blueprintVersion),
151                     packages = packages,
152                     timeOut = envPrepTimeout.toLong()
153
154                 )
155                 val prepareEnvOutput = remoteScriptExecutionService.prepareEnv(prepareEnvInput)
156                 log.info("$ATTRIBUTE_PREPARE_ENV_LOG - ${prepareEnvOutput.response}")
157                 val logs = JacksonUtils.jsonNodeFromObject(prepareEnvOutput.response)
158                 val logsEnv = logs.toString().asJsonPrimitive()
159                 setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, logsEnv)
160
161                 if (prepareEnvOutput.status != StatusType.SUCCESS) {
162                     val errorMessage = prepareEnvOutput.payload
163                     setNodeOutputErrors(prepareEnvOutput.status.name,
164                         STEP_PREPARE_ENV,
165                         logs,
166                         errorMessage,
167                         isLogResponseEnabled
168                     )
169                 } else {
170                     setNodeOutputProperties(prepareEnvOutput.status.name.asJsonPrimitive(),
171                         STEP_PREPARE_ENV,
172                         logsEnv,
173                         "".asJsonPrimitive(),
174                         isLogResponseEnabled
175                     )
176                 }
177             } else {
178                 // set env preparation log to empty...
179                 setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, "".asJsonPrimitive())
180             }
181         } catch (grpcEx: io.grpc.StatusRuntimeException) {
182             val componentLevelWarningMsg = if (timeout < envPrepTimeout) "Note: component-level timeout ($timeout) is shorter than env-prepare timeout ($envPrepTimeout). " else ""
183             val grpcErrMsg = "Command failed during env. preparation... timeout($envPrepTimeout) requestId ($processId). $componentLevelWarningMsg grpcError: ${grpcEx.status}"
184             setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, grpcErrMsg.asJsonPrimitive())
185             setNodeOutputErrors(status = StatusType.FAILURE.name, step = STEP_PREPARE_ENV, message = grpcErrMsg.asJsonPrimitive(), logging = isLogResponseEnabled)
186             log.error(grpcErrMsg, grpcEx)
187         } catch (e: Exception) {
188             val timeoutErrMsg = "Command executor failed during env. preparation.. catch-all case timeout($envPrepTimeout) requestId ($processId). exception msg: ${e.message}"
189             setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, e.message.asJsonPrimitive())
190             setNodeOutputErrors(status = StatusType.FAILURE.name, step = STEP_PREPARE_ENV, message = timeoutErrMsg.asJsonPrimitive(), logging = isLogResponseEnabled)
191             log.error(timeoutErrMsg, e)
192         }
193         // if Env preparation was successful, then proceed with command execution in this Env
194         if (bluePrintRuntimeService.getBluePrintError().errors.isEmpty()) {
195             try {
196                 // Populate command execution properties and pass it to the remote server
197                 val properties = dynamicProperties?.returnNullIfMissing()?.rootFieldsToMap() ?: hashMapOf()
198
199                 val remoteExecutionInput = RemoteScriptExecutionInput(
200                     requestId = processId,
201                     remoteIdentifier = RemoteIdentifier(blueprintName = blueprintName, blueprintVersion = blueprintVersion),
202                     command = scriptCommand,
203                     properties = properties,
204                     timeOut = implementation.timeout.toLong())
205
206                 val remoteExecutionOutputDeferred = GlobalScope.async {
207                     remoteScriptExecutionService.executeCommand(remoteExecutionInput)
208                 }
209
210                 val remoteExecutionOutput = withTimeout(implementation.timeout * 1000L) {
211                     remoteExecutionOutputDeferred.await()
212                 }
213
214                 checkNotNull(remoteExecutionOutput) {
215                     "Error: Request-id $processId did not return a result from remote command execution."
216                 }
217                 val logs = JacksonUtils.jsonNodeFromObject(remoteExecutionOutput.response)
218                 if (remoteExecutionOutput.status != StatusType.SUCCESS) {
219                     setNodeOutputErrors(remoteExecutionOutput.status.name,
220                         STEP_EXEC_CMD,
221                         logs,
222                         remoteExecutionOutput.payload,
223                         isLogResponseEnabled
224                     )
225                 } else {
226                     setNodeOutputProperties(remoteExecutionOutput.status.name.asJsonPrimitive(),
227                         STEP_EXEC_CMD,
228                         logs,
229                         remoteExecutionOutput.payload,
230                         isLogResponseEnabled
231                     )
232                 }
233             } catch (timeoutEx: TimeoutCancellationException) {
234                 val componentLevelWarningMsg = if (timeout < executionTimeout) "Note: component-level timeout ($timeout) is shorter than execution timeout ($executionTimeout). " else ""
235                 val timeoutErrMsg = "Command executor execution timeout. DetailedMessage: (${timeoutEx.message}) requestId ($processId). $componentLevelWarningMsg"
236                 setNodeOutputErrors(status = StatusType.FAILURE.name,
237                     step = STEP_EXEC_CMD,
238                     logs = "".asJsonPrimitive(),
239                     message = timeoutErrMsg.asJsonPrimitive(),
240                     logging = isLogResponseEnabled
241                 )
242                 log.error(timeoutErrMsg, timeoutEx)
243             } catch (grpcEx: io.grpc.StatusRuntimeException) {
244                 val timeoutErrMsg = "Command executor timed out executing after $executionTimeout seconds requestId ($processId) grpcErr: ${grpcEx.status}"
245                 setNodeOutputErrors(status = StatusType.FAILURE.name,
246                     step = STEP_EXEC_CMD,
247                     logs = "".asJsonPrimitive(),
248                     message = timeoutErrMsg.asJsonPrimitive(),
249                     logging = isLogResponseEnabled
250                 )
251                 log.error(timeoutErrMsg, grpcEx)
252             } catch (e: Exception) {
253                 val timeoutErrMsg = "Command executor failed during process catch-all case requestId ($processId) timeout($envPrepTimeout) exception msg: ${e.message}"
254                 setNodeOutputErrors(status = StatusType.FAILURE.name, step = STEP_PREPARE_ENV, message = timeoutErrMsg.asJsonPrimitive(), logging = isLogResponseEnabled)
255                 log.error(timeoutErrMsg, e)
256             }
257         }
258         log.debug("Trying to close GRPC channel. request ($processId)")
259         remoteScriptExecutionService.close()
260     }
261
262     override suspend fun recoverNB(runtimeException: RuntimeException, executionRequest: ExecutionServiceInput) {
263         bluePrintRuntimeService.getBluePrintError()
264             .addError("Failed in ComponentRemotePythonExecutor : ${runtimeException.message}")
265     }
266
267     private fun formatNestedJsonNode(node: JsonNode): String {
268         val sb = StringBuilder()
269         if (node.isValueNode) {
270             sb.append(" $node")
271         } else {
272             node.forEach { sb.append(" $it") }
273         }
274         return sb.toString()
275     }
276
277     /**
278      * Utility function to set the output properties of the executor node
279      */
280     private fun setNodeOutputProperties(
281         status: JsonNode = StatusType.FAILURE.name.asJsonPrimitive(),
282         step: String,
283         logs: JsonNode,
284         message: JsonNode,
285         logging: Boolean = true
286     ) {
287
288         setAttribute(ATTRIBUTE_EXEC_CMD_STATUS, status)
289         setAttribute(ATTRIBUTE_RESPONSE_DATA, message)
290         setAttribute(ATTRIBUTE_EXEC_CMD_LOG, logs)
291
292         if (logging) {
293             log.info("Executor status : $step : $status")
294             log.info("Executor message: $step : $message")
295             log.info("Executor logs   : $step : $logs")
296         }
297     }
298
299     /**
300      * Utility function to set the output properties and errors of the executor node, in case of errors
301      */
302     private fun setNodeOutputErrors(
303         status: String,
304         step: String,
305         logs: JsonNode = "N/A".asJsonPrimitive(),
306         message: JsonNode,
307         logging: Boolean = true
308     ) {
309         setAttribute(ATTRIBUTE_EXEC_CMD_STATUS, status.asJsonPrimitive())
310         setAttribute(ATTRIBUTE_EXEC_CMD_LOG, logs)
311         setAttribute(ATTRIBUTE_RESPONSE_DATA, message)
312
313         if (logging) {
314             log.info("Executor status : $step : $status")
315             log.info("Executor message: $step : $message")
316             log.info("Executor logs   : $step : $logs")
317         }
318
319         addError(status, step, logs.toString())
320     }
321 }