netconf lib bugfixes: invoke_rpc + timeouts.

Issue-ID: CCSDK-1886

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

5 files changed, 64 insertions, 21 deletions

diff --git a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/api/DeviceInfo.kt b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/api/DeviceInfo.kt
index f5567b7a2..2395dddb8 100644
--- a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/api/DeviceInfo.kt
+++ b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/api/DeviceInfo.kt
@@ -29,11 +29,11 @@ class DeviceInfo {
     @get:JsonProperty("port-number")
     var port: Int = 0
     @get:JsonProperty("connection-time-out")
-    var connectTimeout: Long = 5
+    var connectTimeout: Long = 30
     @get:JsonIgnore
     var source: String? = null
     @get:JsonIgnore
-    var replyTimeout: Int = 5
+    var replyTimeout: Int = 20
     @get:JsonIgnore
     var idleTimeout: Int = 99999
 
@@ -50,4 +50,4 @@ class DeviceInfo {
     override fun hashCode(): Int {
         return javaClass.hashCode()
     }
-}
\ No newline at end of file
+}
diff --git a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfDeviceCommunicator.kt b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfDeviceCommunicator.kt
index aa156e2a8..9bd7297c7 100644
--- a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfDeviceCommunicator.kt
+++ b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfDeviceCommunicator.kt
@@ -201,7 +201,7 @@ class NetconfDeviceCommunicator(private var inputStream: InputStream,
     }
 
     fun sendMessage(request: String, messageId: String): CompletableFuture<String> {
-        log.info("$deviceInfo: Sending message: \n $request")
+        log.info("$deviceInfo: Sending message with message-id: $messageId: message: \n $request")
         val future = CompletableFuture<String>()
         replies.put(messageId, future)
         val outputStream = OutputStreamWriter(out, StandardCharsets.UTF_8)
diff --git a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfRpcServiceImpl.kt b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfRpcServiceImpl.kt
index 6fa167a95..f13e08b3f 100644
--- a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfRpcServiceImpl.kt
+++ b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfRpcServiceImpl.kt
@@ -42,15 +42,36 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
         this.netconfSession = netconfSession
     }
 
+    /**
+     * accept a user-supplied RPC message WITH HEADER
+     * <rpc message-id="abc123" xmlns=".....">
+     *     .....
+     *     .....
+     * </rpc>
+     *
+     * and replace the user-supplied message-id with the one that is passed.
+     * Used by NetconfRpcServiceImpl.invokeRpc to keep the message-id consistent
+     * with auto-incremented numbering scheme.
+     * @param rpc: Complete custom RPC call including the header
+     * @param updatedMessageID new message-id to substitute
+     * @return updated RPC message with message-id replaced.
+     */
+    private fun replaceUserSuppliedNetconfMessageID(rpc: String, updatedMessageID: String): String {
+        return rpc.replaceFirst("message-id=\".+\"".toRegex(), "message-id=\"$updatedMessageID\"")
+    }
+
     override fun invokeRpc(rpc: String): DeviceResponse {
         var output = DeviceResponse()
-        val messageId = messageIdInteger.getAndIncrement().toString()
-        log.info("$deviceInfo: invokeRpc: messageId($messageId)")
+        //Attempt to extract the message-id field from the <rpc call
+        val updatedMessageId = messageIdInteger.getAndIncrement().toString()
+        val origMessageId = NetconfMessageUtils.getMsgId(rpc)
+        log.info("$deviceInfo: invokeRpc: updating rpc original message-id:($origMessageId) to messageId($updatedMessageId)")
         try {
-            output = asyncRpc(rpc, messageId)
+            output = asyncRpc(replaceUserSuppliedNetconfMessageID(rpc, updatedMessageId), updatedMessageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'invokeRpc' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'invokeRpc' command. Message: ${e.message}."
+            log.error("$deviceInfo: failed in 'invokeRpc' command. Exception: $e")
         }
         return output
     }
@@ -64,7 +85,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(message, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'get' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'get' command. Message: ${e.message}..."
+            log.error("$deviceInfo: failed in 'get' command. Exception: $e")
         }
         return output
     }
@@ -78,7 +100,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(message, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'get-config' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'get-config' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'get-config' command. Exception: $e")
         }
         return output
     }
@@ -93,7 +116,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(deleteConfigMessage, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'delete-config' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'delete-config' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'deleteConfig' command. Exception: $e")
         }
         return output
     }
