[SSSD-users] FW: startup problem/port 0 not working

Jakub Hrozek jhrozek at redhat.com
Fri Nov 9 20:37:27 UTC 2012


On Fri, Nov 09, 2012 at 03:23:55PM -0500, Dmitri Pal wrote:
> On 11/09/2012 07:27 AM, Longina Przybyszewska wrote:
> > Hi again,
> >
> > Here you are all logs after 'getent passwd imadatestuser'
> >
> > root at victoria:/var/log/sssd# cat /etc/sssd/sssd.conf | grep -v ^#
> >
> > [sssd]
> > debug_level = 0x1310
> > config_file_version = 2
> > services = nss, pam
> > domains = nat.c.sdu.dk
> >
> > [nss]
> > filter_groups = root
> > filter_users = root
> >
> > [pam]
> >
> > [domain/nat.c.sdu.dk]
> >
> > debug_level = 10
> >
> > enumerate = False
> > min_id = 1000
> > max_id = 20000
> >
> > auth_provider = ad
> > krb5_realm = NAT.C.SDU.DK
> >
> >
> > id_provider = ad
> > access_provider = ad
> > chpass_provider = ad
> > ldap_user_search_base = ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk
> > ldap_user_object_class = person
> >
> >
> > ldap_group_object_class = group
> > ldap_group_search_base = ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk
> >
> >
> > ad_server = nat.c.sdu.dk
> > ad_hostname = VICTORIA$@NAT.C.SDU.DK
> > ad_domain = nat.c.sdu.dk
> >
> > .......
> > Krb5_child. Log empty
> > .....
> > Sssd-nat.c.sdu.dk.log
> > ..........................
> > Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_get_family_order] (0x1000): Lookup order: ipv4_first (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 2221550 (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_nat.c.sdu.dk,1) (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_nat.c.sdu.dk.5678 to a link /var/lib/sss/pipes/private/s bus-dp_nat.c.sdu.dk (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Loading backend [ad] with path [/usr/lib/x86_64-linux-gnu/sssd/libsss_ad.so].
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_common_options] (0x0100): Setting domain case-insensitive (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_servers_init] (0x0100): Added failover server nat.c.sdu.dk (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [USER][ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][]
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][]
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): trying to select the most appropriate principal from keytab (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [match_principal] (0x1000): Principal matched to the sample (*$@NAT.C.SDU.DK).
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected primary: VICTORIA$ (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected realm: NAT.C.SDU.DK (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_authid set to VICTORIA$ (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_realm set to NAT.C.SDU.DK (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_server set to nat.c.sdu.dk (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): No kpasswd server explicitly configured, using the KDC or defaults.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): ccache is of type FILE (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad].
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad].
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad].
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x222bab0.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 222BAB0 (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x222cb90] (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x22336b0.
> > (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 22336B0 (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x2233ef0] (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x222cb90] (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [PAM] (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x2233ef0] (Fri Nov  9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [NSS] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=imadatestuser] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port status of port 0 for server 'nat.c.sdu.dk' is 'neutral'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in files (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'resolving name'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'nat.c.sdu.dk' in files (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in DNS (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'name resolved'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200): Found address for server nat.c.sdu.dk: [10.144.5.18] TTL 190 (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://nat.c.sdu.dk'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://nat.c.sdu.dk:389/??base] with fd [23].
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context.
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk].
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][]
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_netgroup_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk].
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][]
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk].
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][]
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_service_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk].
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][]
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_autofs_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk].
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][]
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200): Found address for server nat.c.sdu.dk: [10.144.5.18] TTL 190 (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [create_tgt_req_send_buffer] (0x1000): buffer size: 37 (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting for child [5683].
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child [5683] finished successfully.
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'nat.c.sdu.dk' as 'not working'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port status of port 0 for server 'nat.c.sdu.dk' is 'not working'
> > (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [remove_krb5_info_files] (0x0200): Could not remove [/var/lib/sss/pubconf/kpasswdinfo.NAT.C.SDU.DK], [2][No such file or directory]
> >
> > Ldap_child.log
> > ......
> > (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): total buffer size: 37 (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): princ_str size: 9 (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got princ_str: VICTORIA$ (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [VICTORIA$@NAT.C.SDU.DK] (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
> >
> > ......
> >
> >
> > Sssd.log
> > ......
> > Fri Nov  9 13:06:36 2012) [sssd] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb
> > (Fri Nov  9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nat.c.sdu.dk for startup (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering.
> > (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2640e50.
> > (Fri Nov  9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2640E50 (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov  9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (%BE_nat.c.sdu.dk,1) (Fri Nov  9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nat.c.sdu.dk as started.
> > (Fri Nov  9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0100): Now starting services!
> > (Fri Nov  9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nss for startup (Fri Nov  9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service pam for startup (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering.
> > (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643fa0.
> > (Fri Nov  9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643FA0 (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering.
> > (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643e60.
> > (Fri Nov  9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643E60 (Fri Nov  9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov  9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (pam,1) (Fri Nov  9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking pam as started.
> > (Fri Nov  9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (nss,1) (Fri Nov  9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nss as started.
> > (Fri Nov  9 13:06:39 2012) [sssd] [message_type] (0x0200): netlink Message type: 25 (Fri Nov  9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nat.c.sdu.dk (Fri Nov  9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nss (Fri Nov  9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging pam (Fri Nov  9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nat.c.sdu.dk replied to ping (Fri Nov  9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nss replied to ping (Fri Nov  9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service pam replied to ping
> >
> > ....
> > Sssd_nss.log
> > ....
> >
> > (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 237E690 (Fri Nov  9 13:06:36 2012) [sssd[nss]] [monitor_common_send_id] (0x0100): Sending ID: (nss,1) (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sss_names_init] (0x0100): Using re [(((?P<domain>[^\\]+)\\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\\]+)$))].
> > (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 2380600 (Fri Nov  9 13:06:36 2012) [sssd[nss]] [dp_common_send_id] (0x0100): Sending ID to DP: (1,NSS) (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb
> > (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov  9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov  9 13:06:36 2012) [sssd[nss]] [responder_set_fd_limit] (0x0100): Maximum file descriptors set to [8192] (Fri Nov  9 13:06:36 2012) [sssd[nss]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov  9 13:06:36 2012) [sssd[nss]] [dp_id_callback] (0x0100): Got id ack and version (1) from DP (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1].
> > (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1].
> > (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov  9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for [imadatestuser] from [<ALL>] (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 19 error message: Subdomains back end target is not configured (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov  9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for [imadatestuser at nat.c.sdu.dk] (Fri Nov  9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 1 errno: 11 error message: Offline (Fri Nov  9 13:07:00 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
> >
> > That’s all...
> > Longina
> >
> >  
> >
> >
> > _______________________________________________
> > sssd-users mailing list
> > sssd-users at lists.fedorahosted.org
> > https://lists.fedorahosted.org/mailman/listinfo/sssd-users
> 
> Do I read it right that SSSD thinks that the system is offline and thus
> does not return anything for the user?
> Can you actually access AD at the moment of the test with other tools
> like LDAP search or do kinit?

It seems that the ldap_child completed successfully, according to this:

> (Fri Nov  9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]

That message is saying that the ldap_child was able to retrieve ccache
correctly. But then the backend set the status to not working, but the
logs don't tell why:

> (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$
> (Fri Nov  9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'nat.c.sdu.dk' as 'not working'

I think it might be prudent to supply Longina with a build that would
include more debugging.


More information about the sssd-users mailing list