netconf-pnp-simulator: enable NETCONF send/recv message logging

to aid troubleshooting integration with OpenDaylight

- Add more integration tests
- Defaults to generic subscriber

Issue-ID: INT-1516
Change-Id: Ib5bbf4cdbba6cdfee901f6c07dfa195a21cd8bbb
Signed-off-by: ebo <eliezio.oliveira@est.tech>

19 files changed, 714 insertions, 71 deletions

diff --git a/test/mocks/netconf-pnp-simulator/engine/Dockerfile b/test/mocks/netconf-pnp-simulator/engine/Dockerfile
index a3f8b6ac4..9eec0baa7 100644
--- a/test/mocks/netconf-pnp-simulator/engine/Dockerfile
+++ b/test/mocks/netconf-pnp-simulator/engine/Dockerfile
@@ -189,9 +189,9 @@ RUN mkdir /etc/supervisord.d
 COPY zlog.conf /opt/etc/
 
 # Sensible defaults for loguru configuration
-ENV LOGURU_FORMAT="<green>{time:YYYY-DD-MM HH:mm:ss.SSS}</green> {level: <5} [mynetconf] <lvl>{message}</lvl>"
+ENV LOGURU_FORMAT="<green>{time:YYYY-DD-MM HH:mm:ss.SSS}</green> {level: <5} [{module}] <lvl>{message}</lvl>"
 ENV LOGURU_COLORIZE=True
 
-COPY entrypoint.sh common.sh configure-*.sh reconfigure-*.sh /opt/bin/
+COPY entrypoint.sh common.sh configure-*.sh reconfigure-*.sh generic_subscriber.py /opt/bin/
 
 CMD /opt/bin/entrypoint.sh
