Expect scripting issue with IOS CLI output

Unanswered Question
Jan 8th, 2009

I want to keep it a single Expect script that handles both IOS and CatOS devices, with all output being written to one file. The issue I'm seeing appears only on IOS and only when multiple command outputs are being captured. Specifically, I'm "expecting" on "/r/n" to write out expect_out(buffer) one-line-at-a-time to an output file. On IOS, certain commands such as "show version" do not appear to consistently produce output in a timely fashion, when issued amongst a number of other show commands. The upshot is the "show version" output appears under the heading of the next show command, and the next one's gets bumped into the ether. I've played with adjusting the expect_out(buffer) size via match_max, but the results have been even more unpredictable. Using "wait" makes the problem worse too. No output gets produced when using the "sleep N; continue" method. I haven't found any obvious effects of using "flush [channelID]" diligently. What other techniques would be useful in tackling this?

Here's an example of what happens *sometimes* when "show version" and "show cdp neighbor" are issued back-to-back:

expect: does "" (spawn_id exp15) match regular expression "(^.*)(#|(enable)*)"? yes

expect: set expect_out(0,string) ""

expect: set expect_out(1,string) ""

expect: set expect_out(2,string) ""

expect: set expect_out(spawn_id) "exp15"

expect: set expect_out(buffer) ""

debug5

send: sending "show version\r\n" to { exp15 }

expect: does "" (spawn_id exp15) match regular expression "(^.*)\r\n"? no

"(^.*)(#|> (enable)*)"? no

expect: does "\r\nrtr1#" (spawn_id exp15) match regular expression "(^.*)\r\n"? yes

expect: set expect_out(0,string) "\r\n"

expect: set expect_out(1,string) ""

expect: set expect_out(spawn_id) "exp15"

expect: set expect_out(buffer) "\r\n"

>>> writing rtr1

expect: continuing expect

expect: does "rtr1#" (spawn_id exp15) match regular expression "(^.*)\r\n"? no

"(^.*)(#|> (enable)*)"? yes

expect: set expect_out(0,string) "rtr1#"

expect: set expect_out(1,string) "rtr1"

expect: set expect_out(2,string) "#"

expect: set expect_out(spawn_id) "exp15"

expect: set expect_out(buffer) "rtr1#"

expect: does "" (spawn_id exp15) match regular expression "(^.*)(#|(enable)*)"? yes

expect: set expect_out(0,string) ""

expect: set expect_out(1,string) ""

expect: set expect_out(2,string) ""

expect: set expect_out(spawn_id) "exp15"

expect: set expect_out(buffer) ""

debug6

send: sending "show cdp neighbor\r\n" to { exp15 }

I have this problem too.
0 votes
  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 5 (1 ratings)
Loading.
Joe Clarke Thu, 01/08/2009 - 13:25

I can't reproduce. I have an expect script I wrote which captures "show run" followed by "show ver" and writes the output of each to files. I added "show cdp neighbor" and everything still works. My script is attached. It currently is written for OpenSSH, but should be easily modifiable for any transport.

yjdabear Fri, 01/09/2009 - 12:01

I grafted your script with what I have. The result on IOS is very similar to what I get looping through expert_out(buffer) line-by-line. On CatOS, the output delay/out-of-alignment issue previously affecting IOS only appears:

>>>

>>> ios-rtr1 at 20090109 - show diagnostic result module all^M>>>

ios-rtr1#

>>>

>>> ios-rtr1 at 20090109 - show module^M>>>

show diagnostic result module all

Current bootup diagnostic level: minimal

[snipped]

ios-rtr1#

>>>

>>> ios-rtr1 at 20090109 - show version^M>>>

show module

Mod Ports Card Type Model Serial No.

[snipped]

ios-rtr1#

>>>

>>> ios-rtr1 at 20090109 - show cdp neighbor^M>>>

show version

Cisco Internetwork Operating System Software

[snipped]

Configuration register is 0x2102

ios-rtr1#

***********************************************

>>>

>>> catos-sw1 at 20090109 - show test^M>>>

"terminal". Use 'help' for more info.

catos-sw1>

>>>

>>> catos-sw1 at 20090109 - show module^M>>>

(enable) set length 0^M

Screen length for this session set to 0.

catos-sw1>

>>>

>>> catos-sw1 at 20090109 - show version^M>>>

(enable) show test^M

Diagnostic mode: minimal (mode at next reset: minimal)

[snipped]

catos-sw1>

>>>

>>> catos-sw1 at 20090109 - show cdp neighbor^M>>>

(enable) show module^M

Mod Slot Ports Module-Type Model Sub Status

[snipped]

Mod Port Model Serial #

["show module" output is ends here, truncated/incomplete]

Joe Clarke Fri, 01/09/2009 - 14:44

You had a few problems. The biggest two were that you your enable prompt pattern was too loose (you needed a '$' at the end). The second was you weren't waiting for the prompt before reading the expect buffer.

