Looks like there really are only 3 lines to read.
Telnet is printing those lines, not windows. It's just indicating
that it successfully connected. Windows is saying nothing.
This is a little weird, because:
- It can happen when the telnet server isn't running at all,
but it seemed to be running fine when you connected manually.
- It can happen when trying to connect to the wrong port, but I
see you set the port to 23.
It can also happen due to the short default timeout of 10 seconds.
Windows can take longer than that to send something.
Are you sure you increased the timeout? You only sent a log of 4
seconds (starting at 12:27:25). How long does
read_until_output_matches() wait before it gives up?
----- Original Message -----
From: "sudhir kumar" <smalikphy@xxxxxxxxx>
To: "kvm-devel" <kvm@xxxxxxxxxxxxxxx>
Cc: "Lucas Meneghel Rodrigues" <mrodrigu@xxxxxxxxxx>, "Michael Goldish" <mgoldish@xxxxxxxxxx>, "Ryan Harper" <ryanh@xxxxxxxxxx>
Sent: Tuesday, August 4, 2009 8:06:32 AM (GMT+0200) Auto-Detected
Subject: [AUTOTEST]telnet login fails in win2k8 DC 64. here are debug and other info
Hi,
I am seeing a telnet failure in autotest to a win2k8 DC 64 bit guest.
I have tried some debugging and came to a conclusion that
read_nonblocking() is reading only 3 lines. let me first print the
output of manual login
# telnet -l Administrator 10.0.99.100 23
Trying 10.0.99.100...
Connected to ichigo-dom100.linuxperf9025.net (10.0.99.100).
Escape character is '^]'.
Welcome to Microsoft Telnet Service
password:
*===============================================================
Microsoft Telnet Server.
*===============================================================
C:\Users\Administrator>
Now autotest only reads the first 3 lines(upto Escape.....). It seems
windows is doing something nasty here. I have put some debug prints in
the code and here is the output. let me first put the code snippet
from kvm_utils.py with added debug prints.
def read_until_output_matches(self, patterns, filter=lambda(x):x,
timeout=30.0, internal_timeout=3.0,
print_func=None):
<snip>
end_time = time.time() + timeout
while time.time() < end_time:
# Read data from child
newdata = self.read_nonblocking(internal_timeout)
print("DEBUG: Printing data read by read_nonblocking from output:")
print("DEBUG: data read from output is %s" % newdata)
print("DEBUG: Printing data read by read_nonblocking from
output done.")
# Print it if necessary
if print_func and newdata:
map(print_func, newdata.splitlines())
data += newdata
print("DEBUG: Printing accumulated data read from output:")
print("DEBUG: accumulated data read from output is %s" % data)
print("DEBUG: Printing accumulated data read from output done.")
done = False
# Look for patterns
print("DEBUG: Printing data after filter:")
print("DEBUG: filtered data is %s" % filter(data))
print("DEBUG: Printing data after filter done:")
match = self.match_patterns(filter(data), patterns)
if match != None:
done = True
# Check if child has died
if self.poll() != None:
logging.debug("Process terminated with status %d", self.poll())
done = True
# Are we done?
if done: break
<snip>
Here is the output once the guest comes up.
12:27:25 INFO | DEBUG: Printing data read by read_nonblocking from output:
12:27:25 INFO | DEBUG: data read from output is Trying 10.0.99.100...
12:27:25 INFO | Connected to ichigo-dom100.linuxperf9025.net (10.0.99.100).
12:27:25 INFO | Escape character is '^]'.
12:27:25 INFO |
12:27:25 INFO | DEBUG: Printing data read by read_nonblocking from output done.
12:27:25 INFO | DEBUG: Printing accumulated data read from output:
12:27:25 INFO | DEBUG: accumulated data read from output is Trying
10.0.99.100...
12:27:25 INFO | Connected to ichigo-dom100.linuxperf9025.net (10.0.99.100).
12:27:25 INFO | Escape character is '^]'.
12:27:25 INFO |
12:27:25 INFO | DEBUG: Printing accumulated data read from output done.
12:27:25 INFO | DEBUG: Printing data after filter:
12:27:25 INFO | DEBUG: filtered data is Escape character is '^]'.
12:27:25 INFO | DEBUG: Printing data after filter done:
12:27:29 INFO | DEBUG: Printing data read by read_nonblocking from output:
12:27:29 INFO | DEBUG: data read from output is
12:27:29 INFO | DEBUG: Printing data read by read_nonblocking from output done.
12:27:29 INFO | DEBUG: Printing accumulated data read from output:
12:27:29 INFO | DEBUG: accumulated data read from output is Trying
10.0.99.100...
12:27:29 INFO | Connected to ichigo-dom100.linuxperf9025.net (10.0.99.100).
12:27:29 INFO | Escape character is '^]'.
12:27:29 INFO |
12:27:29 INFO | DEBUG: Printing accumulated data read from output done.
12:27:29 INFO | DEBUG: Printing data after filter:
12:27:29 INFO | DEBUG: filtered data is Escape character is '^]'.
12:27:29 INFO | DEBUG: Printing data after filter done:
and so on... timeout elapses and test fails.
I am not able to find out why read_nonblocking() is reading only 3
lines. I have tried increasing the timeouts and internal_timeouts as
well. But no luck.
Here is how my kvm_tests.cfg looks like.
# colorful prompt, so migration_test_command will fail, try with telnet
ssh_prompt = "C:\Users\Administrator>"
ssh_port = 23
use_telnet = yes
Any clues ?
--
Sudhir Kumar
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
