AD user account get Permission denied when trying to login

[Farshid Mahdavipour]

Hi,
Could you please help me to resolve this issue!

When i want to login to the RHEL 7.5 machine with AD account, i get
permission denied:
`Permission denied, please try again.`

password for the user is correct, have tried it multiple times.

Log for sshd:
[root@azrclchefvm01 ~]# tail /var/log/secure
Jul 23 21:47:01 azrclchefvm01 sshd[35436]: pam_sss(sshd:auth):
authentication failure; logname= uid=0 euid=0 tty=ssh ruser=
rhost=172.17.253.11 user=mahdavif
Jul 23 21:47:01 azrclchefvm01 sshd[35436]: pam_sss(sshd:auth): received for
user mahdavif: 6 (Permission denied)
Jul 23 21:47:03 azrclchefvm01 sshd[35436]: Failed password for mahdavif
from 172.17.253.11 port 36262 ssh2
Jul 23 21:47:17 azrclchefvm01 sshd[35436]: pam_sss(sshd:auth):
authentication failure; logname= uid=0 euid=0 tty=ssh ruser=
rhost=172.17.253.11 user=mahdavif
Jul 23 21:47:17 azrclchefvm01 sshd[35436]: pam_sss(sshd:auth): received for
user mahdavif: 6 (Permission denied)
Jul 23 21:47:19 azrclchefvm01 sshd[35436]: Failed password for mahdavif
from 172.17.253.11 port 36262 ssh2
Jul 23 21:47:25 azrclchefvm01 sshd[35436]: pam_sss(sshd:auth):
authentication failure; logname= uid=0 euid=0 tty=ssh ruser=
rhost=172.17.253.11 user=mahdavif
Jul 23 21:47:25 azrclchefvm01 sshd[35436]: pam_sss(sshd:auth): received for
user mahdavif: 6 (Permission denied)
Jul 23 21:47:28 azrclchefvm01 sshd[35436]: Failed password for mahdavif
from 172.17.253.11 port 36262 ssh2
Jul 23 21:47:28 azrclchefvm01 sshd[35436]: Connection closed by
172.17.253.11 port 36262 [preauth]

