Hi James,

Forgot to mention.We already tried that. It is still the same error.

Thanks,

~ Abhi

On Thu, Jun 4, 2020 at 12:12 PM James Cassell <fedoraproject@cyberpear.com> wrote:

On Thu, Jun 4, 2020, at 11:47 AM, Abhijit Tikekar wrote:
> Hi all,
>
> We recently started having issues with some SSSD clients that are
> connecting to RODC. They were all working fine when suddenly all
> authentications started getting following
>
> sshd[4487]: pam_sss(sshd:auth): received for user firstname.lastname: 4
> (System error)
>

Try setting krb5_validate=false in the domain section.

V/r,
James Cassell

> Being a RODC, keytab was created manually on a writable DC using setspn
> & ktpass and then integrated on the system using ktutil. Things were
> fine until last week when it stopped working on all such systems. We
> are not able to identify if the issue is on the system side or AD.
> Network side looks good and all required ports are open between client
> and Server. Host can also resolve RODC via DNS. Even other utilities
> such as ldapsearch, getent, id etc retrieve the results just fine. It
> is only the main login process that fails. Attaching parts of logs
> generated with debug level 10.
>
> It would be great if someone can review these and point us in the right
> direction.
>
> _*sssd_domain.log*_
>
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [dp_attach_req]
> (0x0400): Number of active DP request: 1
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [sdap_id_op_connect_step] (0x4000): beginning to connect
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [get_server_status]
> (0x1000): Status of server 'RODC.x.y.local' is 'name resolved'
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [get_port_status]
> (0x1000): Port status of port 0 for server 'RODC.x.y.local' is 'not
> working'
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [get_port_status]
> (0x0080): SSSD is unable to complete the full connection request, this
> internal status does not necessarily indicate network port issues.
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [fo_resolve_service_send] (0x0020): No available servers for service
> 'AD'
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [be_resolve_server_done] (0x1000): Server resolution failed: [5]:
> Input/output error
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5
> [Input/output error])
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [be_mark_offline]
> (0x2000): Going offline!
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [be_mark_offline]
> (0x2000): Enable check_if_online_ptask.
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [be_ptask_enable]
> (0x0080): Task [Check if online (periodic)]: already enabled
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [be_run_offline_cb]
> (0x4000): Flag indicates that offline callback were already called.
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [sdap_id_op_connect_done] (0x4000): notify offline to op #1
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [ad_subdomains_refresh_connect_done] (0x0020): Unable to connect to
> LDAP [11]: Resource temporarily unavailable
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [ad_subdomains_refresh_connect_done] (0x0080): No AD server is
> available, cannot get the subdomain list while offline
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [dp_req_done]
> (0x0400): DP Request [Subdomains #2]: Request handler finished [0]:
> Success
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [_dp_req_recv]
> (0x0400): DP Request [Subdomains #2]: Receiving request data.
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #2]:
> Finished. Success.
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [dp_req_reply_std]
> (0x1000): DP Request [Subdomains #2]: Returning [Provider is Offline]:
> 1,1432158212,Offline
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from
> reply table
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [dp_req_destructor]
> (0x0400): DP Request [Subdomains #2]: Request removed.
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [dp_req_destructor]
> (0x0400): Number of active DP request: 0
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]]
> [sdap_id_release_conn_data] (0x4000): releasing unused connection
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [sbus_dispatch]
> (0x4000): dbus conn: 0x55c31927bed0
> (Tue May 26 23:10:52 2020) [sssd[be[x.y.local]]] [be_ptask_offline_cb]
> (0x0400): Back end is offline
>
> _*ldap_child.log*_
>
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [main] (0x0400):
> ldap_child started.
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [main] (0x2000):
> context initialized
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x1000): total buffer size: 73
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x1000): realm_str size: 14
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x1000): got realm_str: x.y.local
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x1000): princ_str size: 35
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x1000): got princ_str: host/dmz_host.x.y.local
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x1000): keytab_name size: 0
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x1000): lifetime: 86400
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [unpack_buffer]
> (0x0200): Will run as [0][0].
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [privileged_krb5_setup] (0x2000): Kerberos context initialized
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [main] (0x2000):
> Kerberos context initialized
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [become_user]
> (0x0200): Trying to become user [0][0].
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [become_user]
> (0x0200): Already user [0].
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [main] (0x2000):
> Running as [0][0].
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [main] (0x2000):
> getting TGT sync
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [ldap_child_get_tgt_sync] (0x2000): got realm_name: [x.y.local]
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [ldap_child_get_tgt_sync] (0x0100): Principal name is:
> [host/dmz_host.x.y.local@x.y.local]
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [ldap_child_get_tgt_sync] (0x0100): Using keytab
> [MEMORY:/etc/krb5.keytab]
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529555: Getting
> initial credentials for host/dmz_host.x.y.local@x.y.local
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529556: Looked
> up etypes in keytab: rc4-hmac, rc4-hmac, rc4-hmac
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529558: Sending
> unauthenticated request
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529559: Sending
> request (227 bytes) to x.y.local
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529560: Sending
> initial UDP request to dgram x.x.x.x:88
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529561: Received
> answer (220 bytes) from dgram x.x.x.x:88
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529562: Response
> was from master KDC
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529563: Received
> error from KDC: -1765328359/Additional pre-authentication required
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529566:
> Preauthenticating using KDC method data
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529567:
> Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15),
> PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529568: Selected
> etype info: etype rc4-hmac, salt "", params ""
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529569:
> Retrieving host/dmz_host.x.y.local@x.y.local from
> MEMORY:/etc/krb5.keytab (vno 0, enctype rc4-hmac) with result: 0/Success
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529570: AS key
> obtained for encrypted timestamp: rc4-hmac/D7FD
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529572:
> Encrypted timestamp (for 1590549052.518887): plain
> 301AA011180F32303230303532373033313035325AA105020307EAE7, encrypted
> 5B0813887E05A9BDC49D2BA37EEC1C61CC0E6A51212B5A29DB1AA6F319E5C11BD6E9F9D843A3E4E5ED511C932BAFAB13B7995E39
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529573: Preauth
> module encrypted_timestamp (2) (real) returned: 0/Success
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529574: Produced
> preauth for next request: PA-ENC-TIMESTAMP (2)
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529575: Sending
> request (303 bytes) to x.y.local
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529576: Sending
> initial UDP request to dgram x.x.x.x:88
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529577: Received
> answer (100 bytes) from dgram x.x.x.x:88
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529578: Response
> was from master KDC
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [sss_child_krb5_trace_cb] (0x4000): [12599] 1590549052.529579: Received
> error from KDC: -1765328370/KDC has no support for encryption type
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [ldap_child_get_tgt_sync] (0x0010): Failed to init credentials: KDC has
> no support for encryption type
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]]
> [unique_filename_destructor] (0x2000): Unlinking
> [/var/lib/sss/db/ccache_x.y.local_AosPub]
> (Tue May 26 23:10:52 2020) [[sssd[ldap_child[12599]]]] [main] (0x0020):
> ldap_child_get_tgt_sync failed.
>
> _*krb5_child.log*_
>
>
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [main] (0x0400):
> krb5_child started.
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [unpack_buffer]
> (0x1000): total buffer size: [171]
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [unpack_buffer]
> (0x0100): cmd [241] uid [xxxxxxxxx] gid [yyyyyyyyy] validate [false]
> enterprise principal [false] offline [true] UPN
> [firstname.lastname@x.y.local]
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [unpack_buffer]
> (0x0100): ccname: [KEYRING:persistent:xxxxxxxxx] old_ccname:
> [KEYRING:persistent:xxxxxxxxx] keytab: [/etc/krb5.keytab]
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [check_use_fast]
> (0x0100): Not using FAST.
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [switch_creds]
> (0x0200): Switch user to [xxxxxxxxx][yyyyyyyyy].
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]]
> [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired.
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [switch_creds]
> (0x0200): Switch user to [0][0].
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]]
> [k5c_check_old_ccache] (0x4000): Ccache_file is
> [KEYRING:persistent:xxxxxxxxx] and is not active and TGT is valid.
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]]
> [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [become_user]
> (0x0200): Trying to become user [xxxxxxxxx][yyyyyyyyy].
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [main] (0x2000):
> Running as [xxxxxxxxx][yyyyyyyyy].
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [become_user]
> (0x0200): Trying to become user [xxxxxxxxx][yyyyyyyyy].
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [become_user]
> (0x0200): Already user [xxxxxxxxx].
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [k5c_setup]
> (0x2000): Running as [xxxxxxxxx][yyyyyyyyy].
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]]
> [set_lifetime_options] (0x0100): No specific renewable lifetime
> requested.
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]]
> [set_lifetime_options] (0x0100): No specific lifetime requested.
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [main] (0x0400):
> Will perform offline auth
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]]
> [create_empty_ccache] (0x1000): Existing ccache still valid, reusing
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [k5c_send_data]
> (0x0200): Received error code 0
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]]
> [pack_response_packet] (0x2000): response packet size: [52]
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [k5c_send_data]
> (0x4000): Response sent.
> (Tue May 26 23:11:06 2020) [[sssd[krb5_child[12603]]]] [main] (0x0400):
> krb5_child completed successfully
>
> _*sssd_pam.log*_
>
> (Tue May 26 23:11:06 2020) [sssd[pam]] [get_client_cred] (0x4000):
> Client creds: euid[0] egid[0] pid[12602].
> (Tue May 26 23:11:06 2020) [sssd[pam]] [setup_client_idle_timer]
> (0x4000): Idle timer re-set for client [0x562762f1f590][19]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [accept_fd_handler] (0x0400):
> Client connected to privileged pipe!
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_cmd_get_version] (0x0200):
> Received client version [3].
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_cmd_get_version] (0x0200):
> Offered version [3].
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_cmd_authenticate] (0x0100):
> entering pam_cmd_authenticate
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_parse_name_for_domains]
> (0x0200): name 'firstname.lastname' matched without domain, user is
> firstname.lastname
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> command: SSS_PAM_AUTHENTICATE
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> domain: not set
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): user:
> firstname.lastname
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> service: sshd
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): tty:
> ssh
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> ruser: not set
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> rhost: remote_host.x.y.local
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> authtok type: 1
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> newauthtok type: 0
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): priv:
> 1
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> cli_pid: 12602
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): logon
> name: firstname.lastname
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_initgr_check_timeout]
> (0x4000): User [firstname.lastname] not found in PAM cache.
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_set_plugin] (0x2000):
> CR #0: Setting "Initgroups by name" plugin
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_send] (0x0400): CR
> #0: New request 'Initgroups by name'
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_process_input]
> (0x0400): CR #0: Parsing input name [firstname.lastname]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_parse_name_for_domains]
> (0x0200): name 'firstname.lastname' matched without domain, user is
> firstname.lastname
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_set_name] (0x0400):
> CR #0: Setting name [firstname.lastname]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_select_domains]
> (0x0400): CR #0: Performing a multi-domain search
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_domains]
> (0x0400): CR #0: Search will bypass the cache and check the data
> provider
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_validate_domain_type]
> (0x2000): Request type POSIX-only for domain x.y.local type POSIX is
> valid
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_set_domain] (0x0400):
> CR #0: Using domain [x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_prepare_domain_data]
> (0x0400): CR #0: Preparing input data for domain [x.y.local] rules
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_send]
> (0x0400): CR #0: Looking up firstname.lastname@x.y.local
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_ncache]
> (0x0400): CR #0: Checking negative cache for
> [firstname.lastname@x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_ncache_check_str] (0x2000):
> Checking negative cache for
> [NCE/USER/x.y.local/firstname.lastname@x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_ncache]
> (0x0400): CR #0: [firstname.lastname@x.y.local] is not present in
> negative cache
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_dp] (0x0400):
> CR #0: Looking up [firstname.lastname@x.y.local] in data provider
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_dp_issue_request] (0x0400):
> Issuing request for
> [0x5627622d5930:3:firstname.lastname@x.y.local@x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_dp_get_account_msg]
> (0x0400): Creating request for
> [x.y.local][0x3][BE_REQ_INITGROUPS][name=firstname.lastname@x.y.local:-]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_add_timeout] (0x2000):
> 0x562762f19c90
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_dp_internal_get_send]
> (0x0400): Entering request
> [0x5627622d5930:3:firstname.lastname@x.y.local@x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_remove_timeout] (0x2000):
> 0x562762f19c90
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_dispatch] (0x4000): dbus
> conn: 0x562762f17990
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_dp_get_reply] (0x0010): The
> Data Provider returned an error
> [org.freedesktop.sssd.Error.DataProvider.Offline]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_common_dp_recv]
> (0x0040): CR #0: Data Provider Error: 3, 5, Failed to get reply from
> Data Provider
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_common_dp_recv]
> (0x0400): CR #0: Due to an error we will return cached data
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_cache]
> (0x0400): CR #0: Looking up [firstname.lastname@x.y.local] in cache
> (Tue May 26 23:11:06 2020) [sssd[pam]] [ldb] (0x4000): Added timed
> event "ltdb_callback": 0x562762f294a0
> ...
> ...
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_ncache_filter]
> (0x0400): CR #0: This request type does not support filtering result by
> negative cache
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_search_done]
> (0x0400): CR #0: Returning updated object [firstname.lastname@x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]]
> [cache_req_create_and_add_result] (0x0400): CR #0: Found 15 entries in
> domain x.y.local
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sss_dp_req_destructor]
> (0x0400): Deleting request:
> [0x5627622d5930:3:firstname.lastname@x.y.local@x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [cache_req_done] (0x0400): CR
> #0: Finished: Success
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pd_set_primary_name] (0x0400):
> User's primary name is firstname.lastname@x.y.local
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_initgr_cache_set] (0x2000):
> [firstname.lastname] added to PAM initgroup cache
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_dp_send_req] (0x0100):
> Sending request with the following data:
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> command: SSS_PAM_AUTHENTICATE
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> domain: x.y.local
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): user:
> firstname.lastname@x.y.local
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> service: sshd
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): tty:
> ssh
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> ruser: not set
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> rhost: remote_host.x.y.local
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> authtok type: 1
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> newauthtok type: 0
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): priv:
> 1
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100):
> cli_pid: 12602
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_print_data] (0x0100): logon
> name: firstname.lastname
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_add_timeout] (0x2000):
> 0x562762f19c90
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_dom_forwarder] (0x0100):
> pam_dp_send_req returned 0
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_remove_timeout] (0x2000):
> 0x562762f19c90
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_dispatch] (0x4000): dbus
> conn: 0x562762f17990
> (Tue May 26 23:11:06 2020) [sssd[pam]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_dp_process_reply] (0x0200):
> received: [4 (System error)][x.y.local]
> (Tue May 26 23:11:06 2020) [sssd[pam]] [ldb] (0x4000): Added timed
> event "ltdb_callback": 0x562762f3be60
> ...
> ...
> (Tue May 26 23:11:06 2020) [sssd[pam]] [filter_responses] (0x0100):
> [pam_response_filter] not available, not fatal.
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_reply] (0x0200): blen: 79
> (Tue May 26 23:11:06 2020) [sssd[pam]] [pam_reply] (0x0200): Returning
> [4]: System error to the client
> (Tue May 26 23:11:08 2020) [sssd[pam]] [client_recv] (0x0200): Client
> disconnected!
> (Tue May 26 23:11:08 2020) [sssd[pam]] [client_close_fn] (0x2000):
> Terminated client [0x562762f1f590][19]
> (Tue May 26 23:11:11 2020) [sssd[pam]] [pam_initgr_cache_remove]
> (0x2000): [firstname.lastname] removed from PAM initgroup cache
>
>
> Thanks,
>
> ~ Abhi
>
>
_______________________________________________
sssd-users mailing list -- sssd-users@lists.fedorahosted.org
To unsubscribe send an email to sssd-users-leave@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/sssd-users@lists.fedorahosted.org