Auth: rlm_krb5: [test1 at CSP-BACK] krb5_rd_req() failed: Permission denied in replay cache code
Jimmy
g17jimmy at gmail.com
Tue Jun 14 22:44:42 CEST 2011
I have Kerberos 1.6 configured to use OpenLDAP 2.3.43 as a back end. I
am trying to configure Freeradius 2.1.7 to authenticate to Kerberos.
I am having problems getting Freeradiusto authenticate while started
in daemon mode. When the process is started in debug mode it seems to
funciton, but authentications while in daemon mode return the error:
>Auth: rlm_krb5: [test1 at CSP-BACK] krb5_rd_req() failed: Permission denied in replay cache code
Since authentication works in debug mode I'm not sure what I can give
to support the error besides the krb5kdc/slapd/radius log outputs and
the client side output. Functional output of debug mode is included as
well. I appreciate any help you can provide. If I should post any
config files please let me know what you would like to see. Thank you
very much.
*****************client side output*****************
radtest test1 at CSP-BACK qwer krb 1812 SharedSecret
Sending Access-Request of id 213 to [SERVER IP ADDRESS ] port 1812
User-Name = "test1 at CSP-BACK"
User-Password = "qwer"
NAS-IP-Address = 127.0.0.1
NAS-Port = 1812
rad_recv: Access-Reject packet from host [SERVER IP ADDRESS ] port
1812, id=213, length=20
***********************************************
*****************radius log*****************
Tue Jun 14 16:17:23 2011 : Auth: rlm_krb5: [test1 at CSP-BACK]
krb5_rd_req() failed: Permission denied in replay cache code
***********************************************
*****************krb5kdc log*****************
Jun 14 16:17:22 krb.csp krb5kdc[10954](info): AS_REQ (12 etypes {18 17
16 23 1 3 2 11 10 15 12 13}) [SERVER IP ADDRESS ]: ISSUE: authtime
1308082642, etypes {rep=18 tkt=18 ses=18}, test1 at CSP-BACK for
krbtgt/CSP-BACK at CSP-BACK
Jun 14 16:17:23 krb.csp krb5kdc[10954](info): TGS_REQ (7 etypes {18 17
16 23 1 3 2}) [SERVER IP ADDRESS ]: ISSUE: authtime 1308082642,
etypes {rep=18 tkt=18 ses=18}, test1 at CSP-BACK for
radius/krb.csp at CSP-BACK
********************************************
*****************slapd log*****************
Jun 14 16:17:22 krb slapd[10742]: conn=9 op=54 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=test1 at CSP-BACK))"
Jun 14 16:17:22 krb slapd[10742]: conn=9 op=54 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:17:22 krb slapd[10742]: conn=9 op=54 SEARCH RESULT tag=101
err=0 nentries=1 text=
Jun 14 16:17:22 krb slapd[10742]: conn=9 op=55 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/CSP-BACK at CSP-BACK))"
Jun 14 16:17:22 krb slapd[10742]: conn=9 op=55 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:17:22 krb slapd[10742]: conn=9 op=55 SEARCH RESULT tag=101
err=0 nentries=1 text=
Jun 14 16:17:23 krb slapd[10742]: conn=9 op=56 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/CSP-BACK at CSP-BACK))"
Jun 14 16:17:23 krb slapd[10742]: conn=9 op=56 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:17:23 krb slapd[10742]: conn=9 op=56 SEARCH RESULT tag=101
err=0 nentries=1 text=
Jun 14 16:17:23 krb slapd[10742]: conn=9 op=57 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=radius/krb.csp at CSP-BACK))"
Jun 14 16:17:23 krb slapd[10742]: conn=9 op=57 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:17:23 krb slapd[10742]: conn=9 op=57 SEARCH RESULT tag=101
err=0 nentries=1 text=
********************************************
****************************************************************************************
****************************************************************************************
DEBUG MODE OUTPUT
When I run the server in debug mode here is the output from radiusd -X:
********************************************
FreeRADIUS Version 2.1.7, for host x86_64-redhat-linux-gnu, built on
Mar 31 2010 at 00:14:28
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/modules/
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/krb5
including configuration file /etc/raddb/eap.conf
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/control-socket
including configuration file /etc/raddb/sites-enabled/inner-tunnel
including configuration file /etc/raddb/sites-enabled/default
group = radiusd
user = radiusd
including dictionary file /etc/raddb/dictionary
main {
prefix = "/usr"
localstatedir = "/var"
logdir = "/var/log/radius"
libdir = "/usr/lib64/freeradius"
radacctdir = "/var/log/radius/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 1024
allow_core_dumps = no
pidfile = "/var/run/radiusd/radiusd.pid"
checkrad = "/usr/sbin/checkrad"
debug_level = 0
proxy_requests = yes
log {
stripped_names = no
auth = no
auth_badpass = no
auth_goodpass = no
}
security {
max_attributes = 200
reject_delay = 1
status_server = yes
}
}
radiusd: #### Loading Realms and Home Servers ####
proxy server {
retry_delay = 5
retry_count = 3
default_fallback = no
dead_time = 120
wake_all_if_all_dead = no
}
home_server localhost {
ipaddr = 127.0.0.1
port = 1812
type = "auth"
secret = "testing123"
response_window = 20
max_outstanding = 65536
require_message_authenticator = no
zombie_period = 40
status_check = "status-server"
ping_interval = 30
check_interval = 30
num_answers_to_alive = 3
num_pings_to_alive = 3
revive_interval = 120
status_check_timeout = 4
irt = 2
mrt = 16
mrc = 5
mrd = 30
}
home_server_pool my_auth_failover {
type = fail-over
home_server = localhost
}
realm example.com {
auth_pool = my_auth_failover
}
realm LOCAL {
}
radiusd: #### Loading Clients ####
client localhost {
ipaddr = 127.0.0.1
require_message_authenticator = no
secret = "testing123"
nastype = "other"
}
client [CLIENT SUBNET]/16 {
require_message_authenticator = no
secret = "SharedSecret"
nastype = "other"
}
radiusd: #### Instantiating modules ####
instantiate {
Module: Linked to module rlm_exec
Module: Instantiating exec
exec {
wait = no
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_expr
Module: Instantiating expr
Module: Linked to module rlm_expiration
Module: Instantiating expiration
expiration {
reply-message = "Password Has Expired "
}
Module: Linked to module rlm_logintime
Module: Instantiating logintime
logintime {
reply-message = "You are calling outside your allowed timespan "
minimum-timeout = 60
}
}
radiusd: #### Loading Virtual Servers ####
server inner-tunnel {
modules {
Module: Checking authorize {...} for more modules to load
} # modules
} # server
server {
modules {
Module: Checking authenticate {...} for more modules to load
Module: Linked to module rlm_krb5
Module: Instantiating krb5
krb5 {
keytab = "/etc/raddb/rad.keytab"
service_principal = "radius/krb.csp"
}
rlm_krb5: krb5_init ok
Module: Linked to module rlm_eap
Module: Instantiating eap
eap {
default_eap_type = "ttls"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 2048
}
Module: Linked to sub-module rlm_eap_tls
Module: Instantiating eap-tls
tls {
rsa_key_exchange = no
dh_key_exchange = yes
rsa_key_length = 512
dh_key_length = 512
verify_depth = 0
pem_file_type = yes
private_key_file = "/etc/raddb/certs/server.pem"
certificate_file = "/etc/raddb/certs/server.pem"
CA_file = "/etc/raddb/certs/ca.pem"
private_key_password = "whatever"
dh_file = "/etc/raddb/certs/dh"
random_file = "/etc/raddb/certs/random"
fragment_size = 1024
include_length = yes
check_crl = no
cipher_list = "DEFAULT"
make_cert_command = "/etc/raddb/certs/bootstrap"
cache {
enable = no
lifetime = 24
max_entries = 255
}
}
Module: Linked to sub-module rlm_eap_ttls
Module: Instantiating eap-ttls
ttls {
default_eap_type = "md5"
copy_request_to_tunnel = no
use_tunneled_reply = no
virtual_server = "inner-tunnel"
include_length = yes
}
Module: Checking authorize {...} for more modules to load
Module: Linked to module rlm_preprocess
Module: Instantiating preprocess
preprocess {
huntgroups = "/etc/raddb/huntgroups"
hints = "/etc/raddb/hints"
with_ascend_hack = no
ascend_channels_per_line = 23
with_ntdomain_hack = no
with_specialix_jetstream_hack = no
with_cisco_vsa_hack = no
with_alvarion_vsa_hack = no
}
Module: Linked to module rlm_detail
Module: Instantiating auth_log
detail auth_log {
detailfile =
"/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Linked to module rlm_realm
Module: Instantiating suffix
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = no
}
Module: Linked to module rlm_unix
Module: Instantiating unix
unix {
radwtmp = "/var/log/radius/radwtmp"
}
Module: Linked to module rlm_files
Module: Instantiating files
files {
usersfile = "/etc/raddb/users"
acctusersfile = "/etc/raddb/acct_users"
preproxy_usersfile = "/etc/raddb/preproxy_users"
compat = "no"
}
Module: Linked to module rlm_pap
Module: Instantiating pap
pap {
encryption_scheme = "auto"
auto_header = no
}
Module: Checking preacct {...} for more modules to load
Module: Linked to module rlm_acct_unique
Module: Instantiating acct_unique
acct_unique {
key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
}
Module: Checking accounting {...} for more modules to load
Module: Instantiating detail
detail {
detailfile =
"/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Linked to module rlm_radutmp
Module: Instantiating radutmp
radutmp {
filename = "/var/log/radius/radutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
perm = 384
callerid = yes
}
Module: Linked to module rlm_attr_filter
Module: Instantiating attr_filter.accounting_response
attr_filter attr_filter.accounting_response {
attrsfile = "/etc/raddb/attrs.accounting_response"
key = "%{User-Name}"
}
Module: Checking session {...} for more modules to load
Module: Checking post-proxy {...} for more modules to load
Module: Checking post-auth {...} for more modules to load
Module: Instantiating attr_filter.access_reject
attr_filter attr_filter.access_reject {
attrsfile = "/etc/raddb/attrs.access_reject"
key = "%{User-Name}"
}
} # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = *
port = 0
}
listen {
type = "acct"
ipaddr = *
port = 0
}
listen {
type = "control"
listen {
socket = "/var/run/radiusd/radiusd.sock"
}
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on proxy address * port 1814
Ready to process requests.
***************************************************upon issing
radtest***************************************************
rad_recv: Access-Request packet from host [CLIENT IP ADDRESS ] port
35916, id=141, length=66
User-Name = "test1 at CSP-BACK"
User-Password = "qwer"
NAS-IP-Address = 127.0.0.1
NAS-Port = 1812
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand:
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/radius/radacct/ [CLIENT IP ADDRESS ]/auth-detail-20110614
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/radius/radacct/ [CLIENT IP ADDRESS
]/auth-detail-20110614
[auth_log] expand: %t -> Tue Jun 14 16:25:45 2011
++[auth_log] returns ok
[suffix] Looking up realm "CSP-BACK" for User-Name = "test1 at CSP-BACK"
[suffix] No such realm "CSP-BACK"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 49
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = Kerberos
+- entering group Kerberos {...}
++[krb5] returns ok
WARNING: Empty section. Using default return values.
Sending Access-Accept of id 141 to [CLIENT IP ADDRESS ] port 35916
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 0 ID 141 with timestamp +168
Ready to process requests.
***************************************************
*****************client side output*****************
radtest test1 at CSP-BACK qwer krb 1812 SharedSecret
Sending Access-Request of id 141 to [CLIENT IP ADDRESS ] port 1812
User-Name = "test1 at CSP-BACK"
User-Password = "qwer"
NAS-IP-Address = 127.0.0.1
NAS-Port = 1812
rad_recv: Access-Accept packet from host [CLIENT IP ADDRESS ] port
1812, id=141, length=20
***************************************************
*****************krb5kdc.log*****************
Jun 14 16:25:45 krb.csp krb5kdc[10954](info): AS_REQ (12 etypes {18 17
16 23 1 3 2 11 10 15 12 13}) [SERVER IP ADDRESS ]: ISSUE: authtime
1308083145, etypes {rep=18 tkt=18 ses=18}, test1 at CSP-BACK for
krbtgt/CSP-BACK at CSP-BACK
Jun 14 16:25:46 krb.csp krb5kdc[10954](info): TGS_REQ (7 etypes {18 17
16 23 1 3 2}) [SERVER IP ADDRESS ]: ISSUE: authtime 1308083145, etypes
{rep=18 tkt=18 ses=18}, test1 at CSP-BACK for radius/krb.csp at CSP-BACK
***************************************************
*****************slapd.log*****************
Jun 14 16:25:45 krb slapd[10742]: conn=9 op=58 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=test1 at CSP-BACK))"
Jun 14 16:25:45 krb slapd[10742]: conn=9 op=58 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:25:45 krb slapd[10742]: conn=9 op=58 SEARCH RESULT tag=101
err=0 nentries=1 text=
Jun 14 16:25:45 krb slapd[10742]: conn=9 op=59 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/CSP-BACK at CSP-BACK))"
Jun 14 16:25:45 krb slapd[10742]: conn=9 op=59 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:25:45 krb slapd[10742]: conn=9 op=59 SEARCH RESULT tag=101
err=0 nentries=1 text=
Jun 14 16:25:46 krb slapd[10742]: conn=9 op=60 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/CSP-BACK at CSP-BACK))"
Jun 14 16:25:46 krb slapd[10742]: conn=9 op=60 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:25:46 krb slapd[10742]: conn=9 op=60 SEARCH RESULT tag=101
err=0 nentries=1 text=
Jun 14 16:25:46 krb slapd[10742]: conn=9 op=61 SRCH
base="cn=KRB,dc=CSPKRB" scope=2 deref=0
filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=radius/krb.csp at CSP-BACK))"
Jun 14 16:25:46 krb slapd[10742]: conn=9 op=61 SRCH
attr=krbprincipalname objectclass krbprincipalkey krbmaxrenewableage
krbmaxticketlife krbticketflags krbprincipalexpiration
krbticketpolicyreference krbUpEnabled krbpwdpolicyreference
krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount
krbLastSuccessfulAuth nsaccountlock loginexpirationtime logindisabled
modifytimestamp krbLastPwdChange krbExtraData krbObjectReferences
Jun 14 16:25:46 krb slapd[10742]: conn=9 op=61 SEARCH RESULT tag=101
err=0 nentries=1 text=
(no radius log output in debug mode)
More information about the Freeradius-Users
mailing list