send_command expect string and delay_factor

[Sh4mSh4m]

Hi,

Context I'm having a hard time figuring out how expect_string and delay_factor work together. I need to script a cisco 2960X stack upgrade which include the painful step of sending "archive download-sw flash:tarfile". This step is high CPU consuming on the switch part and it takes forever (more than an hour and a half). Using ANSIBLE, i'haven't found a effective way of checking when this step is ending, that is why i'm turning to Nornir + Netmiko. However I've been POCing this with a "write mem" command which can take a while as well depending on the load size of the stack.

Setup I'm running the following against a single switch for test purposes:

start_time = time.time()
nr = InitNornir()

result = nr.run(
    task=netmiko_send_command,
    command_string="write mem",
    expect_string="OK",
    delay_factor=50,
)

print_result(result)
print(f"{time.time() - start_time} seconds")

Ouput PS C:\Users\WWW\production\nornir> python .\nornir_writemem.py netmiko_send_command****

• labnxp changed : False **vvvv netmiko_send_command ** changed : False vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv INFO Building configuration... [OK] ^^^^ END netmiko_send_command ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 24.849318027496338 seconds

Expected output I'm expecting the run to stop as soon as OK appears in the output. I've set delay to 50 just to adjust timeout to 50 seconds in case it doesn't find it.

I expected it to finish in 5 seconds.

Is my understanding of the send_command options wrong ? When does it check the output content ? Can we control it ?

Thanks

[Sh4mSh4m]

Also, I've tried netmiko without nornir and it worked as expected. Below the code used:

from netmiko import ConnectHandler
import time

start_time = time.time()

cisco = {
     'device_type': 'cisco_ios',
     'host': '10.196.1.73',
     'username': 'ansible',
     'password': 'XXX',
}

print("init connection")
ssh_conn = ConnectHandler(**cisco)
print("{} seconds".format(time.time() - start_time))

print("running command")
try:
    ssh_conn.send_command_expect(
        "archive download-sw flash1:c2960x-universalk9-tar.152-4.E6.tar",
        expect_string="All software images installed",
        delay_factor=200,
    )
except OSError:
    print("blam")
finally:
    print("{} seconds".format(time.time() - start_time))

My understanding is that default timeout is set to 100 seconds. delay_factor multiplies it this much. So my questions are:

• are those arguments not defined the same way in the nornir framework ?
• during the wait period, how often is the output checked for the string ?

Thanks for you support !

[ktbyers]

I talk about the Netmiko behavior in detail in this article:

https://pynet.twb-tech.com/blog/automation/netmiko-what-is-done.html

You could probably just try to set the timeout here to how long you want send_command to wait.

cisco = {
     'device_type': 'cisco_ios',
     'host': '10.196.1.73',
     'username': 'ansible',
     'password': 'XXX',
     'timeout': 35 * 60,         # Setting timeout to 35 minutes
}

I haven't tested that timeout behavior much however so it wouldn't surprise me if there issues.

If that doesn't work you can adjust delay_factor and max_loops arguments to send_command. I would add a caveat that I probably wouldn't increase delay_factor much beyond 10 as you start to get pretty long sleep times which might slow Netmiko down from realizing it is done.

The defaults for delay_factor and max_loops are 1 and 500 respectively (and this results in about 100 second delay).

If I multiple delay_factor by 10 that gets me up to 1000 seconds (about 17 minutes). So if you set delay_factor = 10 and max_loops = 1000, you should get about 34 minutes.

So back in Nornir probably this:

result = nr.run(
    task=netmiko_send_command,
    command_string="write mem",
    expect_string="OK",
    delay_factor=10,
    max_loops=1000
)

It will slow write mem down a bit from its normal behavior since the sleep times are getting multiplied by 10. This shouldn't matter too much, however, for the archive command (since it is such a slow running command).

[ktbyers]

Let me know if this helps and that you are able to get this working.

Kirk

[ktbyers]

To answer one of your specific questions:

- during the wait period, how often is the output checked for the string ?

Netmiko has a while loop in send_command:

https://github.com/ktbyers/netmiko/blob/develop/netmiko/base_connection.py#L1122

Each time through the while loop it sleeps .2 seconds * delay_factor so with a delay_factor of 200 it will sleep 40 seconds. Thus the output would be checked roughly every 40 seconds. There would also be a 40 second delay at the start before the output is even checked.

This is why I said the large delay_factor probably wouldn't matter too much for the archive command (i.e. it isn't going to complete for 30 minutes anyways). But for a command that runs much faster (like write mem), it will slow things down a lot.

Kirk

[Sh4mSh4m]

Thanks so much for such quick feedback ! Also I should have checked the latest articles on your blog. Your explanation makes it crystal clear now. I'm gonna try again with Nornir and also try with Ansible but using your module instead of default ios_commands.

[Sh4mSh4m]

Great, now that i have a better understanding of the mechanics, I can predict the maximum timeout effectively. Thanks again !

[MichalObs97]

@Sh4mSh4m Hi! Did you ever figured it out with nornir? I am facing similar issue of uploading a new image to the cisco device which takes several minutes to complete

[ktbyers]

@MichalObs97 Did you try what was detailed in the thread?

[MichalObs97]

@ktbyers Hi. I've looked into what was detailed here and also other posts. My problem is that I used fast_cli=true, and that seems to have completely changed the timing of 100 seconds. I am uploading new image to a WLC which is a process that takes around 5-7 minutes and according to the 100 seconds calculations delay around 5 should be plenty. Currently with fast_cli on true I have to have delay_factor on 99999 for it to surely work. Do you know how does timing change with fast_cli? Or you recommend to just turn it off? (I would profit from it being on). Thank you for your time and help.

[ktbyers]

@MichalObs97 You have a couple of options:

1. Use the Netmiko develop branch (which is Netmiko 4.X code). This entire delay_factor/fast_cli/max_loops has been reworked and largely replaced with a much simpler timeout.
2. Set fast_cli=False as a ConnectHandler argument and then you should be back in the 100 seconds for send_command() timing mode. Given that you are doing a long running operation (several minutes), you will want to have fast_cli=False if you are using the Netmiko 3.4.0 code.