Training, Open Source computer languages
PerlPHPPythonMySQLApache / TomcatTclRubyJavaC and C++LinuxCSS 
Search for:
Home Accessibility Courses Diary The Mouth Forum Resources Site Map About Us Contact
 
20.9.2014 - We have just updated our course layouts and descriptions and added our 2015 schedule.

Intermittent failure with telnet

Posted by Kan (Kan), 10 January 2006
I've a expect script in Linux that telnet to a Router. It works fine after a few runs but fails intermittently after that.

It either stop at the Login or password prompt. And then, it exit and showed error "spawn id exp4 not open".

I've enable debug and below showed the result when it worked fine and when it failed.

Can you enlighten me on the cause of this failure?

Here is the script(test6):
----------------------
#!/usr/bin/expect -d
set timeout 60
spawn telnet 1.1.1.2
expect "Login: "
send "User1\r"
expect "Password: "
send "pw123\r"
expect "RTR1>"
send "date\r"
expect "RTR1>"
exit


Result when it worked fine
----------------------------------
bash-2.05$ ./test6
set argv0 "./test6"
set argv ""
executing commands from command file ./test6
spawn telnet 1.1.1.2
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {2489}

expect: does "" (spawn_id exp4) match glob pattern "Login: "? no
Trying 1.1.1.2...

expect: does "Trying 1.1.1.2...\r\r\n" (spawn_id exp4) match glob pattern "Login: "? no
Connected to 1.1.1.2.
Escape character is '^]'.

expect: does "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n" (spawn_id exp4) match glob pattern "Login: "? no


Nortel Networks, Inc.
expect: does "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n\r\n\r\nNortel Networks, Inc." (spawn_id exp4) match glob pattern "Login: "? no
and its Licensors.
Copyright 1992,1993,1994,1995,1996,1997,1998,1999,2000,2001,2002.
All rights reserved.



Login:
expect: does "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n\r\n\r\nNortel Networks, Inc. and its Licensors.\r\nCopyright 1992,1993,1994,1995,1996,1997,1998,1999,2000,2001,2002.\r\nAll rights reserved.\r\n\r\n\r\n\r\nLogin: " (spawn_id exp4) match glob pattern "Login: "? yes
expect: set expect_out(0,string) "Login: "
expect: set expect_out(spawn_id) "exp4"
expect: set expect_out(buffer) "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n\r\n\r\nNortel Networks, Inc. and its Licensors.\r\nCopyright 1992,1993,1994,1995,1996,1997,1998,1999,2000,2001,2002.\r\nAll rights reserved.\r\n\r\n\r\n\r\nLogin: "
send: sending "User1\r" to { exp4 }

expect: does "" (spawn_id exp4) match glob pattern "Password: "? no
User1

expect: does "User1\r\n" (spawn_id exp4) match glob pattern "Password: "? no

Password:
expect: does "User1\r\n\r\nPassword: " (spawn_id exp4) match glob pattern "Password: "? yes
expect: set expect_out(0,string) "Password: "
expect: set expect_out(spawn_id) "exp4"
expect: set expect_out(buffer) "User1\r\n\r\nPassword: "
send: sending "pw123\r" to { exp4 }

expect: does "" (spawn_id exp4) match glob pattern "RTR1>"? no


expect: does "\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no


expect: does "\r\n\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
     Welcome to the Backbone Technician Interface


expect: does "\r\n\r\n      Welcome to the Backbone Technician Interface\r\n\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
Mounting new volume...

expect: does "\r\n\r\n      Welcome to the Backbone Technician Interface\r\n\r\nMounting new volume...\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
Device label:

expect: does "\r\n\r\n      Welcome to the Backbone Technician Interface\r\n\r\nMounting new volume...\r\nDevice label: \r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
Directory: 2:

expect: does "\r\n\r\n      Welcome to the Backbone Technician Interface\r\n\r\nMounting new volume...\r\nDevice label: \r\nDirectory: 2:\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
New Present Working Directory: 2:

expect: does "\r\n\r\n      Welcome to the Backbone Technician Interface\r\n\r\nMounting new volume...\r\nDevice label: \r\nDirectory: 2:\r\nNew Present Working Directory: 2:\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no

