questions about gpo support for offline mode
by Yassir Elley
Hi guys,
With regard to adding support for gpo processing in offline mode, if we have gpo-guids and policy files cached from previous transactions, then we can simply retrieve all the gpo-guids from the cache, construct the policy file names, retrieve the policy files from the local GPO_CACHE directory, and perform the access checks.
However, I have some questions:
1. If we don't have any gpo-guids or policy files cached from previous transactions, should gpo processing deny access by default (assuming that gpo_mode is enforcing)?
2. If we detect that we are off-line, at what points do we need to attempt to recover and perform offline processing (as opposed to simply returning an error). Certainly, we should perform offline processing if the initial ldap connect response (i.e. sdap_id_op_connect_recv) returns a dp_error of DP_ERR_OFFLINE. However, if one of the several ldap search responses (i.e. sdap_get_generic_recv) return a dp_error of DP_ERR_OFFLINE, should we still attempt to recover? Should we attempt to recover if the smb connect or smb read fails (in the gpo_child)?
3. If the initial ldap connection succeeds, but we go offline at a later point (and if the right thing to do is to attempt to recover at that point, per question 2), am I correct in assuming that we should discard any data received from the server up to then (if any), and behave as if we were offline since the connection started?
Thanks,
Yassir.
9 years, 8 months
sssdpac_verify() treats krb5_pac_verify() error as fatal - mspac_verify() does not
by Thomas Sondergaard
Hello,
I've run into a GSSAPI authentication problem that has caused me a
little time to diagnose, but turns out to only occur with
sssd_pac_plugin.so present. I am not an AD, Kerberos or sssd expert, so
let me just present the information I have collected.
Our code, which uses GSSAPI, fails with the following error on a Fedora
20 box with sssd-client (sssd_pac_plugin.so) installed with the
following error codes:
major: 851968='Unspecified GSS failure. Minor code may provide more
information', minor: 22='Invalid argument'
KRB5_TRACE does not give any useful indication for what goes wrong.
With sssd-client (sssd_pac_plugin.so) removed the GSSAPI authentication
works. With KRB5_TRACE I get the following warning:
[23801] 1407018816.872001: PAC checksum verification failed:
-1765328196/Bad encryption type
Looking at the code, I find that without sssd_pac_plugin.so installed
the following verification function is used:
static krb5_error_code
mspac_verify(krb5_context kcontext,
krb5_authdata_context context,
void *plugin_context,
void *request_context,
const krb5_auth_context *auth_context,
const krb5_keyblock *key,
const krb5_ap_req *req)
{
krb5_error_code code;
struct mspac_context *pacctx = (struct mspac_context *)request_context;
if (pacctx->pac == NULL)
return EINVAL;
code = krb5_pac_verify(kcontext, pacctx->pac,
req->ticket->enc_part2->times.authtime,
req->ticket->enc_part2->client, key, NULL);
if (code != 0)
TRACE_MSPAC_VERIFY_FAIL(kcontext, code);
/*
* If the above verification failed, don't fail the whole
authentication,
* just don't mark the PAC as verified. A checksum mismatch can
occur if
* the PAC was copied from a cross-realm TGT by an ignorant KDC,
and Apple
* Mac OS X Server Open Directory (as of 10.6) generates PACs with no
* server checksum at all.
*/
return 0;
}
This incarnation of the mspac_verify() function is from
commit 76ebe5d07c1002b674eb1c4e3ab35f6001eec91c
Author: Greg Hudson <ghudson(a)mit.edu>
Date: Wed Feb 16 23:34:37 2011 +0000
Don't reject AP-REQs based on PACs
Experience has shown that it was a mistake to fail AP-REQ verification
based on failure to verify the signature of PAC authdata contained in
the ticket. We've had two rounds of interoperability issues with the
hmac-md5 checksum code, an interoperability issue OSX generating
unsigned PACs, and another problem where PACs are copied by older KDCs
from a cross-realm TGT into the service ticket. If a PAC signature
cannot be verified, just don't mark it as verified and continue on
with the AP exchange.
ticket: 6870
target_version: 1.9.1
tags: pullup
git-svn-id: svn://anonsvn.mit.edu/krb5/trunk@24640
dc483132-0cff-0310-8789-dd5450dbe970
With sssd-client (sssd_pac_plugin.so) installed the function
sssdpac_verify is used instead, which looks like this
(sssd-client-1.11.6-1):
static krb5_error_code sssdpac_verify(krb5_context kcontext,
krb5_authdata_context context,
void *plugin_context,
void *request_context,
const krb5_auth_context
*auth_context,
const krb5_keyblock *key,
const krb5_ap_req *req)
{
krb5_error_code kerr;
int ret;
krb5_pac pac;
struct sssd_context *sssdctx = (struct sssd_context *)request_context;
struct sss_cli_req_data sss_data;
int errnop;
if (sssdctx == NULL || sssdctx->data.data == NULL) {
return EINVAL;
}
kerr = krb5_pac_parse(kcontext, sssdctx->data.data,
sssdctx->data.length, &pac);
if (kerr != 0) {
return EINVAL;
}
kerr = krb5_pac_verify(kcontext, pac,
req->ticket->enc_part2->times.authtime,
req->ticket->enc_part2->client, key, NULL);
if (kerr != 0) {
return EINVAL;
}
sss_data.len = sssdctx->data.length;
sss_data.data = sssdctx->data.data;
ret = sss_pac_make_request(SSS_PAC_ADD_PAC_USER, &sss_data,
NULL, NULL, &errnop);
if (ret != 0) {
/* Ignore the error */
}
return 0;
}
The krb5_pac_verify header documentation from krb5.h has this to say:
* @note A checksum mismatch can occur if the PAC was copied from a
cross-realm
* TGT by an ignorant KDC; also Apple Mac OS X Server Open Directory (as of
* 10.6) generates PACs with no server checksum at all. One should
consider
* not failing the whole authentication because of this reason, but,
instead,
* treating the ticket as if it did not contain a PAC or marking the PAC
* information as non-verified.
So, sssdpac_verify() treats krb5_pack_verify() errors as fatal, whereas
krb5's mspac_verify() does not. This is all the information that I have
gathered. It looks to me like sssd-client (sssd_pac_plugin.so) is not
doing this right, but I'm looking forward to your comments.
Regards,
Thomas
9 years, 8 months
Trying to ssh with sssd/pam configuration
by Sterling Sahaydak
Running CentOS 6.5 sssd 1.9.2 in a test environment and trying to
authenticate user: testjoe to ssh to server ldap01.something.net
running openldap on ldap01.something.net and trying to authenticate to
it.
[root@testmachine sssd]# cat sssd.conf
[domain/default]
ldap_id_use_start_tls = True
cache_credentials = True
ldap_search_base = dc=something,dc=net
id_provider = ldap
auth_provider = ldap
chpass_provider = ldap
ldap_uri = ldaps://ldap01.something.net
ldap_tls_cacertdir = /etc/openldap/certs
[sssd]
config_file_version = 2
services = nss, pam, sudo
domains = default, LDAP
[nss]
filter_users = root
filter_groups = root
[pam]
[sudo]
[domain/LDAP]
access_provider = ldap
auth_provider = ldap
chpass_provider = ldap
id_provider = ldap
sudo_provider = ldap
debug_level = 7
cache_credentials = true
enumerate = true
ldap_access_filter = cn=allowedusers,ou=Groups,dc=something,dc=net
ldap_search_base = dc=something,dc=net
ldap_sudo_search_base = ou=sudoers,dc=something,dc=net
ldap_tls_cacert = /etc/openldap/certs/cacert.pem
ldap_tls_reqcert = allow
ldap_uri = ldaps://ldap01.something.net
[root@testmachine pam.d]# cat password-auth
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_debug.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so broken_shadow
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_unix.so md5 shadow nullok try_first_pass
use_authtok
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session optional pam_mkhomedir.so umask=0022 skel=/etc/skel/
session [success=1 default=ignore] pam_succeed_if.so service in
crond quiet use_uid
session required pam_unix.so
session optional pam_sss.so
-sh-4.1$ ssh -vvv test1234(a)ldap01.something.net
OpenSSH_5.3p1, OpenSSL 1.0.0-fips 29 Mar 2010
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to ldap01.something.net [54.183.120.59] port 22.
debug1: Connection established.
debug1: identity file /home/users/testjoe/.ssh/identity type -1
debug1: identity file /home/users/testjoe/.ssh/id_rsa type -1
debug1: identity file /home/users/testjoe/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.3
debug1: match: OpenSSH_5.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug2: fd 5 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug3: Wrote 792 bytes for a total of 813
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc(a)lysator.liu.se
debug2: kex_parse_kexinit:
aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc(a)lysator.liu.se
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160(a)openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160(a)openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib(a)openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib(a)openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc(a)lysator.liu.se
debug2: kex_parse_kexinit:
aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc(a)lysator.liu.se
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160(a)openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160(a)openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib(a)openssh.com
debug2: kex_parse_kexinit: none,zlib(a)openssh.com
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_setup: found hmac-md5
debug1: kex: server->client aes128-ctr hmac-md5 none
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug3: Wrote 24 bytes for a total of 837
debug2: dh_gen_key: priv key bits set: 127/256
debug2: bits set: 515/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: Wrote 144 bytes for a total of 981
debug3: check_host_in_hostfile: filename
/home/users/testjoe/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 1
debug3: check_host_in_hostfile: filename
/home/users/testjoe/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 1
debug1: Host 'ldap01.something.net' is known and matches the RSA host
key.
debug1: Found key in /home/users/testjoe/.ssh/known_hosts:1
debug2: bits set: 513/1024
debug1: ssh_rsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: Wrote 16 bytes for a total of 997
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug3: Wrote 48 bytes for a total of 1045
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /home/users/testjoe/.ssh/identity ((nil))
debug2: key: /home/users/testjoe/.ssh/id_rsa ((nil))
debug2: key: /home/users/testjoe/.ssh/id_dsa ((nil))
debug3: Wrote 64 bytes for a total of 1109
debug1: Authentications that can continue:
publickey,gssapi-keyex,gssapi-with-mic,password
debug3: start over, passed a different list
publickey,gssapi-keyex,gssapi-with-mic,password
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: /home/users/testjoe/.ssh/identity
debug3: no such identity: /home/users/testjoe/.ssh/identity
debug1: Trying private key: /home/users/testjoe/.ssh/id_rsa
debug3: no such identity: /home/users/testjoe/.ssh/id_rsa
debug1: Trying private key: /home/users/testjoe/.ssh/id_dsa
debug3: no such identity: /home/users/testjoe/.ssh/id_dsa
debug2: we did not send a packet, disable method
debug3: authmethod_lookup password
debug3: remaining preferred: ,password
debug3: authmethod_is_enabled password
debug1: Next authentication method: password
test1234(a)ldap01.something.net's password:
debug3: packet_send2: adding 48 (len 61 padlen 19 extra_pad 64)
debug2: we sent a password packet, wait for reply
debug3: Wrote 144 bytes for a total of 1253
Connection closed by 54.183.120.59
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'LDAP'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [get_server_status]
(0x1000): Status of server 'ldap01.something.net' is 'name not resolved'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [get_port_status] (0x1000):
Port status of port 636 for server 'ldap01.something.net' is 'neutral'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [get_server_status]
(0x1000): Status of server 'ldap01.something.net' is 'name not resolved'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record
of 'ldap01.something.net' in files
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [set_server_common_status]
(0x0100): Marking server 'ldap01.something.net' as 'resolving name'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA
record of 'ldap01.something.net' in files
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [resolv_gethostbyname_next]
(0x0200): No more address families to retry
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of
'ldap01.something.net' in DNS
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [request_watch_destructor]
(0x0400): Deleting request watch
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [set_server_common_status]
(0x0100): Marking server 'ldap01.something.net' as 'name resolved'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [be_resolve_server_process]
(0x1000): Saving the first resolved server
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [be_resolve_server_process]
(0x0200): Found address for server ldap01.something.net: [54.183.120.59]
TTL 1408
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_uri_callback]
(0x0400): Constructed uri 'ldaps://ldap01.something.net'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sss_ldap_init_send]
(0x0400): Setting 6 seconds timeout for connecting
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_sudo_full_refresh_send] (0x0400): Issuing a full refresh of sudo
rules
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
[ldaps://ldap01.something.net:636/??base] with fd [22].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [*]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [altServer]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [namingContexts]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [supportedControl]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [supportedExtension]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [supportedFeatures]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [supportedLDAPVersion]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [supportedSASLMechanisms]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [domainControllerFunctionality]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [defaultNamingContext]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [lastUSN]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [highestCommittedUSN]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x0400): Search result: Success(0), no errmsg set
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is
supported by this server!
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_get_server_opts_from_rootdse] (0x0200): Will use modification
timestamp as usn!
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_cli_auth_step]
(0x0100): expire timeout is 900
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_cli_auth_step]
(0x1000): the connection will expire at 1406568103
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_cli_auth_step]
(0x1000): No authentication requested or SASL auth forced off
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [fo_set_port_status]
(0x0100): Marking port 636 of server 'ldap01.something.net' as 'working'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [set_server_common_status]
(0x0100): Marking server 'ldap01.something.net' as 'working'
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_search_user_next_base]
(0x0400): Searching for users with base [dc=something,dc=net]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectclass=posixAccount)(uid=*)(uidNumber=*)(gidNumber=*))][dc=something,dc=net].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [uid]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [uidNumber]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gecos]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [homeDirectory]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginShell]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbPrincipalName]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowLastChange]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowMin]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowMax]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowWarning]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowInactive]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowExpire]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowFlag]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbLastPwdChange]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbPasswordExpiration]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [pwdAttribute]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [authorizedService]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [accountExpires]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userAccountControl]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [nsAccountLock]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [host]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginDisabled]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginExpirationTime]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginAllowedTimeMap]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_sudo_refresh_connect_done] (0x0400): SUDO LDAP connection
successful
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_sudo_load_sudoers_next_base] (0x0400): Searching for sudo rules
with base [ou=sudoers,dc=something,dc=net]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectClass=sudoRole)(|(!(sudoHost=*))(sudoHost=ALL)(sudoHost=testmachine.something.net)(sudoHost=testmachine)(sudoHost=172.31.4.163)(sudoHost=172.31.0.0/20)(sudoHost=fe80::889:cff:fe1d:d718)(sudoHost=fe80::/64)(sudoHost=+*)(|(sudoHost=*\\*)(sudoHost=*?*)(sudoHost=*\**)(sudoHost=*[*]*))))][ou=sudoers,dc=something,dc=net].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoCommand]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoHost]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoUser]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoOption]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoRunAsUser]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoRunAsGroup]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoNotBefore]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoNotAfter]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [sudoOrder]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x0400): Search result: Success(0), no errmsg set
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x1000): Total count [0]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_sudo_load_sudoers_process] (0x0400): Receiving sudo rules with
base [ou=sudoers,dc=something,dc=net]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_sudo_load_sudoers_done] (0x0400): Received 2 rules
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sysdb_save_sudorule]
(0x0400): Adding sudo rule testjoe
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sysdb_save_sudorule]
(0x0400): Adding sudo rule test1234
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_sudo_load_sudoers_done] (0x0400): Sudoers is successfuly stored in
cache
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_sudo_full_refresh_done] (0x0400): Successful full refresh of sudo
rules
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_sudo_set_usn]
(0x0200): SUDO higher USN value: [20140728162617Z]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_sudo_schedule_refresh]
(0x0400): Full refresh scheduled at: 1406588803
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_sudo_schedule_refresh]
(0x0400): Smart refresh scheduled at: 1406568103
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x0400): Search result: Success(0), no errmsg set
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x1000): Total count [0]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_search_user_process]
(0x0400): Search for users, returned 2 results.
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x1000):
Original memberOf is not available for [testjoe].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x1000):
Original USN value is not available for [testjoe].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x1000):
User principal is not available for [testjoe].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
Storing info for user testjoe
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x1000):
Original memberOf is not available for [test1234].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x1000):
Original USN value is not available for [test1234].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x1000):
User principal is not available for [test1234].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
Storing info for user test1234
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [enum_users_op_done]
(0x0100): Users higher USN value: [(null)]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_groups_next_base]
(0x0400): Searching for groups with base [dc=something,dc=net]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectclass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=something,dc=net].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [memberuid]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x0400): Search result: Success(0), no errmsg set
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x1000): Total count [0]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_groups_process]
(0x0400): Search for groups, returned 1 results.
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_process_group_members_2307] (0x1000): Member already cached in
sysdb: testjoe
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_process_group_members_2307] (0x1000): Member already cached in
sysdb: test1234
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_process_group_send]
(0x1000): All group members processed
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_group] (0x0400):
Processing group allowedusers
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_group] (0x1000):
Original USN value is not available for [allowedusers].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_process_ghost_members]
(0x0400): Group has 2 members
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_save_group] (0x0400):
Storing info for group allowedusers
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [enum_groups_op_done]
(0x0100): Groups higher USN value: [(null)]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]]
[sdap_get_services_next_base] (0x0400): Searching for services with base
[dc=something,dc=net]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectclass=ipService)(cn=*)(ipServicePort=*)(ipServiceProtocol=*))][dc=something,dc=net].
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipServicePort]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipServiceProtocol]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x0400): Search result: Success(0), no errmsg set
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x1000): Total count [0]
(Mon Jul 28 13:06:43 2014) [sssd[be[LDAP]]] [sdap_get_services_process]
(0x0400): Search for services, returned 0 results.
(Mon Jul 28 13:06:44 2014) [sssd[be[LDAP]]]
[ldap_id_enumerate_set_timer] (0x0400): Scheduling next enumeration at
1406567503.675094
9 years, 8 months
[PATCH] Two patches with more debugging for the LDAP provider
by Jakub Hrozek
Hi,
I was trying to help a user who had problems with the AD provider and
realized I had hard time following what exact server are we searching at
the time and, because we hit a referral, where the referral pointed to.
I wrote the two attached patches. I'm OK with keeping them in my local
tree, but if other developers agree, maybe we can include them upstream
as well.
9 years, 8 months