Implement configuration edited logging

5 files changed, 44 insertions, 14 deletions

diff --git a/ncserver/base/log.py b/ncserver/base/log.py
index af8c105..15fd6ab 100644
--- a/ncserver/base/log.py
+++ b/ncserver/base/log.py
@@ -16,6 +16,8 @@ import logging
 from socket import gethostname
 from taillight import Signal
 
+from ncserver.base.util import user_for_session
+
 
 HOSTNAME_CHANGED = Signal(('node_changed', 'sys:hostname'))
 """The signal that will fire when the hostname is changed."""
@@ -33,6 +35,13 @@ LOG_OPERATIONAL = logging.getLogger('ncserver.operational')
 """The operational logger."""
 
 
+def log_config_change(session, node, info):
+    """Log a configuration change."""
+    LOG_CONFIG.notice('%s on session %d is editing %s: %s',
+        user_for_session(session), session.session_id, node, info
+    )
+
+
 def configure_format(hostname: str):
     """Configure the formatter for the root log handler."""
     fmt = logging.Formatter('%(asctime)s ' + hostname +
diff --git a/ncserver/base/modman.py b/ncserver/base/modman.py
index 8c08fd4..3bf8fcb 100644
--- a/ncserver/base/modman.py
+++ b/ncserver/base/modman.py
@@ -300,7 +300,7 @@ class ModuleManager:
         for mod in self.modules.values():
             mod.operational(node)
 
-    def collect_edit(self, rpc, node, def_op):
+    def collect_edit(self, session, rpc, node, def_op):
         """Send off edit operations to the requested module(s)."""
         for child in node:
             namespace = QName(child.tag).namespace
@@ -312,4 +312,4 @@ class ModuleManager:
             if getattr(module, 'edit', None) is None:
                 raise error.OperationNotSupportedAppError(rpc)
             self.logger.debug('Dispatching edit-config to %s', module.M_NAME)
-            module.edit(rpc, child, def_op)
+            module.edit(session, rpc, child, def_op)
diff --git a/ncserver/module/openrc.py b/ncserver/module/openrc.py
index 5503002..bd10b98 100644
--- a/ncserver/module/openrc.py
+++ b/ncserver/module/openrc.py
@@ -264,5 +264,5 @@ def operational(node):
             ))
 
 
-def edit(rpc, node, def_op):
+def edit(session, rpc, node, def_op):
     """Edit the service configuration for this device."""
diff --git a/ncserver/module/system.py b/ncserver/module/system.py
index af9d9ce..3898576 100644
--- a/ncserver/module/system.py
+++ b/ncserver/module/system.py
@@ -24,6 +24,7 @@ from socket import gethostname, sethostname
 from lxml import etree
 from netconf import error, util
 
+from ncserver.base.log import HOSTNAME_CHANGED, log_config_change
 from ncserver.base.util import _, ensure_leaf, handle_list_operation, \
                                node_operation, yang_dt_for_timestamp
 
@@ -259,7 +260,7 @@ def _save_resolv_conf(conf: dict):
     rcfile.close()
 
 
-def _edit_dns_option(rpc, node, def_op, curr):
+def _edit_dns_option(session, rpc, node, def_op, curr):
     """Edit DNS option configuration."""
     root_op = node_operation(node, def_op)
 
@@ -291,11 +292,13 @@ def _edit_dns_option(rpc, node, def_op, curr):
 
         if operation in ['delete', 'remove']:
             if option in curr:
+                log_config_change(session, opt.tag, '( deleted )')
                 del curr[option]
             continue
 
         try:
             value = int(opt.text)
+            log_config_change(session, opt.tag, value)
         except ValueError as value:
             raise error.InvalidValueAppError(rpc) from value
 
@@ -305,20 +308,23 @@ def _edit_dns_option(rpc, node, def_op, curr):
     _save_resolv_conf(curr)
 
 
-def _edit_dns_search(rpc, node, def_op, curr: dict):
+def _edit_dns_search(session, rpc, node, def_op, curr: dict):
     """Edit DNS search-domain configuration."""
     operation = node_operation(node, def_op)
 
+    log_config_change(session, 'sys:search', operation + ':' + node.text)
     handle_list_operation(rpc, curr['search'], node, operation)
     _save_resolv_conf(curr)
 
 
-def _edit_dns_server(rpc, node, def_op, curr: dict):
+def _edit_dns_server(session, rpc, node, def_op, curr: dict):
     """Edit DNS nameserver configuration."""
     operation = node_operation(node, def_op)
     xmlmap = {'':  'urn:ietf:params:xml:ns:yang:ietf-system'}
     name = node.find('name', xmlmap)
 
