Re: [Expectperl-discuss] Expect issues with custom OpenBSD and application interaction.

[Eric T. <zi...@gm...>]

Roland,

Thanks for the heads up on the version.  I did upgrade and it did make a
little more sense but I still have the same issue.  Here is the debug output
when run with the latest version:

_________________________________________________________________________________
Spawned 'ssh -l admin batista'
        spawn id(5)
        Pid: 30003
        Tty: /dev/pts/4
 at /usr/lib/perl5/site_perl/5.8.6/Expect.pm line 179
        Expect::spawn('Expect', 'ssh -l admin batista') called at bug_15725
line 18
Starting EXPECT pattern matching...
 at /usr/lib/perl5/site_perl/5.8.6/Expect.pm line 559
        Expect::expect('Expect=GLOB(0x8da4ddc)', 30, 'passphrase') called at
bug_15725 line 22
spawn id(5): list of patterns:
  #1: -ex `passphrase'


spawn id(5): Does `'
match:
  pattern #1: -ex `passphrase'? No.

Waiting for new data (30 seconds)...
Enter passphrase for key '/root/.ssh/id_dsa':
spawn id(5): Does `Enter passphrase for key \'/root/.ssh/id_dsa\': '
match:
  pattern #1: -ex `passphrase'? YES!!
    Before match string: `Enter '
    Match string: `passphrase'
    After match string: ` for key \'/root/.ssh/id_dsa\': '
    Matchlist: ()
Returning from expect successfully.
...recieved password prompt
Sending 'password\n' to spawn id(5)
 at /usr/lib/perl5/site_perl/5.8.6/Expect.pm line 1248
        Expect::print('Expect=GLOB(0x8da4ddc)', 'password\x{a}') called at
bug_15725 line 27
Starting EXPECT pattern matching...
 at /usr/lib/perl5/site_perl/5.8.6/Expect.pm line 559
        Expect::expect('Expect=GLOB(0x8da4ddc)', 30, '/# ') called at
bug_15725 line 28
spawn id(5): list of patterns:
  #1: -ex `/# '


spawn id(5): Does ` for key \'/root/.ssh/id_dsa\': '
match:
  pattern #1: -ex `/# '? No.

Waiting for new data (30 seconds)...


spawn id(5): Does ` for key \'/root/.ssh/id_dsa\': \r\n'
match:
  pattern #1: -ex `/# '? No.

Waiting for new data (30 seconds)...
Last login: CLI on Tue Jul 25 15:05:45 2006 from 10.0.2.229

Custom OS v3.5
Copyright (c) 2000-2006 Some Company, Inc.  All Rights Reserved.

Welcome to Custom OS


spawn id(5): Does ` for key \'/root/.ssh/id_dsa\': \r\nLast login: CLI on
Tue Jul 25 15:05:45 2006 from 10.0.2.229\r\n\r\nCustom OS
v3.5\r\nCopyright(c) 2000-2006 Some Company Inc.  All Rights
Reserved.\r\n\r\nWelcome to
Custom OS\r\n\r\n'
match:
  pattern #1: -ex `/# '? No.

Waiting for new data (30 seconds)...
admin@batista:/#
spawn id(5): Does ` for key \'/root/.ssh/id_dsa\': \r\nLast login: CLI on
Tue Jul 25 15:05:45 2006 from 10.0.2.229\r\n\r\nCustom OS
v3.5\r\nCopyright(c) 2000-2006 Some Company, Inc.  All Rights
Reserved.\r\n\r\nWelcome to
Custom OSr\n\r\nadmin@batista:/# '
match:
  pattern #1: -ex `/# '? YES!!
    Before match string: ` for key \'/root/.ssh/id_dsa\': \r\nLast login:
CLI on Tue Jul 25 15:05:45 2006 from 10.0.2.229\r\n\r\nCustom OS
v3.5\r\nCopyright (c) 2000-2006 Some Company, Inc.  All Rights
Reserved.\r\n\r\nWelcome to Custom OS\r\n\r\nadmin@batista:'
    Match string: `/# '
    After match string: `'
    Matchlist: ()
Returning from expect successfully.
Sending 'sys hard\n' to spawn id(5)
 at /usr/lib/perl5/site_perl/5.8.6/Expect.pm line 1248
        Expect::print('Expect=GLOB(0x8da4ddc)', 'sys hard\x{a}') called at
bug_15725 line 32
Starting EXPECT pattern matching...
 at /usr/lib/perl5/site_perl/5.8.6/Expect.pm line 559
        Expect::expect('Expect=GLOB(0x8da4ddc)', 30, '/# ') called at
bug_15725 line 33
spawn id(5): list of patterns:
  #1: -ex `/# '


