[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: odd pam_ldap configuration issues



> > [pam_ldap]
> > Whenever I login, I have to enter the password _twice_ until it is
> > accepted.

> With regard to having to log in twice, and I having to do the same
> until Geoff Silver helped me, try the following /etc/pam.d/login.

[...]
> auth       sufficient pam_ldap.so
> auth       required   pam_unix.so nullok use_first_pass
[...]

Thanks for this. I forgot to point out, however, that this problem
is definitely not related to pam configuration. When I tail -f the
ldap logfile I can see two times the ldap database is accessed: once for
each login attempt (the first time just a connection, and the second
time the expected queries). Besides, I completely turned off unix
authentification in pam for testing purposes (just to avoid such
caveats).
 
> Lastly, check the ACLs that give permissions in slapd.conf, and to
> what. You have to be able to search and authenticate to the necessary
> attributes at the very least.

Ok, done that. I can search via ldapsearch for pretty much anything I
want to. And: login _does_ work (as there is no other authentification
mechanism enabled by now), but only at the second attempt.
 
> > I waited for 10 seconds after the first password failure to
> > illustrate what happens until then (i.e. next to nothing, for my
> > knowledge). 

> Probably because you give 2 alternatives

Well, no (unfortunately, otherwise my problems would no be gone...).

> The long wait could have to do with a defective DNS, don't know.

_I_ have waited for 10 seconds with the next login attempt - so it is
easier to see which lines have been caused by which attempt.

> As I said, it's logging too little. [...] A log level of 256 should be
> good enough. This is what I have in my daemon start up script. It's
> not the same as  '-d256', by the way.

Ah. You mean the log level in /usr/local/etc/openldap/slapd.conf, I
suppose? This _is_ at 256 right now. And - don't want to offend you -
this seems to have pretty much the same impact, as -d on the command
line. The log levels seem to be accumulated bitwise.

I tried -1 now, which enables all debuging and received the following
for the first (invalid) login attempt. I don't print logs of the valid
attempt, simply because this seems to be much too much garbage with very
little use.

------------------------------------------------------------------------
daemon: activity on 1 descriptors
daemon: new connection on 9
daemon: conn=4 fd=9 connection from IP=10.10.0.6:33929 (IP=0.0.0.0:389) accepted.
daemon: added 9r
daemon: activity on:
daemon: select: listen=6 active_threads=0 tvp=NULL
daemon: activity on 1 descriptors
daemon: activity on: 9r
daemon: read activity on 9
connection_get(9)
connection_get(9): got connid=4
connection_read(9): checking for input on id=4
ber_get_next
ldap_read: want=1, got=1
  0000:  30                                                 0                 
ldap_read: want=1, got=1
  0000:  1d                                                 .                 
ldap_read: want=29, got=29
  0000:  02 01 01 77 18 80 16 31  2e 33 2e 36 2e 31 2e 34   ...w...1.3.6.1.4  
  0010:  2e 31 2e 31 34 36 36 2e  32 30 30 33 37            .1.1466.20037     
ber_get_next: tag 0x30 len 29 contents:
ber_dump: buf=0x080ef4e8 ptr=0x080ef4e8 end=0x080ef505 len=29
  0000:  02 01 01 77 18 80 16 31  2e 33 2e 36 2e 31 2e 34   ...w...1.3.6.1.4  
  0010:  2e 31 2e 31 34 36 36 2e  32 30 30 33 37            .1.1466.20037     
ber_get_next
ldap_read: want=1 error=Resource temporarily unavailable
ber_get_next on fd 9 failed errno=11 (Resource temporarily unavailable)
do_extended
ber_scanf fmt ({a) ber:
ber_dump: buf=0x080ef4e8 ptr=0x080ef4eb end=0x080ef505 len=26
  0000:  77 18 80 16 31 2e 33 2e  36 2e 31 2e 34 2e 31 2e   w...1.3.6.1.4.1.  
  0010:  31 34 36 36 2e 32 30 30  33 37                     1466.20037        
do_extended: oid=1.3.6.1.4.1.1466.20037
send_ldap_extended 0: (0)
send_ldap_response: msgid=1 tag=120 err=0
ber_flush: 14 bytes to sd 9
  0000:  30 0c 02 01 01 78 07 0a  01 00 04 00 04 00         0....x........    
ldap_write: want=14, written=14
  0000:  30 0c 02 01 01 78 07 0a  01 00 04 00 04 00         0....x........    
daemon: select: listen=6 active_threads=1 tvp=NULL
daemon: activity on 1 descriptors
daemon: activity on: 9r
daemon: read activity on 9
connection_get(9)
connection_get(9): got connid=4
connection_read(9): checking for input on id=4
TLS trace: SSL_accept:before/accept initialization
tls_read: want=11, got=11
  0000:  80 7a 01 03 01 00 51 00  00 00 20                  .z....Q...        
tls_read: want=113, got=113
  0000:  00 00 16 00 00 13 00 00  0a 07 00 c0 00 00 66 00   ..............f.  
  0010:  00 05 00 00 04 03 00 80  01 00 80 08 00 80 00 00   ................  
  0020:  65 00 00 64 00 00 63 00  00 62 00 00 61 00 00 60   e..d..c..b..a..`  
  0030:  00 00 15 00 00 12 00 00  09 06 00 40 00 00 14 00   ...........@....  
  0040:  00 11 00 00 08 00 00 06  00 00 03 04 00 80 02 00   ................  
  0050:  80 72 c0 96 7d 02 16 2b  9d 8f 4a 15 7d 7d 0d 58   .r..}..+..J.}}.X  
  0060:  cf 95 13 c6 b4 3d 5c b4  e8 ae 93 63 3d 00 c9 3c   .....=\....c=..<  
  0070:  49                                                 I                 
TLS trace: SSL_accept:SSLv3 read client hello A
TLS trace: SSL_accept:SSLv3 write server hello A
TLS trace: SSL_accept:SSLv3 write certificate A
TLS trace: SSL_accept:SSLv3 write server done A
tls_write: want=564, written=564
  [hexdump of certificate snipped]
TLS trace: SSL_accept:SSLv3 flush data
tls_read: want=5 error=Resource temporarily unavailable
TLS trace: SSL_accept:error in SSLv3 read client certificate A
TLS trace: SSL_accept:error in SSLv3 read client certificate A
daemon: select: listen=6 active_threads=0 tvp=NULL
daemon: activity on 1 descriptors
daemon: activity on: 9r
daemon: read activity on 9
connection_get(9)
connection_get(9): got connid=4
connection_read(9): checking for input on id=4
tls_read: want=5, got=5
  0000:  16 03 01 00 86                                     .....             
tls_read: want=134, got=134
  0000:  10 00 00 82 00 80 8f 9e  63 2c bd 92 8f 16 0a 15   ........c,......  
  0010:  42 45 2f 11 7b 4a 01 d8  a8 a0 8a 8f 3d 88 05 e1   BE/.{J......=...  
  0020:  40 19 e8 2c c2 b6 2a a0  b7 8d 26 9e 28 cd 73 fa   @..,..*...&.(.s.  
  0030:  29 69 8a 29 5f f8 e4 84  d7 ad 80 68 9d 66 41 6a   )i.)_......h.fAj  
  0040:  e0 0c df 29 32 35 57 e4  46 05 68 87 94 53 1d 9d   ...)25W.F.h..S..  
  0050:  e1 17 a8 1b 44 9d ae 1f  4a 2d 9f ba 48 e1 81 94   ....D...J-..H...  
  0060:  26 21 70 25 c9 3b c2 87  53 d3 87 09 77 55 cf a2   &!p%.;..S...wU..  
  0070:  fb 00 2e c9 1e 82 65 0d  e9 9f 10 d4 00 6e 33 c7   ......e......n3.  
  0080:  a5 7e 76 84 be 4c                                  .~v..L            
TLS trace: SSL_accept:SSLv3 read client key exchange A
tls_read: want=5, got=5
  0000:  14 03 01 00 01                                     .....             
tls_read: want=1, got=1
  0000:  01                                                 .                 
tls_read: want=5, got=5
  0000:  16 03 01 00 28                                     ....(             
tls_read: want=40, got=40
  0000:  49 e3 24 01 dd b4 f4 08  85 9f 52 bb e6 cf 70 35   I.$.......R...p5  
  0010:  a8 cd 3e f3 be 29 27 58  70 e2 a4 7d 98 cf 42 90   ..>..)'Xp..}..B.  
  0020:  54 31 66 c7 37 13 6c 05                            T1f.7.l.          
TLS trace: SSL_accept:SSLv3 read finished A
TLS trace: SSL_accept:SSLv3 write change cipher spec A
TLS trace: SSL_accept:SSLv3 write finished A
tls_write: want=51, written=51
  0000:  14 03 01 00 01 01 16 03  01 00 28 ed 45 80 26 9e   ..........(.E.&.  
  0010:  aa d0 9e c0 a6 2e 67 47  30 9f b1 2a 3c 30 d4 ad   ......gG0..*<0..  
  0020:  83 62 e9 30 ad d3 08 29  29 ae 42 af cc ee 28 03   .b.0...)).B...(.  
  0030:  95 b2 7c                                           ..|               
TLS trace: SSL_accept:SSLv3 flush data
------------------------------------------------------------------------

The one thing disturbing me, is the "Resource temporarily
unavaiable" message somewhere in the middle of the dump. Could this
be kind of a timing problem or a race condition? And if yes, what to
do about it?

Best Regards,

Stefan Froehlich

-- 
Der beschwerliche Angeber verdient Stefan. Warum wohl?
http://www.sloganizer.de/