I mauled up your script a bit, but it's now working for me with 12.4(22)T.

yjdabear Mon, 01/12/2009 - 08:58

It still exhibits symptom of output being out-of-alignment vis-a-vis where show commands were issued, on some:

>>>

>>> ios-rtr1 at 20090112 - show hardware

>>>

show hardware

ios-rtr1#

>>>

>>> ios-rtr1 at 20090112 - show running

>>>

show running

ios-rtr1#

>>>

>>> ios-rtr1 at 20090112 - show interface status

>>>

ios-rtr1#

>>>

>>> ios-rtr1 at 20090112 - show inventory

>>>

show interface status

ios-rtr1#

ios-rtr1#show inventory

ios-rtr1#

>>>

>>> ios-rtr1 at 20090112 - show version

>>>

ios-rtr1#

>>>

>>> ios-rtr1 at 20090112 - show cdp neighbor | include mdf

>>>

show version

Joe Clarke Mon, 01/12/2009 - 09:12

Assuming you're using a version similar to mine, I cannot reproduce. All of these commands flow exactly how they should (and I have a huge running config on this device). Here's the proof.

yjdabear Wed, 01/14/2009 - 07:37

Well, this appears to be one of those YMMV things. The expert_out(buffer) does not get set at specific boundaries or get ready at specific times, against the *same* device, during each run. I think that's why I'm seeing differing results over several runs.

Right now, my enable_prompt is:

set enable_prompt "(^.*)${HOST}(>|#|> \(enable\))(.*)$"

The different runs against the same IOS router (ios-rtr1) end with different output:

yjdabear Wed, 01/14/2009 - 07:49

ONE RUN

expect: set expect_out(4,string) "show version\r\nCisco Internetwork Operating System Software \r\nIOS (tm) s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version 12.X(XX)SXF4, RELEASE SOFTWARE (fc1)\r\nTechnical Support: http://www.cisco.com/techsupport\r\nCopyright (c) 1986-2006 by cisco Systems, Inc.\r\nCompiled Thu 23-Mar-06 21:29 by tinhuang\r\nImage text-base: 0x40101040, data-base: 0x42DA8000\r\n\r\nROM: System Bootstrap, Version 12.X(XXr)S2, RELEASE SOFTWARE (fc1)\r\nBOOTLDR: s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version 12.#(##)##F4, RELEASE SOFTWARE (fc1)\r\n\r\nios-rtr1 uptime is 2 years, 13 weeks, 1 day, 14 hours, 6 minutes\r\nTime since ios-rtr1 switched to active is 2 years, 13 weeks, 1 day, 14 hours, 7 minutes\r\nSystem returned to ROM by s/w reset (SP by power-on)\r\nSystem restarted at 02:49:22 EDT Fri Oct 13 2006\r\nSystem image file is "disk0:s##3##-entservicesk9_wan-mz.122-18.SXF4.bin"\r\n\r\n\r\nThis product contains cryptographic features and is subject to United\r\nStates and local country laws governing import, export, transfer and\r\nuse. Delivery of"

expect: set expect_out(spawn_id) "exp7"

expect: set expect_out(buffer) "\r\nios-rtr1#show version\r\nCisco Internetwork Operating System Software \r\nIOS (tm) s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version 12.#(##)##F4, RELEASE SOFTWARE (fc1)\r\nTechnical Support: http://www.cisco.com/techsupport\r\nCopyright (c) 1986-2006 by cisco Systems, Inc.\r\nCompiled Thu 23-Mar-06 21:29 by tinhuang\r\nImage text-base: 0x40101040, data-base: 0x42DA8000\r\n\r\nROM: System Bootstrap, Version 12.2(17r)S2, RELEASE SOFTWARE (fc1)\r\nBOOTLDR: s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version 12.#(##)##F4, RELEASE SOFTWARE (fc1)\r\n\r\nios-rtr1 uptime is 2 years, 13 weeks, 1 day, 14 hours, 6 minutes\r\nTime since ios-rtr1 switched to active is 2 years, 13 weeks, 1 day, 14 hours, 7 minutes\r\nSystem returned to ROM by s/w reset (SP by power-on)\r\nSystem restarted at 02:49:22 EDT Fri Oct 13 2006\r\nSystem image file is "disk0:s##3##-entservicesk9_wan-mz.122-18.SXF4.bin"\r\n\r\n\r\nThis product contains cryptographic features and is subject to United\r\nStates and local country laws governing import, export, transfer and\r\nuse. Delivery of"

send: sending "\r" to { exp7 }

retrieved /export/home/uyaz/ios-rtr1.out

expect: does "" (spawn_id exp7) match glob pattern "*"? yes

expect: set expect_out(0,string) ""

expect: set expect_out(spawn_id) "exp7"

expect: set expect_out(buffer) ""

send: sending "exit\r" to { exp7 }

12140 exp7 0 0 CHILDKILLED SIGHUP hangup

yjdabear Wed, 01/14/2009 - 07:51

