ktbyers / netmiko

Multi-vendor library to simplify Paramiko SSH connections to network devices
MIT License
3.63k stars 1.31k forks source link

incomplete received output with send_config_set() and netmiko 4.2.0 #3227

Open laimaretto opened 1 year ago

laimaretto commented 1 year ago

Hello!

Recently I had to execute configurations scripts on several Nokia 7250 routers. The thing is that for some routers, the received output was complete. But for others, the received output was incomplete. We executed these scripts on parallel so I'm going to show you the analysis for one of those, thread-14 of the debug file.

The sent commands totals 450 lines, which is coherent with the analysis of the debug file for Thread-14. Let me show you.

lucas@lucas:~/Downloads$ grep "\[Thread-14\] write_channel" debug.debug -n | wc -l
450

I will show now the very start of the script; middle; and end, because I'll later show you the read_channel event so you'll see how is the received output, incomplete.

write_channel for thread-14

I hid as much sensitive information as I could...

lucas@lucas:~/Downloads$ grep "\[Thread-14\] write_channel" debug.debug -n
4782:[DEBUG] netmiko: [Thread-14] write_channel: b'/environment no more\n'
4812:[DEBUG] netmiko: [Thread-14] write_channel: b'/configure router\n'
4838:[DEBUG] netmiko: [Thread-14] write_channel: b'        policy-options\n'
4866:[DEBUG] netmiko: [Thread-14] write_channel: b'            begin\n'
4894:[DEBUG] netmiko: [Thread-14] write_channel: b'            prefix-list "DEFAULT"\n'
4916:[DEBUG] netmiko: [Thread-14] write_channel: b'                prefix 0.0.0.0/0 exact\n'
4945:[DEBUG] netmiko: [Thread-14] write_channel: b'                prefix ::/0 exact\n'
4971:[DEBUG] netmiko: [Thread-14] write_channel: b'            exit\n'
[ ... ]
9250:[DEBUG] netmiko: [Thread-14] write_channel: b'                prefix 10.XXX.6.96/29   exact\n'
9272:[DEBUG] netmiko: [Thread-14] write_channel: b'            exit\n'
9296:[DEBUG] netmiko: [Thread-14] write_channel: b'exit all\n'
9321:[DEBUG] netmiko: [Thread-14] write_channel: b'/configure router\n'
9347:[DEBUG] netmiko: [Thread-14] write_channel: b'    policy-options\n'
9378:[DEBUG] netmiko: [Thread-14] write_channel: b'        policy-statement OSPF_EXPORT\n'
9399:[DEBUG] netmiko: [Thread-14] write_channel: b'            entry 5\n'
9430:[DEBUG] netmiko: [Thread-14] write_channel: b'                from\n'
9454:[DEBUG] netmiko: [Thread-14] write_channel: b'                    prefix-list "PREFIX-23"\n'
9480:[DEBUG] netmiko: [Thread-14] write_channel: b'                exit\n'
9509:[DEBUG] netmiko: [Thread-14] write_channel: b'            exit\n'
9535:[DEBUG] netmiko: [Thread-14] write_channel: b'        exit\n'
[ ... ]
11187:[DEBUG] netmiko: [Thread-14] write_channel: b'/configure router\n'
11262:[DEBUG] netmiko: [Thread-14] write_channel: b'        policy-options\n'
11278:[DEBUG] netmiko: [Thread-14] write_channel: b'            policy-statement "MY-POLICY"\n'
11303:[DEBUG] netmiko: [Thread-14] write_channel: b'                entry 14\n'
11324:[DEBUG] netmiko: [Thread-14] write_channel: b'                    conditional-expression\n'
11349:[DEBUG] netmiko: [Thread-14] write_channel: b'                        route-exists "[DEFAULT]"\n'
11369:[DEBUG] netmiko: [Thread-14] write_channel: b'                    exit\n'
11390:[DEBUG] netmiko: [Thread-14] write_channel: b'                    from\n'
11417:[DEBUG] netmiko: [Thread-14] write_channel: b'                        protocol static\n'
11441:[DEBUG] netmiko: [Thread-14] write_channel: b'                        community "COMM1"\n'
11463:[DEBUG] netmiko: [Thread-14] write_channel: b'                    exit\n'
11479:[DEBUG] netmiko: [Thread-14] write_channel: b'                    action accept\n'
11502:[DEBUG] netmiko: [Thread-14] write_channel: b'                        community add "COMM2"\n'
11536:[DEBUG] netmiko: [Thread-14] write_channel: b'                    exit\n'
11558:[DEBUG] netmiko: [Thread-14] write_channel: b'                exit\n'
11578:[DEBUG] netmiko: [Thread-14] write_channel: b'            exit\n'
11604:[DEBUG] netmiko: [Thread-14] write_channel: b'            commit\n'
11626:[DEBUG] netmiko: [Thread-14] write_channel: b'exit all\n'
[ ... ]
15868:[DEBUG] netmiko: [Thread-14] write_channel: b'            enable-rr-vpn-forwarding\n'
15883:[DEBUG] netmiko: [Thread-14] write_channel: b'exit all\n'
15895:[DEBUG] netmiko: [Thread-14] write_channel: b'/configure\n'
15912:[DEBUG] netmiko: [Thread-14] write_channel: b'    service\n'
16024:[DEBUG] netmiko: [Thread-14] write_channel: b'        vprn 2020\n'
16036:[DEBUG] netmiko: [Thread-14] write_channel: b'            static-route-entry 10.0.0.0/8\n'
16046:[DEBUG] netmiko: [Thread-14] write_channel: b'                black-hole\n'
16069:[DEBUG] netmiko: [Thread-14] write_channel: b'                    community XXXX:XX\n'
16085:[DEBUG] netmiko: [Thread-14] write_channel: b'                    no shutdown\n'
16106:[DEBUG] netmiko: [Thread-14] write_channel: b'                exit\n'
16117:[DEBUG] netmiko: [Thread-14] write_channel: b'            exit\n'
16134:[DEBUG] netmiko: [Thread-14] write_channel: b'        exit\n'
16161:[DEBUG] netmiko: [Thread-14] write_channel: b'exit all\n'
16175:[DEBUG] netmiko: [Thread-14] write_channel: b'\n'
16187:[DEBUG] netmiko: [Thread-14] write_channel: b'exit all\n'
16198:[DEBUG] netmiko: [Thread-14] write_channel: b'\n'
28019:[DEBUG] netmiko: [Thread-14] write_channel: b'exit all\n'
28574:[DEBUG] netmiko: [Thread-14] write_channel: b'logout\n'

