---------- Forwarded message ----------
From: Johan Vermeulen <jameslast29@gmail.com>
Date: 2018-01-05 10:27 GMT+01:00
Subject: Re: [Freeipa-users] Re: Centos7.4: users not seeing password expired notifications
To: FreeIPA users list <freeipa-users@lists.fedorahosted.org>


Hello All,

I "ve set up a new machine for this test and increased the log levels to 6.
Config for Freeipa-client is done with ipa-client-install, I use chrony in stead of ntp and Selinux is enabled.

When user logs in /var/log/secure indicates:

[root@node1 ~]# tail -f /var/log/secure
Jan  5 09:27:17 node1 lightdm: pam_sss(lightdm:auth): received for user jvanvlasselaer: 7 (Authentication failure)
Jan  5 09:27:29 node1 lightdm: pam_sss(lightdm:auth): authentication failure; logname= uid=0 euid=0 tty=:0 ruser= rhost= user=jvanvlasselaer
Jan  5 09:27:29 node1 lightdm: pam_sss(lightdm:auth): received for user jvanvlasselaer: 12 (Authentication token is no longer valid; new one required)
Jan  5 09:27:29 node1 lightdm: pam_sss(lightdm:account): User info message: Password expired. Change your password now.
Jan  5 09:27:29 node1 lightdm: pam_unix(lightdm:chauthtok): user "jvanvlasselaer" does not exist in /etc/passwd

But the lightdm gui screen indicates nothing.

Here are the hopefully relevant logs:

sssd_network.cawdekempen.be.log
--------------------------------