diff --git a/test/mocks/netconf-pnp-simulator/engine/common.sh b/test/mocks/netconf-pnp-simulator/engine/common.sh
index 6e938e7f5..961d51f9b 100644
--- a/test/mocks/netconf-pnp-simulator/engine/common.sh
+++ b/test/mocks/netconf-pnp-simulator/engine/common.sh
@@ -32,6 +32,9 @@ TEMPLATES=/templates
 PROC_NAME=${0##*/}
 PROC_NAME=${PROC_NAME%.sh}
 
+WORKDIR=$(mktemp -d)
+trap "rm -rf $WORKDIR" EXIT
+
 function now_ms() {
     # Requires coreutils package
     date +"%Y-%m-%d %H:%M:%S.%3N"
@@ -57,10 +60,16 @@ find_file() {
 
 
 # Extracts the body of a PEM file by removing the dashed header and footer
-pem_body() {
-    grep -Fv -- ----- "$1"
-}
+alias pem_body='grep -Fv -- -----'
+
 
+kill_service() {
+    local service=$1
+
+    pid=$(cat /var/run/${service}.pid)
+    log INFO Killing $service pid=$pid
+    kill $pid
+}
 
 # ------------------------------------
 # SSH Common Definitions and Functions
@@ -83,7 +92,7 @@ configure_ssh() {
         --update '//_:name[text()="netconf"]/following-sibling::_:authorized-key/_:name' --value "$name" \
         --update '//_:name[text()="netconf"]/following-sibling::_:authorized-key/_:algorithm' --value "$1" \
         --update '//_:name[text()="netconf"]/following-sibling::_:authorized-key/_:key-data' --value "$2" \
-        $dir/load_auth_pubkey.xml | \
+        $dir/ietf-system.xml | \
     sysrepocfg --datastore=$datastore --permanent --format=xml ietf-system --${operation}=-
 }
 
@@ -109,13 +118,13 @@ configure_tls() {
     xmlstarlet ed --pf --omit-decl \
         --update '//_:name[text()="server_cert"]/following-sibling::_:certificate' --value "$server_cert" \
         --update '//_:name[text()="ca"]/following-sibling::_:certificate' --value "$ca_cert" \
-        $dir/load_server_certs.xml | \
+        $dir/ietf-keystore.xml | \
     sysrepocfg --datastore=$datastore --permanent --format=xml ietf-keystore --${operation}=-
 
     log INFO Configure TLS ingress service
     ca_fingerprint=$(openssl x509 -noout -fingerprint -in $TLS_CONFIG/ca.pem | cut -d= -f2)
     xmlstarlet ed --pf --omit-decl \
         --update '//_:name[text()="netconf"]/preceding-sibling::_:fingerprint' --value "02:$ca_fingerprint" \
-        $dir/tls_listen.xml | \
+        $dir/ietf-netconf-server.xml | \
     sysrepocfg --datastore=$datastore --permanent --format=xml ietf-netconf-server --${operation}=-
 }
diff --git a/test/mocks/netconf-pnp-simulator/engine/config/modules/.gitkeep b/test/mocks/netconf-pnp-simulator/engine/config/modules/.gitkeep
deleted file mode 100644
index e69de29bb..000000000
--- a/test/mocks/netconf-pnp-simulator/engine/config/modules/.gitkeep
+++ /dev/null
diff --git a/test/mocks/netconf-pnp-simulator/engine/config/modules/turing-machine/startup.xml b/test/mocks/netconf-pnp-simulator/engine/config/modules/turing-machine/startup.xml
new file mode 100644
index 000000000..453b3accf
--- /dev/null
+++ b/test/mocks/netconf-pnp-simulator/engine/config/modules/turing-machine/startup.xml
@@ -0,0 +1,72 @@
+<turing-machine xmlns="http://example.net/turing-machine">
+  <transition-function>
+    <delta>
+      <label>left summand</label>
+      <input>
+        <state>0</state>
+        <symbol>1</symbol>
+      </input>
+    </delta>
+    <delta>
+      <label>separator</label>
+      <input>
+        <state>0</state>
+        <symbol>0</symbol>
+      </input>
+      <output>
+        <state>1</state>
+        <symbol>1</symbol>
+      </output>
+    </delta>
+    <delta>
+      <label>right summand</label>
+      <input>
+        <state>1</state>
+        <symbol>1</symbol>
+      </input>
+    </delta>
+    <delta>
+      <label>right end</label>
+      <input>
+        <state>1</state>
+        <symbol/>
+      </input>
+      <output>
+        <state>2</state>
+        <head-move>left</head-move>
+      </output>
+    </delta>
+    <delta>
+      <label>write separator</label>
+      <input>
+        <state>2</state>
+        <symbol>1</symbol>
+      </input>
+      <output>
+        <state>3</state>
+        <symbol>0</symbol>
+        <head-move>left</head-move>
+      </output>
+    </delta>
+    <delta>
+      <label>go home</label>
+      <input>
+        <state>3</state>
+        <symbol>1</symbol>
+      </input>
+      <output>
+        <head-move>left</head-move>
+      </output>
+    </delta>
+    <delta>
+      <label>final step</label>
+      <input>
+        <state>3</state>
+        <symbol/>
+      </input>
+      <output>
+        <state>4</state>
+      </output>
+    </delta>
+  </transition-function>
+</turing-machine>
diff --git a/test/mocks/netconf-pnp-simulator/engine/config/modules/turing-machine/turing-machine.yang b/test/mocks/netconf-pnp-simulator/engine/config/modules/turing-machine/turing-machine.yang
new file mode 100644
index 000000000..abd6794b0
--- /dev/null
+++ b/test/mocks/netconf-pnp-simulator/engine/config/modules/turing-machine/turing-machine.yang
@@ -0,0 +1,262 @@
+module turing-machine {
+
+  namespace "http://example.net/turing-machine";
+
+  prefix "tm";
+
+  description
+    "Data model for the Turing Machine.";
+
+  revision 2013-12-27 {
+    description
+      "Initial revision.";
+  }
+
+  /* Typedefs */
+
+  typedef tape-symbol {
+    type string {
+      length "0..1";
+    }
+    description
+      "Type of symbols appearing in tape cells.
+
+       A blank is represented as an empty string where necessary.";
+  }
+
+  typedef cell-index {
+    type int64;
+    description
+      "Type for indexing tape cells.";
+  }
+
+  typedef state-index {
+    type uint16;
+    description
+      "Type for indexing states of the control unit.";
+  }
+
+  typedef head-dir {
+    type enumeration {
+      enum left;
+      enum right;
+    }
+    default "right";
+    description
+      "Possible directions for moving the read/write head, one cell
+       to the left or right (default).";
+  }
+
+  /* Groupings */
+
+  grouping tape-cells {
+    description
+      "The tape of the Turing Machine is represented as a sparse
+       array.";
+    list cell {
+      key "coord";
+      description
+        "List of non-blank cells.";
+      leaf coord {
+        type cell-index;
+        description
+          "Coordinate (index) of the tape cell.";
+      }
+      leaf symbol {
+        type tape-symbol {
+          length "1";
+        }
+        description
+          "Symbol appearing in the tape cell.
+
+           Blank (empty string) is not allowed here because the
+           'cell' list only contains non-blank cells.";
+      }
+    }
+  }
+
+  /* State data and Configuration */
+
+  container turing-machine {
+    description
+      "State data and configuration of a Turing Machine.";
+    leaf state {
+      type state-index;
+      config "false";
+      mandatory "true";
+      description
+        "Current state of the control unit.
+
+         The initial state is 0.";
+    }
+    leaf head-position {
+      type cell-index;
+      config "false";
+      mandatory "true";
+      description
+        "Position of tape read/write head.";
+    }
+    container tape {
+      config "false";
+      description
+        "The contents of the tape.";
+      uses tape-cells;
+    }
+    container transition-function {
+      description
+        "The Turing Machine is configured by specifying the
+         transition function.";
+      list delta {
+        key "label";
+        unique "input/state input/symbol";
+        description
+          "The list of transition rules.";
+        leaf label {
+          type string;
+          description
+            "An arbitrary label of the transition rule.";
+        }
+        container input {
+          description
+            "Input parameters (arguments) of the transition rule.";
+          leaf state {
+            type state-index;
+            mandatory "true";
+            description
+              "Current state of the control unit.";
+          }
+          leaf symbol {
+            type tape-symbol;
+            mandatory "true";
+            description
+              "Symbol read from the tape cell.";
+          }
+        }
+        container output {
+          description
+            "Output values of the transition rule.";
+          leaf state {
+            type state-index;
+            description
+              "New state of the control unit. If this leaf is not
+               present, the state doesn't change.";
+          }
+          leaf symbol {
+            type tape-symbol;
+            description
+              "Symbol to be written to the tape cell. If this leaf is
+               not present, the symbol doesn't change.";
+          }
+          leaf head-move {
+            type head-dir;
+            description
+              "Move the head one cell to the left or right";
+          }
+        }
+      }
+    }
+  }
+
+  /* RPCs */
+
+  rpc initialize {
+    description
+      "Initialize the Turing Machine as follows:
+
+       1. Put the control unit into the initial state (0).
+
+       2. Move the read/write head to the tape cell with coordinate
+          zero.
+
+       3. Write the string from the 'tape-content' input parameter to
+          the tape, character by character, starting at cell 0. The
+          tape is othewise empty.";
+    input {
+      leaf tape-content {
+        type string;
+        default "";
+        description
+          "The string with which the tape shall be initialized. The
+           leftmost symbol will be at tape coordinate 0.";
+      }
+    }
+  }
+
+  rpc run {
+    description
+      "Start the Turing Machine operation.";
+  }
+
+  rpc run-until {
+    description
+      "Start the Turing Machine operation and let it run until it is halted
+       or ALL the defined breakpoint conditions are satisfied.";
+    input {
+      leaf state {
+        type state-index;
+        description
+          "What state the control unit has to be at for the execution to be paused.";
+      }
+      leaf head-position {
+        type cell-index;
+        description
+          "Position of tape read/write head for which the breakpoint applies.";
+      }
+      container tape {
+        description
+          "What content the tape has to have for the breakpoint to apply.";
+        uses tape-cells;
+      }
+    }
+    output {
+      leaf step-count {
+        type uint64;
+        description
+          "The number of steps executed since the last 'run-until' call.";
+      }
+      leaf halted {
+        type boolean;
+        description
+          "'True' if the Turing machine is halted, 'false' if it is only paused.";
+      }
+    }
+  }
+
+  /* Notifications */
+
+  notification halted {
+    description
+      "The Turing Machine has halted. This means that there is no
+       transition rule for the current state and tape symbol.";
+    leaf state {
+      type state-index;
+      mandatory "true";
+      description
+        "The state of the control unit in which the machine has
+         halted.";
+    }
+  }
+
+  notification paused {
+    description
+      "The Turing machine has reached a breakpoint and was paused.";
+    leaf state {
+      type state-index;
+      mandatory "true";
+      description
+        "State of the control unit in which the machine was paused.";
+    }
+    leaf head-position {
+      type cell-index;
+      mandatory "true";
+      description
+        "Position of tape read/write head when the machine was paused.";
+    }
+    container tape {
+      description
+        "Content of the tape when the machine was paused.";
+      uses tape-cells;
+    }
+  }
+}
+
diff --git a/test/mocks/netconf-pnp-simulator/engine/configure-modules.sh b/test/mocks/netconf-pnp-simulator/engine/configure-modules.sh
index 2010b504f..d40918f31 100755
--- a/test/mocks/netconf-pnp-simulator/engine/configure-modules.sh
+++ b/test/mocks/netconf-pnp-simulator/engine/configure-modules.sh
@@ -26,6 +26,7 @@ source $HERE/common.sh
 
 MODELS_CONFIG=$CONFIG/modules
 BASE_VIRTUALENVS=$HOME/.local/share/virtualenvs
+GENERIC_SUBSCRIBER=/opt/bin/generic_subscriber.py
 
 install_and_configure_yang_model()
 {
@@ -54,6 +55,8 @@ configure_subscriber_execution()
     APP_PATH=$env_dir/bin:$APP_PATH
   fi
   log INFO Preparing launching of module \"$model\" application
+  # shellcheck disable=SC2153
+  loguru_format="${LOGURU_FORMAT//\{module\}/$model}"
   cat > /etc/supervisord.d/$model.conf <<EOF
 [program:subs-$model]
 command=$app $model
@@ -61,7 +64,7 @@ stdout_logfile=/dev/stdout
 stdout_logfile_maxbytes=0
 redirect_stderr=true
 autorestart=true
-environment=PATH=$APP_PATH,PYTHONUNBUFFERED="1"
+environment=PATH=$APP_PATH,PYTHONUNBUFFERED="1",LOGURU_FORMAT="$loguru_format"
 EOF
 }
 
@@ -89,7 +92,11 @@ for dir in "$MODELS_CONFIG"/*; do
     install_and_configure_yang_model $dir $model
     app="$dir/subscriber.py"
     if [ -x "$app" ]; then
-      configure_subscriber_execution $dir $model $app
+      log INFO Module $model is using its own subscriber
+    else
+      log WARN Module $model is using the generic subscriber
+      app=$GENERIC_SUBSCRIBER
     fi
+    configure_subscriber_execution $dir $model $app
   fi
 done
diff --git a/test/mocks/netconf-pnp-simulator/engine/container-tag.yaml b/test/mocks/netconf-pnp-simulator/engine/container-tag.yaml
index 75e0ac656..9bd214eca 100644
--- a/test/mocks/netconf-pnp-simulator/engine/container-tag.yaml
+++ b/test/mocks/netconf-pnp-simulator/engine/container-tag.yaml
@@ -1 +1 @@
-tag: "2.8.2"
+tag: "2.8.4"
diff --git a/test/mocks/netconf-pnp-simulator/engine/generic_subscriber.py b/test/mocks/netconf-pnp-simulator/engine/generic_subscriber.py
new file mode 100755
index 000000000..66fd7b6ab
--- /dev/null
+++ b/test/mocks/netconf-pnp-simulator/engine/generic_subscriber.py
@@ -0,0 +1,133 @@
+#!/usr/bin/env python3
+
+__author__ = "Mislav Novakovic <mislav.novakovic@sartura.hr>"
+__copyright__ = "Copyright 2018, Deutsche Telekom AG"
+__license__ = "Apache 2.0"
+
+# 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.
+
+# This sample application demonstrates use of Python programming language bindings for sysrepo library.
+# Original c application was rewritten in Python to show similarities and differences
+# between the two.
+#
+# Most notable difference is in the very different nature of languages, c is weakly statically typed language
+# while Python is strongly dynamically typed. Python code is much easier to read and logic easier to comprehend
+# for smaller scripts. Memory safety is not an issue but lower performance can be expected.
+#
+# The original c implementation is also available in the source, so one can refer to it to evaluate trade-offs.
+
+import sys
+
+import sysrepo as sr
+from loguru import logger
+
+
+# Helper function for printing changes given operation, old and new value.
+def print_change(op, old_val, new_val):
+    if op == sr.SR_OP_CREATED:
+        logger.info(f"CREATED: {new_val.to_string()}")
+    elif op == sr.SR_OP_DELETED:
+        logger.info(f"DELETED: {old_val.to_string()}")
+    elif op == sr.SR_OP_MODIFIED:
+        logger.info(f"MODIFIED: {old_val.to_string()} to {new_val.to_string()}")
+    elif op == sr.SR_OP_MOVED:
+        logger.info(f"MOVED: {new_val.xpath()} after {old_val.xpath()}")
+
+
+# Helper function for printing events.
+def ev_to_str(ev):
+    if ev == sr.SR_EV_VERIFY:
+        return "verify"
+    elif ev == sr.SR_EV_APPLY:
+        return "apply"
+    elif ev == sr.SR_EV_ABORT:
+        return "abort"
+    else:
+        return "unknown"
+
+
+# Function to print current configuration state.
+# It does so by loading all the items of a session and printing them out.
+def print_current_config(session, module_name):
+    select_xpath = f"/{module_name}:*//*"
+
+    values = session.get_items(select_xpath)
+
+    if values is not None:
+        logger.info("========== BEGIN CONFIG ==========")
+        for i in range(values.val_cnt()):
+            logger.info(f"  {values.val(i).to_string().strip()}")
+        logger.info("=========== END CONFIG ===========")
+
+
+# Function to be called for subscribed client of given session whenever configuration changes.
+def module_change_cb(sess, module_name, event, private_ctx):
+    try:
+        logger.info("========== Notification " + ev_to_str(event) + " =============================================")
+        if event == sr.SR_EV_APPLY:
+            print_current_config(sess, module_name)
+
+        logger.info("========== CHANGES: =============================================")
+
+        change_path = f"/{module_name}:*"
+
+        it = sess.get_changes_iter(change_path)
+
+        while True:
+            change = sess.get_change_next(it)
+            if change is None:
+                break
+            print_change(change.oper(), change.old_val(), change.new_val())
+
+        logger.info("========== END OF CHANGES =======================================")
+    except Exception as e:
+        logger.error(e)
+
+    return sr.SR_ERR_OK
+
+
+def main():
+    # Notable difference between c implementation is using exception mechanism for open handling unexpected events.
+    # Here it is useful because `Connection`, `Session` and `Subscribe` could throw an exception.
+    try:
+        module_name = sys.argv[1]
+        logger.info(f"Application will watch for changes in {module_name}")
+
+        # connect to sysrepo
+        conn = sr.Connection(module_name)
+
+        # start session
+        sess = sr.Session(conn)
+
+        # subscribe for changes in running config */
+        subscribe = sr.Subscribe(sess)
+
+        subscribe.module_change_subscribe(module_name, module_change_cb)
+
+        try:
+            print_current_config(sess, module_name)
+        except Exception as e:
+            logger.error(e)
+
+        logger.info("========== STARTUP CONFIG APPLIED AS RUNNING ==========")
+
+        sr.global_loop()
+
+        logger.info("Application exit requested, exiting.")
+
+    except Exception as e:
+        logger.error(e)
+
+
+if __name__ == '__main__':
+    main()
diff --git a/test/mocks/netconf-pnp-simulator/engine/patches/libnetconf2/04-io-log.patch b/test/mocks/netconf-pnp-simulator/engine/patches/libnetconf2/04-io-log.patch
new file mode 100644
index 000000000..8c83e4b15
--- /dev/null
+++ b/test/mocks/netconf-pnp-simulator/engine/patches/libnetconf2/04-io-log.patch
@@ -0,0 +1,27 @@
+diff --git a/src/io.c b/src/io.c
+index 9c4fa9f..830fc9a 100644
+--- a/src/io.c
++++ b/src/io.c
+@@ -432,7 +432,7 @@ nc_read_msg_io(struct nc_session *session, int io_timeout, struct lyxml_elem **d
+     nc_session_io_unlock(session, __func__);
+     io_locked = 0;
+ 
+-    DBG("Session %u: received message:\n%s\n", session->id, msg);
++    VRB("Session %u: received message:\n%s", session->id, msg);
+ 
+     /* build XML tree */
+     *data = lyxml_parse_mem(session->ctx, msg, 0);
+@@ -718,7 +718,7 @@ nc_write(struct nc_session *session, const void *buf, size_t count)
+         return -1;
+     }
+ 
+-    DBG("Session %u: sending message:\n%.*s\n", session->id, count, buf);
++    VRB("Session %u: sending message:\n%.*s", session->id, count, buf);
+ 
+     do {
+         switch (session->ti_type) {
+@@ -1346,4 +1346,3 @@ nc_realloc(void *ptr, size_t size)
+ 
+     return ret;
+ }
+-
diff --git a/test/mocks/netconf-pnp-simulator/engine/reconfigure-ssh.sh b/test/mocks/netconf-pnp-simulator/engine/reconfigure-ssh.sh
index 2634dc116..7d3863340 100755
--- a/test/mocks/netconf-pnp-simulator/engine/reconfigure-ssh.sh
+++ b/test/mocks/netconf-pnp-simulator/engine/reconfigure-ssh.sh
@@ -26,12 +26,7 @@ source $HERE/common.sh
 
 SSH_CONFIG=$CONFIG/ssh
 
-WORKDIR=$(mktemp -d)
-trap "rm -rf $WORKDIR" EXIT
-
-sysrepocfg --format=xml --export=$WORKDIR/load_auth_pubkey.xml ietf-system
+sysrepocfg --format=xml --export=$WORKDIR/ietf-system.xml ietf-system
 configure_ssh running import $WORKDIR
 
-pid=$(cat /var/run/netopeer2-server.pid)
-log INFO Restart Netopeer2 pid=$pid
-kill $pid
+kill_service netopeer2-server
diff --git a/test/mocks/netconf-pnp-simulator/engine/reconfigure-tls.sh b/test/mocks/netconf-pnp-simulator/engine/reconfigure-tls.sh
index 6c97064ee..10f32873a 100755
--- a/test/mocks/netconf-pnp-simulator/engine/reconfigure-tls.sh
+++ b/test/mocks/netconf-pnp-simulator/engine/reconfigure-tls.sh
@@ -24,13 +24,8 @@ set -eu
 HERE=${0%/*}
 source $HERE/common.sh
 
-WORKDIR=$(mktemp -d)
-trap "rm -rf $WORKDIR" EXIT
-
-sysrepocfg --format=xml --export=$WORKDIR/load_server_certs.xml ietf-keystore
-sysrepocfg --format=xml --export=$WORKDIR/tls_listen.xml ietf-netconf-server
+sysrepocfg --format=xml --export=$WORKDIR/ietf-keystore.xml ietf-keystore
+sysrepocfg --format=xml --export=$WORKDIR/ietf-netconf-server.xml ietf-netconf-server
 configure_tls running import $WORKDIR
 
-pid=$(cat /var/run/netopeer2-server.pid)
-log INFO Restart Netopeer2 pid=$pid
-kill $pid
+kill_service netopeer2-server
diff --git a/test/mocks/netconf-pnp-simulator/engine/templates/load_server_certs.xml b/test/mocks/netconf-pnp-simulator/engine/templates/ietf-keystore.xml
index ef02dedef..ef02dedef 100644
--- a/test/mocks/netconf-pnp-simulator/engine/templates/load_server_certs.xml
+++ b/test/mocks/netconf-pnp-simulator/engine/templates/ietf-keystore.xml
diff --git a/test/mocks/netconf-pnp-simulator/engine/templates/tls_listen.xml b/test/mocks/netconf-pnp-simulator/engine/templates/ietf-netconf-server.xml
index a6b6bedb1..a6b6bedb1 100644
--- a/test/mocks/netconf-pnp-simulator/engine/templates/tls_listen.xml
+++ b/test/mocks/netconf-pnp-simulator/engine/templates/ietf-netconf-server.xml
diff --git a/test/mocks/netconf-pnp-simulator/engine/templates/load_auth_pubkey.xml b/test/mocks/netconf-pnp-simulator/engine/templates/ietf-system.xml
index 93b662f02..93b662f02 100644
--- a/test/mocks/netconf-pnp-simulator/engine/templates/load_auth_pubkey.xml
+++ b/test/mocks/netconf-pnp-simulator/engine/templates/ietf-system.xml
diff --git a/test/mocks/netconf-pnp-simulator/engine/tests/nctest.py b/test/mocks/netconf-pnp-simulator/engine/tests/nctest.py
index 2f848c361..11ff6ffc4 100644
--- a/test/mocks/netconf-pnp-simulator/engine/tests/nctest.py
+++ b/test/mocks/netconf-pnp-simulator/engine/tests/nctest.py
@@ -1,11 +1,41 @@
+import logging.config
+
 from ncclient import manager, operations
+
 import settings
-import unittest
 
-class NCTestCase(unittest.TestCase):
+LOGGER = logging.getLogger(__name__)
+
+
+def check_reply_ok(reply):
+    assert reply is not None
+    _log_netconf_msg("Received", reply.xml)
+    assert reply.ok is True
+    assert reply.error is None
+
+
+def check_reply_err(reply):
+    assert reply is not None
+    _log_netconf_msg("Received", reply.xml)
+    assert reply.ok is False
+    assert reply.error is not None
+
+
+def check_reply_data(reply):
+    check_reply_ok(reply)
+
+
+def _log_netconf_msg(header: str, body: str):
+    """Log a message using a format inspired by NETCONF 1.1 """
+    LOGGER.info("%s:\n\n#%d\n%s\n##", header, len(body), body)
+
+
+class NCTestCase:
     """ Base class for NETCONF test cases. Provides a NETCONF connection and some helper methods. """
 
-    def setUp(self):
+    nc: manager.Manager
+
+    def setup(self):
         self.nc = manager.connect(
             host=settings.HOST,
             port=settings.PORT,
@@ -16,22 +46,5 @@ class NCTestCase(unittest.TestCase):
             hostkey_verify=False)
         self.nc.raise_mode = operations.RaiseMode.NONE
 
-    def tearDown(self):
+    def teardown(self):
         self.nc.close_session()
-
-    def check_reply_ok(self, reply):
-        self.assertIsNotNone(reply)
-        if settings.DEBUG:
-            print(reply.xml)
-        self.assertTrue(reply.ok)
-        self.assertIsNone(reply.error)
-
-    def check_reply_err(self, reply):
-        self.assertIsNotNone(reply)
-        if settings.DEBUG:
-            print(reply.xml)
-        self.assertFalse(reply.ok)
-        self.assertIsNotNone(reply.error)
-
-    def check_reply_data(self, reply):
-        self.check_reply_ok(reply)
diff --git a/test/mocks/netconf-pnp-simulator/engine/tests/settings.py b/test/mocks/netconf-pnp-simulator/engine/tests/settings.py
index 716fdb7a2..124e333cd 100644
--- a/test/mocks/netconf-pnp-simulator/engine/tests/settings.py
+++ b/test/mocks/netconf-pnp-simulator/engine/tests/settings.py
@@ -5,5 +5,3 @@ HOST = "127.0.0.1"
 PORT = int(os.environ["NETCONF_PNP_SIMULATOR_830_TCP_PORT"])
 USERNAME = "netconf"
 KEY_FILENAME = "../config/ssh/id_rsa"
-
-DEBUG = False
diff --git a/test/mocks/netconf-pnp-simulator/engine/tests/test_basic_operations.py b/test/mocks/netconf-pnp-simulator/engine/tests/test_basic_operations.py
index 62d41c259..06164e6b5 100644
--- a/test/mocks/netconf-pnp-simulator/engine/tests/test_basic_operations.py
+++ b/test/mocks/netconf-pnp-simulator/engine/tests/test_basic_operations.py
@@ -1,52 +1,49 @@
-import unittest
 import nctest
 
+
 class TestBasicOperations(nctest.NCTestCase):
     """ Tests basic NETCONF operations with no prerequisites on datastore content. """
 
     def test_capabilities(self):
-        self.assertTrue(":startup" in self.nc.server_capabilities)
-        self.assertTrue(":candidate" in self.nc.server_capabilities)
-        self.assertTrue(":validate" in self.nc.server_capabilities)
-        self.assertTrue(":xpath" in self.nc.server_capabilities)
+        assert ":startup" in self.nc.server_capabilities
+        assert ":candidate" in self.nc.server_capabilities
+        assert ":validate" in self.nc.server_capabilities
+        assert ":xpath" in self.nc.server_capabilities
 
     def test_get(self):
         reply = self.nc.get()
-        self.check_reply_data(reply)
+        nctest.check_reply_data(reply)
 
     def test_get_config_startup(self):
         reply = self.nc.get_config(source='startup')
-        self.check_reply_data(reply)
+        nctest.check_reply_data(reply)
 
     def test_get_config_running(self):
         reply = self.nc.get_config(source='running')
-        self.check_reply_data(reply)
+        nctest.check_reply_data(reply)
 
     def test_copy_config(self):
         reply = self.nc.copy_config(source='startup', target='candidate')
-        self.check_reply_ok(reply)
+        nctest.check_reply_ok(reply)
 
     def test_neg_filter(self):
         reply = self.nc.get(filter=("xpath", "/non-existing-module:non-existing-data"))
-        self.check_reply_err(reply)
+        nctest.check_reply_err(reply)
 
     def test_lock(self):
         reply = self.nc.lock("startup")
-        self.check_reply_ok(reply)
+        nctest.check_reply_ok(reply)
         reply = self.nc.lock("running")
-        self.check_reply_ok(reply)
+        nctest.check_reply_ok(reply)
         reply = self.nc.lock("candidate")
-        self.check_reply_ok(reply)
+        nctest.check_reply_ok(reply)
 
         reply = self.nc.lock("startup")
-        self.check_reply_err(reply)
+        nctest.check_reply_err(reply)
 
         reply = self.nc.unlock("startup")
-        self.check_reply_ok(reply)
+        nctest.check_reply_ok(reply)
         reply = self.nc.unlock("running")
-        self.check_reply_ok(reply)
+        nctest.check_reply_ok(reply)
         reply = self.nc.unlock("candidate")
-        self.check_reply_ok(reply)
-
-if __name__ == '__main__':
-    unittest.main()
+        nctest.check_reply_ok(reply)
diff --git a/test/mocks/netconf-pnp-simulator/engine/tests/test_turing_machine.py b/test/mocks/netconf-pnp-simulator/engine/tests/test_turing_machine.py
new file mode 100644
index 000000000..8ac38b0f5
--- /dev/null
+++ b/test/mocks/netconf-pnp-simulator/engine/tests/test_turing_machine.py
@@ -0,0 +1,130 @@
+import nctest
+
+_NAMESPACES = {
+    "nc": "urn:ietf:params:xml:ns:netconf:base:1.0",
+    "tm": "http://example.net/turing-machine"
+}
+
+
+def check_labels_only_in_data(data):
+    children = data.xpath("/nc:rpc-reply/nc:data/*", namespaces=_NAMESPACES)
+    assert children
+    for child in children:
+        assert child.tag.endswith("turing-machine")
+    children = data.xpath("/nc:rpc-reply/nc:data/tm:turing-machine/*", namespaces=_NAMESPACES)
+    assert children
+    for child in children:
+        assert child.tag.endswith("transition-function")
+    children = data.xpath("/nc:rpc-reply/nc:data/tm:turing-machine/tm:transition-function/*", namespaces=_NAMESPACES)
+    assert children
+    for child in children:
+        assert child.tag.endswith("delta")
+    children = data.xpath("/nc:rpc-reply/nc:data/tm:turing-machine/tm:transition-function/tm:delta/*",
+                          namespaces=_NAMESPACES)
+    assert children
+    for child in children:
+        assert child.tag.endswith("label")
+
+
+def check_deltas_in_data(data):
+    deltas = data.xpath("/nc:rpc-reply/nc:data/tm:turing-machine/tm:transition-function/*", namespaces=_NAMESPACES)
+    assert deltas
+    for d in deltas:
+        assert d.tag.endswith("delta")
+
+
+class TestTuringMachine(nctest.NCTestCase):
+    """ Tests basic NETCONF operations on the turing-machine YANG module. """
+
+    def test_get(self):
+        reply = self.nc.get()
+        nctest.check_reply_data(reply)
+        check_deltas_in_data(reply.data)
+
+    def test_get_config_startup(self):
+        reply = self.nc.get_config(source="startup")
+        nctest.check_reply_data(reply)
+        check_deltas_in_data(reply.data)
+
+    def test_get_config_running(self):
+        reply = self.nc.get_config(source="running")
+        nctest.check_reply_data(reply)
+        check_deltas_in_data(reply.data)
+
+    def test_get_subtree_filter(self):
+        filter_xml = """<nc:filter xmlns:nc="urn:ietf:params:xml:ns:netconf:base:1.0">
+            <turing-machine xmlns="http://example.net/turing-machine">
+                <transition-function>
+                    <delta>
+                        <label />
+                    </delta>
+                </transition-function>
+            </turing-machine>
+            </nc:filter>"""
+        reply = self.nc.get_config(source="running", filter=filter_xml)
+        nctest.check_reply_data(reply)
+        check_deltas_in_data(reply.data)
+        check_labels_only_in_data(reply.data)
+
+    def test_get_xpath_filter(self):
+        # https://github.com/ncclient/ncclient/issues/166
+        filter_xml = """<nc:filter type="xpath" xmlns:nc="urn:ietf:params:xml:ns:netconf:base:1.0"
+            xmlns:tm="http://example.net/turing-machine"
+            select="/tm:turing-machine/transition-function/delta/label" />
+            """
+        reply = self.nc.get(filter=filter_xml)
+        nctest.check_reply_data(reply)
+        check_deltas_in_data(reply.data)
+        check_labels_only_in_data(reply.data)
+
+    def test_edit_config(self):
+        config_xml = """<nc:config xmlns:nc="urn:ietf:params:xml:ns:netconf:base:1.0">
+            <turing-machine xmlns="http://example.net/turing-machine">
+                <transition-function>
+                    <delta nc:operation="{}">
+                        <label>test-transition-rule</label>
+                        <input>
+                            <symbol>{}</symbol>
+                            <state>{}</state>
+                        </input>
+                    </delta>
+                </transition-function>
+            </turing-machine></nc:config>"""
+        # merge
+        reply = self.nc.edit_config(target='running', config=config_xml.format("merge", 9, 99))
+        nctest.check_reply_ok(reply)
+        # get
+        reply = self.nc.get_config(source="running")
+        nctest.check_reply_data(reply)
+        deltas = reply.data.xpath(
+            "/nc:rpc-reply/nc:data/tm:turing-machine/tm:transition-function/tm:delta[tm:label='test-transition-rule']",
+            namespaces=_NAMESPACES)
+        assert len(deltas) == 1
+        # create already existing - expect error
+        reply = self.nc.edit_config(target='running', config=config_xml.format("create", 9, 99))
+        nctest.check_reply_err(reply)
+        # replace
+        reply = self.nc.edit_config(target='running', config=config_xml.format("replace", 9, 88))
+        nctest.check_reply_ok(reply)
+        # get
+        reply = self.nc.get_config(source="running")
+        nctest.check_reply_data(reply)
+        states = reply.data.xpath(
+            "/nc:rpc-reply/nc:data/tm:turing-machine/tm:transition-function/tm:delta[tm:label='test-transition-rule']/"
+            "tm:input/tm:state",
+            namespaces=_NAMESPACES)
+        assert len(states) == 1
+        assert states[0].text == "88"
+        # delete
+        reply = self.nc.edit_config(target='running', config=config_xml.format("delete", 9, 88))
+        nctest.check_reply_ok(reply)
+        # delete non-existing - expect error
+        reply = self.nc.edit_config(target='running', config=config_xml.format("delete", 9, 88))
+        nctest.check_reply_err(reply)
+        # get - should be empty
+        reply = self.nc.get_config(source="running")
+        nctest.check_reply_data(reply)
+        deltas = reply.data.xpath(
+            "/nc:rpc-reply/nc:data/tm:turing-machine/tm:transition-function/tm:delta[tm:label='test-transition-rule']",
+            namespaces=_NAMESPACES)
+        assert not deltas
diff --git a/test/mocks/netconf-pnp-simulator/engine/tox.ini b/test/mocks/netconf-pnp-simulator/engine/tox.ini
index 4b0ac1efe..20870cf5e 100644
--- a/test/mocks/netconf-pnp-simulator/engine/tox.ini
+++ b/test/mocks/netconf-pnp-simulator/engine/tox.ini
@@ -18,6 +18,7 @@
 # ============LICENSE_END=========================================================
 
 [tox]
+envlist = py3
 requires = tox-docker
 skipsdist = True
 
@@ -27,6 +28,10 @@ docker =
   netconf-pnp-simulator:latest
 
 deps =
+  pytest
   ncclient
-  discover
-commands = discover -v
+commands = pytest -v
+
+[pytest]
+log_level = INFO
+log_format = %(asctime)s.%(msecs)03d %(levelname)-5s [%(name)s] %(message)s