>> - added some SSL and SASL configuration options to LDAP lookups setup
>> (based on a patch by Christian Roessner) - not fully tested;
> 
> first of all: Thanks so much for taking the time and looking at my patch. 
> Currently I have a partial success:
> ...

> I tell you later on.
> 
I have added some debugging and one "or" statement. For some reason, amavisd 
does not return from ldap->bind():


--- amavisd     2011-01-25 23:50:22.000000000 +0100
+++ ../src/amavisd-new-2.7.0-pre13/amavisd      2011-01-25 20:19:09.000000000 
+0100
@@ -16770,7 +16770,7 @@
         do_log(3,"connect_to_ldap: TLS version %s enabled", $mesg);
       }
     }
-    if ($self->{bind_dn} or $self->{sasl}) {  # bind required
+    if ($self->{bind_dn}) {  # bind required
       my($sasl);
       my($passw) = $self->{bind_password};
       if ($self->{sasl}) {  # using SASL to authenticate?
@@ -16779,7 +16779,6 @@
         $sasl = Authen::SASL->new(mechanism => $self->{sasl_mech},
                                   callback => { user => $self->{sasl_auth_id},
                                                 pass => $passw } );
-        do_log(3,"connect_to_ldap: sasl object %s", $sasl);
       }
       my($mesg) = $ldap->bind($self->{bind_dn},
                               $sasl          ? (sasl     => $sasl)
@@ -16793,8 +16792,6 @@
       } else {  # bind succeeded
         do_log(3,"connect_to_ldap: bind %s succeeded", $self->{bind_dn});
       }
-    } else {
-      do_log(3,"connect_to_ldap: not binding to LDAP");
     }
   }
   $self->ldap($ldap); $self->{incarnation}++;


OpenLDAP logs:

Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 fd=22 ACCEPT from 
IP=127.0.0.1:39559 (IP=0.0.0.0:389)
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=0 EXT 
oid=1.3.6.1.4.1.1466.20037
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=0 STARTTLS
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=0 RESULT oid= err=0 text=
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 fd=22 TLS established 
tls_ssf=128 ssf=128
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=1 BIND dn="" method=163
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=1 BIND 
authcid="cn=mx1.roessner-net.de" authzid="cn=mx1.roessner-net.de"
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=1 BIND 
dn="cn=mail,ou=mail,ou=it,dc=roessner-net,dc=de" mech=EXTERNAL sasl_ssf=0 
ssf=128
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=1 RESULT tag=97 err=0 text=
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=2 SRCH 
base="ou=accounts,ou=remailer,dc=roessner-net,dc=de" scope=2 deref=0 
filter="(&(objectClass=rnsMSPost
fixAccount)(rnsMSRecipientAddress=fblan.de)(rnsMSEnablePostfix=TRUE))"
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=2 SRCH 
attr=rnsMSDeliverToAddress
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=2 SEARCH RESULT tag=101 
err=0 nentries=0 text=
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=3 SRCH 
base="ou=accounts,ou=remailer,dc=roessner-net,dc=de" scope=2 deref=0 
filter="(&(objectClass=rnsMSPost
fixAccount)(rnsMSRecipientAddress=mailhiding.com)(rnsMSEnablePostfix=TRUE))"
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=3 SRCH 
attr=rnsMSDeliverToAddress
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=3 SEARCH RESULT tag=101 
err=0 nentries=0 text=
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=4 SRCH 
base="ou=accounts,ou=remailer,dc=roessner-net,dc=de" scope=2 deref=0 
filter="(&(objectClass=rnsMSPost
fixAccount)(rnsMSRecipientAddress=j3o...@mailhiding.com)(rnsMSEnablePostfix=TRUE))"
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=4 SRCH 
attr=rnsMSDeliverToAddress
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1128 op=4 SEARCH RESULT tag=101 
err=0 nentries=1 text=
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 fd=23 ACCEPT from 
IP=127.0.0.1:39561 (IP=0.0.0.0:389)
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=0 EXT 
oid=1.3.6.1.4.1.1466.20037
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=0 STARTTLS
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=0 RESULT oid= err=0 text=
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 fd=23 TLS established 
tls_ssf=256 ssf=256
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=1 BIND dn="" method=163
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=1 RESULT tag=97 err=14 
text=SASL(0): successful result: 
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=2 BIND dn="" method=163
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=2 RESULT tag=97 err=14 
text=SASL(0): successful result: 
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=3 BIND dn="" method=163
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=3 RESULT tag=97 err=14 
text=SASL(0): successful result: 
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=4 BIND dn="" method=163
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=4 RESULT tag=97 err=14 
text=SASL(0): successful result: 
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=5 BIND dn="" method=163
Jan 25 23:40:18 roessner1 slapd[1516]: conn=1129 op=5 RESULT tag=97 err=14 
text=SASL(0): successful result: 