Log for sssd:
[root@azrclchefvm01 ~]# tail /var/log/sssd/*
==> /var/log/sssd/krb5_child.log <==
(Mon Jul 23 21:59:34 2018) [[sssd[krb5_child[35846]]]] [become_user]
(0x0200): Trying to become user [39599][59900].
(Mon Jul 23 21:59:34 2018) [[sssd[krb5_child[35846]]]]
[set_lifetime_options] (0x0100): No specific renewable lifetime requested.
(Mon Jul 23 21:59:34 2018) [[sssd[krb5_child[35846]]]]
[set_lifetime_options] (0x0100): No specific lifetime requested.
(Mon Jul 23 21:59:34 2018) [[sssd[krb5_child[35846]]]]
[set_canonicalize_option] (0x0100): Canonicalization is set to [true]
(Mon Jul 23 21:59:34 2018) [[sssd[krb5_child[35846]]]] [main] (0x0400):
Will perform online auth
(Mon Jul 23 21:59:34 2018) [[sssd[krb5_child[35846]]]] [get_and_save_tgt]
(0x0400): Attempting kinit for realm [CORP.example.net]
(Mon Jul 23 21:59:35 2018) [[sssd[krb5_child[35846]]]] [get_and_save_tgt]
(0x0020): 1544: [-1765328366][Client's credentials have been revoked]
(Mon Jul 23 21:59:35 2018) [[sssd[krb5_child[35846]]]] [map_krb5_error]
(0x0020): 1657: [-1765328366][Client's credentials have been revoked]
(Mon Jul 23 21:59:35 2018) [[sssd[krb5_child[35846]]]] [k5c_send_data]
(0x0200): Received error code 1432158272
(Mon Jul 23 21:59:35 2018) [[sssd[krb5_child[35846]]]] [main] (0x0400):
krb5_child completed successfully
==> /var/log/sssd/ldap_child.log <==
(Mon Jul 23 21:59:07 2018) [[sssd[ldap_child[35808]]]] [prepare_response]
(0x0400): Building response for result [0]
(Mon Jul 23 21:59:07 2018) [[sssd[ldap_child[35808]]]] [main] (0x0400):
ldap_child completed successfully
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]] [main] (0x0400):
ldap_child started.
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]] [unpack_buffer]
(0x0200): Will run as [0][0].
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]] [become_user]
(0x0200): Trying to become user [0][0].
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]] [become_user]
(0x0200): Already user [0].
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]]
[ldap_child_get_tgt_sync] (0x0100): Principal name is: [AZRCLCHEFVM01$@
CORP.example.net]
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]]
[ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab]
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]] [prepare_response]
(0x0400): Building response for result [0]
(Mon Jul 23 21:59:19 2018) [[sssd[ldap_child[35835]]]] [main] (0x0400):
ldap_child completed successfully
==> /var/log/sssd/sssd_corp.example.net.log <==
(Mon Jul 23 21:59:34 2018) [sssd[be[corp.example.net]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
(Mon Jul 23 21:59:34 2018) [sssd[be[corp.example.net]]]
[be_resolve_server_process] (0x0200): Found address for server
srv_waddcs001: [10.4.20.32] TTL 1200
(Mon Jul 23 21:59:34 2018) [sssd[be[corp.example.net]]]
[write_pipe_handler] (0x0400): All data has been sent!
(Mon Jul 23 21:59:35 2018) [sssd[be[corp.example.net]]] [child_sig_handler]
(0x0100): child [35846] finished successfully.
(Mon Jul 23 21:59:35 2018) [sssd[be[corp.example.net]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Mon Jul 23 21:59:35 2018) [sssd[be[corp.example.net]]] [dp_req_done]
(0x0400): DP Request [PAM Authenticate #6]: Request handler finished [0]:
Success
(Mon Jul 23 21:59:35 2018) [sssd[be[corp.example.net]]] [_dp_req_recv]
(0x0400): DP Request [PAM Authenticate #6]: Receiving request data.
(Mon Jul 23 21:59:35 2018) [sssd[be[corp.example.net]]] [dp_req_destructor]
(0x0400): DP Request [PAM Authenticate #6]: Request removed.
(Mon Jul 23 21:59:35 2018) [sssd[be[corp.example.net]]] [dp_req_destructor]
(0x0400): Number of active DP request: 0
(Mon Jul 23 21:59:35 2018) [sssd[be[corp.example.net]]] [dp_method_enabled]
(0x0400): Target selinux is not configured
==> /var/log/sssd/sssd.log <==
(Mon Jul 23 21:59:07 2018) [sssd] [sbus_conn_register_path] (0x0400):
Registering object path /org/freedesktop/sssd/monitor with D-Bus connection
(Mon Jul 23 21:59:07 2018) [sssd] [sbus_opath_hash_add_iface] (0x0400):
Registering interface org.freedesktop.DBus.Properties with path
/org/freedesktop/sssd/monitor
(Mon Jul 23 21:59:07 2018) [sssd] [sbus_opath_hash_add_iface] (0x0400):
Registering interface org.freedesktop.DBus.Introspectable with path
/org/freedesktop/sssd/monitor
(Mon Jul 23 21:59:07 2018) [sssd] [client_registration] (0x0100): Received
ID registration: (pam,1)
(Mon Jul 23 21:59:07 2018) [sssd] [mark_service_as_started] (0x0200):
Marking pam as started.
(Mon Jul 23 21:59:07 2018) [sssd] [client_registration] (0x0100): Received
ID registration: (nss,1)
(Mon Jul 23 21:59:07 2018) [sssd] [mark_service_as_started] (0x0200):
Marking nss as started.
(Mon Jul 23 21:59:07 2018) [sssd] [mark_service_as_started] (0x0400): All
services have successfully started, creating pid file
(Mon Jul 23 21:59:07 2018) [sssd] [notify_startup] (0x0400): Sending
startup notification to systemd
(Mon Jul 23 21:59:12 2018) [sssd] [services_startup_timeout] (0x0400):
Handling timeout
==> /var/log/sssd/sssd_nss.log <==
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_prepare_domain_data]
(0x0400): CR #1: Preparing input data for domain [corp.example.net] rules
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_search_send] (0x0400): CR
#1: Looking up mahdavif(a)corp.example.net
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_search_ncache] (0x0400):
CR #1: Checking negative cache for [mahdavif(a)corp.example.net]
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_search_ncache] (0x0400):
CR #1: [mahdavif(a)corp.example.net] is not present in negative cache
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_search_cache] (0x0400):
CR #1: Looking up [mahdavif(a)corp.example.net] in cache
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_search_send] (0x0400): CR
#1: Returning [mahdavif(a)corp.example.net] from cache
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_search_ncache_filter]
(0x0400): CR #1: This request type does not support filtering result by
negative cache
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_create_and_add_result]
(0x0400): CR #1: Found 23 entries in domain corp.example.net
(Mon Jul 23 21:59:14 2018) [sssd[nss]] [cache_req_done] (0x0400): CR #1:
Finished: Success
(Mon Jul 23 21:59:37 2018) [sssd[nss]] [client_recv] (0x0200): Client
disconnected!
==> /var/log/sssd/sssd_pam.log <==
(Mon Jul 23 21:59:34 2018) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0
(Mon Jul 23 21:59:34 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Mon Jul 23 21:59:34 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
35831
(Mon Jul 23 21:59:34 2018) [sssd[pam]] [pam_print_data] (0x0100): logon
name: mahdavif
(Mon Jul 23 21:59:34 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100):
pam_dp_send_req returned 0
(Mon Jul 23 21:59:35 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200):
received: [6 (Permission denied)][corp.example.net]
(Mon Jul 23 21:59:35 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply
called with result [6]: Permission denied.
(Mon Jul 23 21:59:35 2018) [sssd[pam]] [filter_responses] (0x0100):
[pam_response_filter] not available, not fatal.
(Mon Jul 23 21:59:35 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 33
(Mon Jul 23 21:59:37 2018) [sssd[pam]] [client_recv] (0x0200): Client
disconnected!


thanks for your help!
farshid

[Jakub Hrozek]

>  On 24 Jul 2018, at 05:39, Farshid Mahdavipour
> <farchide(a)gmail.com&gt; wrote:
>  
>  (Mon Jul 23 21:59:35 2018) [[sssd[krb5_child[35846]]]] [get_and_save_tgt] (0x0020): 1544:
> [-1765328366][Client's credentials have been revoked]
>  (Mon Jul 23 21:59:35 2018) [[sssd[krb5_child[35846]]]] [map_krb5_error] (0x0020): 1657:
> [-1765328366][Client's credentials have been revoked] 
The account was locked out.