Fix session_log failure to hide "no_log" data. (#3331)

.gitignore

@@ -9,6 +9,7 @@ tests/etc/test_devices.yml
 tests/etc/commands.yml
 tests/etc/responses.yml
 tests/etc/test_devices_exc.yml
+tests/SLOG/test_logging_filter_secrets-netmiko.log
 
 examples/SECRET_DEVICE_CREDS.py
 ./build

netmiko/base_connection.py

@@ -102,6 +102,20 @@ def wrapper_decorator(self: "BaseConnection", *args: Any, **kwargs: Any) -> Any:
     return cast(F, wrapper_decorator)
 
 
+def flush_session_log(func: F) -> F:
+    @functools.wraps(func)
+    def wrapper_decorator(self: "BaseConnection", *args: Any, **kwargs: Any) -> Any:
+        try:
+            return_val = func(self, *args, **kwargs)
+        finally:
+            # Always flush the session_log
+            if self.session_log:
+                self.session_log.flush()
+        return return_val
+
+    return cast(F, wrapper_decorator)
+
+
 def log_writes(func: F) -> F:
     """Handle both session_log and log of writes."""
 
@@ -391,6 +405,7 @@ def __init__(
             elif isinstance(session_log, SessionLog):
                 # SessionLog object
                 self.session_log = session_log
+                self.session_log.open()
             else:
                 raise ValueError(
                     "session_log must be a path to a file, a file handle, "
@@ -1467,6 +1482,7 @@ def command_echo_read(self, cmd: str, read_timeout: float) -> str:
             pass
         return new_data
 
+    @flush_session_log
     @select_cmd_verify
     def send_command_timing(
         self,
@@ -1615,6 +1631,7 @@ def _prompt_handler(self, auto_find_prompt: bool) -> str:
             prompt = self.base_prompt
         return re.escape(prompt.strip())
 
+    @flush_session_log
     @select_cmd_verify
     def send_command(
         self,
@@ -2138,6 +2155,7 @@ def send_config_from_file(
             commands = cfg_file.readlines()
         return self.send_config_set(commands, **kwargs)
 
+    @flush_session_log
     def send_config_set(
         self,
         config_commands: Union[str, Sequence[str], Iterator[str], TextIO, None] = None,

netmiko/session_log.py

@@ -12,6 +12,7 @@ def __init__(
         file_encoding: str = "utf-8",
         no_log: Optional[Dict[str, Any]] = None,
         record_writes: bool = False,
+        slog_buffer: Optional[io.StringIO] = None,
     ) -> None:
         if no_log is None:
             self.no_log = {}
@@ -30,6 +31,13 @@ def __init__(
         else:
             self.session_log = None
 
+        # In order to ensure all the no_log entries get hidden properly,
+        # we must first store everying in memory and then write out to file.
+        # Otherwise, we might miss the data we are supposed to hide (since
+        # the no_log data potentially spans multiple reads).
+        if slog_buffer is None:
+            self.slog_buffer = io.StringIO()
+
         # Ensures last write operations prior to disconnect are recorded.
         self.fin = False
 
@@ -49,15 +57,30 @@ def open(self) -> None:
 
     def close(self) -> None:
         """Close the session_log file (if it is a file that we opened)."""
+        self.flush()
         if self.session_log and self._session_log_close:
             self.session_log.close()
             self.session_log = None
 
-    def write(self, data: str) -> None:
-        if self.session_log is not None and len(data) > 0:
-            # Hide the password and secret in the session_log
-            for hidden_data in self.no_log.values():
-                data = data.replace(hidden_data, "********")
+    def no_log_filter(self, data: str) -> str:
+        """Filter content from the session_log."""
+        for hidden_data in self.no_log.values():
+            data = data.replace(hidden_data, "********")
+        return data
+
+    def _read_buffer(self) -> str:
+        self.slog_buffer.seek(0)
+        data = self.slog_buffer.read()
+        # Once read, create a new buffer
+        self.slog_buffer = io.StringIO()
+        return data
+
+    def flush(self) -> None:
+        """Force the slog_buffer to be written out to the actual file"""
+
+        if self.session_log is not None:
+            data = self._read_buffer()
+            data = self.no_log_filter(data)
 
             if isinstance(self.session_log, io.BufferedIOBase):
                 self.session_log.write(write_bytes(data, encoding=self.file_encoding))
@@ -67,4 +90,10 @@ def write(self, data: str) -> None:
             assert isinstance(self.session_log, io.BufferedIOBase) or isinstance(
                 self.session_log, io.TextIOBase
             )
+
+            # Flush the underlying file
             self.session_log.flush()
+
+    def write(self, data: str) -> None:
+        if len(data) > 0:
+            self.slog_buffer.write(data)

tests/SLOG/cisco881_slog.log

@@ -1,4 +1,3 @@
-
 cisco1>
 cisco1>terminal width 511
 cisco1>terminal length 0

tests/SLOG/cisco881_slog_append.log

@@ -1,5 +1,6 @@
 Initial file contents
 
+
 cisco1>
 cisco1>terminal width 511
 cisco1>terminal length 0
@@ -15,19 +16,3 @@ FastEthernet4              10.220.88.20    YES NVRAM  up                    up
 Vlan1                      unassigned      YES unset  down                  down    
 cisco1>
 cisco1>exit
-cisco1>
-cisco1>terminal width 511
-cisco1>terminal length 0
-cisco1>
-cisco1>
-Testing password and secret replacement
-This is my password ********
-This is my secret ********
-
-cisco1>
-cisco1>terminal width 511
-cisco1>terminal length 0
-cisco1>
-cisco1>
-Testing unicode
-😁😁

tests/SLOG/cisco881_slog_wr.log

@@ -1,5 +1,6 @@
 
 terminal width 511
+
 cisco1>
 cisco1>terminal width 511
 cisco1>terminal length 0
@@ -8,12 +9,22 @@ cisco1>
 
 cisco1>
 
-cisco1>enable
-enable
-Password: ********
+cisco1>show foooooooo
+show foooooooo
+              ^
+% Invalid input detected at '^' marker.
 
-cisco1#
+cisco1>
 
-cisco1#
+cisco1>show ip interface brief
+show ip interface brief
+Interface                  IP-Address      OK? Method Status                Protocol
+FastEthernet0              unassigned      YES unset  down                  down    
+FastEthernet1              unassigned      YES unset  down                  down    
+FastEthernet2              unassigned      YES unset  down                  down    
+FastEthernet3              unassigned      YES unset  down                  down    
+FastEthernet4              10.220.88.20    YES NVRAM  up                    up      
+Vlan1                      unassigned      YES unset  down                  down    
+cisco1>
 
-cisco1#exit
+cisco1>exit

tests/SLOG/netmiko.log

@@ -38,8 +38,8 @@ write_channel: b'terminal width 511\n'
 read_channel: 
 cisco1>
 cisco1>
-read_channel: terminal widt
-read_channel: h 511
+read_channel: terminal wid
+read_channel: th 511
 cisco1>
 Pattern found: (terminal width 511) 
 cisco1>
@@ -64,6 +64,16 @@ write_channel: b'\n'
 read_channel: 
 read_channel: 
 cisco1>
+
+Parenthesis found in pattern.
+
+pattern: (\#|>)
+
+
+This can be problemtic when used in read_until_pattern().
+
+You should ensure that you use either non-capture groups i.e. '(?:' or that the
+parenthesis completely wrap the pattern '(pattern)'
 Pattern found: (\#|>) 
 cisco1>
 read_channel: 
@@ -72,8 +82,8 @@ write_channel: b'\n'
 write_channel: b'terminal width 511\n'
 read_channel: cisco1>
 cisco1>
-read_channel: terminal wid
-read_channel: th 511
+read_channel: terminal widt
+read_channel: h 511
 cisco1>
 Pattern found: (terminal width 511) cisco1>
 cisco1>terminal width 511
@@ -97,6 +107,16 @@ write_channel: b'\n'
 read_channel: 
 read_channel: 
 cisco1>
+
+Parenthesis found in pattern.
+
+pattern: (\#|>)
+
+
+This can be problemtic when used in read_until_pattern().
+
+You should ensure that you use either non-capture groups i.e. '(?:' or that the
+parenthesis completely wrap the pattern '(pattern)'
 Pattern found: (\#|>) 
 cisco1>
 read_channel: 
@@ -110,8 +130,8 @@ read_channel:
 [find_prompt()]: prompt is cisco1>
 write_channel: b'show ip interface brief\n'
 read_channel: 
-read_channel: show ip inter
-read_channel: face brief
+read_channel: show ip interf
+read_channel: ace brief
 Interface                  IP-Address      OK? Method Status                Protocol
 FastEthernet0              unassigned      YES unset  down                  down    
 FastEthernet1              unassigned      YES unset  down                  down    
@@ -129,3 +149,48 @@ cisco1>
 Pattern found: ([>#]) 
 cisco1>
 write_channel: b'exit\n'
+write_channel: b'\n'
+write_channel: b'terminal width 511\n'
+read_channel: 
+cisco1>
+cisco1>
+read_channel: terminal wid
+read_channel: th 511
+cisco1>
+Pattern found: (terminal width 511) 
+cisco1>
+cisco1>terminal width 511
+In disable_paging
+Command: terminal length 0
+
+write_channel: b'terminal length 0\n'
+read_channel: 
+read_channel: terminal lengt
+read_channel: h 0
+cisco1>
+Pattern found: (terminal\ length\ 0) 
+cisco1>terminal length 0
+
+cisco1>terminal length 0
+Exiting disable_paging
+read_channel: 
+Clear buffer detects data in the channel
+read_channel: 
+write_channel: b'\n'
+read_channel: 
+read_channel: 
+cisco1>
+
+Parenthesis found in pattern.
+
+pattern: (\#|>)
+
+
+This can be problemtic when used in read_until_pattern().
+
+You should ensure that you use either non-capture groups i.e. '(?:' or that the
+parenthesis completely wrap the pattern '(pattern)'
+Pattern found: (\#|>) 
+cisco1>
+read_channel: 
+[find_prompt()]: prompt is cisco1>

tests/SLOG/test_session_log_append-cisco881_slog_append.log

@@ -0,0 +1,17 @@
+Initial file contents
+
+cisco1>
+cisco1>terminal width 511
+cisco1>terminal length 0
+cisco1>
+cisco1>
+cisco1>show ip interface brief
+Interface                  IP-Address      OK? Method Status                Protocol
+FastEthernet0              unassigned      YES unset  down                  down    
+FastEthernet1              unassigned      YES unset  down                  down    
+FastEthernet2              unassigned      YES unset  down                  down    
+FastEthernet3              unassigned      YES unset  down                  down    
+FastEthernet4              10.220.88.20    YES NVRAM  up                    up      
+Vlan1                      unassigned      YES unset  down                  down    
+cisco1>
+cisco1>exit

tests/SLOG/test_session_log_append-cisco881_slog_append_compare.log

@@ -0,0 +1,15 @@
+cisco1>
+cisco1>terminal width 511
+cisco1>terminal length 0
+cisco1>
+cisco1>
+cisco1>show ip interface brief
+Interface                  IP-Address      OK? Method Status                Protocol
+FastEthernet0              unassigned      YES unset  down                  down    
+FastEthernet1              unassigned      YES unset  down                  down    
+FastEthernet2              unassigned      YES unset  down                  down    
+FastEthernet3              unassigned      YES unset  down                  down    
+FastEthernet4              10.220.88.20    YES NVRAM  up                    up      
+Vlan1                      unassigned      YES unset  down                  down    
+cisco1>
+cisco1>exit

tests/SLOG/test_session_log_bytesio-cisco881_slog_compare.log

@@ -0,0 +1,22 @@
+
+terminal width 511
+cisco1>
+cisco1>terminal width 511
+cisco1>terminal length 0
+terminal length 0
+cisco1>
+
+cisco1>
+
+cisco1>show ip interface brief
+show ip interface brief
+Interface                  IP-Address      OK? Method Status                Protocol
+FastEthernet0              unassigned      YES unset  down                  down    
+FastEthernet1              unassigned      YES unset  down                  down    
+FastEthernet2              unassigned      YES unset  down                  down    
+FastEthernet3              unassigned      YES unset  down                  down    
+FastEthernet4              10.220.88.20    YES NVRAM  up                    up      
+Vlan1                      unassigned      YES unset  down                  down    
+cisco1>
+
+cisco1>exit

tests/SLOG/test_session_log_custom_session_log-cisco881_slog.log

@@ -0,0 +1,15 @@
+cisco1>
+cisco1>terminal width 511
+cisco1>********
+cisco1>
+cisco1>
+Testing password and secret replacement
+This is my first secret ********
+This is my second secret ********
+This is my third secret ********
+This is my super secret ********
+
+!Testing send_command() and send_command_timing() filtering
+cisco1>********
+cisco1>********
+cisco1>