Holiday Expect mystery

[rubberscissors]

This is expect-specific, and very weird.

Basically, I've created a routine that telnets into certain devices, executes commands, expects a certain range of output depending on the command, then sets the output to a variable which is then searched for certain conditions. For example, it will ask for a list of the configured circuits, then capture the output and check to see if any are down.

Given the following, can anyone help me solve this mystery:

Once the expected output is seen and captured as a string, the string is searched for multiple failure conditions. For purposes of this example, it looks for circuits in the following conditions: "Link is down" "RETRY" and "I/O Slot empty". I have 36 circuits configured.

The script telnets in and issues the command, grabbing the output:

log_file C:\\smrfiles\\logs\\pmCCBs\_$ii
expect ">" { send "pmCCBs\r" }
expect "tcId*value" { send_user "$expect_out(0,string)" }
set x "$expect_out(0,string)"

The script can run many iterations, so $ii just marks the iteration.

Next I search $x for the conditions I mentioned above. The second expect statement looks for the first and last patterns in the output of pmCCBs (tcId and value) I used two test scenarios to see if the script worked:

First, I went to one of the nodes and pulled the link, which caused 10 of my circuits to go down with the reason 'Link is down'. I ran the script, and it correctly reported that circuits 1 through 10 were down because the link had failed.

Second, I went to another node and pulled one of the cards out, which caused an additional 10 circuits to go into RETRY with the reason 'I/O Slot empty'. I ran the script again, and this time it failed to find any failed circuits at all, not even the original 10 it found during the first test!

I did some debugging, and found that the reason for this is because in the second test, $x was not getting set to the actual output, it was getting set to '>' which is the command prompt (comes after 'value') I plug the I/O card back in and let the circuits come back up, and the next time I run the script $x is set correctly.

Here are the steps I've taken to try and debug this; can anyone help me solve this?

- If I put the link from the first test back in and let the original 10 circuits come back up (leaving 10 in RETRY with reason 'I/O Slot empty') then $x is set correctly.

- I created another small script to test how big a string a variable could actually hold and found it to be much much larger than the output I'm dealing with.

- The first line of the snippet I've provided here indicates a log file I'm capturing the output to; even when $x is not set correctly, the correct output still ends up in the log file (this is true whether I use the send_user command or not)

- In the second test, $x is not set correctly whether I log the output or not

- I changed the expected output range to just (*value) so it would just grab everything between the first thing it saw and the last line of the output, and $x was set to a range between just after the G in 'Group ID' of circuit 17 (see the provided output which follows this list) and 'value'.

- However, I also tried changing the expected output to just 'tcId' and it found it and set $x to 'tcId'. The same with 'value', so individually it was able to spot them both.

- Using the above scenario, I had it print $expect_out(buffer) to the screen, and $expect_out(buffer) was equal to $expect_out(0,string).

- The variable $x is defined before the searching ever begins, so it shouldn't have anything to do with the fact that there are multiple matches.

Anyone out there ever see anything like this? I use this technique all throughout this script and it always seems to work, except in this one scenario. Below is the output of the pmCCBs command when all 20 circuits are down (the scenario where $x is not set correctly).

tcId #TS State Cos State EP1 Node/SL/PT/CNID/R# EP2 Node/SL/PT/CNID/R#
---- --- ----- --- ----- -------------------------------------------------

