Netmiko timesout inspite of delay_factor=4 - OSError: Search pattern never detected in send_command_expect

4.7k views Asked by At

This is a section of my much larger program, but I've isolated the error to this short example:

I'm running a ping command on a Cisco IOS XE device, and the ping takes a while to complete. Hence, to avoid unwanted timeouts, I included the 'delay_factor = 5' argument for netmiko.ConnectHandler.send_command()

However, I still get the error:

[[email protected]@unlv1lnxjmpa01 pack_tests]$ time ./wo_thread.py 
Running Command: ping 1.1.1.1 so lo0 r 350 si 1400 df on R1
Traceback (most recent call last):
  File "./wo_thread.py", line 52, in <module>
    exec_cmd(v, 'ping 1.1.1.1 so lo0 r 350 si 1400 df')
  File "./wo_thread.py", line 30, in exec_cmd
    res += net_connect.send_command(cmd, delay_factor=5)
  File "/home/[email protected]/pyScripts/dev/devEnv/lib/python3.7/site-packages/netmiko/utilities.py", line 363, in wrapper_decorator
    return func(self, *args, **kwargs)
  File "/home/[email protected]/pyScripts/dev/devEnv/lib/python3.7/site-packages/netmiko/base_connection.py", line 1488, in send_command
    search_pattern
OSError: Search pattern never detected in send_command_expect: R1#

real    0m23.647s
user    0m0.582s
sys     0m0.127s

Since delay_factor is 5, Netmiko should wait 5*100 = 500 secs = 3mins before throwing the timeout error, but that's not the case since we see: real 0m23.647s. So, it's only executed for 23s when the error is thrown. Further, I tried manually testing how much time the device actually takes to complete the ping. I found:

R1#sh clock
06:41:31.334 UTC Sat Oct 17 2020
R1#ping 1.1.1.1 so lo0 r 350 si 1400 df
Type escape sequence to abort.
Sending 350, 1400-byte ICMP Echos to 1.1.1.1, timeout is 2 seconds:
Packet sent with a source address of 145.55.234.7 
Packet sent with the DF bit set
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Success rate is 100 percent (350/350), round-trip min/avg/max = 47/53/190 ms
R1#sh clock                               
06:41:55.293 UTC Sat Oct 17 2020

As you can see above the actual difference in start and end time is ~24 secs -- so no reason this shouldn't work. Any ideas what's going wrong, guys?

My code is:

#!/usr/bin/python3
import os, sys
from netmiko import ConnectHandler
from pprint import pprint
from datetime import datetime, timedelta


dev = {
    "device_type": "cisco_xe",
    "host": '9.9.9.9',
    "username": 'user',
    "password": 'pass',
}


def exec_cmd(out, cmd):
    with ConnectHandler(**dev) as net_connect:
        if type(cmd) != list:
            d_name = net_connect.find_prompt()
            res = d_name + cmd + '\n'
            print(f"Running Command: {cmd} on {d_name.replace('#', '')}", end='', flush=True)
            res += net_connect.send_command(cmd, delay_factor=5)
            out.append(res)
            print('\x1b[2K\r', end = '') # Clear the old 'Running ...' Line
            print(f"Obtained result for {cmd}")
        else:
            out_lst = []
            for c in cmd:
                exec_cmd(out_lst, c)
            out.append(out_lst)


v = []
exec_cmd(v, 'ping 130.24.4.4 so lo0 r 350 si 1400 df')
print(v)
exit(1)
1

There are 1 answers

0
Somenath Sinha On

Turns out to be a possible bug.

See: https://github.com/ktbyers/netmiko/issues/2008

Fix:

Add "fast_cli": False in the device configuration. Full code:

dev = {
    "device_type": "cisco_xe",
    "host": '9.9.9.9',
    "username": 'user',
    "password": 'pass',
    "fast_cli": False,
}