Ok guys, I’ve finally figured it out.
It was a software that put entries in wrong way on /etc/hosts.
So the host ended up with wrong name stored in Kerberos database and known_hosts nor
Kerberos authentication worked as expected.
Removing the wrong entries from /etc/hosts on the server solved the issue.
On 9 Oct 2019, at 12:40, Vinícius Ferrão via FreeIPA-users
<freeipa-users@lists.fedorahosted.org<mailto:freeipa-users@lists.fedorahosted.org>>
wrote:
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:hpclab01@cluster.iq.ufrj.br<mailto: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<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-leave@lists.fedorahosted.org<mailto: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.fedoraho...
_______________________________________________
FreeIPA-users mailing list --
freeipa-users@lists.fedorahosted.org<mailto:freeipa-users@lists.fedorahosted.org>
To unsubscribe send an email to
freeipa-users-leave@lists.fedorahosted.org<mailto: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.fedoraho...
_______________________________________________
FreeIPA-users mailing list --
freeipa-users@lists.fedorahosted.org<mailto:freeipa-users@lists.fedorahosted.org>
To unsubscribe send an email to
freeipa-users-leave@lists.fedorahosted.org<mailto: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.fedoraho...