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 bc91b7d92..06a71cad3 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
@@ -195,7 +195,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 6a045e365..2e33b9aa2 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
@@ -38,15 +38,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
     }
@@ -60,7 +81,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
     }
@@ -74,7 +96,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
     }
@@ -89,7 +112,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
     }
@@ -104,7 +128,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
@@ -120,7 +145,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
     }
@@ -134,7 +160,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
     }
@@ -148,7 +175,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
     }
@@ -163,7 +191,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
     }
@@ -180,7 +209,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
     }
@@ -194,7 +224,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
     }
@@ -208,7 +239,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
     }
@@ -220,7 +252,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 a0f653591..83622d41e 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
@@ -241,6 +241,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 4d65d36bb..34816b79b 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
@@ -221,7 +221,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/>")
             } else {
@@ -413,4 +421,4 @@ class NetconfMessageUtils {
         }
     }
 
-}
\ No newline at end of file
+}