11:44 a.m.
Greetings,
I am implementing FreeIPA in a large environment ro replace OpenLDAP. I have the initial
client configuration scripted as the machines are diskless and almost everything is
working properly. However I cannot seem to FreeIPA managed user ssh keys working with
sssd. I have been reading for a couple of days and haven't found the answer as of yet.
Here is what I have discerned to be pertinent information. I will gladly add anything else
that's necessary. When 'sss_ssh_authorizedkeys markp --debug 10' produces no
output at all and no errors. I cannot ssh between hosts without entering a password or
using authorized_keys.
'journalctl -u sssd' shows:
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 1
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 1
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 1
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 2
OS: CentOS 7.4
Packages: ipa-client-4.6.5-11.el7.centos.4.x86_64 sssd-1.16.4-21.el7_7.1.x86_64
sssd.conf:
[domain/example.com]
cache_credentials = True
krb5_store_password_if_offline = True
ipa_domain = example.com
id_provider = ipa
auth_provider = ipa
access_provider = ipa
ipa_hostname = host.example.com
chpass_provider = ipa
ipa_server = ipaserver.example.com
ldap_tls_cacert = /etc/ipa/ca.crt
[sssd]
config_file_version = 2
services = nss, sudo, pam, ssh
domains = example.com
[nss]
homedir_substring = /home
[pam]
[sudo]
[autofs]
[ssh]
[pac]
[ifp]
[secrets]
[session_recording]
openldap/ldap.conf
# File modified by ipa-client-install
TLS_CACERTDIR /etc/openldap/certs
# Turning this off breaks GSSAPI used with krb5 when rdns = false
SASL_NOCANON on
URI ldaps://ipaserver.example.com
BASE dc=dugeo,dc=com
TLS_CACERT /etc/ipa/ca.crt
SASL_MECH GSSAPI
krb5.conf
#File modified by ipa-client-install
includedir /etc/krb5.conf.d/
includedir /var/lib/sss/pubconf/krb5.include.d/
[libdefaults]
default_realm = EXAMPLE.COM
dns_lookup_realm = false
dns_lookup_kdc = false
rdns = false
dns_canonicalize_hostname = false
ticket_lifetime = 24h
forwardable = true
udp_preference_limit = 0
default_ccache_name = KEYRING:persistent:%{uid}
[realms]
EXAMPLE.COM = {
kdc = ipaserver.example.com:88
master_kdc = ipaserver.example.com:88
admin_server = ipaserver.example.com:749
kpasswd_server = ipaserver.example.com:464
default_domain = example.com
pkinit_anchors = FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem
pkinit_pool = FILE:/var/lib/ipa-client/pki/ca-bundle.pem
}
[domain_realm]
.example.com = EXAMPLE.COM
example.com = EXAMPLE.COM
host.example.com = EXAMPLE.COM
I am hoping there's something simple that I am missing here, something I've
overlooked or managed to just suck at library skills. Thanks in advance for any help.
11:52 a.m.
On Fri, Feb 28, 2020 at 05:44:38PM -0000, Mark L. Potter via FreeIPA-users wrote:
Greetings,
I am implementing FreeIPA in a large environment ro replace OpenLDAP. I have the initial
client configuration scripted as the machines are diskless and almost everything is
working properly. However I cannot seem to FreeIPA managed user ssh keys working with
sssd. I have been reading for a couple of days and haven't found the answer as of yet.
Here is what I have discerned to be pertinent information. I will gladly add anything else
that's necessary. When 'sss_ssh_authorizedkeys markp --debug 10' produces no
output at all and no errors. I cannot ssh between hosts without entering a password or
using authorized_keys.
'journalctl -u sssd' shows:
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 1
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 1
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 1
Feb 28 11:38:40 hud9 sssd_be[3345]: GSSAPI client step 2
OS: CentOS 7.4
Packages: ipa-client-4.6.5-11.el7.centos.4.x86_64 sssd-1.16.4-21.el7_7.1.x86_64
sssd.conf:
Hi,
please add 'debug_level = 9' to the [domain/...] and [ssh] sections,
restart SSSD, run the sss_ssh_authorizedkeys command again and then send
the sssd_ssh.log and sssd_example.com.log files from /var/log/sssd.
bye,
Sumit
[domain/example.com]
cache_credentials = True
krb5_store_password_if_offline = True
ipa_domain = example.com
id_provider = ipa
auth_provider = ipa
access_provider = ipa
ipa_hostname = host.example.com
chpass_provider = ipa
ipa_server = ipaserver.example.com
ldap_tls_cacert = /etc/ipa/ca.crt
[sssd]
config_file_version = 2
services = nss, sudo, pam, ssh
domains = example.com
[nss]
homedir_substring = /home
[pam]
[sudo]
[autofs]
[ssh]
[pac]
[ifp]
[secrets]
[session_recording]
openldap/ldap.conf
# File modified by ipa-client-install
TLS_CACERTDIR /etc/openldap/certs
# Turning this off breaks GSSAPI used with krb5 when rdns = false
SASL_NOCANON on
URI ldaps://ipaserver.example.com
BASE dc=dugeo,dc=com
TLS_CACERT /etc/ipa/ca.crt
SASL_MECH GSSAPI
krb5.conf
#File modified by ipa-client-install
includedir /etc/krb5.conf.d/
includedir /var/lib/sss/pubconf/krb5.include.d/
[libdefaults]
default_realm = EXAMPLE.COM
dns_lookup_realm = false
dns_lookup_kdc = false
rdns = false
dns_canonicalize_hostname = false
ticket_lifetime = 24h
forwardable = true
udp_preference_limit = 0
default_ccache_name = KEYRING:persistent:%{uid}
[realms]
EXAMPLE.COM = {
kdc = ipaserver.example.com:88
master_kdc = ipaserver.example.com:88
admin_server = ipaserver.example.com:749
kpasswd_server = ipaserver.example.com:464
default_domain = example.com
pkinit_anchors = FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem
pkinit_pool = FILE:/var/lib/ipa-client/pki/ca-bundle.pem
}
[domain_realm]
.example.com = EXAMPLE.COM
example.com = EXAMPLE.COM
host.example.com = EXAMPLE.COM
I am hoping there's something simple that I am missing here, something I've
overlooked or managed to just suck at library skills. Thanks in advance for any help.
_______________________________________________
FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-leave(a)lists.fedorahosted.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedoraho...
12:31 p.m.
sssd_ssh.log
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [get_client_cred] (0x4000): Client creds:
euid[2063] egid[2080] pid[4353].
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [get_client_cred] (0x0080): The following failure
is expected to happen in case SELinux is disabled:
SELINUX_getpeercon failed [92][Protocol not available].
Please, consider enabling SELinux in your system.
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [setup_client_idle_timer] (0x4000): Idle timer
re-set for client [0x55d51e299aa0][18]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [accept_fd_handler] (0x0400): Client connected!
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Received client
version [0].
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Offered version
[0].
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ssh_protocol_parse_request] (0x0400): Requested
domain [<ALL>]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ssh_cmd_get_user_pubkeys] (0x0400): Requesting SSH
user public keys for [user] from [<ALL>]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_set_plugin] (0x2000): CR #2: Setting
"User by name" plugin
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_send] (0x0400): CR #2: New request
'User by name'
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_process_input] (0x0400): CR #2: Parsing
input name [user]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [sss_parse_name_for_domains] (0x0200): name
'user' matched without domain, user is user
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_set_name] (0x0400): CR #2: Setting name
[user]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_select_domains] (0x0400): CR #2:
Performing a multi-domain search
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_search_domains] (0x0400): CR #2: Search
will check the cache and check the data provider
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_validate_domain_type] (0x2000): Request
type POSIX-only for domain example.com type POSIX is valid
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_set_domain] (0x0400): CR #2: Using
domain [example.com]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_prepare_domain_data] (0x0400): CR #2:
Preparing input data for domain [example.com] rules
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_search_send] (0x0400): CR #2: Looking up
user(a)example.com
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_search_ncache] (0x0400): CR #2: Checking
negative cache for [user(a)example.com]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [sss_ncache_check_str] (0x2000): Checking negative
cache for [NCE/USER/example.com/user@example.com]
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_search_ncache] (0x0400): CR #2:
[user(a)example.com] is not present in negative cache
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_search_cache] (0x0400): CR #2: Looking
up [user(a)example.com] in cache
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55d51e2a6740
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55d51e2a6800
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x55d51e2a6740
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Destroying timer event
0x55d51e2a6800 "ltdb_timeout"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x55d51e2a6740
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55d51e29e220
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55d51e29e2e0
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x55d51e29e220
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Destroying timer event
0x55d51e29e2e0 "ltdb_timeout"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x55d51e29e220
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_search_send] (0x0400): CR #2: Returning
[user(a)example.com] from cache
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_search_ncache_filter] (0x0400): CR #2:
This request type does not support filtering result by negative cache
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_create_and_add_result] (0x0400): CR #2:
Found 1 entries in domain example.com
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [cache_req_done] (0x0400): CR #2: Finished:
Success
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55d51e2a9970
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55d51e2a9a30
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x55d51e2a9970
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Destroying timer event
0x55d51e2a9a30 "ltdb_timeout"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x55d51e2a9970
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55d51e2a9970
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55d51e2a9a30
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x55d51e2a9970
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Destroying timer event
0x55d51e2a9a30 "ltdb_timeout"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x55d51e2a9970
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55d51e2a9970
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55d51e2a9a30
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x55d51e2a9970
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Destroying timer event
0x55d51e2a9a30 "ltdb_timeout"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x55d51e2a9970
"ltdb_callback"
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [ssh_protocol_done] (0x4000): Sending reply:
success
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [client_recv] (0x0200): Client disconnected!
(Fri Feb 28 12:14:23 2020) [sssd[ssh]] [client_close_fn] (0x2000): Terminated client
[0x55d51e299aa0][18]
sssd_example.com.log (same request, just a little later so I could get clean output)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): dbus conn:
0x55905bec2f60
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path
/org/freedesktop/sssd/dataprovider
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_get_sender_id_send] (0x2000): Not
a sysbus message, quit
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_get_account_info_handler] (0x0200):
Got request for [0x5][BE_REQ_SERVICES][name=ntp]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): DP Request
[Account #337]: New request. Flags [0x0001].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): Number of
active DP request: 1
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [services_get_send] (0x1000): Preparing
to search for services with filter
[(&(cn=ntp)(ipServiceProtocol=udp)(objectclass=ipService))]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_connect_step] (0x4000):
reusing cached connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_next_base] (0x0400):
Searching for services with base [cn=accounts,dc=example,dc=com]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_print_server] (0x2000): Searching
172.27.16.5:389
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x0400):
calling ldap_search_ext with
[(&(cn=ntp)(ipServiceProtocol=udp)(objectclass=ipService))][cn=accounts,dc=example,dc=com].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [objectClass]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [cn]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServicePort]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServiceProtocol]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [entryUSN]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x2000):
ldap_search_ext called, msgid = 24
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_add] (0x2000): New operation
24 timeout 6
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[0x55905bee7ba0], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_destructor] (0x2000):
Operation 24 finished
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_process] (0x0400):
Search for services, returned 0 results.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_done] (0x4000): releasing
operation connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): start ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000):
Search services with filter:
(&(objectclass=service)(&(serviceProtocol=udp)(|(nameAlias=ntp)(name=ntp))))
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55905bee29a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55905befc3a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Running timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Destroying timer event
0x55905befc3a0 "ltdb_timeout"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Ending timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000): No
such entry
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): cancel ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_done] (0x0400): DP Request
[Account #337]: Request handler finished [0]: Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [_dp_req_recv] (0x0400): DP Request
[Account #337]: Receiving request data.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_list_success] (0x0400):
DP Request [Account #337]: Finished. Success.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_std] (0x1000): DP Request
[Account #337]: Returning [Success]: 0,0,Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_table_value_destructor] (0x0400):
Removing [0:1:0x0001:5:udp:example.com:name=ntp] from reply table
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): DP
Request [Account #337]: Request removed.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): Number of
active DP request: 0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[(nil)], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
end of ldap_result list
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): dbus conn:
0x55905bec2f60
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path
/org/freedesktop/sssd/dataprovider
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_get_sender_id_send] (0x2000): Not
a sysbus message, quit
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_get_account_info_handler] (0x0200):
Got request for [0x5][BE_REQ_SERVICES][name=ntp]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): DP Request
[Account #338]: New request. Flags [0x0001].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): Number of
active DP request: 1
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [services_get_send] (0x1000): Preparing
to search for services with filter
[(&(cn=ntp)(ipServiceProtocol=tcp)(objectclass=ipService))]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_connect_step] (0x4000):
reusing cached connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_next_base] (0x0400):
Searching for services with base [cn=accounts,dc=example,dc=com]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_print_server] (0x2000): Searching
172.27.16.5:389
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x0400):
calling ldap_search_ext with
[(&(cn=ntp)(ipServiceProtocol=tcp)(objectclass=ipService))][cn=accounts,dc=example,dc=com].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [objectClass]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [cn]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServicePort]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServiceProtocol]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [entryUSN]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x2000):
ldap_search_ext called, msgid = 25
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_add] (0x2000): New operation
25 timeout 6
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[0x55905bee7ba0], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_destructor] (0x2000):
Operation 25 finished
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_process] (0x0400):
Search for services, returned 0 results.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_done] (0x4000): releasing
operation connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): start ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000):
Search services with filter:
(&(objectclass=service)(&(serviceProtocol=tcp)(|(nameAlias=ntp)(name=ntp))))
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55905bee29a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55905befc3a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Running timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Destroying timer event
0x55905befc3a0 "ltdb_timeout"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Ending timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000): No
such entry
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): cancel ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_done] (0x0400): DP Request
[Account #338]: Request handler finished [0]: Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [_dp_req_recv] (0x0400): DP Request
[Account #338]: Receiving request data.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_list_success] (0x0400):
DP Request [Account #338]: Finished. Success.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_std] (0x1000): DP Request
[Account #338]: Returning [Success]: 0,0,Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_table_value_destructor] (0x0400):
Removing [0:1:0x0001:5:tcp:example.com:name=ntp] from reply table
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): DP
Request [Account #338]: Request removed.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): Number of
active DP request: 0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[(nil)], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
end of ldap_result list
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): dbus conn:
0x55905bec2f60
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path
/org/freedesktop/sssd/dataprovider
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_get_sender_id_send] (0x2000): Not
a sysbus message, quit
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_get_account_info_handler] (0x0200):
Got request for [0x5][BE_REQ_SERVICES][name=ntp]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): DP Request
[Account #339]: New request. Flags [0x0001].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): Number of
active DP request: 1
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [services_get_send] (0x1000): Preparing
to search for services with filter
[(&(cn=ntp)(ipServiceProtocol=dccp)(objectclass=ipService))]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_connect_step] (0x4000):
reusing cached connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_next_base] (0x0400):
Searching for services with base [cn=accounts,dc=example,dc=com]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_print_server] (0x2000): Searching
172.27.16.5:389
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x0400):
calling ldap_search_ext with
[(&(cn=ntp)(ipServiceProtocol=dccp)(objectclass=ipService))][cn=accounts,dc=example,dc=com].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [objectClass]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [cn]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServicePort]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServiceProtocol]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [entryUSN]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x2000):
ldap_search_ext called, msgid = 26
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_add] (0x2000): New operation
26 timeout 6
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[0x55905bee7ba0], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_destructor] (0x2000):
Operation 26 finished
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_process] (0x0400):
Search for services, returned 0 results.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x0400):
calling ldap_search_ext with
[(&(cn=ntp)(ipServiceProtocol=tcp)(objectclass=ipService))][cn=accounts,dc=example,dc=com].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [objectClass]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [cn]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServicePort]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServiceProtocol]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [entryUSN]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x2000):
ldap_search_ext called, msgid = 25
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_add] (0x2000): New operation
25 timeout 6
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[0x55905bee7ba0], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_destructor] (0x2000):
Operation 25 finished
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_process] (0x0400):
Search for services, returned 0 results.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_done] (0x4000): releasing
operation connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): start ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000):
Search services with filter:
(&(objectclass=service)(&(serviceProtocol=tcp)(|(nameAlias=ntp)(name=ntp))))
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55905bee29a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55905befc3a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Running timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Destroying timer event
0x55905befc3a0 "ltdb_timeout"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Ending timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000): No
such entry
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): cancel ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_done] (0x0400): DP Request
[Account #338]: Request handler finished [0]: Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [_dp_req_recv] (0x0400): DP Request
[Account #338]: Receiving request data.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_list_success] (0x0400):
DP Request [Account #338]: Finished. Success.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_std] (0x1000): DP Request
[Account #338]: Returning [Success]: 0,0,Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_table_value_destructor] (0x0400):
Removing [0:1:0x0001:5:tcp:example.com:name=ntp] from reply table
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): DP
Request [Account #338]: Request removed.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): Number of
active DP request: 0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[(nil)], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
end of ldap_result list
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): dbus conn:
0x55905bec2f60
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path
/org/freedesktop/sssd/dataprovider
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_get_sender_id_send] (0x2000): Not
a sysbus message, quit
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_get_account_info_handler] (0x0200):
Got request for [0x5][BE_REQ_SERVICES][name=ntp]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): DP Request
[Account #339]: New request. Flags [0x0001].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): Number of
active DP request: 1
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [services_get_send] (0x1000): Preparing
to search for services with filter
[(&(cn=ntp)(ipServiceProtocol=dccp)(objectclass=ipService))]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_connect_step] (0x4000):
reusing cached connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_next_base] (0x0400):
Searching for services with base [cn=accounts,dc=example,dc=com]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_print_server] (0x2000): Searching
172.27.16.5:389
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x0400):
calling ldap_search_ext with
[(&(cn=ntp)(ipServiceProtocol=dccp)(objectclass=ipService))][cn=accounts,dc=example,dc=com].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [objectClass]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [cn]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServicePort]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServiceProtocol]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [entryUSN]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x2000):
ldap_search_ext called, msgid = 26
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_add] (0x2000): New operation
26 timeout 6
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[0x55905bee7ba0], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_destructor] (0x2000):
Operation 26 finished
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_process] (0x0400):
Search for services, returned 0 results.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000): No
such entry
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): cancel ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_done] (0x0400): DP Request
[Account #340]: Request handler finished [0]: Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [_dp_req_recv] (0x0400): DP Request
[Account #340]: Receiving request data.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_list_success] (0x0400):
DP Request [Account #340]: Finished. Success.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_std] (0x1000): DP Request
[Account #340]: Returning [Success]: 0,0,Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_table_value_destructor] (0x0400):
Removing [0:1:0x0001:5:udplite:example.com:name=ntp] from reply table
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): DP
Request [Account #340]: Request removed.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): Number of
active DP request: 0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[(nil)], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
end of ldap_result list
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): dbus conn:
0x55905bec2f60
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path
/org/freedesktop/sssd/dataprovider
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sbus_get_sender_id_send] (0x2000): Not
a sysbus message, quit
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_get_account_info_handler] (0x0200):
Got request for [0x5][BE_REQ_SERVICES][name=ntp]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): DP Request
[Account #341]: New request. Flags [0x0001].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_attach_req] (0x0400): Number of
active DP request: 1
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sss_domain_get_state] (0x1000): Domain
example.com is Active
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [services_get_send] (0x1000): Preparing
to search for services with filter
[(&(cn=ntp)(ipServiceProtocol=sctp)(objectclass=ipService))]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_connect_step] (0x4000):
reusing cached connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_next_base] (0x0400):
Searching for services with base [cn=accounts,dc=example,dc=com]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_print_server] (0x2000): Searching
172.27.16.5:389
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x0400):
calling ldap_search_ext with
[(&(cn=ntp)(ipServiceProtocol=sctp)(objectclass=ipService))][cn=accounts,dc=example,dc=com].
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [objectClass]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [cn]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServicePort]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [ipServiceProtocol]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [entryUSN]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_ext_step] (0x2000):
ldap_search_ext called, msgid = 28
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_add] (0x2000): New operation
28 timeout 6
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[0x55905bee7ba0], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_op_destructor] (0x2000):
Operation 28 finished
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_get_services_process] (0x0400):
Search for services, returned 0 results.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_id_op_done] (0x4000): releasing
operation connection
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): start ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000):
Search services with filter:
(&(objectclass=service)(&(serviceProtocol=sctp)(|(nameAlias=ntp)(name=ntp))))
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55905bee29a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55905befc3a0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Running timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Destroying timer event
0x55905befc3a0 "ltdb_timeout"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): Ending timer event
0x55905bee29a0 "ltdb_callback"
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sysdb_search_services] (0x2000): No
such entry
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [ldb] (0x4000): cancel ldb transaction
(nesting: 0)
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_done] (0x0400): DP Request
[Account #341]: Request handler finished [0]: Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [_dp_req_recv] (0x0400): DP Request
[Account #341]: Receiving request data.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_list_success] (0x0400):
DP Request [Account #341]: Finished. Success.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_reply_std] (0x1000): DP Request
[Account #341]: Returning [Success]: 0,0,Success
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_table_value_destructor] (0x0400):
Removing [0:1:0x0001:5:sctp:example.com:name=ntp] from reply table
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): DP
Request [Account #341]: Request removed.
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [dp_req_destructor] (0x0400): Number of
active DP request: 0
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
sh[0x55905beef580], connected[1], ops[(nil)], ldap[0x55905bed38d0]
(Fri Feb 28 12:28:00 2020) [sssd[be[example.com]]] [sdap_process_result] (0x2000): Trace:
end of ldap_result list
12:27 a.m.
On Fri, Feb 28, 2020 at 06:31:28PM -0000, Mark L. Potter via FreeIPA-users wrote:
...
>
>
> _______________________________________________
> FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
> To unsubscribe send an email to freeipa-users-leave(a)lists.fedorahosted.org
> Fedora Code of Conduct:
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedoraho...
sssd_ssh.log
...
sssd_example.com.log (same request, just a little later so I could get clean output)
Hi,
unfortunately this didn't work. The domain log didn't contain any lookup
for the user since all the data were already in the cache. According the
sssd_ssh.log is looks like no key were in the cache, so it would be good
to see the user lookup in the domain log.
Can you call 'sss_cache -E' before running to test again to invalidate
the cached entries and send new logs?
bye,
Sumit
8:31 a.m.
Without any intervention on my part this is now working. I remain a bit confused and at
this point am trying to recreate it failing to work.
‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
On Monday, 2 March 2020 00:27, Sumit Bose via FreeIPA-users
<freeipa-users(a)lists.fedorahosted.org> wrote:
On Fri, Feb 28, 2020 at 06:31:28PM -0000, Mark L. Potter via
FreeIPA-users wrote:
> sssd_ssh.log
...
> sssd_example.com.log (same request, just a little later so I could get clean
output)
Hi,
unfortunately this didn't work. The domain log didn't contain any lookup
for the user since all the data were already in the cache. According the
sssd_ssh.log is looks like no key were in the cache, so it would be good
to see the user lookup in the domain log.
Can you call 'sss_cache -E' before running to test again to invalidate
the cached entries and send new logs?
bye,
Sumit
>
...
> FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
> To unsubscribe send an email to freeipa-users-leave(a)lists.fedorahosted.org
> Fedora Code of Conduct:
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedoraho...
FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-leave(a)lists.fedorahosted.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedoraho...
1509
days inactive
1513
days old
freeipa-users@lists.fedorahosted.org
4 comments
3 participants
participants (3)
-
Mark L Potter -
Mark L. Potter
-
Sumit Bose