1 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/1000/03
Reason: Link is down at endpoint 2
2 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/1001/03
Reason: Link is down at endpoint 2
3 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/1002/03
Reason: Link is down at endpoint 2
4 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/1003/03
Reason: Link is down at endpoint 2
5 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/1004/03
Reason: Link is down at endpoint 2
6 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/2001/03
Reason: Link is down at endpoint 2
7 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/2002/03
Reason: Link is down at endpoint 2
8 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/2003/03
Reason: Link is down at endpoint 2
9 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/2004/03
Reason: Link is down at endpoint 2
10 0/2 U-DN D-4 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.2 03/01/2005/03
Reason: Link is down at endpoint 2
11 0/2 U-UP D-3 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.3 06/01/0000/03
12 0/2 U-UP D-3 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.3 06/02/0000/03
13 0/2 U-UP D-3 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.3 06/03/0000/03
14 0/2 U-UP D-3 ENABLED 10.130.4.100 03/01/0000/03 10.130.4.3 06/04/0000/03
15 0/2 U-UP S-4 ENABLED x.x.x.x 00/00/0000/00 10.130.4.2 10/03/0000/03
16 0/1 U-UP D-1 ENABLED 10.130.4.100 02/02/0000/00 10.130.4.100 02/01/0000/00
17 0/0 U-UP G-4 TC CREATE Group Id: 1000
18 0/1 U-UP M-4 ENABLED x.x.x.x 00/00/0000/00 10.130.4.2 05/03/0000/00
19 0/1 U-UP S-4 ENABLED x.x.x.x 00/00/0000/00 10.130.4.100 10/03/0000/03
20 0/0 U-DN D-1 RETRY 10.130.4.3 04/05/0000/03 10.130.4.1 03/05/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
21 0/1 U-UP M-4 ENABLED x.x.x.x 00/00/0000/00 10.130.4.100 03/01/0000/00
22 0/0 U-DN D-1 RETRY 10.130.4.3 04/06/0000/03 10.130.4.1 03/06/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
23 0/0 U-DN D-1 RETRY 10.130.4.3 04/07/0000/03 10.130.4.1 03/07/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
24 0/0 U-DN D-2 RETRY 10.130.4.3 04/08/0000/03 10.130.4.1 03/08/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
25 0/3 U-UP D-0 ENABLED 10.130.4.2 05/01/0100/03 10.130.4.3 06/01/0000/03
26 0/3 U-UP D-4 ENABLED 10.130.4.2 05/02/0101/03 10.130.4.3 06/01/0000/03
27 0/0 U-DN D-2 RETRY 10.130.4.3 04/09/0000/03 10.130.4.1 03/09/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
28 0/0 U-DN D-2 RETRY 10.130.4.3 04/10/0000/03 10.130.4.1 03/10/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
29 0/0 U-DN D-3 RETRY 10.130.4.3 04/11/0000/03 10.130.4.1 03/11/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
30 0/0 U-DN D-3 RETRY 10.130.4.3 04/12/0000/03 10.130.4.1 03/12/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
31 0/0 U-DN D-3 RETRY 10.130.4.3 04/13/0000/03 10.130.4.1 03/13/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
32 0/0 U-DN D-4 RETRY 10.130.4.3 04/14/0000/03 10.130.4.1 03/14/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
33 0/0 U-DN D-4 RETRY 10.130.4.3 04/15/0000/03 10.130.4.1 03/15/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
34 0/0 U-DN D-4 RETRY 10.130.4.3 04/16/0000/03 10.130.4.1 03/16/0000/01
Err Loc: 10.130.4.3 Reason: I/O Slot empty
35 0/0 U-DN D-4 RETRY 10.130.4.3 04/01/0000/00 10.130.4.3 06/01/0000/00
Err Loc: 10.130.4.3 Reason: I/O Slot empty

value = 0 = 0x0

 

[marsd]

I feel that I shouldn't bother to post this now since
my advice was rejected the first time due to a basic
misunderstanding on how and why expect works and the philosophy of pattern matching in expect.
With that out of my system..

Buy the expect book(Exploring Expect, O'reilly) and read chapters 4,5,6 and 7 before attempting anything else, paying close attention to the examples.

Hint: Write a procedure to parse expect_out(buffer) by splitting using \n and use a start and end pattern delimiter with the expect -re command,so that your matches are precise. This is the major problem with "weird" problems in expect..the expected patterns are not defined precisely enough.

 

[rubberscissors]

I'll check it out, thanks...and don't feel like your advice was simply rejected; I made the original post right before leaving for the Thanksgiving weekend and didn't even check anything until I got back - when I got to it, the string thing just seemed the easier way to go, that's all, I didn't mean for you to take offense. Hey, believe me, I know it's true I have some (perhaps many) basic misunderstandings about Expect and the philosophy of pattern matching - I'm trying to hack through them and I totally appreciate the advice you all give me. If I commited a forum-ettiquite gaffe it was unintentional.

I'll check it out and see what I can come up with.