[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/