Thousands of these BIND/RESULT lines :-)

>From the mail.log:

Jan 25 23:40:47 roessner1 amavis[30126]: (30126-01) lookup_ldap 
"j3o...@mailhiding.com", query keys: "j3o...@mailhiding.com", 
"@mailhiding.com", "@.mailhiding.com", "@.com", "@.", base: 
ou=accounts,ou=remailer,dc=roessner-net,dc=de, filter: 
(&(objectClass=rnsMSPostfixAccount)(rnsMSRecipientAddress=%m))Jan 25 23:40:47 
roessner1 amavis[30126]: (30126-01) ldap begin_work
Jan 25 23:40:47 roessner1 amavis[30126]: (30126-01) Connecting to LDAP server
Jan 25 23:40:47 roessner1 amavis[30126]: (30126-01) connect_to_ldap: trying 
ldap://ldap0.roessner-net.de, ldap://db.roessner-net.de
Jan 25 23:40:47 roessner1 amavis[30126]: (30126-01) connect_to_ldap: connected 
to ldap://ldap0.roessner-net.de, ldap://db.roessner-net.de
Jan 25 23:40:47 roessner1 amavis[30126]: (30126-01) connect_to_ldap: TLS 
version Net::LDAP::Extension=HASH(0x7aaff38) enabled
Jan 25 23:40:47 roessner1 amavis[30126]: (30126-01) connect_to_ldap: sasl 
object Authen::SASL=HASH(0x7fb1838)
Jan 25 23:40:47 roessner1 amavis[30123]: (30123-01) Net::Server: Child leaving 
(20)
Jan 25 23:40:47 roessner1 amavis[30123]: (30123-01) Amavis::LDAP::Connection 
DESTROY called
Jan 25 23:40:47 roessner1 amavis[30123]: (30123-01) Amavis::Lookup::LDAP 
DESTROY called

I had added a "I was here" log entry right after the ldap->bind, but that never 
appeared in the logs. I will have a closer look to the ldap routine tomorrow. 
Not sure about bind_dn with SASL and the callback stuff.

Good night from Germany
Christian


---
Roessner-Network-Solutions
Bachelor of Science Informatik
Nahrungsberg 81, 35390 Gießen
F: +49 641 5879091, M: +49 176 93118939
USt-IdNr.: DE225643613
http://www.roessner-network-solutions.com


------------------------------------------------------------------------------
Special Offer-- Download ArcSight Logger for FREE (a $49 USD value)!
Finally, a world-class log management solution at an even better price-free!
Download using promo code Free_Logger_4_Dev2Dev. Offer expires 
February 28th, so secure your free ArcSight Logger TODAY! 
http://p.sf.net/sfu/arcsight-sfd2d
_______________________________________________
AMaViS-user mailing list
AMaViS-user@lists.sourceforge.net 
https://lists.sourceforge.net/lists/listinfo/amavis-user 
 Please visit http://www.ijs.si/software/amavisd/ regularly
 For administrativa requests please send email to rainer at openantivirus dot 
org

Reply via email to