Re: Cisco Software Manager 3.5.2 problems accessing IOS-XE devices

renato.lopez@telecomputing.se · ‎10-09-2018

Hello!

I have installed CSM 3.5.2 and it is working fine with IOS-XR devices but I have problems while accessing devices running IOS-XE.

The strange thing is that when I create the new host and I do a reachability test it works(green text) but when I try to execute any command or retrieve the inventory fails(read text). After trying that I did a reachability test again and it does not work anymore.

This the error message while I am trying to execute a pre upgrade customed command profile.

If I test a ssh session from the same machine and the same user credentials it works fine. Any well know bug in condor library ?

Best Regards

Renato

__________________________________

Traceback (most recent call last):
File "/usr/local/csm/csmserver/work_units/install_work_unit.py", line 95, in start
handler_class = get_install_handler_class(ctx)
File "/usr/local/csm/csmserver/handlers/loader.py", line 74, in get_install_handler_class
discover_platform_info(ctx)
File "/usr/local/csm/csmserver/handlers/loader.py", line 48, in discover_platform_info
conn.connect(force_discovery=True)
File "/usr/lib/python2.7/site-packages/condoor/connection.py", line 252, in connect
retry=False)
File "/usr/lib/python2.7/site-packages/condoor/connection.py", line 355, in reconnect
raise excpt
ConnectionTimeoutError: 10.112.48.66: Connection timeout

______________________