(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [Initgroups #75]: New request. Flags [0x0001].
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [be_resolve_server_process] (0x0200): Found address for server freeipa03.network.cawdekempen.be: [192.168.250.12] TTL 1200
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/node1.network.cawdekempen.be, NETWORK.CAWDEKEMPEN.BE, 86400)
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [be_resolve_server_process] (0x0200): Found address for server freeipa03.network.cawdekempen.be: [192.168.250.12] TTL 1200
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 79
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [write_pipe_handler] (0x0400): All data has been sent!
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_NETWORK.CAWDEKEMPEN.BE], expired on [1515227236]
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900
(Fri Jan  5 09:27:16 2018) [sssd[be[network.cawdekempen.be]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/node1.network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [child_sig_handler] (0x0100): child [1688] finished successfully.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_cli_connect_recv] (0x0400): Connection established.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [set_server_common_status] (0x0100): Marking server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [cn=accounts,dc=network,dc=cawdekempen,dc=be]
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=jvanvlasselaer)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Save user
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_primary_name] (0x0400): Processing object jvanvlasselaer
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Processing user jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [jvanvlasselaer@network.cawdekempen.be].
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Adding user principal [jvanvlasselaer@NETWORK.CAWDEKEMPEN.BE] to attributes of [jvanvlasselaer@network.cawdekempen.be].
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Storing info for user jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb] has set [cache, ts_cache] attrs.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_primary_name] (0x0400): Processing object jvanvlasselaer
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_primary_name] (0x0400): Processing object ipausers
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_initgr_done] (0x0400): Primary group already cached, nothing to do.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb] has set [ts_cache] attrs.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:IPA:network.cawdekempen.be:ce59521a-f15e-11e7-9a7e-7aa69aa21e18))][cn=Default Trust View,cn=views,cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: No such object(32), no errmsg set
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [Initgroups #75]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [Initgroups #75]: Receiving request data.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_initgr_pp] (0x0400): Ordering NSS responder to update memory cache
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_reply_list_success] (0x0400): DP Request [Initgroups #75]: Finished. Success.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:3::network.cawdekempen.be:name=jvanvlasselaer@network.cawdekempen.be] from reply table
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [Initgroups #75]: Request removed.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_pam_handler] (0x0100): Got request with the following data
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): ruser:
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): rhost:
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): cli_pid: 1588
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): logon name: not set
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [PAM Authenticate #76]: New request. Flags [0000].
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [krb5_auth_send] (0x0020): Illegal zero-length authtok for user [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [PAM Authenticate #76]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [PAM Authenticate #76]: Receiving request data.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [PAM Authenticate #76]: Request removed.
(Fri Jan  5 09:27:17 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [dp_pam_handler] (0x0100): Got request with the following data
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): command: SSS_PAM_PREAUTH
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): ruser:
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): rhost:
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): cli_pid: 1689
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): logon name: not set
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [PAM Preauth #77]: New request. Flags [0000].
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [be_resolve_server_process] (0x0200): Found address for server freeipa03.network.cawdekempen.be: [192.168.250.12] TTL 1200
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://freeipa03.network.cawdekempen.be'
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [write_pipe_handler] (0x0400): All data has been sent!
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [set_server_common_status] (0x0100): Marking server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb] has set [cache, ts_cache] attrs.
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [PAM Preauth #77]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [PAM Preauth #77]: Receiving request data.
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [PAM Preauth #77]: Request removed.
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:19 2018) [sssd[be[network.cawdekempen.be]]] [child_sig_handler] (0x0100): child [1690] finished successfully.
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [dp_pam_handler] (0x0100): Got request with the following data
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): command: SSS_PAM_PREAUTH
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): ruser:
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): rhost:
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): logon name: not set
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [PAM Preauth #78]: New request. Flags [0000].
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [be_resolve_server_process] (0x0200): Found address for server freeipa03.network.cawdekempen.be: [192.168.250.12] TTL 1200
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://freeipa03.network.cawdekempen.be'
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [write_pipe_handler] (0x0400): All data has been sent!
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [set_server_common_status] (0x0100): Marking server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'freeipa03.network.cawdekempen.be' as 'working'
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb] has set [ts_cache] attrs.
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [PAM Preauth #78]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [PAM Preauth #78]: Receiving request data.
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [PAM Preauth #78]: Request removed.
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:22 2018) [sssd[be[network.cawdekempen.be]]] [child_sig_handler] (0x0100): child [1692] finished successfully.
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [Initgroups #79]: New request. Flags [0x0001].
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [cn=accounts,dc=network,dc=cawdekempen,dc=be]
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=jvanvlasselaer)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Save user
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_primary_name] (0x0400): Processing object jvanvlasselaer
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Processing user jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [jvanvlasselaer@network.cawdekempen.be].
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Adding user principal [jvanvlasselaer@NETWORK.CAWDEKEMPEN.BE] to attributes of [jvanvlasselaer@network.cawdekempen.be].
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_save_user] (0x0400): Storing info for user jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb] has set [ts_cache] attrs.
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_primary_name] (0x0400): Processing object jvanvlasselaer
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_primary_name] (0x0400): Processing object ipausers
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_initgr_done] (0x0400): Primary group already cached, nothing to do.
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb] has set [ts_cache] attrs.
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:IPA:network.cawdekempen.be:ce59521a-f15e-11e7-9a7e-7aa69aa21e18))][cn=Default Trust View,cn=views,cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: No such object(32), no errmsg set
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [Initgroups #79]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [Initgroups #79]: Receiving request data.
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_initgr_pp] (0x0400): Ordering NSS responder to update memory cache
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_reply_list_success] (0x0400): DP Request [Initgroups #79]: Finished. Success.
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:3::network.cawdekempen.be:name=jvanvlasselaer@network.cawdekempen.be] from reply table
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [Initgroups #79]: Request removed.
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_pam_handler] (0x0100): Got request with the following data
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): ruser:
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): rhost:
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): authtok type: 1
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): logon name: not set
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [PAM Authenticate #80]: New request. Flags [0000].
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [be_resolve_server_process] (0x0200): Found address for server freeipa03.network.cawdekempen.be: [192.168.250.12] TTL 1200
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://freeipa03.network.cawdekempen.be'
(Fri Jan  5 09:27:27 2018) [sssd[be[network.cawdekempen.be]]] [write_pipe_handler] (0x0400): All data has been sent!
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb] has set [cache] attrs.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=jvanvlasselaer@network.cawdekempen.be,cn=users,cn=network.cawdekempen.be,cn=sysdb
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [PAM Authenticate #80]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [PAM Authenticate #80]: Receiving request data.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [PAM Authenticate #80]: Request removed.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [child_sig_handler] (0x0100): child [1693] finished successfully.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_pam_handler] (0x0100): Got request with the following data
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): ruser:
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): rhost:
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [pam_print_data] (0x0100): logon name: not set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [PAM Account #81]: New request. Flags [0000].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_access_send] (0x0400): Performing access check for user [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_account_expired_rhds] (0x0400): Performing RHDS access check for user [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_account_expired] (0x0400): IPA access control succeeded, checking AD access control
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_account_expired_ad] (0x0400): Performing AD access check for user [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaHost)(fqdn=node1.network.cawdekempen.be))][cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_x_deref_search_send] (0x0400): Dereferencing entry [fqdn=node1.network.cawdekempen.be,cn=computers,cn=accounts,dc=network,dc=cawdekempen,dc=be] using OpenLDAP deref
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_send] (0x0400): WARNING: Disabling paging because scope is set to base.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][fqdn=node1.network.cawdekempen.be,cn=computers,cn=accounts,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_x_deref_parse_entry] (0x0400): Got deref control
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_x_deref_parse_entry] (0x0400): All deref results from a single control parsed
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_hostgroup_info_done] (0x0200): No host groups were dereferenced
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_hbac_service_info_next] (0x0400): Sending request for next search base: [cn=hbac,dc=network,dc=cawdekempen,dc=be][2][(objectClass=ipaHBACService)]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectClass=ipaHBACService)][cn=hbac,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_hbac_servicegroup_info_next] (0x0400): Sending request for next search base: [cn=hbac,dc=network,dc=cawdekempen,dc=be][2][(objectClass=ipaHBACServiceGroup)]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectClass=ipaHBACServiceGroup)][cn=hbac,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_hbac_rule_info_next] (0x0400): Sending request for next search base: [cn=hbac,dc=network,dc=cawdekempen,dc=be][2][(&(objectclass=ipaHBACRule)(ipaenabledflag=TRUE)(accessRuleType=allow)(|(hostCategory=all)(memberHost=fqdn=node1.network.cawdekempen.be,cn=computers,cn=accounts,dc=network,dc=cawdekempen,dc=be)))]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=ipaHBACRule)(ipaenabledflag=TRUE)(accessRuleType=allow)(|(hostCategory=all)(memberHost=fqdn=node1.network.cawdekempen.be,cn=computers,cn=accounts,dc=network,dc=cawdekempen,dc=be)))][cn=hbac,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [hbac_get_category] (0x0200): Category is set to 'all'.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [hbac_get_category] (0x0200): Category is set to 'all'.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [hbac_get_category] (0x0200): Category is set to 'all'.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [hbac_shost_attrs_to_rule] (0x0400): Processing source hosts for rule [allow_all]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [hbac_evaluate] (0x0100): [< hbac_evaluate()
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [hbac_evaluate] (0x0100): ALLOWED by rule [allow_all].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [hbac_evaluate] (0x0100): hbac_evaluate() >]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_hbac_evaluate_rules] (0x0080): Access granted by HBAC rule [allow_all]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [PAM Account #81]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [PAM Account #81]: Receiving request data.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [PAM Account #81]: Request removed.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): DP Request [PAM SELinux #82]: New request. Flags [0000].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_get_selinux_send] (0x0400): Retrieving SELinux user mapping
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(cn=ipaConfig)(objectClass=ipaGuiConfig))][cn=etc,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_selinux_get_maps_next] (0x0400): Trying to fetch SELinux maps with following parameters: [2][(&(objectclass=ipaselinuxusermap)(ipaEnabledFlag=TRUE))][cn=selinux,dc=network,dc=cawdekempen,dc=be]
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=ipaselinuxusermap)(ipaEnabledFlag=TRUE))][cn=selinux,dc=network,dc=cawdekempen,dc=be].
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [ipa_selinux_get_maps_done] (0x0400): No SELinux user maps found!
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_entry_attrs_diff] (0x0400): Entry [cn=selinux,cn=network.cawdekempen.be,cn=sysdb] differs, reason: ts_cache doesn't trace this type of entry.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [sysdb_set_entry_attr] (0x0200): Entry [cn=selinux,cn=network.cawdekempen.be,cn=sysdb] has set [cache] attrs.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [write_pipe_handler] (0x0400): All data has been sent!
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_done] (0x0400): DP Request [PAM SELinux #82]: Request handler finished [0]: Gelukt
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [_dp_req_recv] (0x0400): DP Request [PAM SELinux #82]: Receiving request data.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): DP Request [PAM SELinux #82]: Request removed.
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Fri Jan  5 09:27:29 2018) [sssd[be[network.cawdekempen.be]]] [child_sig_handler] (0x0100): child [1694] finished successfully.


sssd_pam.log
-------------
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [accept_fd_handler] (0x0400): Client connected to privileged pipe!
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3].
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Offered version [3].
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: not set
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1588
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_send] (0x0400): CR #10: New request 'Initgroups by name'
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_process_input] (0x0400): CR #10: Parsing input name [jvanvlasselaer]
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_set_name] (0x0400): CR #10: Setting name [jvanvlasselaer]
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #10: Performing a multi-domain search
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #10: Search will bypass the cache and check the data provider
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #10: Using domain [network.cawdekempen.be]
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #10: Preparing input data for domain [network.cawdekempen.be] rules
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #10: Looking up jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #10: Checking negative cache for [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #10: [jvanvlasselaer@network.cawdekempen.be] is not present in negative cache
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [cache_req_search_dp] (0x0400): CR #10: Looking up [jvanvlasselaer@network.cawdekempen.be] in data provider
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x555c978f71d0:3:jvanvlasselaer@network.cawdekempen.be@network.cawdekempen.be]
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [network.cawdekempen.be][0x3][BE_REQ_INITGROUPS][name=jvanvlasselaer@network.cawdekempen.be:-]
(Fri Jan  5 09:27:16 2018) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x555c978f71d0:3:jvanvlasselaer@network.cawdekempen.be@network.cawdekempen.be]
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #10: Looking up [jvanvlasselaer@network.cawdekempen.be] in cache
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #10: This request type does not support filtering result by negative cache
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [cache_req_search_done] (0x0400): CR #10: Returning updated object [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #10: Found 2 entries in domain network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #10: Finished: Success
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1588
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x555c978f71d0:3:jvanvlasselaer@network.cawdekempen.be@network.cawdekempen.be]
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [7 (Authenticatiefout)][network.cawdekempen.be]
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [7]: Authenticatiefout.
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal.
(Fri Jan  5 09:27:17 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 39
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [client_recv] (0x0200): Client disconnected!
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [accept_fd_handler] (0x0400): Client connected to privileged pipe!
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3].
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Offered version [3].
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_cmd_preauth] (0x0100): entering pam_cmd_preauth
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_PREAUTH
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: not set
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1689
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_send] (0x0400): CR #11: New request 'Initgroups by name'
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_process_input] (0x0400): CR #11: Parsing input name [jvanvlasselaer]
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_set_name] (0x0400): CR #11: Setting name [jvanvlasselaer]
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #11: Performing a multi-domain search
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #11: Search will check the cache and check the data provider
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #11: Using domain [network.cawdekempen.be]
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #11: Preparing input data for domain [network.cawdekempen.be] rules
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #11: Looking up jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #11: Checking negative cache for [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #11: [jvanvlasselaer@network.cawdekempen.be] is not present in negative cache
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #11: Looking up [jvanvlasselaer@network.cawdekempen.be] in cache
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #11: Returning [jvanvlasselaer@network.cawdekempen.be] from cache
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #11: This request type does not support filtering result by negative cache
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #11: Found 2 entries in domain network.cawdekempen.be
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #11: Finished: Success
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_PREAUTH
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1689
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Succes)][network.cawdekempen.be]
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0]: Succes.
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal.
(Fri Jan  5 09:27:19 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 39
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [client_recv] (0x0200): Client disconnected!
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [accept_fd_handler] (0x0400): Client connected to privileged pipe!
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3].
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Offered version [3].
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_cmd_preauth] (0x0100): entering pam_cmd_preauth
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_PREAUTH
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: not set
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_send] (0x0400): CR #12: New request 'Initgroups by name'
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_process_input] (0x0400): CR #12: Parsing input name [jvanvlasselaer]
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_set_name] (0x0400): CR #12: Setting name [jvanvlasselaer]
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #12: Performing a multi-domain search
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #12: Search will check the cache and check the data provider
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #12: Using domain [network.cawdekempen.be]
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #12: Preparing input data for domain [network.cawdekempen.be] rules
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #12: Looking up jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: Checking negative cache for [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: [jvanvlasselaer@network.cawdekempen.be] is not present in negative cache
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #12: Looking up [jvanvlasselaer@network.cawdekempen.be] in cache
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #12: Returning [jvanvlasselaer@network.cawdekempen.be] from cache
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #12: This request type does not support filtering result by negative cache
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #12: Found 2 entries in domain network.cawdekempen.be
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #12: Finished: Success
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_PREAUTH
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Succes)][network.cawdekempen.be]
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0]: Succes.
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal.
(Fri Jan  5 09:27:22 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 39
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: not set
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_send] (0x0400): CR #13: New request 'Initgroups by name'
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_process_input] (0x0400): CR #13: Parsing input name [jvanvlasselaer]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_set_name] (0x0400): CR #13: Setting name [jvanvlasselaer]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #13: Performing a multi-domain search
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #13: Search will bypass the cache and check the data provider
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #13: Using domain [network.cawdekempen.be]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #13: Preparing input data for domain [network.cawdekempen.be] rules
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #13: Looking up jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #13: Checking negative cache for [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #13: [jvanvlasselaer@network.cawdekempen.be] is not present in negative cache
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_dp] (0x0400): CR #13: Looking up [jvanvlasselaer@network.cawdekempen.be] in data provider
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x555c978f71d0:3:jvanvlasselaer@network.cawdekempen.be@network.cawdekempen.be]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [network.cawdekempen.be][0x3][BE_REQ_INITGROUPS][name=jvanvlasselaer@network.cawdekempen.be:-]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x555c978f71d0:3:jvanvlasselaer@network.cawdekempen.be@network.cawdekempen.be]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #13: Looking up [jvanvlasselaer@network.cawdekempen.be] in cache
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #13: This request type does not support filtering result by negative cache
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_search_done] (0x0400): CR #13: Returning updated object [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #13: Found 2 entries in domain network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #13: Finished: Success
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Fri Jan  5 09:27:27 2018) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x555c978f71d0:3:jvanvlasselaer@network.cawdekempen.be@network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [12 (Authenticatietoken is niet langer geldig; nieuwe is vereist)][network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [12]: Authenticatietoken is niet langer geldig; nieuwe is vereist.
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal.
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 39
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_cmd_acct_mgmt] (0x0100): entering pam_cmd_acct_mgmt
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: not set
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_send] (0x0400): CR #14: New request 'Initgroups by name'
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_process_input] (0x0400): CR #14: Parsing input name [jvanvlasselaer]
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jvanvlasselaer' matched without domain, user is jvanvlasselaer
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_set_name] (0x0400): CR #14: Setting name [jvanvlasselaer]
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #14: Performing a multi-domain search
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #14: Search will check the cache and check the data provider
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #14: Using domain [network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #14: Preparing input data for domain [network.cawdekempen.be] rules
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #14: Looking up jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #14: Checking negative cache for [jvanvlasselaer@network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #14: [jvanvlasselaer@network.cawdekempen.be] is not present in negative cache
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #14: Looking up [jvanvlasselaer@network.cawdekempen.be] in cache
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #14: Returning [jvanvlasselaer@network.cawdekempen.be] from cache
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #14: This request type does not support filtering result by negative cache
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #14: Found 2 entries in domain network.cawdekempen.be
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #14: Finished: Success
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: network.cawdekempen.be
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): user: jvanvlasselaer@network.cawdekempen.be
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: :0
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1691
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: jvanvlasselaer
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Succes)][network.cawdekempen.be]
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0]: Succes.
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal.
(Fri Jan  5 09:27:29 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 39


2018-01-04 13:53 GMT+01:00 Jakub Hrozek via FreeIPA-users <freeipa-users@lists.fedorahosted.org>:
On Thu, Jan 04, 2018 at 11:30:22AM +0100, Johan Vermeulen via FreeIPA-users wrote:
> Hello,
>
> apologies for the late reply, due to the holidays.
>
> I had a call from a user this morning, she had to do multiple login
> attempts and reboot several times before she could login.
>
> Trying to follow
> https://docs.pagure.org/SSSD.sssd/users/troubleshooting.html
>
> I assume the general setup works, as troubles only show up when password
> expires.
> On the  users laptop:
>
> [root@lremijsen ~]# systemctl status sssd
> ● sssd.service - System Security Services Daemon
>    Loaded: loaded (/usr/lib/systemd/system/sssd.service; enabled; vendor
> preset: disabled)
>   Drop-In: /etc/systemd/system/sssd.service.d
>            └─journal.conf
>    Active: active (running) since do 2018-01-04 08:42:01 CET; 2h 35min ago
>   Process: 730 ExecStart=/usr/sbin/sssd -D -f (code=exited,
> status=0/SUCCESS)
>  Main PID: 757 (sssd)
>    CGroup: /system.slice/sssd.service
>            ├─757 /usr/sbin/sssd -D -f
>            ├─767 /usr/libexec/sssd/sssd_be --domain network.cawdekempen.be
> --uid 0 --gid 0 --debug-to-files
>            ├─774 /usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --debug-to-files
>            ├─775 /usr/libexec/sssd/sssd_sudo --uid 0 --gid 0
> --debug-to-files
>            ├─776 /usr/libexec/sssd/sssd_pam --uid 0 --gid 0 --debug-to-files
>            ├─777 /usr/libexec/sssd/sssd_ssh --uid 0 --gid 0 --debug-to-files
>            └─778 /usr/libexec/sssd/sssd_pac --uid 0 --gid 0 --debug-to-files
>
> jan 04 10:37:45 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 1
> jan 04 10:37:45 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 2
> jan 04 10:52:45 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 1
> jan 04 10:52:45 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 1
> jan 04 10:52:46 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 1
> jan 04 10:52:46 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 2
> jan 04 11:07:45 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 1
> jan 04 11:07:45 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 1
> jan 04 11:07:46 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 1
> jan 04 11:07:46 lremijsen.network.cawdekempen.be sssd_be[767]: GSSAPI
> client step 2
>
> In /var/log/secure there is always a clear message that the password is
> expired:
>
> Jan  4 10:06:13 lremijsen mate-screensaver-dialog:
> pam_sss(mate-screensaver:auth): authentication failure; logname=
> uid=382900705 euid=382900705 tty=:0.0 ruser= rhost= user=lremijsen
> Jan  4 10:06:13 lremijsen mate-screensaver-dialog:
> pam_sss(mate-screensaver:auth): received for user lremijsen: 12
> (Authenticatietoken is niet langer geldig; nieuwe is vereist)
> Jan  4 10:06:14 lremijsen mate-screensaver-dialog:
> pam_sss(mate-screensaver:account): User info message: Wachtwoord verlopen.
> Verander nu uw wachtwoord.
>
>     sssd_pam.log only shows:
>
> (Tue Jan  2 13:05:46 2018) [sssd[pam]] [orderly_shutdown] (0x0010):
> SIGTERM: killing children
>
>    sssd_network.cawdekempen.be.log only shows:
>
> (Tue Jan  2 13:05:46 2018) [sssd[be[network.cawdekempen.be]]]
> [orderly_shutdown] (0x0010): SIGTERM: killing children
>
> I suppose I have to increase the log levels?

Yes, by default, SSSD doesn't log much. I think you would need
especially the pam and domain service debug logs.
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org