Hello,

On 9 Oct 2019, at 05:59, Jakub Hrozek via FreeIPA-users 
<freeipa-users@lists.fedorahosted.org<mailto: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:hpcla...@cluster.iq.ufrj.br<mailto:hpcla...@cluster.iq.ufrj.br><mailto:hpcla...@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<http://cluster.iq.ufrj.br>]]] [sbus_dispatch] 
(0x4000): dbus conn: 0x55b328b4ac90
(Tue Oct  8 21:10:45 2019) 
[sssd[be[cluster.iq.ufrj.br<http://cluster.iq.ufrj.br>]]] [sbus_dispatch] 
(0x4000): Dispatching.
(Tue Oct  8 21:10:45 2019) 
[sssd[be[cluster.iq.ufrj.br<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://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<http://cluster.iq.ufrj.br>]]] [sdap_op_destructor] 
(0x2000): Operation 27 finished
(Tue Oct  8 21:10:45 2019) 
[sssd[be[cluster.iq.ufrj.br<http://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<http://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<http://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<http://cluster.iq.ufrj.br>]]] [ldb] (0x4000): start 
ldb transaction (nesting: 0)
(Tue Oct  8 21:10:45 2019) 
[sssd[be[cluster.iq.ufrj.br<http://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<http://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<http://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<http://cluster.iq.ufrj.br>]]] [ldb] (0x4000): 
Target entry 
(name=hpclab01,cn=ssh_hosts,cn=custom,cn=cluster.iq.ufrj.br<http://cluster.iq.ufrj.br>,cn=sysdb)
 not found
(Tue Oct  8 21:10:45 2019) 
[sssd[be[cluster.iq.ufrj.br<http://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<http://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<http://cluster.iq.ufrj.br>]]] [ldb] (0x4000): 
cancel ldb transaction (nesting: 0)
(Tue Oct  8 21:10:45 2019) 
[sssd[be[cluster.iq.ufrj.br<http://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<http://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<http://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<http://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<http://cluster.iq.ufrj.br>]]] 
[dp_table_value_destructor] (0x0400): Removing 
[7:7:0000:hpclab01:hpclab01.cluster.iq.ufrj.br<http://hpclab01.cluster.iq.ufrj.br>]
 from reply table
(Tue Oct  8 21:10:45 2019) 
[sssd[be[cluster.iq.ufrj.br<http://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<http://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<http://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<http://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<mailto:freeipa-users@lists.fedorahosted.org>
To unsubscribe send an email to 
freeipa-users-le...@lists.fedorahosted.org<mailto:freeipa-users-le...@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<mailto:freeipa-users@lists.fedorahosted.org>
To unsubscribe send an email to 
freeipa-users-le...@lists.fedorahosted.org<mailto:freeipa-users-le...@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-le...@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

Reply via email to