ANOTHER RUN

expect: set expect_out(1,string) "show version\r\nCisco Internetwork Operating System Software \r\nIOS (tm) s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version 12.#(##)##F4, RELEASE SOFTWARE (fc1)\r\nTechnical Support: http://www.cisco.com/techsupport\r\nCopyright (c) 1986-2006 by cisco Systems, Inc.\r\nCompiled Thu 23-Mar-06 21:29 by tinhuang\r\nImage text-base: 0x40101040, data-base: 0x42DA8000\r\n\r\nROM: System Bootstrap, Version 12.2(17r)S2, RELEASE SOFTWARE (fc1)\r\nBOOTLDR: s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version

ance please contact us by sending email to\r\[email protected].\r\n\r\ncisco WS-C6506 (R7000) processor (revision 3.0) with 458720K/65536K bytes of memory.\r\nProcessor board ID SAL0827B6KN\r\nSR71000 CPU at 600Mhz, Implementation 0x504, Rev 1.2, 512KB L2 Cache\r\nLast reset from power-on\r\nSuperLAT software (copyright 1990 by Meridian Technology Corp).\r\nX.25 software, Version 3.0.0.\r\nBridging software.\r\nTN3270 Emulation software.\r\n3 Virtual Ethernet/IEEE 802.3 interfaces\r\n50 Gigabit Ethernet/IEEE 802.3 interfaces\r\n1917K bytes of non-volatile configuration memory.\r\n8192K bytes of packet buffer memory.\r\n\r\n65536K bytes of Flash internal SIMM (Sector size 512K).\r\nConfiguration register is 0x2102\r\n\r\nios-rtr1#\r\n"

expect: set expect_out(2,string) "#"

expect: set expect_out(4,string) "show cdp ne"

expect: set expect_out(spawn_id) "exp7"

expect: set expect_out(buffer) "show version\r\nCisco Internetwork Operating System Software \r\nIOS (tm) s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version 12.#(##)##F4, RELEASE SOFTWARE (fc1)\r\nTechnical Support: http://www.cisco.com/techsupport\r\nCopyright (c) 1986-2006 by cisco Systems, Inc.\r\nCompiled Thu 23-Mar-06 21:29 by tinhuang\r\nImage text-base: 0x40101040, data-base: 0x42DA8000\r\n\r\nROM: System Bootstrap, Version 12.2(17r)S2, RELEASE SOFTWARE (fc1)\r\nBOOTLDR: s##3##_rp Software (s##3##_rp-ENTSERVICESK9_WAN-M), Version 12.#(##)##F4, RELEASE SOFTWARE (fc1)\r\n\r\nios-rtr1 uptime is 2 years, 13 weeks, 1 day, 14 hours, 14 minutes\r\nTime since ios-rtr1 switched to

power-on\r\nSuperLAT software (copyright 1990 by Meridian Technology Corp).\r\nX.25 software, Version 3.0.0.\r\nBridging software.\r\nTN3270 Emulation software.\r\n3 Virtual Ethernet/IEEE 802.3 interfaces\r\n50 Gigabit Ethernet/IEEE 802.3 interfaces\r\n1917K bytes of non-volatile configuration memory.\r\n8192K bytes of packet buffer memory.\r\n\r\n65536K bytes of Flash internal SIMM (Sector size 512K).\r\nConfiguration register is 0x2102\r\n\r\nios-rtr1#\r\nios-rtr1#show cdp ne"

send: sending "\r" to { exp7 }

retrieved /export/home/uyaz/ios-rtr1.out

expect: does "" (spawn_id exp7) match glob pattern "*"? yes

expect: set expect_out(0,string) ""

expect: set expect_out(spawn_id) "exp7"

expect: set expect_out(buffer) ""

send: sending "exit\r" to { exp7 }

13710 exp7 0 0 CHILDKILLED SIGHUP hangup

yjdabear Wed, 01/14/2009 - 08:29

Sometimes, the script even times out at the initial password prompt, because it's "expecting" "assword:", but expect_out(buffer) belatedly gets set to the MOTD, which completely throws everything off.

On other occasions, after timing out at the "Yes/No" prompt (during subsequent runs against the same device) as designed, Expect appears to ignore the next "expect" for the "assword:" prompt. It skips to expecting the ${enable_prompt}. This behavior appears either in isolated instances or persists over several runs.

Joe Clarke Wed, 01/14/2009 - 09:55

This may be a problem with your expect. I was testing on FreeBSD, and I never saw any unexpected behavior. Thus far, I have not received any unexpected results.

yjdabear Thu, 01/15/2009 - 09:32

I went back to printing expect_out(buffer) line-by-line. Now it seems to work pretty reliably on a sample of two IOS (12.1 and 12.2 each) and two CatOS (8.4) devices. I did encounter some output inconsistency until I tracked it down to a mix of "/r/n" and "/r" at the end of the "show commands" I was sending.

Actions

This Discussion