RTR1>
expect: does "\r\n\r\n      Welcome to the Backbone Technician Interface\r\n\r\nMounting new volume...\r\nDevice label: \r\nDirectory: 2:\r\nNew Present Working Directory: 2:\r\n\r\nRTR1>" (spawn_id exp4) match glob pattern "RTR1>"? yes
expect: set expect_out(0,string) "RTR1>"
expect: set expect_out(spawn_id) "exp4"
expect: set expect_out(buffer) "\r\n\r\n      Welcome to the Backbone Technician Interface\r\n\r\nMounting new volume...\r\nDevice label: \r\nDirectory: 2:\r\nNew Present Working Directory: 2:\r\n\r\nRTR1>"
send: sending "date\r" to { exp4 }

expect: does "" (spawn_id exp4) match glob pattern "RTR1>"? no
d
expect: does "d" (spawn_id exp4) match glob pattern "RTR1>"? no
at
expect: does "dat" (spawn_id exp4) match glob pattern "RTR1>"? no
e
expect: does "date" (spawn_id exp4) match glob pattern "RTR1>"? no


expect: does "date\r\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
Jan 10, 2006  8:46:53 [GMT]

expect: does "date\r\r\nJan 10, 2006  8:46:53 [GMT]\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no


expect: does "date\r\r\nJan 10, 2006  8:46:53 [GMT]\r\n\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
RTR1>
expect: does "date\r\r\nJan 10, 2006  8:46:53 [GMT]\r\n\r\nRTR1>" (spawn_id exp4) match glob pattern "RTR1>"? yes
expect: set expect_out(0,string) "RTR1>"
expect: set expect_out(spawn_id) "exp4"
expect: set expect_out(buffer) "date\r\r\nJan 10, 2006  8:46:53 [GMT]\r\n\r\nRTR1>"

Result when it stop at the Login prompt
--------------------------------------------------
bash-2.05$ ./test6
expect version 5.32.2
argv[0] = /usr/bin/expect  argv[1] = -d  argv[2] = ./test6  
set argc 0
set argv0 "./test6"
set argv ""
executing commands from command file ./test6
spawn telnet 1.1.1.2
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {3175}

expect: does "" (spawn_id exp4) match glob pattern "Login: "? no
Trying 1.1.1.2...

expect: does "Trying 1.1.1.2...\r\r\n" (spawn_id exp4) match glob pattern "Login: "? no
Connected to 1.1.1.2.
Escape character is '^]'.

expect: does "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n" (spawn_id exp4) match glob pattern "Login: "? no


Nortel Networks, Inc.
expect: does "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n\r\n\r\nNortel Networks, Inc." (spawn_id exp4) match glob pattern "Login: "? no
and its Licensors.
Copyright 1992,1993,1994,1995,1996,1997,1998,1999,2000,2001,2002.
All rights reserved.



Login:
expect: does "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n\r\n\r\nNortel Networks, Inc. and its Licensors.\r\nCopyright 1992,1993,1994,1995,1996,1997,1998,1999,2000,2001,2002.\r\nAll rights reserved.\r\n\r\n\r\n\r\nLogin: " (spawn_id exp4) match glob pattern "Login: "? yes
expect: set expect_out(0,string) "Login: "
expect: set expect_out(spawn_id) "exp4"
expect: set expect_out(buffer) "Trying 1.1.1.2...\r\r\nConnected to 1.1.1.2.\r\r\nEscape character is '^]'.\r\r\n\r\n\r\nNortel Networks, Inc. and its Licensors.\r\nCopyright 1992,1993,1994,1995,1996,1997,1998,1999,2000,2001,2002.\r\nAll rights reserved.\r\n\r\n\r\n\r\nLogin: "
send: sending "User1\r" to { exp4 }

expect: does "" (spawn_id exp4) match glob pattern "Password: "? no

** Login Timed out **

expect: does "\r\n** Login Timed out **\r\n" (spawn_id exp4) match glob pattern "Password: "? no
** Goodbye **

expect: does "\r\n** Login Timed out **\r\n** Goodbye **\r\n" (spawn_id exp4) match glob pattern "Password: "? no
expect: timed out
send: sending "pw123\r" to { exp4 }