spawn id(5): Does `'
match:
  pattern #1: -ex `/# '? No.

Waiting for new data (30 seconds)...
sys hard

spawn id(5): Does `sys hard\r\n'
match:
  pattern #1: -ex `/# '? No.

Waiting for new data (30 seconds)...
Connection to batista closed.

spawn id(5): Does `sys hard\r\nConnection to batista closed.\r\r\n'
match:
  pattern #1: -ex `/# '? No.

Waiting for new data (30 seconds)...
Returning from expect with TIMEOUT or EOF
Error 03::Never got sec prompt, 3:Child PID 30003 exited with status 0
_________________________________________________________________________________

Here is the source to the script I am using in case that will help.

_________________________________________________________________________________
#!/usr/bin/perl -w

use strict;
use Expect;

my $username = "admin";
my $password = "password\n";

##### flip this value to 0 to turn off stout and 1 to turn it on
$Expect::Log_Stdout=1;

# Lets see what expect is doing!
$Expect::Exp_Internal = 1;
#$Expect::Debug = 3;

my $terminal = new Expect;
$terminal->raw_pty(1);
$terminal = Expect->spawn("ssh -l $username batista");

$terminal->log_file("test_err.txt");

unless ($terminal->expect(30,"passphrase")) {
   die "Error 01::Never got password prompt, ".$terminal->exp_error()."\n";
}
print "...recieved password prompt\n";

$terminal->send($password);
unless ($terminal->expect(30, '/# ')) {
   die "Error 02::Never got first prompt, ".$terminal->exp_error()."\n";
}

$terminal->send("sys hard\n");
unless ($terminal->expect(30, '/# ')) {
   die "Error 03::Never got sec prompt, ".$terminal->exp_error()."\n";
}

$terminal->send("exit\n");
$terminal->log_file(undef);
_________________________________________________________________________________

This session does work normally from a cli ssh session and works fine using
TCL expect and Python expect, just not perl expect.  I think I have nailed
down the location of the issue.  It is the sysread() call on or around line
832 (v 1.20).  After matching on the first promt and sending the "sys hard"
command to the remote server this sysread call only reads back the echoed
command and then detects 0 bytes read ($nread) and translates that to an EOF
and does a hard close:

$nread = 0 unless defined ($nread);
if ($nread == 0) {
   ...
   ...
   blah
   $exp->hard_close();
}

So it is the expect module that is sending the hard close to the distant
end.  The question is why does it not read the correct data from the socket
and continue to try and match?  The only thing it sees back once the sys
hard command is sent is the sys hard command and then text saying the
connection has been terminiated.






On 7/25/06, Roland Giersig <RGi...@cp...> wrote:
>
> Hi Eric,
>
> please upgrade to the latest Expect version (1.20), as you obviously
> have a version where _make_readable() doesn't work. :-( I'm sure that
> the debug output will make much more sense then... ;-)
>
> Ah, yes, and sorry to all for that mistake! That blunder was a good case
> to show that you always should follow the procedure: first create a
> testcase for the bug, showing the bug in the old version. Then fix it
> and test it with the testcase...
>
> Cheers! Roland
>
> > spawn id(5): Does `'
> > match:
> >   pattern #1: -ex `'? YES!!
> >     Before match string: `'
> >     Match string: `'
> >     After match string: `'
> >     Matchlist: ()
>
> --
> RGi...@cp...
>