@@ -108,7 +132,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(lockMessage, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'lock' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'lock' command. Message ${e.message}"
+            log.error("$deviceInfo: failed in 'lock' command. Exception: $e")
         }
 
         return output
@@ -124,7 +149,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(unlockMessage, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'unLock' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'unLock' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'unLock' command. Exception: $e")
         }
         return output
     }
@@ -138,7 +164,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(messageContent, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'commit' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'commit' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'commit' command. Exception: $e")
         }
         return output
     }
@@ -152,7 +179,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(messageContent, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'cancelCommit' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'cancelCommit' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'cancelCommit' command. Exception: $e")
         }
         return output
     }
@@ -167,7 +195,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(discardChangesMessage, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'discard-config' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'discard-config' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'discard-config' command. Exception: $e")
         }
         return output
     }
@@ -184,7 +213,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             response = asyncRpc(editMessage, messageId)
         } catch (e: Exception) {
             response.status = RpcStatus.FAILURE
-            response.errorMessage = "$deviceInfo: failed in 'editConfig' command ${e.message}"
+            response.errorMessage = "$deviceInfo: failed in 'editConfig' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'editConfig' command. Exception: $e")
         }
         return response
     }
@@ -198,7 +228,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(validateMessage, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'validate' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'validate' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'validate' command. Exception: $e")
         }
         return output
     }
@@ -212,7 +243,8 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
             output = asyncRpc(messageContent, messageId)
         } catch (e: Exception) {
             output.status = RpcStatus.FAILURE
-            output.errorMessage = "$deviceInfo: failed in 'closeSession' command ${e.message}"
+            output.errorMessage = "$deviceInfo: failed in 'closeSession' command. Message: ${e.message}"
+            log.error("$deviceInfo: failed in 'closeSession' command. Exception: $e")
         }
         return output
     }
@@ -224,7 +256,9 @@ class NetconfRpcServiceImpl(private var deviceInfo: DeviceInfo) : NetconfRpcServ
         response.requestMessage = request
 
         val rpcResponse = netconfSession.asyncRpc(request, messageId).get(responseTimeout.toLong(), TimeUnit.SECONDS)
+        //TODO catch TimeoutException and ExecutionException
         if (!NetconfMessageUtils.checkReply(rpcResponse)) {
+            log.error("RPC response didn't pass validation... $rpcResponse")
             throw NetconfException(rpcResponse)
         }
         response.responseMessage = rpcResponse
diff --git a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfSessionImpl.kt b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfSessionImpl.kt
index 4daaceeff..03f20080c 100644
--- a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfSessionImpl.kt
+++ b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/core/NetconfSessionImpl.kt
@@ -251,6 +251,7 @@ class NetconfSessionImpl(private val deviceInfo: DeviceInfo, private val rpcServ
 
         if (sessionIDMatcher.find()) {
             sessionId = sessionIDMatcher.group(1)
+            log.info("netconf exchangeHelloMessage sessionID: $sessionId")
         } else {
             throw NetconfException("$deviceInfo: Missing sessionId in server hello message: $serverHelloResponse")
         }
diff --git a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/utils/NetconfMessageUtils.kt b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/utils/NetconfMessageUtils.kt
index 37ff67433..2fa310538 100644
--- a/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/utils/NetconfMessageUtils.kt
+++ b/ms/blueprintsprocessor/functions/netconf-executor/src/main/kotlin/org/onap/ccsdk/cds/blueprintsprocessor/functions/netconf/executor/utils/NetconfMessageUtils.kt
@@ -224,7 +224,15 @@ class NetconfMessageUtils {
 
         fun closeSession(messageId: String, force: Boolean): String {
             val request = StringBuilder()
-
+            //TODO: kill-session without session-id is a cisco-only variant.
+            //will fail on JUNIPER device.
+            //netconf RFC for kill-session requires session-id
+            //Cisco can accept <kill-session/> for current session
+            //or <kill-session><session-id>####</session-id></kill-session>
+            //as long as session ID is not the same as the current session.
+
+            //Juniperhttps://www.juniper.net/documentation/en_US/junos/topics/task/operational/netconf-session-terminating.html
+            //will accept only with session-id
             if (force) {
                 request.append("<kill-session/>").append(NEW_LINE)
             } else {
@@ -416,4 +424,4 @@ class NetconfMessageUtils {
         }
     }
 
-}
\ No newline at end of file
+}