+    # XXX TODO: log changes
+
     # This lets us handle cases where there are no resolvers yet.
     # We set the dict key to the value in case we used the default.
     resolvers = curr.get('resolvers', dict())
@@ -418,7 +424,7 @@ def _is_resolv_conf_empty(curr: dict) -> bool:
     )
 
 
-def _edit_dns(rpc, node, def_op):
+def _edit_dns(session, rpc, node, def_op):
     """Edit the DNS configuration for this system."""
     curr = _parse_resolv_conf()
 
@@ -427,11 +433,13 @@ def _edit_dns(rpc, node, def_op):
         curr = {}
     elif root_op == 'remove':
         curr = {}
+        log_config_change(session, 'sys:dns-resolver', '( deleted )')
         _save_resolv_conf(curr)
     elif root_op == 'delete':
         if _is_resolv_conf_empty(curr):
             raise error.DataMissingAppError(rpc)
         curr = {}
+        log_config_change(session, 'sys:dns-resolver', '( deleted )')
         _save_resolv_conf(curr)
     elif root_op == 'create':
         if not _is_resolv_conf_empty(curr):
@@ -445,10 +453,10 @@ def _edit_dns(rpc, node, def_op):
         if key not in editors:
             raise error.UnknownElementAppError(rpc, key)
 
-        editors[key](rpc, key_node, root_op, curr)
+        editors[key](session, rpc, key_node, root_op, curr)
 
 
-def _edit_file(rpc, node, def_op):
+def _edit_file(session, rpc, node, def_op):
     """Edit a file-based configuration for this system."""
     operation = node_operation(node, def_op)
     ensure_leaf(rpc, node)
@@ -465,14 +473,16 @@ def _edit_file(rpc, node, def_op):
 
     if operation in ['delete', 'remove']:
         if already:
+            log_config_change(session, node.tag, '( deleted )')
             pathlib.Path(selected).unlink()
         return
 
+    log_config_change(session, node.tag, node.text)
     with open(selected, 'wt') as myfile:
         myfile.write(node.text)
 
 
-def _edit_hostname(rpc, node, def_op):
+def _edit_hostname(session, rpc, node, def_op):
     """Edit the hostname for this system."""
     operation = node_operation(node, def_op)
     ensure_leaf(rpc, node)
@@ -488,16 +498,18 @@ def _edit_hostname(rpc, node, def_op):
         raise error.OperationNotSupportedAppError(rpc)
 
     newname = node.text
+    log_config_change(session, 'sys:hostname', newname)
     with open('/etc/hostname', 'wt') as hostfile:
         hostfile.write(newname + '\n')
     sethostname(newname)
+    HOSTNAME_CHANGED.call(newname)
 
 
-def _edit_ntp(rpc, node, def_op):
+def _edit_ntp(session, rpc, node, def_op):
     """Edit NTP configuration for this system."""
 
 
-def edit(rpc, node, def_op):
+def edit(session, rpc, node, def_op):
     """Edit the configuration for this system."""
     methods = {'dns-resolver': _edit_dns,
                'contact': _edit_file, 'location': _edit_file,
@@ -507,6 +519,6 @@ def edit(rpc, node, def_op):
     for subsystem in node:
         name = QName(subsystem.tag).localname
         if name in methods:
-            methods[name](rpc, subsystem, def_op)
+            methods[name](session, rpc, subsystem, def_op)
         else:
             raise error.UnknownElementAppError(rpc, subsystem)
diff --git a/ncserver/server.py b/ncserver/server.py
index 3945a99..f081217 100644
--- a/ncserver/server.py
+++ b/ncserver/server.py
@@ -36,6 +36,13 @@ def log_read(session, rpc):
     )
 
 
+def log_write(session, rpc):
+    """Log a configuration write attempt."""
+    LOG_CONFIG.debug('%s on session %d is editing configuration: %s',
+            user_for_session(session), session.session_id, etree.tostring(rpc)
+    )
+
+
 class AuthenticationController(SSHAuthorizedKeysController):
     """Authentication controller that logs failures."""
     def check_auth_publickey(self, username, key):
@@ -135,6 +142,8 @@ class Server:
             # We must have exactly 1 target.
             raise error.BadElementProtoError(rpc, target)
 
+        log_write(session, rpc)
+
         # strip the xmlns off the tag name.
         datastore = QName(target[0].tag).localname
         if datastore != "running":
@@ -145,7 +154,7 @@ class Server:
         else:
             def_op = default_or_none.text
 
-        self.modman.collect_edit(rpc, config, def_op)
+        self.modman.collect_edit(session, rpc, config, def_op)
 
         root = util.elm('nc:ok')
         return root