2018-10-10 15:58:21,178 condoor.connection:reconnect(290): --------------------
2018-10-10 15:58:21,179 condoor.connection:reconnect(291): Condoor Version 1.0.17
2018-10-10 15:58:21,179 condoor.connection:reconnect(292): Cache filename: /tmp/condoor.1.0.17
2018-10-10 15:58:21,183 condoor.device:make_driver(323): Make Device: ssh://csm@x.x.x.x:22 with Driver: generic
2018-10-10 15:58:21,183 condoor.device:driver_name(308): Driver generic
2018-10-10 15:58:21,183 condoor.connection:reconnect(295): Connecting
2018-10-10 15:58:21,183 condoor.connection:_clear_cache(220): Clearing connection cache
2018-10-10 15:58:21,183 condoor.connection:_get_key(187): Cache key: [ssh://csm@x.x.x.x:22]
2018-10-10 15:58:21,198 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] is_target<-True
2018-10-10 15:58:21,199 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] family<-ASR900
2018-10-10 15:58:21,199 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] os_version<-03.18.03.SP.156-2.SP3-ext
2018-10-10 15:58:21,199 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] hostname<-pe03
2018-10-10 15:58:21,199 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] platform<-ASR-920
2018-10-10 15:58:21,199 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] driver_name<-XE
2018-10-10 15:58:21,199 condoor.device:driver_name(304): Driver change generic -> XE
2018-10-10 15:58:21,200 condoor.device:make_driver(323): Make Device: ssh://csm@x.x.x.x:22 with Driver: XE
2018-10-10 15:58:21,200 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] is_console<-False
2018-10-10 15:58:21,200 condoor.device:device_info(85): Update: [ssh://csm@1x.x.x.x:22] mode<-global
2018-10-10 15:58:21,200 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] os_type<-XE
2018-10-10 15:58:21,201 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] udi<-{'description': 'Cisco ASR920 Series - 12GE and 2-10GE - AC model', 'pid': 'ASR-920-12CZ-A', 'sn': 'CAT2210
U1FW', 'vid': 'V03', 'name': 'Chassis'}
2018-10-10 15:58:21,201 condoor.chain:update(169): Device information updated -> [ssh://csm@x.x.x.x:22]
2018-10-10 15:58:21,201 condoor.connection:description_record(854): Connection information updated from cache.
2018-10-10 15:58:21,201 condoor.connection:_read_cache(212): Read cached information.
2018-10-10 15:58:21,201 condoor.connection:description_record(844): Connection information cleared
2018-10-10 15:58:21,201 condoor.connection:_clear_cache(223): Description record: {'connections': [{'chain': [{'platform': None, 'driver_name': 'XE', 'is_console': False, 'mode': 'global', 'family': None,
'os_version': None, 'os_type': None, 'udi': None, 'hostname': 'pe03', 'is_target': True}]}], 'last_chain': 0}
2018-10-10 15:58:21,201 condoor.connection:_get_key(187): Cache key: [ssh://csm@x.x.x.x:22]
2018-10-10 15:58:21,203 condoor.connection:_write_cache(204): Connection information cached: 6afb139e4e0f5c73b06b0e54eaf16521
2018-10-10 15:58:21,203 condoor.connection:emit_message(592): Connection chain 1/1: ssh://csm@x.x.x.x:22
2018-10-10 15:58:21,203 condoor.connection:emit_message(592): Trying to (re)connect within 120 seconds
2018-10-10 15:58:21,203 condoor.connection:emit_message(592): Connection chain/attempt [1/1]
2018-10-10 15:58:21,203 condoor.connection:emit_message(592): Connecting ssh://csm@x.x.x.x:22
2018-10-10 15:58:21,203 condoor.controller:spawn_session(50): Spawning command: 'ssh -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR -2 -p 22 csm@x.x.x.x'
2018-10-10 15:58:21,214 condoor.controller:spawn_session(62): Child process FD: 12
2018-10-10 15:58:21,214 condoor.controller:spawn_session(68): Terminal window size changed from 24x80 to 512x240
2018-10-10 15:58:21,214 condoor.controller:set_session_log(82): Setting the session log
2018-10-10 15:58:21,214 protocols.ssh:connect(80): EXPECTED_PROMPT='(?P<hostname>[\\w\\-\\_\\=\\+]+)(\$[^()]*\$)?[#|>]'
2018-10-10 15:58:21,215 condoor.fsm:run(162): SSH-CONNECT Start
2018-10-10 16:00:21,306 condoor.fsm:run(186): E=9,S=0,T=120,RT=120.09
2018-10-10 16:00:21,306 condoor.fsm:call_action(31): A=Send text line to the controller.
2018-10-10 16:00:21,607 condoor.fsm:run(203): NS=5,NT=10
2018-10-10 16:00:31,617 condoor.fsm:run(186): E=9,S=5,T=10,RT=10.01
2018-10-10 16:00:31,618 condoor.fsm:run(192): A=Exception 10.112.48.68: Connection timeout
2018-10-10 16:00:31,618 condoor.device:disconnect(184): Disconnecting: ssh://csm@x.x.x.x:22
2018-10-10 16:00:31,618 condoor.controller:disconnect(108): Disconnecting the sessions
2018-10-10 16:00:31,719 condoor.controller:disconnect(114): Disconnected
2018-10-10 16:00:31,719 condoor.connection:emit_message(592): Connection error: 10.112.48.68: Connection timeout
2018-10-10 16:00:31,719 condoor.connection:emit_message(592): Time elapsed 131s/120s
2018-10-10 16:00:31,720 condoor.connection:emit_message(592): Unable to (re)connect within 131s
2018-10-10 16:00:31,720 condoor.connection:_clear_cache(220): Clearing connection cache
2018-10-10 16:00:31,720 condoor.connection:_get_key(187): Cache key: [ssh://csm@x.x.x.x:22]
2018-10-10 16:00:31,721 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] is_target<-True
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] family<-None
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] os_version<-None
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] hostname<-pe03
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] platform<-None
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] driver_name<-XE
2018-10-10 16:00:31,722 condoor.device:driver_name(308): Driver XE
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] is_console<-False
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] mode<-global
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] os_type<-None
2018-10-10 16:00:31,722 condoor.device:device_info(85): Update: [ssh://csm@x.x.x.x:22] udi<-None
2018-10-10 16:00:31,722 condoor.chain:update(169): Device information updated -> [ssh://csm@x.x.x.x:22]
2018-10-10 16:00:31,722 condoor.connection:description_record(854): Connection information updated from cache.
2018-10-10 16:00:31,723 condoor.connection:_read_cache(212): Read cached information.
2018-10-10 16:00:31,723 condoor.connection:description_record(844): Connection information cleared
2018-10-10 16:00:31,723 condoor.connection:_clear_cache(223): Description record: {'connections': [{'chain': [{'platform': None, 'driver_name': 'XE', 'is_console': False, 'mode': 'global', 'family': None,
'os_version': None, 'os_type': None, 'udi': None, 'hostname': 'pe03', 'is_target': True}]}], 'last_chain': 0}
2018-10-10 16:00:31,723 condoor.connection:_get_key(187): Cache key: [ssh://csm@1x.x.x.x:22]
2018-10-10 16:00:31,725 condoor.connection:_write_cache(204): Connection information cached: 6afb139e4e0f5c73b06b0e54eaf16521
2018-10-10 16:00:31,725 condoor.connection:_disable_logging(165): Closing logs

Regards

Renato

jawei · ‎10-10-2018

Hi Renato,

It looks like the ssh timeout occurred after Condoor was waiting for the following prompt pattern:

2018-10-10 15:58:21,214 protocols.ssh:connect(80): EXPECTED_PROMPT='(?P<hostname>[\\w\\-\\_\\=\\+]+)(\$[^()]*\$)?[#|>]'

Can you please let us know what is the prompt of the device? Is it ASR920?

Cheers,

-James

renato.lopez@telecomputing.se · ‎10-11-2018

Hi James!

This is the promo I get when I do a ssh session to one of the routers I have problems from CSM.

Regards

/Renato

[relo@smzsmg114 ~]$ ssh pe01.pop04
C
pe01.po04.se.tcnet.link
______ __ ______ __ _
/_ __/__ / /__ / ____/___ ____ ___ ____ __ __/ /_(_)___ ____ _
/ / / _ \/ / _ \/ / / __ \/ __ `__ \/ __ \/ / / / __/ / __ \/ __ `/
/ / / __/ / __/ /___/ /_/ / / / / / / /_/ / /_/ / /_/ / / / / /_/ /
/_/ \___/_/\___/\____/\____/_/ /_/ /_/ .___/\__,_/\__/_/_/ /_/\__, /
/_/ /____/

This is a private system.
Unauthorized use of this and other systems belonging
to Telecomputing ASA is prohibited and will be prosecuted
to the full extent of the law!
password:
pe01#

jawei · ‎10-11-2018

Hi Renato,

I am not able to reproduce the error in house. However, the console output I received is a little different from yours.

[sjc-ads-1915:jawei] ssh 172.27.148.28

C
pe01.po04.se.tcnet.link
______ __ ______ __ _
/_ __/__ / /__ / ____/___ ____ ___ ____ __ __/ /_(_)___ ____ _
/ / / _ \/ / _ \/ / / __ \/ __ `__ \/ __ \/ / / / __/ / __ \/ __ `/
/ / / __/ / __/ /___/ /_/ / / / / / / /_/ / /_/ / /_/ / / / / /_/ /
/_/ \___/_/\___/\____/\____/_/ /_/ /_/ .___/\__,_/\__/_/_/ /_/\__, /
/_/ /____/

This is a private system.
Unauthorized use of this and other systems belonging
to Telecomputing ASA is prohibited and will be prosecuted
to the full extent of the law!

jawei@172.27.148.28's password:

RP/0/RSP0/CPU0:pe01#

The difference is mainly the prompt. I got 'RP/0/RSP0/CPU0:pe01#' but it seems to me that the prompt you have is 'pe01#'?

Can you please try to login manually with the following ssh command and let us know what happens?

ssh -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR -2 -p 22 csm@pe01.pop04

Best,

-James

renato.lopez@telecomputing.se · ‎10-16-2018

Hello James!

I have not issues with routers running IOS-XR , only with IOS-XE devices. Is it possible for you to test with for example an ASR920?

Regards

Renato

jawei · ‎10-16-2018

Hi Renato,

My bad! Yes, you did mention it was ASR920 :)

I tried again with an ASR920 but still could not reproduce the error.

Can you please share with us the following?

(1) The IOS-XE version that you are running

(2) the output of show run

(3) session session_logs.zip which can be retrieved by clicking on the file icon.

Please send the info to cs-software-manager@cisco.com.

I thought to compare notes with you.

Below are the console output and log I collected. As you can tell that I am testing with 03.18.01.SP.156-2.SP1.

(1) From manual login, the following is what I received:

[sj16lab-as1:~] ssh -l csm 1.57.37.11

C
pe01.po04.se.tcnet.link
______ __ ______ __ _
/_ __/__ / /__ / ____/___ ____ ___ ____ __ __/ /_(_)___ ____ _
/ / / _ \/ / _ \/ / / __ \/ __ `__ \/ __ \/ / / / __/ / __ \/ __ `/
/ / / __/ / __/ /___/ /_/ / / / / / / /_/ / /_/ / /_/ / / / / /_/ /
/_/ \___/_/\___/\____/\____/_/ /_/ /_/ .___/\__,_/\__/_/_/ /_/\__, /
/_/ /____/

This is a private system.
Unauthorized use of this and other systems belonging
to Telecomputing ASA is prohibited and will be prosecuted
to the full extent of the law!
Password:
pe01#
pe01#exit
Connection to 1.57.37.11 closed by remote host.
Connection to 1.57.37.11 closed.
[sj16lab-as1:~] ssh -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR -2 -p 22 csm@1.57.37.11
Password:
pe01#
pe01#exit
Connection to 1.57.37.11 closed.

[sj16lab-as1:~]

(2) From running CSM Server, the following is what I received from the session log:

[sj16lab-as1:~] uname -sr
Linux 2.6.32-642.11.1.el6.x86_64
[sj16lab-as1:~] ssh -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR -2 -p 22 csm@1.57.37.11
Password: 

pe01#
pe01#
pe01#
pe01#
pe01#terminal len 0
pe01#terminal width 0
pe01#show version
Cisco IOS XE Software, Version 03.18.01.SP.156-2.SP1-ext
Cisco IOS Software, ASR920 Software (PPC_LINUX_IOSD-UNIVERSALK9_NPE-M), Version 15.6(2)SP1, RELEASE SOFTWARE (fc3)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2016 by Cisco Systems, Inc.
Compiled Wed 23-Nov-16 16:25 by mcpre

Cheers,

-James