Hello,

On 9 Oct 2019, at 05:59, Jakub Hrozek via FreeIPA-users <freeipa-users@lists.fedorahosted.org> wrote:

On Wed, Oct 09, 2019 at 12:25:33AM +0000, Vinícius Ferrão via FreeIPA-users wrote:
Hello,

The /var/lib/sss/pubconf/known_hosts file is empty on a new installed FreeIPA server. I’ve already joined a machine to the domain but the file is still empty.

I can’t get it populated, already rebooted and/or restarted sssd without success.

Looking on the web I came across this bug:
https://bugzilla.redhat.com/show_bug.cgi?id=1574778

It is Fedora related, but it’s the same version that I’m running, since I’m on CentOS 7.6.

How can I check if is in fact this bug?

Here are some errors on sssd_ssh with debug_level = 9 enabled:

==> /var/log/sssd/sssd_ssh.log <==
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [sbus_remove_timeout] (0x2000): 0x55b758c55dc0
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [sbus_dispatch] (0x4000): dbus conn: 0x55b758c56e10
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [sbus_dispatch] (0x4000): Dispatching.
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 22 error message: Invalid argument
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [cache_req_common_dp_recv] (0x0040): CR #2: Data Provider Error: 3, 22, Invalid argument
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [cache_req_common_dp_recv] (0x0400): CR #2: Due to an error we will return cached data
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [cache_req_search_cache] (0x0400): CR #2: Looking up [hpclab01] in cache
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55b758c62d50

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55b758c62e10

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x55b758c62d50 "ltdb_callback"

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x55b758c62e10 "ltdb_timeout"

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x55b758c62d50 "ltdb_callback"

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [sysdb_search_ssh_hosts] (0x0400): No such host
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [cache_req_search_cache] (0x0400): CR #2: Object [hpclab01] was not found in cache
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [cache_req_process_result] (0x0400): CR #2: Finished: Not found
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55b758c60990

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55b758c63960

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x55b758c60990 "ltdb_callback"

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x55b758c63960 "ltdb_timeout"

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x55b758c60990 "ltdb_callback"

(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [sysdb_search_ssh_hosts] (0x0400): No such host
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/pubconf/.known_hosts.yfSd2J]
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/pubconf/.known_hosts.yfSd2J]
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [ssh_protocol_done] (0x4000): Sending reply: error [2]: No such file or directory
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x55b7572d88e0:hpclab01:hpclab01@cluster.iq.ufrj.br<mailto:hpclab01@cluster.iq.ufrj.br>]

==> /var/log/sssd/sssd_cluster.iq.ufrj.br.log <==

Can you also enable debug_level for the domain to see why is sssd_be
replying with Invalid Argument?

It was already on. I followed the instructions on the ticket, so here it is:

==> /var/log/sssd/sssd_cluster.iq.ufrj.br.log <==
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sbus_dispatch] (0x4000): dbus conn: 0x55b328b4ac90
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sbus_dispatch] (0x4000): Dispatching.
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.hostHandler on path /org/freedesktop/sssd/dataprovider
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_attach_req] (0x0400): DP Request [HostID #9]: New request. Flags [0000].
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_print_server] (0x2000): Searching 172.26.255.254:389
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaHost)(fqdn=hpclab01))][cn=accounts,dc=cluster,dc=iq,dc=ufrj,dc=br].
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [fqdn]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [serverHostname]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSshPubKey]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaUniqueID]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 27
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_op_add] (0x2000): New operation 27 timeout 60
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_process_result] (0x2000): Trace: sh[0x55b328b3bf20], connected[1], ops[0x55b328b26700], ldap[0x55b328b2d830]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_get_generic_op_finished] (0x2000): Total count [0]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_op_destructor] (0x2000): Operation 27 finished
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [hosts_get_done] (0x0040): No host with name [hpclab01] found.
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sysdb_delete_ssh_host] (0x0400): Deleting host hpclab01
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55b328b6c3f0

(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55b328b6c4b0

(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): Running timer event 0x55b328b6c3f0 "ltdb_callback"

(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): Target entry (name=hpclab01,cn=ssh_hosts,cn=custom,cn=cluster.iq.ufrj.br,cn=sysdb) not found
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): Destroying timer event 0x55b328b6c4b0 "ltdb_timeout"

(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): Ending timer event 0x55b328b6c3f0 "ltdb_callback"

(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [ldb] (0x4000): cancel ldb transaction (nesting: 0)
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_req_done] (0x0400): DP Request [HostID #9]: Request handler finished [0]: Success
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [_dp_req_recv] (0x0400): DP Request [HostID #9]: Receiving request data.
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_req_reply_list_success] (0x0400): DP Request [HostID #9]: Finished. Success.
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_req_reply_std] (0x1000): DP Request [HostID #9]: Returning [Internal Error]: 3,22,Invalid argument
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_table_value_destructor] (0x0400): Removing [7:7:0000:hpclab01:hpclab01.cluster.iq.ufrj.br] from reply table
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_req_destructor] (0x0400): DP Request [HostID #9]: Request removed.
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_process_result] (0x2000): Trace: sh[0x55b328b3bf20], connected[1], ops[(nil)], ldap[0x55b328b2d830]
(Tue Oct  8 21:10:45 2019) [sssd[be[cluster.iq.ufrj.br]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list

Thanks!


==> /var/log/sssd/sssd_ssh.log <==
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [client_recv] (0x0200): Client disconnected!
(Tue Oct  8 21:10:37 2019) [sssd[ssh]] [client_close_fn] (0x2000): Terminated client [0x55b758c4f940][18]




Installed versions:

[root@headnode ~]# rpm -qa | grep -i sssd
sssd-client-1.16.4-21.el7.x86_64
sssd-ldap-1.16.4-21.el7.x86_64
sssd-common-pac-1.16.4-21.el7.x86_64
sssd-dbus-1.16.4-21.el7.x86_64
sssd-ipa-1.16.4-21.el7.x86_64
sssd-proxy-1.16.4-21.el7.x86_64
sssd-common-1.16.4-21.el7.x86_64
sssd-ad-1.16.4-21.el7.x86_64
python-sssdconfig-1.16.4-21.el7.noarch
sssd-krb5-common-1.16.4-21.el7.x86_64
sssd-1.16.4-21.el7.x86_64
sssd-krb5-1.16.4-21.el7.x86_64


Thanks,



_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org