Discussion:
[rancid] Extreme XOS (etc.) slow buffered output & clogin
Zenon Mousmoulas
2012-06-06 08:52:55 UTC
Permalink
Hi,

There is an issue with clogin and buffered output, easily reproducible
with Extreme XOS devices, which by default show a sizable banner
post-login, but I have also been able to reproduce it with Cisco switches,
[...]
However there's still a problem in this version with buffered output
from
the extreme. After login, when you send "\r", the following expect
catches the first prompt, not the one after "\r". This becomes evident
later on, when the expect statement in the loop within run_commands
catches
"disable clipaging\r\n\<prompt>" rather than the command echoed and
its' output. So you're always one step behind, until the end, where you
erroneously see a prompt after sending "quit\r" so you also
send -h "exit\r". This obviously messes up xrancid parsing as
well. See the attached clogin log for more evidence (with exp_internal
added after login).
Some time ago I had posted a patch which tried to address this, among
other things related to XOS & rancid. Other changes were accepted in 2.3.7
(thanks for that), however this issue is still present in 2.3.8.
My rather ugly workaround was to add this code after login and before
prompt detection:

diff -ru rancid-2.3.8/bin/clogin.in rancid-2.3.8-zmousm/bin/clogin.in
--- rancid-2.3.8/bin/clogin.in 2012-02-01 00:42:14.000000000 +0200
+++ rancid-2.3.8-zmousm/bin/clogin.in 2012-06-06 09:00:59.000000000 +0300
@@ -858,6 +858,16 @@
# if login failed or rsh was unsuccessful, move on to the next device
continue
}
+ # Get all (output after login) you can eat in 1s
+ # (hopefully up to and including the first prompt).
+ # This is mostly necessary to work around
+ # stoopid extreme output buffering.
+ expect {
+ -timeout 1
+ -re "\[\n\r]+" { exp_continue }
+ -re "\[^\n\r]+" { exp_continue -continue_timer }
+ timeout {}
+ }
# Figure out the prompt.
if { [regexp -- "(#| \\(enable\\))" $prompt_match junk] == 1 } {
set enable 0

Unfortunately this introduces a 1 second delay for all (not just XOS)
clogin-controlled devices, but there is no obvious way to avoid this, since
we haven't done prompt detection yet and haven't set $platform.
Furthermore, this issue is not strictly limited to XOS devices, as noted
previously, therefore a slightly different approach would be perhaps to
trigger this delay when the output received after login exceeds some
conservative threshold, but I'm not really sure if and how one could do
such a thing.

I can send again (off-list) clogin output with expect debugging enabled,
depicting the issue described above, as well as the correct output of
clogin patched with the code above.
While going through the list archives, I also found this post which shows
how xrancid parsing (see: missed cmds) and output is messed up exactly due
to this issue:
http://www.shrubbery.net/pipermail/rancid-discuss/2012-April/006308.html

Please advise how this issue can be addressed.

Thanks,
Zenon Mousmoulas
Zenon Mousmoulas
2012-06-06 17:54:27 UTC
Permalink
Hi again,

Taking a closer look, the particular issue is due to '>' appearing in the
banner XOS sends (by default) after login. The attached patch takes care of
this. I can not recall if this appeared in XOS 12.5 or earlier.

I understand there is a timeout pattern, implicitly added by a previous
expect_after command, therefore slow/late output should never be an issue.
As mentioned previously, I have also seen this issue on Cisco switches with
similarly large post-login banners (banner motd). However I can't reproduce
this currently, so let me take this back and the suggested ugly workaround.
Sorry for the noise.

Best regards,
Z.
Post by Zenon Mousmoulas
Hi,
There is an issue with clogin and buffered output, easily reproducible
with Extreme XOS devices, which by default show a sizable banner
post-login, but I have also been able to reproduce it with Cisco switches,
On Thu, 01 Dec 2011 03:44:32 +0200, Zenon Mousmoulas
[...]
However there's still a problem in this version with buffered output
from
the extreme. After login, when you send "\r", the following expect
catches the first prompt, not the one after "\r". This becomes evident
later on, when the expect statement in the loop within run_commands
catches
"disable clipaging\r\n\<prompt>" rather than the command echoed and
its' output. So you're always one step behind, until the end, where you
erroneously see a prompt after sending "quit\r" so you also
send -h "exit\r". This obviously messes up xrancid parsing as
well. See the attached clogin log for more evidence (with exp_internal
added after login).
Some time ago I had posted a patch which tried to address this, among
other things related to XOS & rancid. Other changes were accepted in 2.3.7
(thanks for that), however this issue is still present in 2.3.8.
My rather ugly workaround was to add this code after login and before
diff -ru rancid-2.3.8/bin/clogin.in rancid-2.3.8-zmousm/bin/clogin.in
--- rancid-2.3.8/bin/clogin.in 2012-02-01 00:42:14.000000000 +0200
+++ rancid-2.3.8-zmousm/bin/clogin.in 2012-06-06 09:00:59.000000000 +0300
@@ -858,6 +858,16 @@
# if login failed or rsh was unsuccessful, move on to the next device
continue
}
+ # Get all (output after login) you can eat in 1s
+ # (hopefully up to and including the first prompt).
+ # This is mostly necessary to work around
+ # stoopid extreme output buffering.
+ expect {
+ -timeout 1
+ -re "\[\n\r]+" { exp_continue }
+ -re "\[^\n\r]+" { exp_continue -continue_timer }
+ timeout {}
+ }
# Figure out the prompt.
if { [regexp -- "(#| \\(enable\\))" $prompt_match junk] == 1 } {
set enable 0
Unfortunately this introduces a 1 second delay for all (not just XOS)
clogin-controlled devices, but there is no obvious way to avoid this, since
we haven't done prompt detection yet and haven't set $platform.
Furthermore, this issue is not strictly limited to XOS devices, as noted
previously, therefore a slightly different approach would be perhaps to
trigger this delay when the output received after login exceeds some
conservative threshold, but I'm not really sure if and how one could do
such a thing.
I can send again (off-list) clogin output with expect debugging enabled,
depicting the issue described above, as well as the correct output of
clogin patched with the code above.
While going through the list archives, I also found this post which shows
how xrancid parsing (see: missed cmds) and output is messed up exactly due
http://www.shrubbery.net/pipermail/rancid-discuss/2012-April/006308.html
Please advise how this issue can be addressed.
Thanks,
Zenon Mousmoulas
Zenon Mousmoulas
2012-06-06 18:03:44 UTC
Permalink
Re-posting the patch with one minor correction.
Post by Zenon Mousmoulas
Hi again,
Taking a closer look, the particular issue is due to '>' appearing in the
banner XOS sends (by default) after login. The attached patch takes care of
this. I can not recall if this appeared in XOS 12.5 or earlier.
I understand there is a timeout pattern, implicitly added by a previous
expect_after command, therefore slow/late output should never be an issue.
As mentioned previously, I have also seen this issue on Cisco switches with
similarly large post-login banners (banner motd). However I can't reproduce
this currently, so let me take this back and the suggested ugly workaround.
Sorry for the noise.
Best regards,
Z.
On Wed, 06 Jun 2012 11:52:55 +0300, Zenon Mousmoulas
Post by Zenon Mousmoulas
Hi,
There is an issue with clogin and buffered output, easily reproducible
with Extreme XOS devices, which by default show a sizable banner
post-login, but I have also been able to reproduce it with Cisco
switches,
Post by Zenon Mousmoulas
On Thu, 01 Dec 2011 03:44:32 +0200, Zenon Mousmoulas
[...]
However there's still a problem in this version with buffered output
from
the extreme. After login, when you send "\r", the following expect
catches the first prompt, not the one after "\r". This becomes evident
later on, when the expect statement in the loop within run_commands
catches
"disable clipaging\r\n\<prompt>" rather than the command echoed and
its' output. So you're always one step behind, until the end, where you
erroneously see a prompt after sending "quit\r" so you also
send -h "exit\r". This obviously messes up xrancid parsing as
well. See the attached clogin log for more evidence (with exp_internal
added after login).
Some time ago I had posted a patch which tried to address this, among
other things related to XOS & rancid. Other changes were accepted in
2.3.7
Post by Zenon Mousmoulas
(thanks for that), however this issue is still present in 2.3.8.
My rather ugly workaround was to add this code after login and before
diff -ru rancid-2.3.8/bin/clogin.in rancid-2.3.8-zmousm/bin/clogin.in
--- rancid-2.3.8/bin/clogin.in 2012-02-01 00:42:14.000000000 +0200
+++ rancid-2.3.8-zmousm/bin/clogin.in 2012-06-06 09:00:59.000000000
+0300
Post by Zenon Mousmoulas
@@ -858,6 +858,16 @@
# if login failed or rsh was unsuccessful, move on to the next device
continue
}
+ # Get all (output after login) you can eat in 1s
+ # (hopefully up to and including the first prompt).
+ # This is mostly necessary to work around
+ # stoopid extreme output buffering.
+ expect {
+ -timeout 1
+ -re "\[\n\r]+" { exp_continue }
+ -re "\[^\n\r]+" { exp_continue -continue_timer }
+ timeout {}
+ }
# Figure out the prompt.
if { [regexp -- "(#| \\(enable\\))" $prompt_match junk] == 1 } {
set enable 0
Unfortunately this introduces a 1 second delay for all (not just XOS)
clogin-controlled devices, but there is no obvious way to avoid this,
since
Post by Zenon Mousmoulas
we haven't done prompt detection yet and haven't set $platform.
Furthermore, this issue is not strictly limited to XOS devices, as noted
previously, therefore a slightly different approach would be perhaps to
trigger this delay when the output received after login exceeds some
conservative threshold, but I'm not really sure if and how one could do
such a thing.
I can send again (off-list) clogin output with expect debugging enabled,
depicting the issue described above, as well as the correct output of
clogin patched with the code above.
While going through the list archives, I also found this post which
shows
Post by Zenon Mousmoulas
how xrancid parsing (see: missed cmds) and output is messed up exactly
due
http://www.shrubbery.net/pipermail/rancid-discuss/2012-April/006308.html
Post by Zenon Mousmoulas
Post by Zenon Mousmoulas
Please advise how this issue can be addressed.
Thanks,
Zenon Mousmoulas
Mickey Everts
2012-06-07 15:24:40 UTC
Permalink
This patch appears to have resolved all of our issues on our switches with Extreme XOS 12.5.X and 12.6.X, and not created any new ones in our mixed environment of Cisco, Extreme, and Juniper devices.

It would be really nice to see this included by default in the next release.

Mickey

-----Original Message-----
From: Zenon Mousmoulas [mailto:***@noc.grnet.gr]
Sent: Wednesday, June 06, 2012 1:04 PM
To: rancid-***@shrubbery.net
Cc: Mickey Everts
Subject: Re: [PATCH] clogin default prompt matches Extreme XOS banner (was: Re: Extreme XOS (etc.) slow buffered output & clogin)

Re-posting the patch with one minor correction.
Post by Zenon Mousmoulas
Hi again,
Taking a closer look, the particular issue is due to '>' appearing in the
banner XOS sends (by default) after login. The attached patch takes
care
of
Post by Zenon Mousmoulas
this. I can not recall if this appeared in XOS 12.5 or earlier.
I understand there is a timeout pattern, implicitly added by a
previous expect_after command, therefore slow/late output should never
be an
issue.
Post by Zenon Mousmoulas
As mentioned previously, I have also seen this issue on Cisco switches with
similarly large post-login banners (banner motd). However I can't reproduce
this currently, so let me take this back and the suggested ugly workaround.
Sorry for the noise.
Best regards,
Z.
On Wed, 06 Jun 2012 11:52:55 +0300, Zenon Mousmoulas
Post by Zenon Mousmoulas
Hi,
There is an issue with clogin and buffered output, easily
reproducible with Extreme XOS devices, which by default show a
sizable banner post-login, but I have also been able to reproduce it
with Cisco
switches,
Post by Zenon Mousmoulas
On Thu, 01 Dec 2011 03:44:32 +0200, Zenon Mousmoulas
[...]
However there's still a problem in this version with buffered output
from
the extreme. After login, when you send "\r", the following expect
catches the first prompt, not the one after "\r". This becomes
evident later on, when the expect statement in the loop within
run_commands catches "disable clipaging\r\n\<prompt>" rather than
the command echoed and its' output. So you're always one step
behind, until the end, where
you
Post by Zenon Mousmoulas
Post by Zenon Mousmoulas
erroneously see a prompt after sending "quit\r" so you also send -h
"exit\r". This obviously messes up xrancid parsing as well. See the
attached clogin log for more evidence (with exp_internal added after
login).
Some time ago I had posted a patch which tried to address this, among
other things related to XOS & rancid. Other changes were accepted in
2.3.7
Post by Zenon Mousmoulas
(thanks for that), however this issue is still present in 2.3.8.
My rather ugly workaround was to add this code after login and before
diff -ru rancid-2.3.8/bin/clogin.in rancid-2.3.8-zmousm/bin/clogin.in
--- rancid-2.3.8/bin/clogin.in 2012-02-01 00:42:14.000000000 +0200
+++ rancid-2.3.8-zmousm/bin/clogin.in 2012-06-06 09:00:59.000000000
+0300
Post by Zenon Mousmoulas
@@ -858,6 +858,16 @@
# if login failed or rsh was unsuccessful, move on to the next device
continue
}
+ # Get all (output after login) you can eat in 1s
+ # (hopefully up to and including the first prompt).
+ # This is mostly necessary to work around
+ # stoopid extreme output buffering.
+ expect {
+ -timeout 1
+ -re "\[\n\r]+" { exp_continue }
+ -re "\[^\n\r]+" { exp_continue -continue_timer }
+ timeout {}
+ }
# Figure out the prompt.
if { [regexp -- "(#| \\(enable\\))" $prompt_match junk] == 1 } {
set enable 0
Unfortunately this introduces a 1 second delay for all (not just XOS)
clogin-controlled devices, but there is no obvious way to avoid this,
since
Post by Zenon Mousmoulas
we haven't done prompt detection yet and haven't set $platform.
Furthermore, this issue is not strictly limited to XOS devices, as noted
previously, therefore a slightly different approach would be perhaps
to trigger this delay when the output received after login exceeds
some conservative threshold, but I'm not really sure if and how one
could do such a thing.
I can send again (off-list) clogin output with expect debugging enabled,
depicting the issue described above, as well as the correct output of
clogin patched with the code above.
While going through the list archives, I also found this post which
shows
Post by Zenon Mousmoulas
how xrancid parsing (see: missed cmds) and output is messed up exactly
due
http://www.shrubbery.net/pipermail/rancid-discuss/2012-April/006308.html
Post by Zenon Mousmoulas
Post by Zenon Mousmoulas
Please advise how this issue can be addressed.
Thanks,
Zenon Mousmoulas
Loading...