Alexander Bokovoy <[email protected]> writes: >>1. KDC to ipa-otd: this can be changed in >>/var/kerberos/krb5kdc/kdc.conf. I think the timeout should be larger >>then the (largest) second timeout - and I think retries=0 is best. >>This is for communication between KDC and ipa-otd. >> >>2. There is a timeout in each RADIUS server config in IPA for the >>communication from ipa-otp to external RADIUS servers: >>`---- >>Again I think that for OTPs we are probably best with retries=0. >> >>On older clients it might be helpful to add "udp_preference_limit = 0" >>to /etc/krb5.conf - at least on my Debian/Ubuntu machines.
> Ok. It would probably make sense to file a ticket to FreeIPA tracker to > get these changes in FreeIPA 4.5. I think I've won my fight... Here's what I've learned. The short story is that probably no timeout should be changed. Shall I still file a ticket concerning retry counts? Authentication of IPA users against RADIUS were mostly failing, but not always. There were hints about timeouts almost everywhere. Multiple authentication requests from kerberos, timeouts from sssd, but that should have sent me on the right track from the start: Dec 19 22:11:51 freeipa1 ipa-otpd: LDAP: ldapi://%2Fvar%2Frun%2Fslapd-JOCHEN-ORG.socket Dec 19 22:11:51 freeipa1 ipa-otpd: [email protected]: request received Dec 19 22:11:51 freeipa1 ipa-otpd: [email protected]: user query start Dec 19 22:11:51 freeipa1 ipa-otpd: [email protected]: user query end: uid=jkellner,cn=users,cn=accounts,dc=jochen,dc=org Dec 19 22:11:51 freeipa1 ipa-otpd: [email protected]: radius query start: cn=athene,cn=radiusproxy,dc=jochen,dc=org Dec 19 22:11:51 freeipa1 ipa-otpd: [email protected]: radius query end: athene.jochen.org Dec 19 22:11:51 freeipa1 ipa-otpd: [email protected]: forward start: [email protected] / athene.jochen.org Dec 19 22:12:01 freeipa1 ipa-otpd: [email protected]: forward end: Connection timed out Dec 19 22:12:01 freeipa1 ipa-otpd: [email protected]: response sent: Access-Reject or: Dec 20 22:40:23 freeipa1 ipa-otpd: [email protected]: request received Dec 20 22:40:23 freeipa1 ipa-otpd: [email protected]: user query start Dec 20 22:40:23 freeipa1 ipa-otpd: [email protected]: user query end: uid=jkellner,cn=users,cn=accounts,dc=jochen,dc=org Dec 20 22:40:23 freeipa1 ipa-otpd: [email protected]: radius query start: cn=athene,cn=radiusproxy,dc=jochen,dc=org Dec 20 22:40:23 freeipa1 ipa-otpd: [email protected]: radius query end: athene.jochen.org Dec 20 22:40:23 freeipa1 ipa-otpd: [email protected]: forward start: [email protected] / athene.jochen.org Dec 20 22:40:31 freeipa1 ipa-otpd: [email protected]: forward end: Access-Accept Dec 20 22:40:31 freeipa1 ipa-otpd: [email protected]: response sent: Access-Accept Why is there such a long delay? The Log of the RADIUS server has: Tue Dec 20 22:40:30 2016 : Info: rlm_perl: Config File /opt/privacyIDEA/rlm_perl.ini found! Tue Dec 20 22:40:30 2016 : Info: rlm_perl: Debugging config: true Tue Dec 20 22:40:30 2016 : Info: rlm_perl: Default URL https://athene.jochen.org/validate/check Tue Dec 20 22:40:30 2016 : Info: rlm_perl: Looking for config for auth-type Perl Tue Dec 20 22:40:30 2016 : Info: rlm_perl: Auth-Type: Perl Tue Dec 20 22:40:30 2016 : Info: rlm_perl: url: https://athene.jochen.org/validate/check Tue Dec 20 22:40:30 2016 : Info: rlm_perl: user sent to privacyidea: [email protected] Tue Dec 20 22:40:30 2016 : Info: rlm_perl: realm sent to privacyidea: jochen.org Tue Dec 20 22:40:30 2016 : Info: rlm_perl: resolver sent to privacyidea: Tue Dec 20 22:40:30 2016 : Info: rlm_perl: client sent to privacyidea: 192.168.30.121 Tue Dec 20 22:40:30 2016 : Info: rlm_perl: state sent to privacyidea: Tue Dec 20 22:40:31 2016 : Info: rlm_perl: privacyIDEA access granted Tue Dec 20 22:40:31 2016 : Info: rlm_perl: return RLM_MODULE_OK So RADIUS thinks, it got a request a 30 seconds, but why did we wait so long? I took a tcpdump and saw: 22:40:23.364355 IP6 freeipa1.jochen.org.41198 > athene.jochen.org.radius: RADIUS, Access-Request (1), id: 0x10 length: 134 22:40:30.872136 IP freeipa1.jochen.org.44314 > athene.jochen.org.radius: RADIUS, Access-Request (1), id: 0x9c length: 134 22:40:31.572217 IP athene.jochen.org.radius > freeipa1.jochen.org.44314: RADIUS, Access-Accept (2), id: 0x9c length: 48 So, we received an IPv6 packet, but didn't react. Some seconds later IPA-OTP retried with IPv4 and succeeded. A quick check showed that freeradius did not listen on IPv6. After fixing that, a request looks like this: Dec 20 22:54:57 freeipa2 ipa-otpd: [email protected]: request received Dec 20 22:54:57 freeipa2 ipa-otpd: [email protected]: user query start Dec 20 22:54:57 freeipa2 ipa-otpd: [email protected]: user query end: uid=jkellner,cn=users,cn=accounts,dc=jochen,dc=org Dec 20 22:54:57 freeipa2 ipa-otpd: [email protected]: radius query start: cn=athene,cn=radiusproxy,dc=jochen,dc=org Dec 20 22:54:57 freeipa2 ipa-otpd: [email protected]: radius query end: athene.jochen.org Dec 20 22:54:57 freeipa2 ipa-otpd: [email protected]: forward start: [email protected] / athene.jochen.org Dec 20 22:54:58 freeipa2 ipa-otpd: [email protected]: forward end: Access-Accept Dec 20 22:54:58 freeipa2 ipa-otpd: [email protected]: response sent: Access-Accept and Tue Dec 20 22:54:57 2016 : Info: rlm_perl: Config File /opt/privacyIDEA/rlm_perl.ini found! Tue Dec 20 22:54:57 2016 : Info: rlm_perl: Debugging config: true Tue Dec 20 22:54:57 2016 : Info: rlm_perl: Default URL https://athene.jochen.org/validate/check Tue Dec 20 22:54:57 2016 : Info: rlm_perl: Looking for config for auth-type Perl Tue Dec 20 22:54:57 2016 : Info: rlm_perl: Auth-Type: Perl Tue Dec 20 22:54:57 2016 : Info: rlm_perl: url: https://athene.jochen.org/validate/check Tue Dec 20 22:54:57 2016 : Info: rlm_perl: user sent to privacyidea: [email protected] Tue Dec 20 22:54:57 2016 : Info: rlm_perl: realm sent to privacyidea: jochen.org Tue Dec 20 22:54:57 2016 : Info: rlm_perl: resolver sent to privacyidea: Tue Dec 20 22:54:57 2016 : Info: rlm_perl: client sent to privacyidea: Tue Dec 20 22:54:57 2016 : Info: rlm_perl: state sent to privacyidea: Tue Dec 20 22:54:58 2016 : Info: rlm_perl: privacyIDEA access granted Tue Dec 20 22:54:58 2016 : Info: rlm_perl: return RLM_MODULE_OK 22:54:57.623116 IP6 fd23:e163:19f7:1234:5054:ff:fe07:ff5a.39817 > athene.jochen.org.radius: RADIUS, Access-Request (1), id: 0x23 length: 134 22:54:58.778278 IP6 athene.jochen.org.radius > fd23:e163:19f7:1234:5054:ff:fe07:ff5a.39817: RADIUS, Access-Accept (2), id: 0x23 length: 48 Runtime is quite short and stable, so I'll go mostly back to the default timeouts. I've learned about the following timeouts for RADIUS authentication, every single one can hit you when RADIUS takes a long time (which it souldn't): * sssd has a default kerberos timeout of six seconds. Can be changed in /etc/sssd/sssd.conf: krb5_auth_timeout, which also seems to work for auth_provider = ipa, but is not documented in sssd-ipa(5). * There is a timeout for krb5kdc talking to ipa-otpd. Can be change in /var/kerberos/krb5kdc/kdc.conf with: [otp] DEFAULT = { timeout = 15 retries = 0 strip_realm = false } * In IPA there is also a radius-timeout which can be changed in the webui or with "ipa radiusproxy-mod <radius> --timeout=INT" I found it quite challenging to wrap my head around the hole process from PAM/SSS/KRB5/IPA-OTPD to FreeRADIUS/privacyidea, but now I'm quite happy with what I've learned. Thanks for you help. Jochen -- The only problem with troubleshooting is that the trouble shoots back. -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
