Add reactive log tracing service.

Issue-ID: CCSDK-1046
Signed-off-by: Brinda Santh <bs2796@att.com>
Change-Id: Ic20013045dd5d2681243c03f9e4cdfe557b630be

7 files changed, 229 insertions, 24 deletions

diff --git a/ms/blueprintsprocessor/application/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/LoggingWebFilter.kt b/ms/blueprintsprocessor/application/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/LoggingWebFilter.kt
new file mode 100644
index 000000000..5ed5ff450
--- /dev/null
+++ b/ms/blueprintsprocessor/application/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/LoggingWebFilter.kt
@@ -0,0 +1,39 @@
+/*
+ * Copyright © 2018-2019 AT&T Intellectual Property.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.onap.ccsdk.cds.blueprintsprocessor
+
+import org.onap.ccsdk.cds.blueprintsprocessor.core.service.LoggingService
+import org.onap.ccsdk.cds.controllerblueprints.core.MDCContext
+import org.springframework.stereotype.Component
+import org.springframework.web.server.ServerWebExchange
+import org.springframework.web.server.WebFilter
+import org.springframework.web.server.WebFilterChain
+import reactor.core.publisher.Mono
+import reactor.util.context.Context
+
+@Component
+open class LoggingWebFilter : WebFilter {
+    override fun filter(serverWebExchange: ServerWebExchange, webFilterChain: WebFilterChain): Mono<Void> {
+
+        val loggingService = LoggingService()
+        loggingService.entering(serverWebExchange.request)
+        val filterChain = webFilterChain.filter(serverWebExchange).subscriberContext(
+                Context.of(MDCContext,  MDCContext()))
+        loggingService.exiting(serverWebExchange.request, serverWebExchange.response)
+        return filterChain
+    }
+}
\ No newline at end of file
diff --git a/ms/blueprintsprocessor/application/src/main/resources/application-dev.properties b/ms/blueprintsprocessor/application/src/main/resources/application-dev.properties
index e40ccba09..faabb80e7 100755
--- a/ms/blueprintsprocessor/application/src/main/resources/application-dev.properties
+++ b/ms/blueprintsprocessor/application/src/main/resources/application-dev.properties
@@ -36,7 +36,7 @@ blueprintsprocessor.blueprintArchivePath=blueprints/archive
 blueprintsprocessor.blueprintWorkingPath=blueprints/work
 # Controller Blueprint Load Configurations
 # blueprints.load.initial-data may be overridden by ENV variables
-blueprintsprocessor.loadInitialData=true
+blueprintsprocessor.loadInitialData=false
 blueprintsprocessor.loadBluePrint=false
 blueprintsprocessor.loadBluePrintPaths=./../../../components/model-catalog/blueprint-model/service-blueprint
 blueprintsprocessor.loadModelType=true
diff --git a/ms/blueprintsprocessor/application/src/main/resources/logback.xml b/ms/blueprintsprocessor/application/src/main/resources/logback.xml
index 6f917096d..9d2b82f25 100644
--- a/ms/blueprintsprocessor/application/src/main/resources/logback.xml
+++ b/ms/blueprintsprocessor/application/src/main/resources/logback.xml
@@ -15,11 +15,16 @@
   -->
 
 <configuration>
+
+    <property name="localPattern" value="%d{HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n"/>
+    <property name="defaultPattern"
+              value="%date{ISO8601,UTC}|%X{RequestID}|%X{InvocationID}|%thread|%X{ServiceName}|%X{ClientIPAddress}|%logger{50}| %msg%n"/>
+
     <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
         <!-- encoders are assigned the type
              ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
         <encoder>
-            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
+            <pattern>${defaultPattern}</pattern>
         </encoder>
     </appender>
 
diff --git a/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/LoggerExtensions.kt b/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/LoggerExtensions.kt
new file mode 100644
index 000000000..cdf6ce195
--- /dev/null
+++ b/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/LoggerExtensions.kt
@@ -0,0 +1,45 @@
+/*
+ * Copyright © 2018-2019 AT&T Intellectual Property.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.onap.ccsdk.cds.blueprintsprocessor.core
+
+import kotlinx.coroutines.*
+import kotlinx.coroutines.reactor.ReactorContext
+import kotlinx.coroutines.reactor.asCoroutineContext
+import org.onap.ccsdk.cds.blueprintsprocessor.core.service.MonoMDCCoroutine
+import org.onap.ccsdk.cds.controllerblueprints.core.MDCContext
+import reactor.core.publisher.Mono
+import kotlin.coroutines.CoroutineContext
+import kotlin.coroutines.EmptyCoroutineContext
+
+/** Used in Rest controller API methods to populate MDC context to nested coroutines from reactor web filter context. */
+@UseExperimental(InternalCoroutinesApi::class)
+fun <T> monoMdc(context: CoroutineContext = EmptyCoroutineContext,
+                block: suspend CoroutineScope.() -> T?): Mono<T> = Mono.create { sink ->
+
+    val reactorContext = (context[ReactorContext]?.context?.putAll(sink.currentContext())
+            ?: sink.currentContext()).asCoroutineContext()
+    /** Populate MDC context only if present in Reactor Context */
+    val newContext = if (!reactorContext.context.isEmpty
+            && reactorContext.context.hasKey(MDCContext)) {
+        val mdcContext = reactorContext.context.get<MDCContext>(MDCContext)
+        GlobalScope.newCoroutineContext(context + reactorContext + mdcContext)
+    } else GlobalScope.newCoroutineContext(context + reactorContext)
+
+    val coroutine = MonoMDCCoroutine(newContext, sink)
+    sink.onDispose(coroutine)
+    coroutine.start(CoroutineStart.DEFAULT, coroutine, block)
+}
\ No newline at end of file
diff --git a/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/service/BluePrintProcessorLoggingService.kt b/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/service/BluePrintProcessorLoggingService.kt
new file mode 100644
index 000000000..4da7dcd0e
--- /dev/null
+++ b/ms/blueprintsprocessor/modules/commons/processor-core/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/core/service/BluePrintProcessorLoggingService.kt
@@ -0,0 +1,109 @@
+/*
+ * Copyright © 2018-2019 AT&T Intellectual Property.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.onap.ccsdk.cds.blueprintsprocessor.core.service
+
+import kotlinx.coroutines.AbstractCoroutine
+import kotlinx.coroutines.InternalCoroutinesApi
+import kotlinx.coroutines.handleCoroutineException
+import org.onap.ccsdk.cds.controllerblueprints.core.logger
+import org.slf4j.MDC
+import org.springframework.http.server.reactive.ServerHttpRequest
+import org.springframework.http.server.reactive.ServerHttpResponse
+import reactor.core.Disposable
+import reactor.core.publisher.MonoSink
+import java.time.ZoneOffset
+import java.time.ZonedDateTime
+import java.time.format.DateTimeFormatter
+import java.util.*
+import kotlin.coroutines.CoroutineContext
+
+class LoggingService {
+    private val log = logger(LoggingService::class)
+
+    companion object {
+        const val ONAP_REQUEST_ID = "X-ONAP-RequestID"
+        const val ONAP_INVOCATION_ID = "X-ONAP-InvocationID"
+        const val ONAP_PARTNER_NAME = "X-ONAP-PartnerName"
+    }
+
+    fun entering(request: ServerHttpRequest) {
+        val headers = request.headers
+        val requestID = defaultToUUID(headers.getFirst(ONAP_REQUEST_ID))
+        val invocationID = defaultToUUID(headers.getFirst(ONAP_INVOCATION_ID))
+        val partnerName = defaultToEmpty(headers.getFirst(ONAP_PARTNER_NAME))
+        MDC.put("InvokeTimestamp", ZonedDateTime.now(ZoneOffset.UTC).format(DateTimeFormatter.ISO_INSTANT))
+        MDC.put("RequestID", requestID)
+        MDC.put("InvocationID", invocationID)
+        MDC.put("PartnerName", partnerName)
+        MDC.put("ClientIPAddress", defaultToEmpty(request.remoteAddress?.address?.hostAddress))
+        MDC.put("ServerFQDN", defaultToEmpty(request.remoteAddress?.hostString))
+        if (MDC.get("ServiceName") == null || MDC.get("ServiceName").equals("", ignoreCase = true)) {
+            MDC.put("ServiceName", request.uri.path)
+        }
+    }
+
+    fun exiting(request: ServerHttpRequest, response: ServerHttpResponse) {
+        try {
+            val reqHeaders = request.headers
+            val resHeaders = response.headers
+            resHeaders[ONAP_REQUEST_ID] = MDC.get("RequestID")
+            resHeaders[ONAP_INVOCATION_ID] = MDC.get("InvocationID")
+        } catch (e: Exception) {
+            log.warn("couldn't set response headers", e)
+        } finally {
+            MDC.clear()
+        }
+    }
+
+    private fun defaultToEmpty(input: Any?): String {
+        return input?.toString() ?: ""
+    }
+
+    private fun defaultToUUID(input: String?): String {
+        return input ?: UUID.randomUUID().toString()
+    }
+}
+
+
+@InternalCoroutinesApi
+class MonoMDCCoroutine<in T>(
+        parentContext: CoroutineContext,
+        private val sink: MonoSink<T>
+) : AbstractCoroutine<T>(parentContext, true), Disposable {
+    private var disposed = false
+
+    override fun onCompleted(value: T) {
+        if (!disposed) {
+            if (value == null) sink.success() else sink.success(value)
+        }
+    }
+
+    override fun onCancelled(cause: Throwable, handled: Boolean) {
+        if (!disposed) {
+            sink.error(cause)
+        } else if (!handled) {
+            handleCoroutineException(context, cause)
+        }
+    }
+
+    override fun dispose() {
+        disposed = true
+        cancel()
+    }
+
+    override fun isDisposed(): Boolean = disposed
+}
diff --git a/ms/blueprintsprocessor/modules/inbounds/designer-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/designer/api/BlueprintModelController.kt b/ms/blueprintsprocessor/modules/inbounds/designer-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/designer/api/BlueprintModelController.kt
index 4d13486c3..a6bff7051 100644
--- a/ms/blueprintsprocessor/modules/inbounds/designer-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/designer/api/BlueprintModelController.kt
+++ b/ms/blueprintsprocessor/modules/inbounds/designer-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/designer/api/BlueprintModelController.kt
@@ -19,7 +19,7 @@ package org.onap.ccsdk.cds.blueprintsprocessor.designer.api
 
 import io.swagger.annotations.ApiOperation
 import io.swagger.annotations.ApiParam
-import kotlinx.coroutines.runBlocking
+import org.onap.ccsdk.cds.blueprintsprocessor.core.monoMdc
 import org.onap.ccsdk.cds.blueprintsprocessor.db.primary.domain.BlueprintModelSearch
 import org.onap.ccsdk.cds.blueprintsprocessor.designer.api.handler.BluePrintModelHandler
 import org.onap.ccsdk.cds.controllerblueprints.core.BluePrintException
@@ -29,6 +29,7 @@ import org.springframework.http.ResponseEntity
 import org.springframework.http.codec.multipart.FilePart
 import org.springframework.security.access.prepost.PreAuthorize
 import org.springframework.web.bind.annotation.*
+import reactor.core.publisher.Mono
 
 /**
  * BlueprintModelController Purpose: Handle controllerBlueprint API request
@@ -44,7 +45,7 @@ open class BlueprintModelController(private val bluePrintModelHandler: BluePrint
     @ResponseBody
     @Throws(BluePrintException::class)
     @PreAuthorize("hasRole('USER')")
-    fun saveBlueprint(@RequestPart("file") filePart: FilePart): BlueprintModelSearch = runBlocking {
+    fun saveBlueprint(@RequestPart("file") filePart: FilePart): Mono<BlueprintModelSearch> = monoMdc {
         bluePrintModelHandler.saveBlueprintModel(filePart)
     }
 
@@ -67,8 +68,9 @@ open class BlueprintModelController(private val bluePrintModelHandler: BluePrint
     @Throws(BluePrintException::class)
     @PreAuthorize("hasRole('USER')")
     fun getBlueprintByNameAndVersion(@PathVariable(value = "name") name: String,
-                                     @PathVariable(value = "version") version: String): BlueprintModelSearch {
-        return this.bluePrintModelHandler.getBlueprintModelSearchByNameAndVersion(name, version)
+                                     @PathVariable(value = "version") version: String)
+            : Mono<BlueprintModelSearch> = monoMdc {
+        bluePrintModelHandler.getBlueprintModelSearchByNameAndVersion(name, version)
     }
 
     @GetMapping("/download/by-name/{name}/version/{version}", produces = [MediaType.APPLICATION_JSON_VALUE])
@@ -76,8 +78,9 @@ open class BlueprintModelController(private val bluePrintModelHandler: BluePrint
     @Throws(BluePrintException::class)
     @PreAuthorize("hasRole('USER')")
     fun downloadBlueprintByNameAndVersion(@PathVariable(value = "name") name: String,
-                                          @PathVariable(value = "version") version: String): ResponseEntity<Resource> {
-        return this.bluePrintModelHandler.downloadBlueprintModelFileByNameAndVersion(name, version)
+                                          @PathVariable(value = "version") version: String)
+            : Mono<ResponseEntity<Resource>> = monoMdc {
+        bluePrintModelHandler.downloadBlueprintModelFileByNameAndVersion(name, version)
     }
 
     @GetMapping("/{id}", produces = [MediaType.APPLICATION_JSON_VALUE])
@@ -92,8 +95,8 @@ open class BlueprintModelController(private val bluePrintModelHandler: BluePrint
     @ResponseBody
     @Throws(BluePrintException::class)
     @PreAuthorize("hasRole('USER')")
-    fun downloadBluePrint(@PathVariable(value = "id") id: String): ResponseEntity<Resource> {
-        return this.bluePrintModelHandler.downloadBlueprintModelFile(id)
+    fun downloadBluePrint(@PathVariable(value = "id") id: String): Mono<ResponseEntity<Resource>> = monoMdc {
+        bluePrintModelHandler.downloadBlueprintModelFile(id)
     }
 
     @PostMapping("/enrich", produces = [MediaType.APPLICATION_JSON_VALUE], consumes = [MediaType
@@ -101,7 +104,7 @@ open class BlueprintModelController(private val bluePrintModelHandler: BluePrint
     @ResponseBody
     @Throws(BluePrintException::class)
     @PreAuthorize("hasRole('USER')")
-    fun enrichBlueprint(@RequestPart("file") file: FilePart): ResponseEntity<Resource> = runBlocking {
+    fun enrichBlueprint(@RequestPart("file") file: FilePart): Mono<ResponseEntity<Resource>> = monoMdc {
         bluePrintModelHandler.enrichBlueprint(file)
     }
 
@@ -109,7 +112,7 @@ open class BlueprintModelController(private val bluePrintModelHandler: BluePrint
     @ResponseBody
     @Throws(BluePrintException::class)
     @PreAuthorize("hasRole('USER')")
-    fun publishBlueprint(@RequestPart("file") file: FilePart): BlueprintModelSearch = runBlocking {
+    fun publishBlueprint(@RequestPart("file") file: FilePart): Mono<BlueprintModelSearch> = monoMdc {
         bluePrintModelHandler.publishBlueprint(file)
     }
 
@@ -128,7 +131,7 @@ open class BlueprintModelController(private val bluePrintModelHandler: BluePrint
     fun deleteBlueprint(@ApiParam(value = "Name of the CBA.", required = true)
                         @PathVariable(value = "name") name: String,
                         @ApiParam(value = "Version of the CBA.", required = true)
-                        @PathVariable(value = "version") version: String) = runBlocking {
+                        @PathVariable(value = "version") version: String) = monoMdc {
         bluePrintModelHandler.deleteBlueprintModel(name, version)
     }
 }
diff --git a/ms/blueprintsprocessor/modules/inbounds/selfservice-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/selfservice/api/ExecutionServiceController.kt b/ms/blueprintsprocessor/modules/inbounds/selfservice-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/selfservice/api/ExecutionServiceController.kt
index 4441d2b4b..f14f61e60 100644
--- a/ms/blueprintsprocessor/modules/inbounds/selfservice-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/selfservice/api/ExecutionServiceController.kt
+++ b/ms/blueprintsprocessor/modules/inbounds/selfservice-api/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/selfservice/api/ExecutionServiceController.kt
@@ -17,27 +17,29 @@
 
 package org.onap.ccsdk.cds.blueprintsprocessor.selfservice.api
 
-import com.fasterxml.jackson.databind.JsonNode
 import io.swagger.annotations.Api
 import io.swagger.annotations.ApiOperation
 import io.swagger.annotations.ApiParam
-import kotlinx.coroutines.runBlocking
 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.ACTION_MODE_ASYNC
 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.ExecutionServiceInput
 import org.onap.ccsdk.cds.blueprintsprocessor.core.api.data.ExecutionServiceOutput
+import org.onap.ccsdk.cds.blueprintsprocessor.core.monoMdc
 import org.onap.ccsdk.cds.blueprintsprocessor.selfservice.api.utils.determineHttpStatusCode
 import org.onap.ccsdk.cds.controllerblueprints.core.asJsonPrimitive
+import org.onap.ccsdk.cds.controllerblueprints.core.logger
 import org.springframework.beans.factory.annotation.Autowired
 import org.springframework.http.MediaType
 import org.springframework.http.ResponseEntity
 import org.springframework.security.access.prepost.PreAuthorize
 import org.springframework.web.bind.annotation.*
+import reactor.core.publisher.Mono
 
 @RestController
 @RequestMapping("/api/v1/execution-service")
 @Api(value = "/api/v1/execution-service",
         description = "Interaction with CBA.")
 open class ExecutionServiceController {
+    val log = logger(ExecutionServiceController::class)
 
     @Autowired
     lateinit var executionServiceHandler: ExecutionServiceHandler
@@ -47,7 +49,8 @@ open class ExecutionServiceController {
             produces = [MediaType.APPLICATION_JSON_VALUE])
     @ResponseBody
     @ApiOperation(value = "Health Check", hidden = true)
-    fun executionServiceControllerHealthCheck(): JsonNode = runBlocking {
+    fun executionServiceControllerHealthCheck() = monoMdc {
+        log.info("Health check success...")
         "Success".asJsonPrimitive()
     }
 
@@ -59,12 +62,13 @@ open class ExecutionServiceController {
     @ResponseBody
     @PreAuthorize("hasRole('USER')")
     fun process(@ApiParam(value = "ExecutionServiceInput payload.", required = true)
-                @RequestBody executionServiceInput: ExecutionServiceInput): ResponseEntity<ExecutionServiceOutput> =
-            runBlocking {
-                if (executionServiceInput.actionIdentifiers.mode == ACTION_MODE_ASYNC) {
-                    throw IllegalStateException("Can't process async request through the REST endpoint. Use gRPC for async processing.")
-                }
-                val processResult = executionServiceHandler.doProcess(executionServiceInput)
-                ResponseEntity(processResult, determineHttpStatusCode(processResult.status.code))
-            }
+                @RequestBody executionServiceInput: ExecutionServiceInput)
+            : Mono<ResponseEntity<ExecutionServiceOutput>> = monoMdc {
+
+        if (executionServiceInput.actionIdentifiers.mode == ACTION_MODE_ASYNC) {
+            throw IllegalStateException("Can't process async request through the REST endpoint. Use gRPC for async processing.")
+        }
+        val processResult = executionServiceHandler.doProcess(executionServiceInput)
+        ResponseEntity(processResult, determineHttpStatusCode(processResult.status.code))
+    }
 }