The same seems to be with Kerberos negotiation, but not so noticeable because it happens almost instantaneously.
I add Kerberos in Firefox and enable option KrbMethodNegotiate on the server (and KrbMethodK5Passwd on or off) And I saw a recurring 9 blocks: [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos detailed log in attach
==> /var/log/heimdal-kdc.log <== 2009-10-21T08:28:20 AS-REQ t...@h-----g.com from IPv4:192.168.1.75 for krbtgt/h-----g....@h-----g.com 2009-10-21T08:28:20 No preauth found, returning PREAUTH-REQUIRED -- t...@h-----g.com 2009-10-21T08:28:20 sending 400 bytes to IPv4:192.168.1.75 2009-10-21T08:28:20 AS-REQ t...@h-----g.com from IPv4:192.168.1.75 for krbtgt/h-----g....@h-----g.com 2009-10-21T08:28:20 Client sent patypes: encrypted-timestamp 2009-10-21T08:28:20 Looking for PKINIT pa-data -- t...@h-----g.com 2009-10-21T08:28:20 Looking for ENC-TS pa-data -- t...@h-----g.com 2009-10-21T08:28:20 ENC-TS Pre-authentication succeeded -- t...@h-----g.com using aes256-cts-hmac-sha1-96 2009-10-21T08:28:20 Client supported enctypes: aes256-cts-hmac-sha1-96, aes128-cts-hmac-sha1-96, des3-cbc-sha1, des3-cbc-md5, arcfour-hmac-md5, des-cbc-md5, des-cbc-md4, des-cbc-crc 2009-10-21T08:28:20 Using aes256-cts-hmac-sha1-96/aes256-cts-hmac-sha1-96 2009-10-21T08:28:20 Requested flags: proxiable, forwardable 2009-10-21T08:28:20 AS-REQ authtime: 2009-10-21T08:28:20 starttime: unset endtime: 2009-10-21T18:28:20 renew till: unset 2009-10-21T08:28:20 sending 638 bytes to IPv4:192.168.1.75 ==> /var/log/apache2/error.log <== [Wed Oct 21 08:28:22 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:22 2009] [debug] mod_deflate.c(615): [client 192.168.1.75] Zlib: Compressed 482 to 325 : URL /profile/ ==> /var/log/heimdal-kdc.log <== 2009-10-21T08:28:22 TGS-REQ t...@h-----g.com from IPv4:192.168.1.75 for HTTP/h-----g....@h-----g.com [canonicalize, proxiable, forwardable] 2009-10-21T08:28:22 TGS-REQ authtime: 2009-10-21T08:28:20 starttime: 2009-10-21T08:28:22 endtime: 2009-10-21T18:28:20 renew till: unset 2009-10-21T08:28:22 sending 639 bytes to IPv4:192.168.1.75 ==> /var/log/apache2/other_vhosts_access.log <== www.h-----g.com:80 192.168.1.75 - - [21/Oct/2009:08:28:22 +0800] "GET /profile/ HTTP/1.1" 401 650 "-" "Mozilla/5.0 (X11; U; Linux i686; ru; rv:1.9.0.13) Gecko/2009082121 Iceweasel/3.0.6 (Debian-3.0.6-3)" ==> /var/log/apache2/error.log <== [Wed Oct 21 08:28:30 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:30 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:30 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:30 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:30 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1579): [client 192.168.1.75] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1261): [client 192.168.1.75] Acquiring creds for HTTP/h-----g.com [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1407): [client 192.168.1.75] Verifying client data using KRB5 GSS-API [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1423): [client 192.168.1.75] Verification returned code 0 [Wed Oct 21 08:28:31 2009] [debug] src/mod_auth_kerb.c(1441): [client 192.168.1.75] GSS-API token of length 22 bytes will be sent back [Wed Oct 21 08:28:31 2009] [debug] mod_deflate.c(615): [client 192.168.1.75] Zlib: Compressed 915 to 431 : URL /profile/ ==> /var/log/apache2/other_vhosts_access.log <== www.h-----g.com:80 192.168.1.75 - t...@h-----g.com [21/Oct/2009:08:28:30 +0800] "GET /profile/ HTTP/1.1" 200 762 "-" "Mozilla/5.0 (X11; U; Linux i686; ru; rv:1.9.0.13) Gecko/2009082121 Iceweasel/3.0.6 (Debian-3.0.6-3)"
signature.asc
Description: PGP signature
