nornir-netmiko behaves differently than netmiko in regards to use_timing and prompts?

[bgile]

I was wondering if anyone else has experienced this.
When using nornir-netmiko and specifically using "use_timing=True" it will of course execute send_command_timing which does not have an option to match on a prompt. If you need to match on prompt because it has changed (which in my case it does with the device I am interacting with which is AdTran) then I can't match the prompt AND invoke use_timing. This is causing my previous commands to not be sent because it's not waiting long enough and I'm losing data. By this I mean the data returned in the Result is actually the send_command command that was never executed:

^^^^^^^^ Executing Netmiko Send Command: term length 0 on Devices with Expect String Matching ^^^^^^^^
^^^^^^^^ Executing Netmiko Send Command: de gp cou 0 0x0 on Devices with Expect String Matching ^^^^^^^^
Result Output:
term length 0
OLT#

Above you can see that it data returned in the Nornir Restult was actually the command I should have sent previously.

If I use netmiko by itself I don't encounter this issue when using send_command_timing as it does not look for a prompt and the issue is bypassed. I don't know if there is a way to ignore the prompt somehow in nornir-netmiko when using use_timing. I would expect the same behavior but nornir always seems to be looking for the HOST# prompt.

def execute_command(nr_inventory: object,
                    command: str,
                    use_expect_string: bool = False,
                    expect_string: str = None,
                    use_textfsm: bool = False,
                    template_path: str = None) -> str or List[Dict]:

    if use_expect_string:
        print_color(
            msg=
            f"Executing Netmiko Send Command: {command} on Devices with Expect String Matching",
            color="green",
            seperator="^^^^^^^^")
        send_command = nr_inventory.run(
            task=netmiko_send_command,
            command_string=command,
            expect_string=expect_string,
        )
    else:
        print_color(
            msg=f"Executing Netmiko Send Command: {command} on Devices",
            color="green",
            seperator="^^^^^^^^")
        send_command = nr_inventory.run(task=netmiko_send_command,
                                        command_string=f"{command}",
                                        use_timing=True,
                                        enable=True)

VS a simple test with netmiko:

...
...
connection.send_command_timing("en")
print(connection.find_prompt())
connection.send_command_timing("term length 0")
print(connection.find_prompt())
pon_output = connection.send_command_timing("de gp cou 0 0x0")
print(pon_output)

OUTPUT:
OLT#
OLT#
OLT#de gp cou 0 0x0
"cli output shows here as expected. Left our for privacy reasons"

[ktbyers]

@bgile use_timing=True in nornir-netmiko executes send_command_timing.

What you are seeing is not send_command_timing executing the previous command, but the echo of the previous command by the device. Likely what this means is your Python script is ahead of the state of the device (i.e. your device is slow to respond so you are reading things that you think should be already done).

Try setting global_cmd_verify=True as a ConnectHandler argument to Netmiko (mapped into a Nornir-netmiko context), adtran Netmiko driver defaults this to False (we are in process of changing this as someone separately brought it up and we realized that global_cmd_verify should probably now be switched to True). This should help keep Netmiko in sync with the end-device state.

[bgile]

So this worked, but had an interesting artifact to it.

I added this to my Nornir Inventory:

"groups":
  {self.vendor}:
    "username": {self.username}
    "password": {self.password}
    "connection_options":
      "netmiko":
        "platform": "adtran_os"
        "extras":
          "global_cmd_verify": True
          "fast_cli": False

I don't see that one command getting hung up anymore so that is awesome. Interestingly though there is a point in the workflow where I need to execute ctrl + z so I send the Hex for it, which has always worked fine, but now I get an odd error saying that netmiko is trying to match the prompt of the hex value which doesn't make any sense to me. I am sending "\x1A" matching the expect_string regex ".*" because I don't really care what the prompt is but instead it somehow is ignoring that expect_string and overriding it? IDK...

2023-10-23 15:45:11,774 - nornir.core - INFO - run() - Running task 'netmiko_send_command' with args {'command_string': '\x1a', 'expect_string': '.*', 'use_timing': False, 'read_timeout': 120.0} on 1 hosts

Pattern not detected: '\x1a' in output.

Things you might try to fix this:
1. Adjust the regex pattern to better identify the terminating string. Note, in
many situations the pattern is automatically based on the network device's prompt.
2. Increase the read_timeout to a larger value.

You can also look at the Netmiko session_log or debug log for more information.

If this was really an issue then the code would fail entirely since I can't transition out of an elevated cli area with ctrlz, however, this looks to be a red herring as the code continues just fine and I am able to grab all the data I am trying to extract.

[bgile]

Also to note, if I run the HEX command without supplementing the expect_string arg then it looks for the hostname by default and bombs out so I imagine the regex expect_string is working in some manner but the exception output makes it seem like its not.

[ktbyers]

You can turn off cmd_verify for any particular send_command() call, by adding the argument cmd_verify=False.

Note, cmd_verify causes Netmiko to not move ahead until it sees what it sent gets echoed back properly (for send_command() ) and some other contexts.

[bgile]

OK got it, makes sense. I will play around with this. I'm allowing on_failed so that this doesn't stop a host from executing tasks and everything works, but I will see if I can clean this up a little. Thanks as always!

[bgile]

Not sure if it took or if something is off, but like I said, it seems to work regardless and so I'm ok omitting this for now. I will continue to muck around.

2023-10-24 15:13:30,483 -  nornir.core -     INFO -        run() - Running task 'netmiko_send_command' with args {'command_string': '\x1a', 'expect_string': '.*', 'use_timing': False, 'read_timeout': 120.0, 'cmd_verify': False} on 1 hosts

2023-10-24 15:13:30,483 - nornir.core.task -    DEBUG -      start() - Host 'olt1.prodtest': running task 'netmiko_send_command'
2023-10-24 15:13:39,601 - nornir.core.task -    ERROR -      start() - Host 'olt1.snrtcalb': task 'netmiko_send_command' failed with traceback:
Traceback (most recent call last):
  File "/home/bgile/.local/lib/python3.8/site-packages/nornir/core/task.py", line 99, in start
    r = self.task(self, **self.params)
  File "/home/bgile/.local/lib/python3.8/site-packages/nornir_netmiko/tasks/netmiko_send_command.py", line 32, in netmiko_send_command
    result = net_connect.send_command(command_string, **kwargs)
  File "/home/bgile/.local/lib/python3.8/site-packages/netmiko/utilities.py", line 596, in wrapper_decorator
    return func(self, *args, **kwargs)
  File "/home/bgile/.local/lib/python3.8/site-packages/netmiko/base_connection.py", line 1641, in send_command
    new_data = self.command_echo_read(cmd=cmd, read_timeout=10)
  File "/home/bgile/.local/lib/python3.8/site-packages/netmiko/base_connection.py", line 1366, in command_echo_read
    new_data = self.read_until_pattern(
  File "/home/bgile/.local/lib/python3.8/site-packages/netmiko/base_connection.py", line 651, in read_until_pattern
    raise ReadTimeout(msg)
netmiko.exceptions.ReadTimeout:

Pattern not detected: '\x1a' in output.