Authen::SASL 2.13 infinite loop bug (resend?)
Forrest Cahoon
archives. Now I've subscribed and am resending to see if that works.
Sorry if this is a duplicate.
I'm porting some code from our old system to a new one, and I
encountered this bug with Authen::SASL 2.13 which was resolved by
downgrading to 2.12.
I'm afraid I don't know that much about SASL (or LDAP), but I did cut
this down to as close to a "hello world" version as I could.
Here's my code (with some names changed to protect the innocent):
use strict;
use Net::LDAP;
use Authen::SASL;
my $ldap = Net::LDAP->new(
'ldaps://my.ldap.server',
version => 3,
verify => 'require',
clientcert => '/path/to/my/client/cert',
clientkey => '/path/to/my/client/key',
cafile => '/path/to/my/cafile',
timeout => 10,
);
die "no Net::LDAP: $!\n" unless $ldap;
my $sasl = Authen::SASL->new(
mechanism => 'EXTERNAL',
callback => { user => '' },
debug => 13,
);
alarm(10); # for Devel::SimpleTrace
my $result = $ldap->bind( "sn=msiScripts,dc=DTC", sasl => $sasl );
if ( $result->code ) {
die "bind with sasl failed: " . $result->error;
}
print "success!\n";
__END__
Using Authen::SASL 2.13, running this code with -wMDevel::SimpleTrace
gives the following stack trace when the alarm times out:
Deep recursion on subroutine "Net::LDAP::_sendmesg"
at Net::LDAP::_sendmesg(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP/Bind.pm
line 64, <DATA>:275)
at Net::LDAP::Bind::decode(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP/Bind.pm:64)
at Net::LDAP::process(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:865)
at Net::LDAP::sync(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:760)
at Net::LDAP::_sendmesg(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:813)
at Net::LDAP::Bind::decode(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP/Bind.pm:64)
at Net::LDAP::process(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:865)
at Net::LDAP::sync(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:760)
at Net::LDAP::_sendmesg(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:813)
[ ... many, many, many, many, many iterations of the same loop omitted ... ]
at Net::LDAP::Bind::decode(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP/Bind.pm:64)
at Net::LDAP::process(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:865)
at Net::LDAP::sync(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:760)
at Net::LDAP::_sendmesg(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:813)
at Net::LDAP::bind(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:422)
at main::(ldaptest.pl:25)
When I downgraded to Authen::SASL 2.12, I got a "success!" message
(yay!) but I also got an interesting stack trace from
Devel::Simpletrace:
Use of uninitialized value in numeric gt (>)
at Authen::SASL::Perl::securesocket(/usr/local/lib/perl5/site_perl/5.10.1/Authen/SASL/Perl.pm
line 130, <DATA>:275)
at Net::LDAP::Bind::decode(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP/Bind.pm:39)
at Net::LDAP::process(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:865)
at Net::LDAP::sync(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:760)
at Net::LDAP::_sendmesg(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:813)
at Net::LDAP::Bind::decode(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP/Bind.pm:64)
at Net::LDAP::process(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:865)
at Net::LDAP::sync(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:760)
at Net::LDAP::_sendmesg(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:813)
at Net::LDAP::bind(/usr/local/lib/perl5/site_perl/5.10.1/Net/LDAP.pm:422)
at main::(ldaptest.pl:25)
success!
Perhaps the changes in 2.13 included a bad fix for the nonfatal error
shown for 2.12 here?
Forrest Cahoon
Graham Barr
> I sent this to the list yesterday, but I never saw it show up in the
> archives. Now I've subscribed and am resending to see if that works.
> Sorry if this is a duplicate.
I did not see it yesterday.
> I'm porting some code from our old system to a new one, and I
> encountered this bug with Authen::SASL 2.13 which was resolved by
> downgrading to 2.12.
I suspect this was caused by this change
http://github.com/gbarr/perl-authen-sasl/commit/c636a0603732b031d9274e123dd4900749d8d5d9
I do not know much about EXTERNAL, but what happens if we revert client_step to what it was ?
Can you also turn on debug with $ldap->debug(15); so we can see what responses the server
is returning as this should not loop.
Graham.
Forrest Cahoon
> On Feb 11, 2010, at 9:10 AM, Forrest Cahoon wrote:
>
>> I'm porting some code from our old system to a new one, and I
>> encountered this bug with Authen::SASL 2.13 which was resolved by
>> downgrading to 2.12.
>
> I suspect this was caused by this change
>
> http://github.com/gbarr/perl-authen-sasl/commit/c636a0603732b031d9274e123dd4900749d8d5d9
>
> I do not know much about EXTERNAL, but what happens if we revert client_step to what it was ?
Reinstalling 2.13 from CPAN and uncommenting the client_step sub
worked, giving me the same results as I got with 2.12.
I also happened to notice there are some patch output files that get
installed in Authen/SASL/Perl -- a couple of .orig files and (somewhat
disconcertingly) a *.rej file. They don't hurt anything, of course,
but should probably be cleaned up.
>> When I downgraded to Authen::SASL 2.12, I got a "success!" message
>> (yay!) but I also got an interesting stack trace from
>> Devel::Simpletrace:
>>
>> Use of uninitialized value in numeric gt (>)
>> at Authen::SASL::Perl::securesocket(/usr/local/lib/perl5/site_perl/5.10.1/Authen/SASL/Perl.pm
>> line 130, <DATA>:275)
I eliminated this warning by adding a check for definedness. Even
though I don't really understand what the code does, this seems like a
pretty safe fix (since that's what its doing anyway after the
warning);
--- Authen/SASL/Perl.pm~ 2009-09-23 23:38:17.000000000 -0500
+++ Authen/SASL/Perl.pm 2010-02-11 10:15:48.030213720 -0600
@@ -127,7 +127,7 @@
sub securesocket {
my $self = shift;
- return $_[0] unless ($self->property('ssf') > 0);
+ return $_[0] unless (defined $self->property('ssf') &&
$self->property('ssf') > 0);
local *GLOB; # avoid used only once warning
my $glob = \do { local *GLOB; };
Graham Barr
On Feb 11, 2010, at 10:59 AM, Forrest Cahoon wrote:
> On Thu, Feb 11, 2010 at 9:43 AM, Graham Barr <gb...@pobox.com> wrote:
>> On Feb 11, 2010, at 9:10 AM, Forrest Cahoon wrote:
>
>>
>>> I'm porting some code from our old system to a new one, and I
>>> encountered this bug with Authen::SASL 2.13 which was resolved by
>>> downgrading to 2.12.
>>
>> I suspect this was caused by this change
>>
>> http://github.com/gbarr/perl-authen-sasl/commit/c636a0603732b031d9274e123dd4900749d8d5d9
>>
>> I do not know much about EXTERNAL, but what happens if we revert client_step to what it was ?
>
> Reinstalling 2.13 from CPAN and uncommenting the client_step sub
> worked, giving me the same results as I got with 2.12.
I do not understand why you are getting asked for the extra step though, as it should not happen.
Thats why the debug trace from Net::LDAP would be useful.
> I also happened to notice there are some patch output files that get
> installed in Authen/SASL/Perl -- a couple of .orig files and (somewhat
> disconcertingly) a *.rej file. They don't hurt anything, of course,
> but should probably be cleaned up.
Eek! how did they get into the release. They will be gone next time :)
Graham.
Forrest Cahoon
>
> On Feb 11, 2010, at 10:59 AM, Forrest Cahoon wrote:
>
>> Reinstalling 2.13 from CPAN and uncommenting the client_step sub
>> worked, giving me the same results as I got with 2.12.
>
> I do not understand why you are getting asked for the extra step though, as it should not happen.
>
> Thats why the debug trace from Net::LDAP would be useful.
Oh, duh, I was thinking of the debug on SASL, which didn't seem to
produce any output. Here's what you're looking for:
Net::LDAP=HASH(0xc1b4c8) sending:
30 2A 02 01 01 60 25 02 01 03 04 14 73 6E 3D 6D 0*...`%.....sn=m
73 69 53 63 72 69 70 74 73 2C 64 63 3D 44 54 43 siScripts,dc=DTC
A3 0A 04 08 45 58 54 45 52 4E 41 4C __ __ __ __ ....EXTERNAL
0000 42: SEQUENCE {
0002 1: INTEGER = 1
0005 37: [APPLICATION 0] {
0007 1: INTEGER = 3
000A 20: STRING = 'sn=msiScripts,dc=DTC'
0020 10: [CONTEXT 3] {
0022 8: STRING = 'EXTERNAL'
002C : }
002C : }
002C : }
Net::LDAP=HASH(0xc1b4c8) received:
30 2A 02 01 01 61 25 0A 01 0E 04 00 04 1C 53 41 0*...a%.......SA
53 4C 28 30 29 3A 20 73 75 63 63 65 73 73 66 75 SL(0): successfu
6C 20 72 65 73 75 6C 74 3A 20 87 00 __ __ __ __ l result: ..
0000 42: SEQUENCE {
0002 1: INTEGER = 1
0005 37: [APPLICATION 1] {
0007 1: ENUM = 14
000A 0: STRING = ''
000C 28: STRING = 'SASL(0): successful result: '
002A 0: [CONTEXT 7]
002C : }
002C : }
Net::LDAP=HASH(0xd312f8) sending:
30 2C 02 01 02 60 27 02 01 03 04 14 73 6E 3D 6D 0,...`'.....sn=m
73 69 53 63 72 69 70 74 73 2C 64 63 3D 44 54 43 siScripts,dc=DTC
A3 0C 04 08 45 58 54 45 52 4E 41 4C 04 00 __ __ ....EXTERNAL..
0000 44: SEQUENCE {
0002 1: INTEGER = 2
0005 39: [APPLICATION 0] {
0007 1: INTEGER = 3
000A 20: STRING = 'sn=msiScripts,dc=DTC'
0020 12: [CONTEXT 3] {
0022 8: STRING = 'EXTERNAL'
002C 0: STRING = ''
002E : }
002E : }
002E : }
Net::LDAP=HASH(0xd312f8) received:
30 0C 02 01 02 61 07 0A 01 00 04 00 04 00 __ __ 0....a........
0000 12: SEQUENCE {
0002 1: INTEGER = 2
0005 7: [APPLICATION 1] {
0007 1: ENUM = 0
000A 0: STRING = ''
000C 0: STRING = ''
000E : }
000E : }
success!
Forrest
Graham Barr
Thats odd. It is responding that the SASL was a success, then the status code 14 = LDAP_SASL_BIND_IN_PROGRESS
> Net::LDAP=HASH(0xd312f8) sending:
>
> 30 2C 02 01 02 60 27 02 01 03 04 14 73 6E 3D 6D 0,...`'.....sn=m
> 73 69 53 63 72 69 70 74 73 2C 64 63 3D 44 54 43 siScripts,dc=DTC
> A3 0C 04 08 45 58 54 45 52 4E 41 4C 04 00 __ __ ....EXTERNAL..
>
> 0000 44: SEQUENCE {
> 0002 1: INTEGER = 2
> 0005 39: [APPLICATION 0] {
> 0007 1: INTEGER = 3
> 000A 20: STRING = 'sn=msiScripts,dc=DTC'
> 0020 12: [CONTEXT 3] {
> 0022 8: STRING = 'EXTERNAL'
> 002C 0: STRING = ''
Hm, odd that 2nd STRING was not in the first request. I wonder if thats why
In Net/LDAP.pm the bind sub we have
$passwd = {
mechanism => $sasl_conn->mechanism,
credentials => (length($initial) ? $initial : undef)
};
what happens if you change that to be just credentials => $initial,
Graham
Forrest Cahoon
> In Net/LDAP.pm the bind sub we have
>
> $passwd = {
> mechanism => $sasl_conn->mechanism,
> credentials => (length($initial) ? $initial : undef)
> };
>
> what happens if you change that to be just credentials => $initial,
Here we go:
Net::LDAP=HASH(0xc04818) sending:
30 2C 02 01 01 60 27 02 01 03 04 14 73 6E 3D 6D 0,...`'.....sn=m
73 69 53 63 72 69 70 74 73 2C 64 63 3D 44 54 43 siScripts,dc=DTC
A3 0C 04 08 45 58 54 45 52 4E 41 4C 04 00 __ __ ....EXTERNAL..
0000 44: SEQUENCE {
0002 1: INTEGER = 1
0005 39: [APPLICATION 0] {
0007 1: INTEGER = 3
000A 20: STRING = 'sn=msiScripts,dc=DTC'
0020 12: [CONTEXT 3] {
0022 8: STRING = 'EXTERNAL'
002C 0: STRING = ''
002E : }
002E : }
002E : }
Net::LDAP=HASH(0xc04818) received:
30 0C 02 01 01 61 07 0A 01 00 04 00 04 00 __ __ 0....a........
0000 12: SEQUENCE {
0002 1: INTEGER = 1
0005 7: [APPLICATION 1] {
0007 1: ENUM = 0
000A 0: STRING = ''
000C 0: STRING = ''
000E : }
000E : }
success!
> Graham
Forrest
Forrest Cahoon
Just checking up ... did you ever make any changes based on this issue?
Forrest