expect: does "\r\n** Login Timed out **\r\n** Goodbye **\r\n" (spawn_id exp4) match glob pattern "RTR1>""? no
Connection closed by foreign host.

expect: does "\r\n** Login Timed out **\r\n** Goodbye **\r\nConnection closed by foreign host.\r\r\n" (spawn_id exp4) match glob pattern "RTR1>"? no
expect: read eof
expect: set expect_out(spawn_id) "exp4"
expect: set expect_out(buffer) "\r\n** Login Timed out **\r\n** Goodbye **\r\nConnection closed by foreign host.\r\r\n"
send: sending "date\r" to { exp4 send: spawn id exp4 not open
   while executing
"send "date\r""
   (file "./test6" line 9)


Posted by admin (Graham Ellis), 10 January 2006
That's a long post to find a problem in ... if you could cut the problem down it might help us make suggestions and it might even lead to the answer.

HOWEVER ... it does strike me that you're exiting the test script without terminating your telnet, so you might be leaving orphan telnet sessions around whihc prevent you connecting again later - I'm sure your router has a limit and it may be changing its behaviour if it thinks it's under attack.  Try sending an exit and waiting for it to take effect before unning the Tcl exit

I also note that you're just expecting a single string.   If you add extra code to expect a timeout and also other possibilities if things go wrong, you should trap the error (and also learn more about what's causing it).  That was you'll end up with more resilient code as well as fixing the problem.

Posted by Kan (Kan), 16 January 2006
Graham,

Sorry to put in such long post.  
I've followed your advise & modified the script as follows:

#!/usr/bin/expect
set timeout 50
spawn telnet 1.1.1.2
expect {
timeout
       {
       puts "\rTimout waiting for login prompt.\r"
       puts "$expect_out(buffer)\r"
       exit }
"Login Timed out"
       {
       puts "\rRouter Login Timeout.\r "
       puts "$expect_out(buffer)\r"
       exit }
"Login: "
}
send "User1\r"
expect "Password: "
expect {
timeout
       {
       puts "\rTimout waiting for password prompt.\r"
       puts "$expect_out(buffer)\r"
       exit }
"Input timed out."
       {
       puts "\rPassword timeout out.\r"
       puts "$expect_out(buffer)\r"
       exit
       }
"Password: "
}
send "pw123\r"
expect "RTR1>"
send "date\r"
expect "RTR1>"
send "logout\r"
expect {
"Connection closed by foreign host."
{puts "logout completed"}
}
exit

Now, I see the problem. When it stops at the Login prompt, the script exit with "Timeout waiting for password prompts" and the $expect_out(buffer) contain "...Login: ".

This is strange as expect has detected the Login prompt earlier. I think the problem is on the statement
send "User1\r".  The send command did not get thru' and the next  expect statement is waiting for the password prompt.

Not sure if this is due to some timing issue. I've added
"sleep 3" before the send command and it seem to work so far.

Have you seen such issue before? Any recommendation?

Posted by admin (Graham Ellis), 16 January 2006
on 01/16/06 at 07:08:36, Kan wrote:
Have you seen such issue before? Any recommendation?


Yes - because you're automating a process that is designed for human operation, there are occasions when expect scripts respond quicker than the system they're talking with can manage.  You're going the right way about identifying this now - find out where the issues are and then make it more human-like.  There's even a -h option to the send command to help you ....

One other thought struck me.  Your router may have some measures in place to counter automatic attacks, so it may delay and vary its response, or even hang, if you try to contact it more than every so often.   It's a cat and mouse scripting game to sort out if you have that sort of situation!



This page is a thread posted to the opentalk forum at www.opentalk.org.uk and archived here for reference. To jump to the archive index please follow this link.

You can Add a comment or ranking to this page

© WELL HOUSE CONSULTANTS LTD., 2014: Well House Manor • 48 Spa Road • Melksham, Wiltshire • United Kingdom • SN12 7NY
PH: 01144 1225 708225 • FAX: 01144 1225 899360 • EMAIL: info@wellho.net • WEB: http://www.wellho.net • SKYPE: wellho