The previous looks ok to me, because I have one write_channel event per original commands, which is good. I mean, it looks to me that all the intended command were sent over to the router.

read_channel for thread-14

Analyzing the read_channel is a little bit more complicated, because in the debug file some times you get chunks of text per each read_channel event (note: I wrote yesterday about per-thread debug files). But let me show you from the pattern detection onward ... (which, by the way, it's tricky, because in the write_channel above you can see a couple of router policy-options commands: which one is the one detected when there is a Pattern Found?).

[DEBUG] netmiko: [Thread-14] read_channel: *A:MY-ROUTER>config>router>policy-options>policy-statement>entry$  
[DEBUG] netmiko: [Thread-14] Pattern found: (A:MY\-ROUTER.*) *A:MY-ROUTER>config>router>policy-options>policy-statement>entry$  
[DEBUG] netmiko: [Thread-14] /environment no more 
A:MY-ROUTER# /configure router 
A:MY-ROUTER>config>router#         policy-options 
A:MY-ROUTER>config>router>policy-options#             begin 
*A:MY-ROUTER>config>router>policy-options#             prefix-list "DEFAULT"
*A:MY-ROUTER>config>router>policy-options>prefix-list#                 prefix 0.0.0.0/0 exact 
*A:MY-ROUTER>config>router>policy-options>prefix-list#                 prefix ::/0 exact 
*A:MY-ROUTER>config>router>policy-options>prefix-list#             exit 
[ ... ]
*A:MY-ROUTER>config>router>policy-options>prefix-list$                 prefix 10.XXX.6.96/29   exact 
*A:MY-ROUTER>config>router>policy-options>prefix-list$             exit 
*A:MY-ROUTER>config>router>policy-options# exit all 
*A:MY-ROUTER# /configure router 
*A:MY-ROUTER>config>router#     policy-options 
*A:MY-ROUTER>config>router>policy-options#         policy-statement OSPF_EXPORT"OSPF_EXPORT" 
*A:MY-ROUTER>config>router>policy-options>policy-statement#             entry 5 
*A:MY-ROUTER>config>router>policy-options>policy-statement>entry#                 from 
*A:MY-ROUTER>config>router>policy-options>policy-statement>entry>from#                     prefix-list "PREFIX-23"
*A:MY-ROUTER>config>router>policy-options>policy-statement>entry>from#                 exit 
*A:MY-ROUTER>config>router>policy-options>policy-statement>entry#             exit 
*A:MY-ROUTER>config>router>policy-options>policy-statement#         exit
[ ... ] 
*A:MY-ROUTER# /configure router 
*A:MY-ROUTER>config>router#         policy-options 
*A:MY-ROUTER>config>router>policy-options#             policy-statement "MY-POLICY"
*A:MY-ROUTER>config>router>policy-options>policy-statement#                 entry 14 
*A:MY-ROUTER>config>router>policy-options>policy-statement>entry$  
[DEBUG] netmiko: [Thread-14] write_channel: b'logout\n'

As you can see, the latest string received from the router is that of the Policy MY-POLICY and the Entry 14. So after the last line *A:MY-ROUTER>config>router>policy-options>policy-statement>entry$ I have nothing more about MY-ROUTER, meaning that the last part of the write_channel info that you see up above, is missing.

The behavior is a little random. Out of 30 routers, 6 had this issue, but I'm not sure there is a pattern here. I'll do more tests to see if I can get an idea of what is going on ...

I'm using netmiko 4.2.0. Connection with ConnLogOnly(), with device_type=nokia_sros.

Also, send_config_set() with cmd_verify=True, read_time_out=800.

Any hint? May be the network is noisy but I'd like to know how to either (i) better be aware of that or (ii) overcome that situation ... it is very strange that the output gets trimmed and no other sign of timeout of something be seen in the debug ...

thanks!

ktbyers commented 1 year ago

@laimaretto Can you show what this looks like on the SROS-CLI (if you do this configuration manually).

Just the policy-statement "MY-POLICY" to the end is fine (i.e. through the logout).