[Freeipa-users] Not able to SSH with User Created in IPA Server

Jakub Hrozek jhrozek at redhat.com
Fri Mar 27 07:02:05 UTC 2015 

On Fri, Mar 27, 2015 at 10:28:13AM +0530, Yogesh Sharma wrote:
> Hi Jakub,
> 
> Please find the logs for the user "test" created in IPA.
> 
> (Fri Mar 27 10:19:52 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [test] from [<ALL>]
> (Fri Mar 27 10:19:52 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [be_get_account_info]
> (0x0100): Got request for [4097][1][name=test]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [sdap_attrs_get_sid_str]
> (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [acctinfo_callback] (0x0100):
> Request processed. Returned 0,0,Success
> (Fri Mar 27 10:19:52 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [test] from [<ALL>]
> (Fri Mar 27 10:19:52 2015) [sssd[nss]] [nss_cmd_initgroups_search]
> (0x0100): Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [be_get_account_info]
> (0x0100): Got request for [4099][1][name=test]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [sdap_attrs_get_sid_str]
> (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [sdap_attrs_get_sid_str]
> (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[nss]] [nss_cmd_initgroups_search]
> (0x0100): Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [acctinfo_callback] (0x0100):
> Request processed. Returned 0,0,Success
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [be_get_account_info]
> (0x0100): Got request for [1][1][name=test]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [sdap_attrs_get_sid_str]
> (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:52 2015) [sssd[be[sd.int]]] [acctinfo_callback] (0x0100):
> Request processed. Returned 0,0,Success
> (Fri Mar 27 10:19:56 2015) [sssd] [service_send_ping] (0x0100): Pinging
> sd.int
> (Fri Mar 27 10:19:56 2015) [sssd] [service_send_ping] (0x0100): Pinging nss
> (Fri Mar 27 10:19:56 2015) [sssd] [service_send_ping] (0x0100): Pinging pam
> (Fri Mar 27 10:19:56 2015) [sssd] [service_send_ping] (0x0100): Pinging ssh
> (Fri Mar 27 10:19:56 2015) [sssd] [service_send_ping] (0x0100): Pinging pac
> (Fri Mar 27 10:19:56 2015) [sssd] [ping_check] (0x0100): Service pam
> replied to ping
> (Fri Mar 27 10:19:56 2015) [sssd] [ping_check] (0x0100): Service pac
> replied to ping
> (Fri Mar 27 10:19:56 2015) [sssd] [ping_check] (0x0100): Service ssh
> replied to ping
> (Fri Mar 27 10:19:56 2015) [sssd] [ping_check] (0x0100): Service nss
> replied to ping
> (Fri Mar 27 10:19:56 2015) [sssd] [ping_check] (0x0100): Service sd.int
> replied to ping
> (Fri Mar 27 10:19:57 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [test] from [<ALL>]
> (Fri Mar 27 10:19:57 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:57 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [test] from [<ALL>]
> (Fri Mar 27 10:19:57 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:57 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [test] from [<ALL>]
> (Fri Mar 27 10:19:57 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_cmd_authenticate] (0x0100):
> entering pam_cmd_authenticate
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): command:
> PAM_AUTHENTICATE
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): domain:
> not set
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): user: test
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): service:
> sshd
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser:
> not set
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost:
> 125.63.90.34
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok
> type: 1
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100):
> newauthtok type: 0
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
> 16634
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [be_get_account_info]
> (0x0100): Got request for [3][1][name=test]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [sdap_attrs_get_sid_str]
> (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [sdap_attrs_get_sid_str]
> (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]]
> [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> domain SID from [(null)]
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_check_user_search] (0x0100):
> Requesting info for [test at sd.int]
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending
> request with the following data:
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): command:
> PAM_AUTHENTICATE
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): domain:
> sd.int
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): user: test
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): service:
> sshd
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser:
> not set
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost:
> 125.63.90.34
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok
> type: 1
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100):
> newauthtok type: 0
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
> 16634
> (Fri Mar 27 10:19:57 2015) [sssd[pam]] [pam_dom_forwarder] (0x0100):
> pam_dp_send_req returned 0
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [acctinfo_callback] (0x0100):
> Request processed. Returned 0,0,Success
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [be_pam_handler] (0x0100):
> Got request with the following data
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> command: PAM_AUTHENTICATE
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> domain: sd.int
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> user: test
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> service: sshd
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> tty: ssh
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> ruser:
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> rhost: 125.63.90.34
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> authtok type: 1
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> newauthtok type: 0
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> priv: 1
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [pam_print_data] (0x0100):
> cli_pid: 16634
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [sss_krb5_cc_verify_ccache]
> (0x0020): 1078: [-1765328190][Credentials cache permissions incorrect]
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [check_old_ccache] (0x0040):
> Cannot check if saved ccache FILE:/tmp/krb5cc_1312800003_LTtoQU is valid
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [krb5_auth_send] (0x0020):
> check_if_ccache_file_is_used failed.
> (Fri Mar 27 10:19:57 2015) [sssd[be[sd.int]]] [fo_resolve_service_send]
> (0x0100): Trying to resolve service 'IPA'
> (Fri Mar 27 10:19:57 2015) [[sssd[krb5_child[16637]]]] [unpack_buffer]
> (0x0100): cmd [241] uid [1312800011] gid [1312800011] validate [true]
> enterprise principal [false] offline [false] UPN [test at SD.INT]
> (Fri Mar 27 10:19:57 2015) [[sssd[krb5_child[16637]]]] [unpack_buffer]
> (0x0100): ccname: [FILE:/tmp/krb5cc_1312800011_XXXXXX] keytab:
> [/etc/krb5.keytab]
> (Fri Mar 27 10:19:57 2015) [[sssd[krb5_child[16637]]]]
> [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME]
> from environment.
> (Fri Mar 27 10:19:57 2015) [[sssd[krb5_child[16637]]]]
> [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
> environment.
> (Fri Mar 27 10:19:57 2015) [[sssd[krb5_child[16637]]]]
> [set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
> (Fri Mar 27 10:19:57 2015) [[sssd[krb5_child[16637]]]] [k5c_setup_fast]
> (0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to [host/
> dns-inf-stg-sg1-01.sd.int at SD.INT]
> *(Fri Mar 27 10:19:58 2015) [[sssd[krb5_child[16637]]]] [get_and_save_tgt]
> (0x0020): 981: [-1765328361][Password has expired]*
> *(Fri Mar 27 10:20:01 2015) [[sssd[krb5_child[16637]]]] [map_krb5_error]
> (0x0020): 1043: [-1765328360][Preauthentication failed]*
> (Fri Mar 27 10:20:01 2015) [sssd[be[sd.int]]] [child_sig_handler] (0x0100):
> child [16637] finished successfully.
> (Fri Mar 27 10:20:01 2015) [sssd[be[sd.int]]] [ipa_get_migration_flag_done]
> (0x0100): Password migration is not enabled.
> (Fri Mar 27 10:20:01 2015) [sssd[be[sd.int]]] [be_pam_handler_callback]
> (0x0100): Backend returned: (0, 17, <NULL>) [Success]
> (Fri Mar 27 10:20:01 2015) [sssd[be[sd.int]]] [be_pam_handler_callback]
> (0x0100): Sending result [17][sd.int]
> (Fri Mar 27 10:20:01 2015) [sssd[be[sd.int]]] [be_pam_handler_callback]
> (0x0100): Sent result [17][sd.int]
> (Fri Mar 27 10:20:01 2015) [sssd[pam]] [pam_dp_process_reply] (0x0100):
> received: [17][sd.int]
> 
> 
> 
> *We do not see any of the above error when try to login with "admin" user
> created by IPA and able to login. Seems like there is any issue in creating
> user from our side, though not able to figure out.*

But this is the very first login after the user has been created right?
Then SSH should prompt you for password change and after that, the
second login should use the updated password.

More information about the Freeipa-users mailing list