On 21/09/2021 13:26, Rob Crittenden wrote:
lejeczek via FreeIPA-users wrote:
Hi guys.
I've noticed I think a patter, such that when IPA clientA does lots of
ssh to a former IPA clientB (or might be to any non-IPA host?) then logs
size go up rapidly.
Logs: sssd_ssh.log, sssd_private.lot.log,
In terms of IPA client configs - those are vanilla default, nothing
added for extra verbosity.
As soon as I add such a non-IPA host as a client then logs stop growing.
Before I start going through logs I thought I'd ask if this might be a
result of some obvious & gruesome IPA misconfiguration?
many thanks, L.
Version(s)? distros?
So you're saying that you have one or more IPA servers and one or more
IPA clients and those clients are logging excessively until you add a
non-IPA host? What is a non-IPA host and adding it where?
I think you'll need to see what is in those logs.
rob
Here is sssd_ssh.log's snippet. This from 'c8kubernode3'
whereas 'c8kubernode2' is to IPA domain a foreign host.
...
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE
FOLLOWING BACKTRACE:
* (2021-09-21 19:01:05): [ssh]
[cache_req_common_process_dp_reply] (0x0400): CR #62325: Due
to an error we will return cached data
* (2021-09-21 19:01:05): [ssh] [sss_domain_get_state]
(0x1000): Domain implicit_files is Active
* (2021-09-21 19:01:05): [ssh] [cache_req_search_cache]
(0x0400): CR #62325: Looking up [c8kubernode2.private.lot]
in cache
* (2021-09-21 19:01:05): [ssh] [sysdb_search_ssh_hosts]
(0x0400): No such host
* (2021-09-21 19:01:05): [ssh] [cache_req_search_cache]
(0x0400): CR #62325: Object [c8kubernode2.private.lot] was
not found in cache
* (2021-09-21 19:01:05): [ssh]
[cache_req_validate_domain_type] (0x2000): Request type
POSIX-only for domain private.lot type POSIX is valid
* (2021-09-21 19:01:05): [ssh] [cache_req_set_domain]
(0x0400): CR #62325: Using domain [private.lot]
* (2021-09-21 19:01:05): [ssh] [cache_req_search_send]
(0x0400): CR #62325: Looking up c8kubernode2.private.lot
* (2021-09-21 19:01:05): [ssh]
[cache_req_search_ncache] (0x2000): CR #62325: This request
type does not support negative cache
* (2021-09-21 19:01:05): [ssh] [cache_req_search_dp]
(0x0400): CR #62325: Looking up [c8kubernode2.private.lot]
in data provider
* (2021-09-21 19:01:05): [ssh] [sbus_dispatch]
(0x4000): Dispatching.
* (2021-09-21 19:01:05): [ssh] [sss_domain_get_state]
(0x1000): Domain private.lot is Active
* (2021-09-21 19:01:05): [ssh] [cache_req_search_cache]
(0x0400): CR #62325: Looking up [c8kubernode2.private.lot]
in cache
* (2021-09-21 19:01:05): [ssh]
[sysdb_merge_res_ts_attrs] (0x2000): TS cache doesn't handle
this DN type, skipping
* (2021-09-21 19:01:05): [ssh]
[cache_req_search_ncache_filter] (0x0400): CR #62325: This
request type does not support filtering result by negative cache
* (2021-09-21 19:01:05): [ssh] [cache_req_search_done]
(0x0400): CR #62325: Returning updated object
[c8kubernode2.private.lot]
* (2021-09-21 19:01:05): [ssh]
[cache_req_create_and_add_result] (0x0400): CR #62325: Found
1 entries in domain private.lot
* (2021-09-21 19:01:05): [ssh] [cache_req_done]
(0x0400): CR #62325: Finished: Success
* (2021-09-21 19:01:05): [ssh]
[sysdb_update_ssh_known_host_expire] (0x0400): Updating
known_hosts expire time of host c8kubernode2.private.lot
* (2021-09-21 19:01:05): [ssh]
[sysdb_merge_res_ts_attrs] (0x2000): TS cache doesn't handle
this DN type, skipping
* (2021-09-21 19:01:05): [ssh] [sysdb_search_ssh_hosts]
(0x0400): No such host
* (2021-09-21 19:01:05): [ssh] [sss_domain_get_state]
(0x1000): Domain private.lot is Active
* (2021-09-21 19:01:05): [ssh]
[sysdb_merge_res_ts_attrs] (0x2000): TS cache doesn't handle
this DN type, skipping
* (2021-09-21 19:01:05): [ssh]
[unique_filename_destructor] (0x2000): Unlinking
[/var/lib/sss/pubconf/.known_hosts.BDXlgY]
* (2021-09-21 19:01:05): [ssh] [unlink_dbg] (0x2000):
File already removed: [/var/lib/sss/pubconf/.known_hosts.BDXlgY]
* (2021-09-21 19:01:05): [ssh] [ssh_protocol_done]
(0x4000): Sending reply: success
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad77322330][27]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad7734a370][24]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad773371a0][26]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad77314be0][23]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad773c8870][39]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad77337bb0][35]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad77381890][28]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad773cc010][34]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad77345ff0][36]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad77346350][33]
* (2021-09-21 19:01:05): [ssh] [client_recv] (0x0200):
Client disconnected!
* (2021-09-21 19:01:05): [ssh] [client_close_fn]
(0x2000): Terminated client [0x55ad773ca9d0][38]
* (2021-09-21 19:01:05): [ssh] [get_client_cred]
(0x4000): Client [0x55ad77314be0][23] creds: euid[0] egid[0]
pid[756106] cmd_line['/usr/bin/sss_ssh_knownhostsproxy'].
* (2021-09-21 19:01:05): [ssh]
[setup_client_idle_timer] (0x4000): Idle timer re-set for
client [0x55ad77314be0][23]
* (2021-09-21 19:01:05): [ssh] [accept_fd_handler]
(0x0400): Client [CID #62331][cmd
/usr/bin/sss_ssh_knownhostsproxy][0x55ad77314be0][23] connected!
* (2021-09-21 19:01:05): [ssh] [sss_cmd_get_version]
(0x0200): Received client version [0].
* (2021-09-21 19:01:05): [ssh] [sss_cmd_get_version]
(0x0200): Offered version [0].
* (2021-09-21 19:01:05): [ssh]
[ssh_protocol_parse_request] (0x0400): Requested domain [<ALL>]
* (2021-09-21 19:01:05): [ssh]
[ssh_cmd_get_host_pubkeys] (0x0400): Requesting SSH host
public keys for [c8kubernode2.private.lot] from [<ALL>]
* (2021-09-21 19:01:05): [ssh] [cache_req_set_plugin]
(0x2000): CR #62326: Setting "SSH Host ID by name" plugin
* (2021-09-21 19:01:05): [ssh] [cache_req_send]
(0x0400): CR #62326: REQ_TRACE: New request [CID #62331]
'SSH Host ID by name'
* (2021-09-21 19:01:05): [ssh]
[cache_req_process_input] (0x0400): CR #62326: Parsing input
name [c8kubernode2.private.lot]
* (2021-09-21 19:01:05): [ssh] [sss_domain_get_state]
(0x1000): Domain private.lot is Active
* (2021-09-21 19:01:05): [ssh] [sss_parse_name]
(0x0100): Domain not provided!
* (2021-09-21 19:01:05): [ssh]
[sss_parse_name_for_domains] (0x0200): name
'c8kubernode2.private.lot' matched without domain, user is
c8kubernode2.private.lot
* (2021-09-21 19:01:05): [ssh] [cache_req_set_name]
(0x0400): CR #62326: Setting name [c8kubernode2.private.lot]
* (2021-09-21 19:01:05): [ssh]
[cache_req_select_domains] (0x0400): CR #62326: Performing a
multi-domain search
* (2021-09-21 19:01:05): [ssh]
[cache_req_search_domains] (0x0400): CR #62326: Search will
bypass the cache and check the data provider
* (2021-09-21 19:01:05): [ssh]
[cache_req_validate_domain_type] (0x2000): Request type
POSIX-only for domain implicit_files type POSIX is valid
* (2021-09-21 19:01:05): [ssh] [cache_req_set_domain]
(0x0400): CR #62326: Using domain [implicit_files]
* (2021-09-21 19:01:05): [ssh] [cache_req_search_send]
(0x0400): CR #62326: Looking up c8kubernode2.private.lot
* (2021-09-21 19:01:05): [ssh]
[cache_req_search_ncache] (0x2000): CR #62326: This request
type does not support negative cache
* (2021-09-21 19:01:05): [ssh] [cache_req_search_dp]
(0x0400): CR #62326: Looking up [c8kubernode2.private.lot]
in data provider
* (2021-09-21 19:01:05): [ssh] [sbus_dispatch]
(0x4000): Dispatching.
* (2021-09-21 19:01:05): [ssh] [sbus_reply_check]
(0x4000): D-Bus error [sbus.Error.Errno]: 1432158215: DP
target is not configured
* (2021-09-21 19:01:05): [ssh]
[cache_req_common_process_dp_reply] (0x0040): CR #62326:
Could not get account info [1432158215]: DP target is not
configured
********************** BACKTRACE DUMP ENDS HERE
*********************************
log file is full of these BACKTRACEs.
thanks, L.
_______________________________________________
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
Do not reply to spam on the list, report it:
https://pagure.io/fedora-infrastructure
