On 04/15/2013 11:33 AM, Jakub Hrozek wrote:
Have you been able to check what kind of searches (with wireshark or
similar
or even just looking at the debug logs) sssd is doing? There should be
one search for users and one for groups every 300 seconds by default
(can be overriden with ldap_enumeration_refresh_timeout).
Also how many users/groups do you have on the server?
Hi
Test setup with 2 users and 2 groups. The ldap server (Samba4 AD) is
flooded with requests every second. I attach small bits from each log.
If you coud have a look that would be great.
TIA
Steve
Samba 4 DC
Kerberos: AS-REQ DOLORESDC$(a)DOLORES.SITE from ipv4:192.168.1.100:51613
for krbtgt/DOLORES.SITE(a)DOLORES.SITE
Kerberos: Client sent patypes: 149
Kerberos: Looking for PKINIT pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: Looking for ENC-TS pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: No preauth found, returning PREAUTH-REQUIRED --
DOLORESDC$(a)DOLORES.SITE
Kerberos: AS-REQ DOLORESDC$(a)DOLORES.SITE from ipv4:192.168.1.100:50962
for krbtgt/DOLORES.SITE(a)DOLORES.SITE
Kerberos: Client sent patypes: encrypted-timestamp, 149
Kerberos: Looking for PKINIT pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: Looking for ENC-TS pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: ENC-TS Pre-authentication succeeded -- DOLORESDC$(a)DOLORES.SITE
using arcfour-hmac-md5
Kerberos: AS-REQ authtime: 2013-04-15T12:00:40 starttime: unset endtime:
2013-04-15T22:00:40 renew till: 2013-04-16T12:00:40
Kerberos: Client supported enctypes: aes256-cts-hmac-sha1-96,
aes128-cts-hmac-sha1-96, des3-cbc-sha1, arcfour-hmac-md5, using
arcfour-hmac-md5/arcfour-hmac-md5
Kerberos: Requested flags: renewable-ok, canonicalize
Kerberos: TGS-REQ DOLORESDC$(a)DOLORES.SITE from ipv4:192.168.1.100:39978
for ldap/doloresdc.dolores.site(a)DOLORES.SITE [canonicalize, renewable]
Kerberos: TGS-REQ authtime: 2013-04-15T12:00:40 starttime:
2013-04-15T12:00:40 endtime: 2013-04-15T22:00:40 renew till:
2013-04-16T12:00:40
Not authoritative for 'dolores.site.dragonet.es', forwarding
ldb_wrap open of secrets.ldb
Terminating connection - 'LDAP_PROTOCOL_ERROR'
single_terminate: reason[LDAP_PROTOCOL_ERROR]
Terminating connection - 'ldapsrv_call_loop:
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
single_terminate: reason[ldapsrv_call_loop: tstream_read_pdu_blob_recv()
- NT_STATUS_CONNECTION_DISCONNECTED]
ldb_wrap open of secrets.ldb
Kerberos: AS-REQ DOLORESDC$(a)DOLORES.SITE from ipv4:192.168.1.100:60133
for krbtgt/DOLORES.SITE(a)DOLORES.SITE
Kerberos: Client sent patypes: 149
Kerberos: Looking for PKINIT pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: Looking for ENC-TS pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: No preauth found, returning PREAUTH-REQUIRED --
DOLORESDC$(a)DOLORES.SITE
Kerberos: AS-REQ DOLORESDC$(a)DOLORES.SITE from ipv4:192.168.1.100:43142
for krbtgt/DOLORES.SITE(a)DOLORES.SITE
Kerberos: Client sent patypes: encrypted-timestamp, 149
Kerberos: Looking for PKINIT pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: Looking for ENC-TS pa-data -- DOLORESDC$(a)DOLORES.SITE
Kerberos: ENC-TS Pre-authentication succeeded -- DOLORESDC$(a)DOLORES.SITE
using arcfour-hmac-md5
Kerberos: AS-REQ authtime: 2013-04-15T12:00:43 starttime: unset endtime:
2013-04-15T22:00:43 renew till: 2013-04-16T12:00:43
Kerberos: Client supported enctypes: aes256-cts-hmac-sha1-96,
aes128-cts-hmac-sha1-96, des3-cbc-sha1, arcfour-hmac-md5, using
arcfour-hmac-md5/arcfour-hmac-md5
Kerberos: Requested flags: renewable-ok, canonicalize
Kerberos: TGS-REQ DOLORESDC$(a)DOLORES.SITE from ipv4:192.168.1.100:36908
for ldap/doloresdc.dolores.site(a)DOLORES.SITE [canonicalize, renewable]
Kerberos: TGS-REQ authtime: 2013-04-15T12:00:43 starttime:
2013-04-15T12:00:43 endtime: 2013-04-15T22:00:43 renew till:
2013-04-16T12:00:43
Not authoritative for 'dolores.site.dragonet.es', forwarding
ldb_wrap open of secrets.ldb
Terminating connection - 'LDAP_PROTOCOL_ERROR'
single_terminate: reason[LDAP_PROTOCOL_ERROR]
Terminating connection - 'ldapsrv_call_loop:
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
single_terminate: reason[ldapsrv_call_loop: tstream_read_pdu_blob_recv()
- NT_STATUS_CONNECTION_DISCONNECTED]
------------------------
sssd.conf
[sssd]
debug_level = 6
services = nss, pam
config_file_version = 2
domains = default
[nss]
debug_level = 6
[pam]
debug_level = 6
[domain/default]
debug_level = 6
ldap_schema = rfc2307bis
access_provider = simple
Enumerate = true
cache_credentials = true
id_provider = ldap
auth_provider = krb5
chpass_provider = krb5
krb5_realm = DOLORES.SITE
krb5_server = 192.168.1.100
krb5_kpasswd = 192.168.1.100
ldap_uri = ldap://192.168.1.100/
ldap_search_base = dc=dolores,dc=site
#ldap_tls_cacertdir = /usr/local/samba/private/tls
#ldap_id_use_start_tls = true
ldap_user_object_class = user
ldap_user_name = samAccountName
ldap_user_uid_number = uidNumber
ldap_user_gid_number = gidNumber
ldap_user_home_directory = unixHomeDirectory
ldap_user_shell = loginShell
ldap_group_object_class = group
ldap_group_search_base = dc=dolores,dc=site
ldap_group_name = cn
ldap_group_member = member
ldap_user_search_filter =(&(objectCategory=user)(uidNumber=*))
ldap_sasl_mech = GSSAPI
ldap_sasl_authid = DOLORESDC$
ldap_krb5_keytab = /etc/krb5.keytab
ldap_krb5_init_creds = true
------------------------------------
ldap_child.log
(Mon Apr 15 12:00:34 2013) [[sssd[ldap_child[4238]]]] [main] (0x0400):
ldap_child completed successfully
(Mon Apr 15 12:00:39 2013) [[sssd[ldap_child[4241]]]] [main] (0x0400):
ldap_child started.
(Mon Apr 15 12:00:39 2013) [[sssd[ldap_child[4241]]]]
[ldap_child_get_tgt_sync] (0x0100): Principal name is:
[DOLORESDC$(a)DOLORES.SITE]
(Mon Apr 15 12:00:39 2013) [[sssd[ldap_child[4241]]]]
[ldap_child_get_tgt_sync] (0x0100): Using keytab [/etc/krb5.keytab]
(Mon Apr 15 12:00:39 2013) [[sssd[ldap_child[4241]]]]
[ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
(Mon Apr 15 12:00:39 2013) [[sssd[ldap_child[4241]]]] [prepare_response]
(0x0400): Building response for result [0]
(Mon Apr 15 12:00:39 2013) [[sssd[ldap_child[4241]]]] [main] (0x0400):
ldap_child completed successfully
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4254]]]] [main] (0x0400):
ldap_child started.
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4254]]]]
[ldap_child_get_tgt_sync] (0x0100): Principal name is:
[DOLORESDC$(a)DOLORES.SITE]
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4254]]]]
[ldap_child_get_tgt_sync] (0x0100): Using keytab [/etc/krb5.keytab]
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4254]]]]
[ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4254]]]] [prepare_response]
(0x0400): Building response for result [0]
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4254]]]] [main] (0x0400):
ldap_child completed successfully
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4257]]]] [main] (0x0400):
ldap_child started.
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4257]]]]
[ldap_child_get_tgt_sync] (0x0100): Principal name is:
[DOLORESDC$(a)DOLORES.SITE]
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4257]]]]
[ldap_child_get_tgt_sync] (0x0100): Using keytab [/etc/krb5.keytab]
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4257]]]]
[ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4257]]]] [prepare_response]
(0x0400): Building response for result [0]
(Mon Apr 15 12:00:40 2013) [[sssd[ldap_child[4257]]]] [main] (0x0400):
ldap_child completed successfully
(Mon Apr 15 12:00:43 2013) [[sssd[ldap_child[4260]]]] [main] (0x0400):
ldap_child started.
(Mon Apr 15 12:00:43 2013) [[sssd[ldap_child[4260]]]]
[ldap_child_get_tgt_sync] (0x0100): Principal name is:
[DOLORESDC$(a)DOLORES.SITE]
(Mon Apr 15 12:00:43 2013) [[sssd[ldap_child[4260]]]]
[ldap_child_get_tgt_sync] (0x0100): Using keytab [/etc/krb5.keytab]
(Mon Apr 15 12:00:43 2013) [[sssd[ldap_child[4260]]]]
[ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
(Mon Apr 15 12:00:43 2013) [[sssd[ldap_child[4260]]]] [prepare_response]
(0x0400): Building response for result [0]
(Mon Apr 15 12:00:43 2013) [[sssd[ldap_child[4260]]]] [main] (0x0400):
ldap_child completed successfully
---------------------------------
sssd_default.log
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]]
[sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no
errmsg set
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [get_naming_context]
(0x0200): Using value from [defaultNamingContext] as naming context.
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [sdap_set_search_base]
(0x0100): Setting option [ldap_sudo_search_base] to [DC=dolores,DC=site].
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]]
[common_parse_search_base] (0x0100): Search base added:
[SUDO][DC=dolores,DC=site][SUBTREE][]
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]]
[sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility
level to [4]
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [sdap_kinit_send]
(0x0400): Attempting kinit (/etc/krb5.keytab, DOLORESDC$, DOLORES.SITE,
86400)
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'KERBEROS'
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]]
[be_resolve_server_process] (0x0200): Found address for server
192.168.1.100: [192.168.1.100] TTL 7200
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [set_tgt_child_timeout]
(0x0400): Setting 6 seconds timeout for tgt child
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [child_sig_handler]
(0x0100): child [4257] finished successfully.
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [sdap_get_tgt_recv]
(0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_DOLORES.SITE],
expired on [1366056040]
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [sdap_cli_auth_step]
(0x0100): expire timeout is 900
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [sasl_bind_send]
(0x0100): Executing sasl bind mech: GSSAPI, user: DOLORESDC$
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]] [fo_set_port_status]
(0x0100): Marking port 389 of server '192.168.1.100' as 'working'
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]]
[set_server_common_status] (0x0100): Marking server '192.168.1.100' as
'working'
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]]
[sdap_get_users_next_base] (0x0400): Searching for users with base
[dc=dolores,dc=site]
(Mon Apr 15 12:00:40 2013) [sssd[be[default]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(&(&(objectclass=user)(samAccountName=*)(uidNumber=*)(gidNumber=*))(&(objectCategory=user)(uidNumber=*)))][dc=dolores,dc=site].
(Mon Apr 15 12:00:41 2013) [sssd[be[default]]] [sdap_process_result]
(0x0040): ldap_result error: [Can't contact LDAP server]
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [server_setup] (0x0400):
CONFDB: /var/lib/sss/db/config.ldb
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [recreate_ares_channel]
(0x0100): Initializing new c-ares channel
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [fo_context_init]
(0x0400): Created new fail over context, retry timeout is 30
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]]
[sysdb_domain_init_internal] (0x0200): DB File for default:
/var/lib/sss/db/cache_default.ldb
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [ldb] (0x0400): asq:
Unable to register control with rootdse!
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [sbus_init_connection]
(0x0200): Adding connection 9A24720
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [monitor_common_send_id]
(0x0100): Sending ID: (%BE_default,1)
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [sss_names_init]
(0x0100): Using re [(?P<name>[^@]+)@?(?P<domain>[^@]*$)].
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [sbus_new_server]
(0x0400): D-BUS Server listening on
unix:path=/var/lib/sss/pipes/private/sbus-dp_default.4259,guid=c7bed4b88515d11a9bda7a81516bcfcb
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_uri has value ldap://192.168.1.100/
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_backup_uri has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_search_base has value dc=dolores,dc=site
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_default_bind_dn has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_default_authtok_type has value password
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_default_authtok has no binary value.
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_search_timeout has value 6
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_network_timeout has value 6
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_opt_timeout has value 6
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_tls_reqcert has value hard
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_user_search_base has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_user_search_scope has value sub
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_user_search_filter has value
(&(objectCategory=user)(uidNumber=*))
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_group_search_base has value dc=dolores,dc=site
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_group_search_scope has value sub
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_group_search_filter has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_service_search_base has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_search_base has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_full_refresh_interval has value 21600
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_smart_refresh_interval has value 900
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_use_host_filter is TRUE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_hostnames has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_ip has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_include_netgroups is TRUE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sudo_include_regexp is TRUE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_autofs_search_base has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_schema has value rfc2307bis
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_offline_timeout has value 60
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_force_upper_case_realm is FALSE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_enumeration_refresh_timeout has value 300
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_purge_cache_timeout has value 10800
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_tls_cacert has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_tls_cacertdir has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_tls_cert has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_tls_key has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_tls_cipher_suite has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_id_use_start_tls is FALSE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_id_mapping is FALSE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sasl_mech has value GSSAPI
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sasl_authid has value DOLORESDC$
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sasl_realm has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_sasl_minssf has value -1
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_krb5_keytab has value /etc/krb5.keytab
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_krb5_init_creds is TRUE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option krb5_server has value 192.168.1.100
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option krb5_backup_server has no value
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option krb5_realm has value DOLORES.SITE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option krb5_canonicalize is TRUE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_pwd_policy has value none
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_referrals is TRUE
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option account_cache_expiration has value 0
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_dns_service_name has value ldap
(Mon Apr 15 12:00:43 2013) [sssd[be[default]]] [dp_get_options]
(0x0400): Option ldap_krb5_ticket_lifetime has value 86400
------------------------------
sss.log
(Mon Apr 15 12:00:40 2013) [sssd] [client_registration] (0x0100):
Received ID registration: (pam,1)
(Mon Apr 15 12:00:40 2013) [sssd] [mark_service_as_started] (0x0200):
Marking pam as started.
(Mon Apr 15 12:00:40 2013) [sssd] [sbus_server_init_new_connection]
(0x0200): Entering.
(Mon Apr 15 12:00:40 2013) [sssd] [sbus_server_init_new_connection]
(0x0200): Adding connection 0x8708c60.
(Mon Apr 15 12:00:40 2013) [sssd] [sbus_init_connection] (0x0200):
Adding connection 8708C60
(Mon Apr 15 12:00:40 2013) [sssd] [sbus_server_init_new_connection]
(0x0200): Got a connection
(Mon Apr 15 12:00:40 2013) [sssd] [monitor_service_init] (0x0400):
Initializing D-BUS Service
(Mon Apr 15 12:00:40 2013) [sssd] [client_registration] (0x0100):
Received ID registration: (nss,1)
(Mon Apr 15 12:00:40 2013) [sssd] [mark_service_as_started] (0x0200):
Marking nss as started.
(Mon Apr 15 12:00:40 2013) [sssd] [mark_service_as_started] (0x0400):
SSSD is initialized, terminating parent process
(Mon Apr 15 12:00:40 2013) [sssd] [sbus_dispatch] (0x0080): Connection
is not open for dispatching.
(Mon Apr 15 12:00:40 2013) [sssd] [mt_svc_exit_handler] (0x0040): Child
[default] terminated with signal [6]
(Mon Apr 15 12:00:40 2013) [sssd] [mt_svc_restart] (0x0400): Scheduling
service default for restart 1
(Mon Apr 15 12:00:40 2013) [sssd] [get_ping_config] (0x0100): Time
between service pings for [default]: [10]
(Mon Apr 15 12:00:40 2013) [sssd] [get_ping_config] (0x0100): Time
between SIGTERM and SIGKILL for [default]: [60]
(Mon Apr 15 12:00:40 2013) [sssd] [start_service] (0x0100): Queueing
service default for startup
(Mon Apr 15 12:00:40 2013) [sssd] [sbus_server_init_new_connection]
(0x0200): Entering.
(Mon Apr 15 12:00:40 2013) [sssd] [sbus_server_init_new_connection]
(0x0200): Adding connection 0x870c7a8.
---------------------------------
sssd_nss.log
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [server_setup] (0x0400): CONFDB:
/var/lib/sss/db/config.ldb
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sbus_init_connection] (0x0200):
Adding connection 97EEC00
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [monitor_common_send_id]
(0x0100): Sending ID: (nss,1)
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_names_init] (0x0100): Using
re [(?P<name>[^@]+)@?(?P<domain>[^@]*$)].
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sbus_init_connection] (0x0200):
Adding connection 97EDD08
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [dp_common_send_id] (0x0100):
Sending ID to DP: (1,NSS)
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sysdb_domain_init_internal]
(0x0200): DB File for default: /var/lib/sss/db/cache_default.ldb
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [ldb] (0x0400): asq: Unable to
register control with rootdse!
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_process_init] (0x0400):
Responder Initialization complete
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): name 'root' matched without domain, user is root
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): using default domain [(null)]
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_ncache_set_str] (0x0400):
Adding [NCE/USER/default/root] to negative cache permanently
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): name 'root' matched without domain, user is root
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): using default domain [(null)]
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [sss_ncache_set_str] (0x0400):
Adding [NCE/GROUP/default/root] to negative cache permanently
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [nss_get_etc_shells] (0x0400):
Found shell /bin/sh in /etc/shells
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [nss_get_etc_shells] (0x0400):
Found shell /bin/dash in /etc/shells
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [nss_get_etc_shells] (0x0400):
Found shell /bin/bash in /etc/shells
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [nss_get_etc_shells] (0x0400):
Found shell /bin/rbash in /etc/shells
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [responder_set_fd_limit]
(0x0100): Maximum file descriptors set to [8192]
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [nss_process_init] (0x0400): NSS
Initialization complete
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [id_callback] (0x0100): Got id
ack and version (1) from Monitor
(Mon Apr 15 12:00:06 2013) [sssd[nss]] [dp_id_callback] (0x0100): Got id
ack and version (1) from DP
(Mon Apr 15 12:00:07 2013) [sssd[nss]] [sbus_dispatch] (0x0020):
Performing auto-reconnect
(Mon Apr 15 12:00:08 2013) [sssd[nss]] [sbus_reconnect] (0x0080): Making
reconnection attempt 1 to
[unix:path=/var/lib/sss/pipes/private/sbus-dp_default]
(Mon Apr 15 12:00:08 2013) [sssd[nss]] [sbus_reconnect] (0x0020): Failed
to open connection: name=org.freedesktop.DBus.Error.NoServer,
message=Failed to connect to socket
/var/lib/sss/pipes/private/sbus-dp_default: Connection refused
(Mon Apr 15 12:00:11 2013) [sssd[nss]] [sbus_reconnect] (0x0080): Making
reconnection attempt 2 to
[unix:path=/var/lib/sss/pipes/private/sbus-dp_default]
(Mon Apr 15 12:00:11 2013) [sssd[nss]] [sbus_reconnect] (0x0020): Failed
to open connection: name=org.freedesktop.DBus.Error.NoServer,
message=Failed to connect to socket
/var/lib/sss/pipes/private/sbus-dp_default: Connection refused
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_responder_ctx_destructor]
(0x0400): Responder is being shut down
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [server_setup] (0x0400): CONFDB:
/var/lib/sss/db/config.ldb
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sbus_init_connection] (0x0200):
Adding connection 9B13C00
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [monitor_common_send_id]
(0x0100): Sending ID: (nss,1)
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_names_init] (0x0100): Using
re [(?P<name>[^@]+)@?(?P<domain>[^@]*$)].
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sbus_init_connection] (0x0200):
Adding connection 9B12D08
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [dp_common_send_id] (0x0100):
Sending ID to DP: (1,NSS)
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sysdb_domain_init_internal]
(0x0200): DB File for default: /var/lib/sss/db/cache_default.ldb
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [ldb] (0x0400): asq: Unable to
register control with rootdse!
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_process_init] (0x0400):
Responder Initialization complete
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): name 'root' matched without domain, user is root
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): using default domain [(null)]
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_ncache_set_str] (0x0400):
Adding [NCE/USER/default/root] to negative cache permanently
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): name 'root' matched without domain, user is root
(Mon Apr 15 12:00:15 2013) [sssd[nss]] [sss_parse_name_for_domains]
(0x0200): using default domain [(null)]
----------------------------------
sssd_pam.log
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [server_setup] (0x0400): CONFDB:
/var/lib/sss/db/config.ldb
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sbus_init_connection] (0x0200):
Adding connection 84E0D88
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [monitor_common_send_id]
(0x0100): Sending ID: (pam,1)
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_names_init] (0x0100): Using
re [(?P<name>[^@]+)@?(?P<domain>[^@]*$)].
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sbus_init_connection] (0x0200):
Adding connection 84E2858
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [dp_common_send_id] (0x0100):
Sending ID to DP: (1,PAM)
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sysdb_domain_init_internal]
(0x0200): DB File for default: /var/lib/sss/db/cache_default.ldb
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [ldb] (0x0400): asq: Unable to
register control with rootdse!
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_process_init] (0x0400):
Responder Initialization complete
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): name 'root' matched without domain, user is root
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): using default domain [(null)]
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_ncache_set_str] (0x0400):
Adding [NCE/USER/default/root] to negative cache permanently
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): name 'root' matched without domain, user is root
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): using default domain [(null)]
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [sss_ncache_set_str] (0x0400):
Adding [NCE/GROUP/default/root] to negative cache permanently
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [responder_set_fd_limit]
(0x0100): Maximum file descriptors set to [8192]
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [id_callback] (0x0100): Got id
ack and version (1) from Monitor
(Mon Apr 15 12:00:06 2013) [sssd[pam]] [dp_id_callback] (0x0100): Got id
ack and version (1) from DP
(Mon Apr 15 12:00:07 2013) [sssd[pam]] [sbus_dispatch] (0x0020):
Performing auto-reconnect
(Mon Apr 15 12:00:08 2013) [sssd[pam]] [sbus_reconnect] (0x0080): Making
reconnection attempt 1 to
[unix:path=/var/lib/sss/pipes/private/sbus-dp_default]
(Mon Apr 15 12:00:08 2013) [sssd[pam]] [sbus_reconnect] (0x0020): Failed
to open connection: name=org.freedesktop.DBus.Error.NoServer,
message=Failed to connect to socket
/var/lib/sss/pipes/private/sbus-dp_default: Connection refused
(Mon Apr 15 12:00:11 2013) [sssd[pam]] [sbus_reconnect] (0x0080): Making
reconnection attempt 2 to
[unix:path=/var/lib/sss/pipes/private/sbus-dp_default]
(Mon Apr 15 12:00:11 2013) [sssd[pam]] [sbus_reconnect] (0x0020): Failed
to open connection: name=org.freedesktop.DBus.Error.NoServer,
message=Failed to connect to socket
/var/lib/sss/pipes/private/sbus-dp_default: Connection refused
(Mon Apr 15 12:00:15 2013) [sssd[pam]] [sss_responder_ctx_destructor]
(0x0400): Responder is being shut down