ms/blueprintsprocessor/functions/python-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/python/executor/ComponentRemotePythonExecutor.kt

   1 /*
   2  *  Copyright Â© 2019 IBM.
   3  *  Modifications Copyright © 2020 Bell Canada.
   4  *
   5  *  Licensed under the Apache License, Version 2.0 (the "License");
   6  *  you may not use this file except in compliance with the License.
   7  *  You may obtain a copy of the License at
   8  *
   9  *      http://www.apache.org/licenses/LICENSE-2.0
  10  *
  11  *  Unless required by applicable law or agreed to in writing, software
  12  *  distributed under the License is distributed on an "AS IS" BASIS,
  13  *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  14  *  See the License for the specific language governing permissions and
  15  *  limitations under the License.
  16  */
  17
  18 package org.onap.ccsdk.cds.blueprintsprocessor.functions.python.executor
  19
  20 import com.fasterxml.jackson.databind.JsonNode
  21 import com.google.protobuf.ByteString
  22 import kotlinx.coroutines.GlobalScope
  23 import kotlinx.coroutines.TimeoutCancellationException
  24 import kotlinx.coroutines.async
  25 import kotlinx.coroutines.withTimeout
  26 import org.onap.ccsdk.cds.blueprintsprocessor.core.BluePrintPropertiesService
  27 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.ExecutionServiceInput
  28 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.PrepareRemoteEnvInput
  29 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.RemoteIdentifier
  30 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.RemoteScriptExecutionInput
  31 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.RemoteScriptExecutionOutput
  32 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.RemoteScriptUploadBlueprintInput
  33 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.StatusType
  34 import org.onap.ccsdk.cds.blueprintsprocessor.db.primary.repository.BlueprintModelRepository
  35 import org.onap.ccsdk.cds.blueprintsprocessor.services.execution.AbstractComponentFunction
  36 import org.onap.ccsdk.cds.blueprintsprocessor.services.execution.ExecutionServiceConstant
  37 import org.onap.ccsdk.cds.blueprintsprocessor.services.execution.RemoteScriptExecutionService
  38 import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintProcessorException
  39 import org.onap.ccsdk.cds.controllerblueprints.core.asJsonPrimitive
  40 import org.onap.ccsdk.cds.controllerblueprints.core.asJsonType
  41 import org.onap.ccsdk.cds.controllerblueprints.core.checkFileExists
  42 import org.onap.ccsdk.cds.controllerblueprints.core.checkNotBlank
  43 import org.onap.ccsdk.cds.controllerblueprints.core.data.OperationAssignment
  44 import org.onap.ccsdk.cds.controllerblueprints.core.normalizedFile
  45 import org.onap.ccsdk.cds.controllerblueprints.core.returnNullIfMissing
  46 import org.onap.ccsdk.cds.controllerblueprints.core.rootFieldsToMap
  47 import org.onap.ccsdk.cds.controllerblueprints.core.utils.JacksonUtils
  48 import org.slf4j.LoggerFactory
  49 import org.springframework.beans.factory.config.ConfigurableBeanFactory
  50 import org.springframework.boot.autoconfigure.condition.ConditionalOnBean
  51 import org.springframework.context.annotation.Scope
  52 import org.springframework.stereotype.Component
  53
  54 @ConditionalOnBean(name = [ExecutionServiceConstant.SERVICE_GRPC_REMOTE_SCRIPT_EXECUTION])
  55 @Component("component-remote-python-executor")
  56 @Scope(value = ConfigurableBeanFactory.SCOPE_PROTOTYPE)
  57 open class ComponentRemotePythonExecutor(
  58     private val remoteScriptExecutionService: RemoteScriptExecutionService,
  59     private val bluePrintPropertiesService: BluePrintPropertiesService,
  60     private val blueprintModelRepository: BlueprintModelRepository
  61 ) : AbstractComponentFunction() {
  62
  63     private val log = LoggerFactory.getLogger(ComponentRemotePythonExecutor::class.java)!!
  64
  65     companion object {
  66
  67         const val SELECTOR_CMD_EXEC = "blueprintsprocessor.remote-script-command"
  68         const val INPUT_ENDPOINT_SELECTOR = "endpoint-selector"
  69         const val INPUT_DYNAMIC_PROPERTIES = "dynamic-properties"
  70         const val INPUT_ARGUMENT_PROPERTIES = "argument-properties"
  71
  72         const val INPUT_COMMAND = "command"
  73         const val INPUT_PACKAGES = "packages"
  74         const val DEFAULT_SELECTOR = "remote-python"
  75         const val INPUT_ENV_PREPARE_TIMEOUT = "env-prepare-timeout"
  76         const val INPUT_EXECUTE_TIMEOUT = "execution-timeout"
  77
  78         const val STEP_PREPARE_ENV = "prepare-env"
  79         const val STEP_EXEC_CMD = "execute-command"
  80         const val ATTRIBUTE_EXEC_CMD_STATUS = "status"
  81         const val ATTRIBUTE_PREPARE_ENV_LOG = "prepare-environment-logs"
  82         const val ATTRIBUTE_EXEC_CMD_LOG = "execute-command-logs"
  83         const val ATTRIBUTE_RESPONSE_DATA = "response-data"
  84         const val DEFAULT_ENV_PREPARE_TIMEOUT_IN_SEC = 120
  85         const val DEFAULT_EXECUTE_TIMEOUT_IN_SEC = 180
  86         const val TIMEOUT_DELTA = 100L
  87         const val DEFAULT_CBA_UPLOAD_TIMEOUT_IN_SEC = 30
  88     }
  89
  90     override suspend fun processNB(executionRequest: ExecutionServiceInput) {
  91
  92         log.debug("Processing : $operationInputs")
  93
  94         val isLogResponseEnabled = bluePrintPropertiesService.propertyBeanType("$SELECTOR_CMD_EXEC.response.log.enabled", Boolean::class.java)
  95
  96         val bluePrintContext = bluePrintRuntimeService.bluePrintContext()
  97         val blueprintName = bluePrintContext.name()
  98         val blueprintVersion = bluePrintContext.version()
  99
 100         // fetch the template (plus cba bindata) from repository
 101         val cbaModel = blueprintModelRepository.findByArtifactNameAndArtifactVersion(blueprintName, blueprintVersion)
 102         val blueprintUUID = cbaModel?.id!!
 103         val cbaBinData = ByteString.copyFrom(cbaModel?.blueprintModelContent?.content)
 104         val archiveType = cbaModel?.blueprintModelContent?.contentType // TODO: should be enum
 105         val remoteIdentifier = RemoteIdentifier(blueprintName = blueprintName, blueprintVersion = blueprintVersion, blueprintUUID = blueprintUUID)
 106         val originatorId = executionServiceInput.commonHeader.originatorId
 107         val subRequestId = executionServiceInput.commonHeader.subRequestId
 108         val requestId = processId
 109
 110         val operationAssignment: OperationAssignment = bluePrintContext
 111             .nodeTemplateInterfaceOperation(nodeTemplateName, interfaceName, operationName)
 112
 113         val artifactName: String = operationAssignment.implementation?.primary
 114             ?: throw BluePrintProcessorException("missing primary field to get artifact name for node template ($nodeTemplateName)")
 115
 116         val artifactDefinition =
 117             bluePrintRuntimeService.resolveNodeTemplateArtifactDefinition(nodeTemplateName, artifactName)
 118
 119         checkNotBlank(artifactDefinition.file) { "couldn't get python script path($artifactName)" }
 120
 121         val pythonScript = normalizedFile(bluePrintContext.rootPath, artifactDefinition.file)
 122
 123         checkFileExists(pythonScript) { "python script(${pythonScript.absolutePath}) doesn't exists" }
 124
 125         val endPointSelector = getOperationInput(INPUT_ENDPOINT_SELECTOR)
 126         val dynamicProperties = getOptionalOperationInput(INPUT_DYNAMIC_PROPERTIES)
 127         var packages = getOptionalOperationInput(INPUT_PACKAGES)?.returnNullIfMissing()
 128
 129         // This prevents unescaping values, as well as quoting the each parameter, in order to allow for spaces in values
 130         val args = getOptionalOperationInput(INPUT_ARGUMENT_PROPERTIES)?.returnNullIfMissing()
 131             ?.rootFieldsToMap()?.toSortedMap()?.values?.joinToString(" ") { formatNestedJsonNode(it) }
 132
 133         val command = getOperationInput(INPUT_COMMAND).asText()
 134         val cbaNameVerUuid = "blueprintName($blueprintName) blueprintVersion($blueprintVersion) blueprintUUID($blueprintUUID)"
 135
 136         /**
 137          * Timeouts that are specific to the command executor.
 138          * Note: the interface->input->timeout is the component level timeout.
 139          */
 140         val envPrepTimeout = getOptionalOperationInput(INPUT_ENV_PREPARE_TIMEOUT)?.asInt()
 141             ?: DEFAULT_ENV_PREPARE_TIMEOUT_IN_SEC
 142         val executionTimeout = getOptionalOperationInput(INPUT_EXECUTE_TIMEOUT)?.asInt()
 143             ?: DEFAULT_EXECUTE_TIMEOUT_IN_SEC
 144
 145         // component level timeout should be => env_prep_timeout + execution_timeout
 146         val timeout = implementation.timeout
 147
 148         var scriptCommand = command.replace(pythonScript.name, artifactDefinition.file)
 149         if (args != null && args.isNotEmpty()) {
 150             scriptCommand = scriptCommand.plus(" ").plus(args)
 151         }
 152
 153         try {
 154             // Open GRPC Connection
 155             if (DEFAULT_SELECTOR == endPointSelector.asText()) {
 156                 remoteScriptExecutionService.init(endPointSelector.asText())
 157             } else {
 158                 // Get endpoint from DSL
 159                 val endPointSelectorJson = bluePrintRuntimeService.resolveDSLExpression(endPointSelector.asText())
 160                 remoteScriptExecutionService.init(endPointSelectorJson)
 161             }
 162
 163             // If packages are defined, then install in remote server
 164             if (packages == null) {
 165                 // set env preparation log to empty...
 166                 setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, "".asJsonPrimitive())
 167                 packages = mutableListOf<Object>().asJsonType()
 168             }
 169             prepareEnv(originatorId, requestId, subRequestId, remoteIdentifier, packages, envPrepTimeout, cbaNameVerUuid, archiveType, cbaBinData, isLogResponseEnabled)
 170             // in cases where the exception is caught in BP side due to timeout, we do not have `err_msg` returned by cmd-exec (inside `payload`),
 171             // hence `artifact` field will be empty
 172         } catch (grpcEx: io.grpc.StatusRuntimeException) {
 173             val componentLevelWarningMsg =
 174                 if (timeout < envPrepTimeout) "Note: component-level timeout ($timeout) is shorter than env-prepare timeout ($envPrepTimeout). " else ""
 175             val grpcErrMsg =
 176                 "Command failed during env. preparation... timeout($envPrepTimeout) requestId ($processId).$componentLevelWarningMsg grpcError: (${grpcEx.cause?.message})"
 177             // no execution log in case of timeout (as cmd-exec side hasn't finished to transfer output)
 178             // set prepare-env-log to the error msg, and cmd-exec-log to empty
 179             setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, grpcErrMsg.asJsonPrimitive())
 180             setNodeOutputErrors(STEP_PREPARE_ENV, "[]".asJsonPrimitive(), "{}".asJsonPrimitive(), isLogResponseEnabled)
 181             addError(StatusType.FAILURE.name, STEP_PREPARE_ENV, grpcErrMsg)
 182             log.error(grpcErrMsg, grpcEx)
 183         } catch (e: Exception) {
 184             val catchallErrMsg =
 185                 "Command executor failed during env. preparation.. catch-all case. timeout($envPrepTimeout) requestId ($processId). exception msg: ${e.message}"
 186             // no environment prepare log from executor in case of timeout (as cmd-exec side hasn't finished to transfer output), set it to error msg. Execution logs is empty.
 187             setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, catchallErrMsg.asJsonPrimitive())
 188             setNodeOutputErrors(STEP_PREPARE_ENV, "[]".asJsonPrimitive(), "{}".asJsonPrimitive(), isLogResponseEnabled)
 189             addError(StatusType.FAILURE.name, STEP_PREPARE_ENV, catchallErrMsg)
 190             log.error(catchallErrMsg, e)
 191         }
 192         // if Env preparation was successful, then proceed with command execution in this Env
 193         if (noBlueprintErrors()) {
 194             try {
 195                 // Populate command execution properties and pass it to the remote server
 196                 val properties = dynamicProperties?.returnNullIfMissing()?.rootFieldsToMap() ?: hashMapOf()
 197
 198                 val remoteExecutionInput = RemoteScriptExecutionInput(
 199                     originatorId = executionServiceInput.commonHeader.originatorId,
 200                     requestId = processId,
 201                     subRequestId = executionServiceInput.commonHeader.subRequestId,
 202                     remoteIdentifier = remoteIdentifier,
 203                     command = scriptCommand,
 204                     properties = properties,
 205                     timeOut = executionTimeout.toLong()
 206                 )
 207
 208                 val remoteExecutionOutputDeferred = GlobalScope.async {
 209                     remoteScriptExecutionService.executeCommand(remoteExecutionInput)
 210                 }
 211
 212                 val remoteExecutionOutput = withTimeout(executionTimeout * 1000L + TIMEOUT_DELTA) {
 213                     remoteExecutionOutputDeferred.await()
 214                 }
 215
 216                 checkNotNull(remoteExecutionOutput) {
 217                     "Error: Request-id $processId did not return a result from remote command execution."
 218                 }
 219                 val logs = JacksonUtils.jsonNodeFromObject(remoteExecutionOutput.response)
 220                 val returnedPayload = remoteExecutionOutput.payload
 221                 // In case of execution, `payload` (dictionary from Python execution) is preserved in `remoteExecutionOutput.payload`;
 222                 // It would contain `err_msg` key. It is valid to return it.
 223                 if (remoteExecutionOutput.status != StatusType.SUCCESS) {
 224                     setNodeOutputErrors(STEP_EXEC_CMD, logs, returnedPayload, isLogResponseEnabled)
 225                     addError(StatusType.FAILURE.name, STEP_EXEC_CMD, logs.toString())
 226                 } else {
 227                     setNodeOutputProperties(remoteExecutionOutput.status, STEP_EXEC_CMD, logs, returnedPayload, isLogResponseEnabled)
 228                 } // In timeout exception cases, we don't have payload, hence `payload` is empty value.
 229             } catch (timeoutEx: TimeoutCancellationException) {
 230                 val componentLevelWarningMsg =
 231                     if (timeout < executionTimeout) "Note: component-level timeout ($timeout) is shorter than execution timeout ($executionTimeout). " else ""
 232                 val timeoutErrMsg =
 233                     "Command executor execution timeout. DetailedMessage: (${timeoutEx.message}) requestId ($processId). $componentLevelWarningMsg"
 234                 setNodeOutputErrors(STEP_EXEC_CMD, listOf(timeoutErrMsg).asJsonType(), logging = isLogResponseEnabled)
 235                 addError(StatusType.FAILURE.name, STEP_EXEC_CMD, timeoutErrMsg)
 236                 log.error(timeoutErrMsg, timeoutEx)
 237             } catch (grpcEx: io.grpc.StatusRuntimeException) {
 238                 val timeoutErrMsg =
 239                     "Command executor timed out executing after $executionTimeout seconds requestId ($processId) grpcErr: ${grpcEx.status}"
 240                 setNodeOutputErrors(STEP_EXEC_CMD, listOf(timeoutErrMsg).asJsonType(), logging = isLogResponseEnabled)
 241                 addError(StatusType.FAILURE.name, STEP_EXEC_CMD, timeoutErrMsg)
 242                 log.error(timeoutErrMsg, grpcEx)
 243             } catch (e: Exception) {
 244                 val catchAllErrMsg =
 245                     "Command executor failed during process catch-all case requestId ($processId) timeout($envPrepTimeout) exception msg: ${e.message}"
 246                 setNodeOutputErrors(STEP_PREPARE_ENV, listOf(catchAllErrMsg).asJsonType(), logging = isLogResponseEnabled)
 247                 addError(StatusType.FAILURE.name, STEP_EXEC_CMD, catchAllErrMsg)
 248                 log.error(catchAllErrMsg, e)
 249             }
 250         }
 251         log.debug("Trying to close GRPC channel. request ($processId)")
 252         remoteScriptExecutionService.close()
 253     }
 254
 255     // wrapper for call to prepare_env step on cmd-exec - reupload CBA and call prepare env again if cmd-exec reported CBA uuid mismatch
 256     private suspend fun prepareEnv(originatorId: String, requestId: String, subRequestId: String, remoteIdentifier: RemoteIdentifier, packages: JsonNode, envPrepTimeout: Int, cbaNameVerUuid: String, archiveType: String?, cbaBinData: ByteString?, isLogResponseEnabled: Boolean, retries: Int = 3) {
 257         val prepareEnvInput = PrepareRemoteEnvInput(
 258             originatorId = originatorId,
 259             requestId = requestId,
 260             subRequestId = subRequestId,
 261             remoteIdentifier = remoteIdentifier,
 262             packages = packages,
 263             timeOut = envPrepTimeout.toLong()
 264         )
 265         val prepareEnvOutput = remoteScriptExecutionService.prepareEnv(prepareEnvInput)
 266         log.info("$ATTRIBUTE_PREPARE_ENV_LOG - ${prepareEnvOutput.response}")
 267         val logs = JacksonUtils.jsonNodeFromObject(prepareEnvOutput.response)
 268         setAttribute(ATTRIBUTE_PREPARE_ENV_LOG, logs)
 269
 270         // there are no artifacts for env. prepare, but we reuse it for err_log...
 271         if (prepareEnvOutput.status != StatusType.SUCCESS) {
 272             // Check for the flag that blueprint is mismatched first, if so, reupload the blueprint
 273             if (prepareEnvOutput.payload.has("reupload_cba")) {
 274                 log.info("Cmd-exec is missing the CBA $cbaNameVerUuid, it will be reuploaded.")
 275                 uploadCba(remoteIdentifier, requestId, subRequestId, originatorId, archiveType, cbaBinData, cbaNameVerUuid, prepareEnvOutput, isLogResponseEnabled, logs)
 276                 // call prepare_env again.
 277                 if (retries > 0) {
 278                     log.info("Calling prepare environment again")
 279                     prepareEnv(originatorId, requestId, subRequestId, remoteIdentifier, packages, envPrepTimeout, cbaNameVerUuid, archiveType, cbaBinData, isLogResponseEnabled, retries - 1)
 280                 } else {
 281                     val errMsg = "Something is wrong: prepare_env step attempted to call itself too many times after upload CBA step!"
 282                     log.error(errMsg)
 283                     setNodeOutputErrors(STEP_PREPARE_ENV, "[]".asJsonPrimitive(), prepareEnvOutput.payload, isLogResponseEnabled)
 284                     addError(StatusType.FAILURE.name, STEP_PREPARE_ENV, errMsg)
 285                 }
 286             } else {
 287                 setNodeOutputErrors(STEP_PREPARE_ENV, "[]".asJsonPrimitive(), prepareEnvOutput.payload, isLogResponseEnabled)
 288                 addError(StatusType.FAILURE.name, STEP_PREPARE_ENV, logs.toString())
 289             }
 290         } else {
 291             setNodeOutputProperties(prepareEnvOutput.status, STEP_PREPARE_ENV, logs, prepareEnvOutput.payload, isLogResponseEnabled)
 292         }
 293     }
 294
 295     private suspend fun uploadCba(remoteIdentifier: RemoteIdentifier, requestId: String, subRequestId: String, originatorId: String, archiveType: String?, cbaBinData: ByteString?, cbaNameVerUuid: String, prepareEnvOutput: RemoteScriptExecutionOutput, isLogResponseEnabled: Boolean, logs: JsonNode) {
 296         val uploadCbaInput = RemoteScriptUploadBlueprintInput(
 297             remoteIdentifier = remoteIdentifier,
 298             requestId = requestId,
 299             subRequestId = subRequestId,
 300             originatorId = originatorId,
 301             timeOut = DEFAULT_CBA_UPLOAD_TIMEOUT_IN_SEC.toLong(),
 302             archiveType = archiveType!!,
 303             binData = cbaBinData!!
 304         )
 305
 306         val cbaUploadOutput = remoteScriptExecutionService.uploadBlueprint(uploadCbaInput)
 307         if (cbaUploadOutput.status != StatusType.SUCCESS) {
 308             log.error("Error uploading CBA $cbaNameVerUuid error(${cbaUploadOutput.payload})")
 309             setNodeOutputErrors(STEP_PREPARE_ENV, "[]".asJsonPrimitive(), prepareEnvOutput.payload, isLogResponseEnabled)
 310             addError(StatusType.FAILURE.name, STEP_PREPARE_ENV, logs.toString())
 311         } else {
 312             log.info("Finished uploading CBA $cbaNameVerUuid")
 313         }
 314     }
 315
 316     private fun noBlueprintErrors() =
 317         bluePrintRuntimeService.getBluePrintError().stepErrors(stepName).isNullOrEmpty()
 318
 319     override suspend fun recoverNB(runtimeException: RuntimeException, executionRequest: ExecutionServiceInput) {
 320         addError("Failed in ComponentRemotePythonExecutor : ${runtimeException.message}")
 321     }
 322
 323     private fun formatNestedJsonNode(node: JsonNode): String {
 324         val sb = StringBuilder()
 325         if (node.isValueNode) {
 326             sb.append(" $node")
 327         } else {
 328             node.forEach { sb.append(" $it") }
 329         }
 330         return sb.toString()
 331     }
 332
 333     /**
 334      * Utility function to set the output properties of the executor node
 335      */
 336     private fun setNodeOutputProperties(
 337         status: StatusType,
 338         step: String,
 339         executionLogs: JsonNode,
 340         artifacts: JsonNode,
 341         logging: Boolean = true
 342     ) {
 343
 344         setAttribute(ATTRIBUTE_EXEC_CMD_STATUS, status.name.asJsonPrimitive())
 345         setAttribute(ATTRIBUTE_EXEC_CMD_LOG, executionLogs)
 346         setAttribute(ATTRIBUTE_RESPONSE_DATA, artifacts)
 347
 348         if (logging) {
 349             log.info("Executor status : $step : $status")
 350             log.info("Executor logs   : $step : $executionLogs")
 351             log.info("Executor artifacts: $step : $artifacts")
 352         }
 353     }
 354
 355     /**
 356      * Utility function to set the output properties and errors of the executor node, in case of errors
 357      */
 358     private fun setNodeOutputErrors(
 359         step: String,
 360         executionLogs: JsonNode = "[]".asJsonPrimitive(),
 361         artifacts: JsonNode = "{}".asJsonPrimitive(),
 362         logging: Boolean = true
 363     ) {
 364         val status = StatusType.FAILURE.name
 365         setAttribute(ATTRIBUTE_EXEC_CMD_STATUS, status.asJsonPrimitive())
 366         setAttribute(ATTRIBUTE_EXEC_CMD_LOG, executionLogs)
 367         setAttribute(ATTRIBUTE_RESPONSE_DATA, artifacts)
 368
 369         if (logging) {
 370             log.info("Executor status : $step : $status")
 371             log.info("Executor logs   : $step : $executionLogs")
 372             log.info("Executor artifacts: $step : $artifacts")
 373         }
 374     }
 375 }