[Freeipa-users] Password-based authentication with AD users does not work
Ronald Wimmer
ronaldw at ronzo.at
Thu Apr 6 10:58:32 UTC 2017
On 2017-04-06 11:21, Sumit Bose wrote:
> On Thu, Apr 06, 2017 at 12:10:29PM +0200, Ronald Wimmer wrote:
>> Hi,
>>
>> when I try to login to an IPA client with my AD user it works perfectly when
>> I already have a kerberos ticket for my user. When I do not and I try a
>> password-based login it fails:
> Please send the sssd_domain.log and krb5_child.log form the same time as
> well.
>
AD trust:
mydomain.at (forest root)
xyz (subdomain -> where myuser resides)
BCC (appearing in krb5_child.log) is not a domain here. It is my
company's name and might derive from some information in the AD.
sssd_domain.log snippet:
[....]
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f14f467feb0
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [sbus_dispatch]
(0x4000): Dispatching.
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[sbus_message_handler] (0x2000): Received SBUS method
org.freedesktop.sssd.dataprovider.pamHandler on path
/org/freedesktop/sssd/dataprovider
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [dp_pam_handler]
(0x0100): Got request with the following data
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): command: SSS_PAM_AUTHENTICATE
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): domain: XYZ
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): user: myuser at xyz.mydomain.at
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): service: sshd
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): tty: ssh
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): ruser:
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): rhost: chupacabra.ipa.mydomain.at
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): authtok type: 1
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): newauthtok type: 0
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): priv: 1
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): cli_pid: 31812
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [pam_print_data]
(0x0100): logon name: not set
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [dp_attach_req]
(0x0400): DP Request [PAM Authenticate #15]: New request. Flags [0000].
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [dp_attach_req]
(0x0400): Number of active DP request: 1
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[krb5_auth_queue_send] (0x1000): Wait queue of user
[myuser at xyz.mydomain.at] is empty, running request [0x7f14f4670f70]
immediately.
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [krb5_setup]
(0x4000): No mapping for: myuser at xyz.mydomain.at
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Added timed event "ltdb_callback": 0x7f14f468c030
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Added timed event "ltdb_timeout": 0x7f14f468c0f0
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Running timer event 0x7f14f468c030 "ltdb_callback"
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Destroying timer event 0x7f14f468c0f0 "ltdb_timeout"
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Ending timer event 0x7f14f468c030 "ltdb_callback"
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Added timed event "ltdb_callback": 0x7f14f46aad10
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Added timed event "ltdb_timeout": 0x7f14f468c4a0
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Running timer event 0x7f14f46aad10 "ltdb_callback"
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Destroying timer event 0x7f14f468c4a0 "ltdb_timeout"
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Ending timer event 0x7f14f46aad10 "ltdb_callback"
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[get_server_status] (0x1000): Status of server 'ipa1.ipa.mydomain.at' is
'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [get_port_status]
(0x1000): Port status of port 0 for server 'ipa1.ipa.mydomain.at' is
'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[get_server_status] (0x1000): Status of server 'ipa1.ipa.mydomain.at' is
'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[be_resolve_server_process] (0x0200): Found address for server
ipa1.ipa.mydomain.at: [10.66.39.130] TTL 86400
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[ipa_resolve_callback] (0x0400): Constructed uri
'ldap://ipa1.ipa.mydomain.at'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[unique_filename_destructor] (0x2000): Unlinking
[/var/lib/sss/pubconf/.krb5info_dummy_hs3EBJ]
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [unlink_dbg]
(0x2000): File already removed:
[/var/lib/sss/pubconf/.krb5info_dummy_hs3EBJ]
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_handler_setup] (0x2000): Setting up signal handler up for pid [31814]
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_handler_setup] (0x2000): Signal handler set up for pid [31814]
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[write_pipe_handler] (0x0400): All data has been sent!
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_sig_handler] (0x1000): Waiting for child [31814].
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_sig_handler] (0x0100): child [31814] finished successfully.
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[read_pipe_handler] (0x0400): EOF received, client finished
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[_be_fo_set_port_status] (0x8000): Setting status: PORT_NOT_WORKING.
Called from: src/providers/krb5/krb5_auth.c: krb5_auth_done: 939
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_set_port_status] (0x0100): Marking port 0 of server
'ipa1.ipa.mydomain.at' as 'not working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_set_port_status] (0x0400): Marking port 0 of duplicate server
'ipa1.ipa.mydomain.at' as 'not working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[get_server_status] (0x1000): Status of server 'ipa1.ipa.mydomain.at' is
'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [get_port_status]
(0x1000): Port status of port 0 for server 'ipa1.ipa.mydomain.at' is
'not working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[get_server_status] (0x1000): Status of server 'ipa1.ipa.mydomain.at' is
'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [get_port_status]
(0x1000): Port status of port 0 for server 'ipa1.ipa.mydomain.at' is
'not working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_resolve_service_send] (0x0020): No available servers for service 'IPA'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[be_resolve_server_done] (0x1000): Server resolution failed: [5]:
Input/output error
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[be_mark_dom_offline] (0x1000): Marking subdomain xyz.mydomain.at offline
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[be_mark_subdom_offline] (0x1000): Marking subdomain xyz.mydomain.at as
inactive
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_handler_setup] (0x2000): Setting up signal handler up for pid [31815]
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_handler_setup] (0x2000): Signal handler set up for pid [31815]
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[write_pipe_handler] (0x0400): All data has been sent!
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_sig_handler] (0x1000): Waiting for child [31815].
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[child_sig_handler] (0x0100): child [31815] finished successfully.
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[read_pipe_handler] (0x0400): EOF received, client finished
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[parse_krb5_child_response] (0x1000): child response [0][3][41].
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[_be_fo_set_port_status] (0x8000): Setting status: PORT_WORKING. Called
from: src/providers/krb5/krb5_auth.c: krb5_auth_done: 1036
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_set_port_status] (0x0100): Marking port 0 of server
'ipa1.ipa.mydomain.at' as 'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[set_server_common_status] (0x0100): Marking server
'ipa1.ipa.mydomain.at' as 'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]]
[fo_set_port_status] (0x0400): Marking port 0 of duplicate server
'ipa1.ipa.mydomain.at' as 'working'
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [krb5_mod_ccname]
(0x4000): Save ccname [KEYRING:persistent:1073895519] for user
[myuser at xyz.mydomain.at].
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
start ldb transaction (nesting: 0)
(Thu Apr 6 10:39:12 2017) [sssd[be[ipa.mydomain.at]]] [ldb] (0x4000):
Added timed event "ltdb_callback": 0x7f14f46b1d80
[...]
krb5_child.log snippet:
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [main] (0x0400):
krb5_child started.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [unpack_buffer]
(0x1000): total buffer size: [156]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [unpack_buffer]
(0x0100): cmd [241] uid [1073895519] gid [1073895519] validate [true]
enterprise principal [false] offline [false] UPN [myuser at BCC.MYDOMAIN.AT]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [unpack_buffer]
(0x0100): ccname: [KEYRING:persistent:1073895519] old_ccname:
[KEYRING:persistent:1073895519] keytab: [/etc/krb5.keytab]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [switch_creds]
(0x0200): Switch user to [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [switch_creds]
(0x0200): Switch user to [0][0].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[k5c_check_old_ccache] (0x4000): Ccache_file is
[KEYRING:persistent:1073895519] and is not active and TGT is valid.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[k5c_precreate_ccache] (0x4000): Recreating ccache
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [k5c_setup_fast]
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to
[host/testclient.ipa.mydomain.at at LINUX.MYDOMAIN.AT]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[find_principal_in_keytab] (0x4000): Trying to find principal
host/testclient.ipa.mydomain.at at LINUX.MYDOMAIN.AT in keytab.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [match_principal]
(0x1000): Principal matched to the sample
(host/testclient.ipa.mydomain.at at LINUX.MYDOMAIN.AT).
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[check_fast_ccache] (0x0200): FAST TGT is still valid.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [become_user]
(0x0200): Trying to become user [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [main] (0x2000):
Running as [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [k5c_setup]
(0x2000): Running as [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[set_lifetime_options] (0x0100): Cannot read
[SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
environment.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [main] (0x0400):
Will perform online auth
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [tgt_req_child]
(0x1000): Attempting to get a TGT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[get_and_save_tgt] (0x0400): Attempting kinit for realm [BCC.MYDOMAIN.AT]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.830664: Getting
initial credentials for myuser at BCC.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.830855: FAST
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_LINUX.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.830976:
Retrieving host/testclient.ipa.mydomain.at at LINUX.MYDOMAIN.AT ->
krb5_ccache_conf_data/fast_avail/krbtgt\/BCC.MYDOMAIN.AT\@BCC.MYDOMAIN.AT at X-CACHECONF:
from MEMORY:/var/lib/sss/db/fast_ccache_LINUX.MYDOMAIN.AT with result:
-1765328243/Matching credential not found
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.831121: Sending
request (167 bytes) to BCC.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.834221: Retrying
AS request with master KDC
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.834290: Getting
initial credentials for myuser at BCC.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.834368: FAST
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_LINUX.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.834434:
Retrieving host/testclient.ipa.mydomain.at at LINUX.MYDOMAIN.AT ->
krb5_ccache_conf_data/fast_avail/krbtgt\/BCC.MYDOMAIN.AT\@BCC.MYDOMAIN.AT at X-CACHECONF:
from MEMORY:/var/lib/sss/db/fast_ccache_LINUX.MYDOMAIN.AT with result:
-1765328243/Matching credential not found
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[sss_child_krb5_trace_cb] (0x4000): [31814] 1491467952.834506: Sending
request (167 bytes) to BCC.MYDOMAIN.AT (master)
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[get_and_save_tgt] (0x0020): 1296: [-1765328230][Cannot find KDC for
realm "BCC.MYDOMAIN.AT"]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [map_krb5_error]
(0x0020): 1365: [-1765328230][Cannot find KDC for realm "BCC.MYDOMAIN.AT"]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [k5c_send_data]
(0x0200): Received error code 1432158228
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]]
[pack_response_packet] (0x2000): response packet size: [4]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [k5c_send_data]
(0x4000): Response sent.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31814]]]] [main] (0x0400):
krb5_child completed successfully
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [main] (0x0400):
krb5_child started.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [unpack_buffer]
(0x1000): total buffer size: [156]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [unpack_buffer]
(0x0100): cmd [241] uid [1073895519] gid [1073895519] validate [true]
enterprise principal [false] offline [true] UPN [myuser at BCC.MYDOMAIN.AT]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [unpack_buffer]
(0x0100): ccname: [KEYRING:persistent:1073895519] old_ccname:
[KEYRING:persistent:1073895519] keytab: [/etc/krb5.keytab]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [switch_creds]
(0x0200): Switch user to [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]]
[sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [switch_creds]
(0x0200): Switch user to [0][0].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]]
[k5c_check_old_ccache] (0x4000): Ccache_file is
[KEYRING:persistent:1073895519] and is not active and TGT is valid.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [become_user]
(0x0200): Trying to become user [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [main] (0x2000):
Running as [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [become_user]
(0x0200): Trying to become user [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [become_user]
(0x0200): Already user [1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [k5c_setup]
(0x2000): Running as [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]]
[set_lifetime_options] (0x0100): Cannot read
[SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
environment.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [main] (0x0400):
Will perform offline auth
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]]
[create_empty_ccache] (0x1000): Existing ccache still valid, reusing
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [k5c_send_data]
(0x0200): Received error code 0
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]]
[pack_response_packet] (0x2000): response packet size: [53]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [k5c_send_data]
(0x4000): Response sent.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31815]]]] [main] (0x0400):
krb5_child completed successfully
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [main] (0x0400):
krb5_child started.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [unpack_buffer]
(0x1000): total buffer size: [51]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [unpack_buffer]
(0x0100): cmd [249] uid [1073895519] gid [1073895519] validate [true]
enterprise principal [false] offline [true] UPN [myuser at BCC.MYDOMAIN.AT]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [become_user]
(0x0200): Trying to become user [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [main] (0x2000):
Running as [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [become_user]
(0x0200): Trying to become user [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [become_user]
(0x0200): Already user [1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [k5c_setup]
(0x2000): Running as [1073895519][1073895519].
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[set_lifetime_options] (0x0100): Cannot read
[SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
environment.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [main] (0x0400):
Will perform pre-auth
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [tgt_req_child]
(0x1000): Attempting to get a TGT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[get_and_save_tgt] (0x0400): Attempting kinit for realm [BCC.MYDOMAIN.AT]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[sss_child_krb5_trace_cb] (0x4000): [31817] 1491467952.889026: Getting
initial credentials for myuser at BCC.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[sss_child_krb5_trace_cb] (0x4000): [31817] 1491467952.889307: Sending
request (167 bytes) to BCC.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[sss_child_krb5_trace_cb] (0x4000): [31817] 1491467952.892050: Retrying
AS request with master KDC
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[sss_child_krb5_trace_cb] (0x4000): [31817] 1491467952.892107: Getting
initial credentials for myuser at BCC.MYDOMAIN.AT
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[sss_child_krb5_trace_cb] (0x4000): [31817] 1491467952.892252: Sending
request (167 bytes) to BCC.MYDOMAIN.AT (master)
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[get_and_save_tgt] (0x0400): krb5_get_init_creds_password returned
[-1765328230} during pre-auth.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [k5c_send_data]
(0x0200): Received error code 0
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]]
[pack_response_packet] (0x2000): response packet size: [4]
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [k5c_send_data]
(0x4000): Response sent.
(Thu Apr 6 10:39:12 2017) [[sssd[krb5_child[31817]]]] [main] (0x0400):
krb5_child completed successfully
Regards,
Ronald
More information about the Freeipa-users
mailing list