On Thu, Dec 10, 2015 at 01:39:42PM +0100, Petr Cech wrote:
> On 12/10/2015 11:31 AM, Jakub Hrozek wrote:
>> On Wed, Dec 09, 2015 at 02:25:06PM +0100, Petr Cech wrote:
>>> Hi,
>>>
>>> simple patch is attached.
>>>
>>> Regards
>>>
>>> Petr
>>
>> I think we should put the debug message into sss_send_pac() after we
>> actually succeeded in writing to the socket to avoid printing the
>> message for cases where the PAC responder is not running but send_pac is
>> set.
>
> Hi Jakub,
>
> I agree. There is fixed patch attached. Thank you for review.
>
> Petr
> From 98c14cd263f0eefb98b10978ab03b52aac8cd213 Mon Sep 17 00:00:00 2001
> From: Petr Cech <pcech(a)redhat.com>
> Date: Wed, 9 Dec 2015 08:13:59 -0500
> Subject: [PATCH] KRB5_CHILD: Debug logs for PAC timeout
>
> This patch adds debug messages that inform user when KRB5_CHILD calls
> PAC responder. This action might take a bit of time in case the cache
> is not populated or up to date.
>
> Resolves:
>
https://fedorahosted.org/sssd/ticket/2846
> ---
> src/providers/krb5/krb5_child.c | 9 +++++++++
> 1 file changed, 9 insertions(+)
>
> diff --git a/src/providers/krb5/krb5_child.c b/src/providers/krb5/krb5_child.c
> index
b39269ee8028e5992b22860bb8a97b4ff824d087..05219b1c3dd599465a498466ee42c041df3a0753 100644
> --- a/src/providers/krb5/krb5_child.c
> +++ b/src/providers/krb5/krb5_child.c
> @@ -193,6 +193,7 @@ static errno_t sss_send_pac(krb5_authdata **pac_authdata)
> ret, errnop);
> return EIO;
> }
> + DEBUG(SSSDBG_TRACE_FUNC, "PAC request written to the socket.\n");
This is the only place where we want to add the debug message
>
> return EOK;
> }
> @@ -1111,6 +1112,10 @@ static krb5_error_code validate_tgt(struct krb5_req *kr)
> /* Try to find and send the PAC to the PAC responder.
> * Failures are not critical. */
> if (kr->send_pac) {
> + DEBUG(SSSDBG_TRACE_FUNC, "PAC responder contacted. It might take a
" \
> + "bit of time in case the cache is not "
\
> + "up to date.\n");
> +
Adding a message here....
> kerr = sss_extract_pac(kr->ctx, validation_ccache, validation_princ,
> kr->creds->client, keytab,
&pac_authdata);
> if (kerr != 0) {
> @@ -2560,6 +2565,10 @@ static krb5_error_code privileged_krb5_setup(struct krb5_req
*kr,
> }
>
> if (kr->send_pac) {
> + DEBUG(SSSDBG_TRACE_FUNC, "PAC responder contacted. It might take a
" \
> + "bit of time in case the cache is not "
\
> + "up to date.\n");
> +
...and here is not correct, because then with AD provider, we tell the
admin the PAC responder would be contacted even if it's not running:
(Fri Dec 11 10:52:47 2015) [[sssd[krb5_child[2951]]]] [get_and_save_tgt] (0x0400):
Attempting kinit for realm [WIN.TRUST.TEST]
(Fri Dec 11 10:52:47 2015) [[sssd[krb5_child[2951]]]] [validate_tgt] (0x0400): TGT
verified using key for [ADCLIENT$(a)WIN.TRUST.TEST].
(Fri Dec 11 10:52:47 2015) [[sssd[krb5_child[2951]]]] [validate_tgt] (0x0400): PAC
responder contacted. It might take a bit of time in case the cache is not up to date.
(Fri Dec 11 10:52:47 2015) [[sssd[krb5_child[2951]]]] [sss_send_pac] (0x0040):
sss_pac_make_request failed [-1][2].
(Fri Dec 11 10:52:47 2015) [[sssd[krb5_child[2951]]]] [validate_tgt] (0x0040):
sss_send_pac failed, group membership for user with principal
[Administrator\@WIN.TRUST.TEST(a)WIN.TRUST.TEST] might not be correct.
Hi Jakub,
you're right, my fault. I was little confused. Fixed patch attached.
Petr
> ret = sss_pac_check_and_open();
> if (ret != EOK) {
> DEBUG(SSSDBG_MINOR_FAILURE, "Cannot open the PAC responder
socket\n");
> --
> 2.4.3