One one of the test servers sssd fails to start correctly. Here are the
errors and their respective logs, with debug enabled.
freeipa-server-4.9.1-1.fc33.x86_64
systemctl status sssd --no-pager -l
* sssd.service - System Security Services Daemon
Loaded: loaded (/usr/lib/systemd/system/sssd.service; enabled; vendor
preset: enabled)
Active: activating (start) since Tue 2021-02-16 15:15:32 EST; 1s ago
Main PID: 809519 (sssd)
Tasks: 2 (limit: 9484)
Memory: 10.9M
CPU: 998ms
CGroup: /system.slice/sssd.service
|-809519 /usr/sbin/sssd -i --logger=files
`-809520 /usr/libexec/sssd/sssd_be --domain implicit_files
--uid 0 --gid 0 --logger=files
Feb 16 15:15:32
sssd[809519]: NSCD socket was detected and
seems to be configured to cache some of the databases controlled by SSSD
[passwd,group,netgroup,services]. It is recommended not to run NSCD in
parallel with SSSD, unless NSCD is configured not to cache these.
Feb 16 15:15:33
sssd[809519]: Starting up
However:
systemctl status nscd
* nscd.service - Name Service Cache Daemon
Loaded: loaded (/usr/lib/systemd/system/nscd.service; disabled; vendor
preset: disabled)
Active: inactive (dead)
/var/log/sssd/sssd_ourdomain.edu.log
(2021-02-16 15:06:30): [be[ourdomain.edu]] [ipa_init_dyndns] (0x0100):
Dynamic DNS updates are off.
(2021-02-16 15:06:30): [be[ourdomain.edu]] [setup_tls_config] (0x0020):
Unknown value for tls_reqcert 'never (or allow'.
(2021-02-16 15:06:30): [be[ourdomain.edu]] [ipa_init_misc] (0x0020): Unable
to get TLS options [22]: Invalid argument
(2021-02-16 15:06:30): [be[ourdomain.edu]] [sssm_ipa_init] (0x0020): Unable
to init IPA module [22]: Invalid argument
(2021-02-16 15:06:30): [be[ourdomain.edu]] [dp_module_run_constructor]
(0x0010): Module [ipa] constructor failed [22]: Invalid argument
(2021-02-16 15:06:30): [be[ourdomain.edu]] [dp_load_module] (0x0020):
Unable to create DP module.
(2021-02-16 15:06:30): [be[ourdomain.edu]] [dp_target_init] (0x0010):
Unable to load module ipa
(2021-02-16 15:06:30): [be[ourdomain.edu]] [dp_load_targets] (0x0020):
Unable to load target [id] [80]: Accessing a corrupted shared library.
(2021-02-16 15:06:30): [be[ourdomain.edu]] [dp_init_done] (0x0020): Unable
to initialize DP targets [1432158209]: Internal Error
(2021-02-16 15:06:30): [be[ourdomain.edu]] [dp_terminate_active_requests]
(0x0400): Terminating active data provider requests
(2021-02-16 15:06:30): [be[ourdomain.edu]] [sbus_server_symlink_remove]
(0x0400): Symlink removed [/var/lib/sss/pipes/private/sbus-dp_ourdomain.edu]
/var/log/sssd/sssd.log
(2021-02-16 15:13:21): [sssd] [monitor_cleanup] (0x0010): Error removing
pidfile! (2 [No such file or directory])
(2021-02-16 15:13:22): [sssd] [server_setup] (0x0040): Starting with debug
level = 0x0070
(2021-02-16 15:13:22): [sssd] [svc_child_info] (0x0040): Child [809126] ('
ourdomain.edu':'%BE_ourdomain.edu') exited with code [3]
(2021-02-16 15:13:22): [sssd] [svc_child_info] (0x0040): Child [809127] ('
ourdomain.edu':'%BE_ourdomain.edu') exited with code [3]
(2021-02-16 15:13:24): [sssd] [svc_child_info] (0x0040): Child [809133] ('
ourdomain.edu':'%BE_ourdomain.edu') exited with code [3]
(2021-02-16 15:13:27): [sssd] [services_startup_timeout] (0x0020):
Providers did not start in time, forcing services startup!
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809137]
('nss':'nss') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809139]
('ifp':'ifp') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809141]
('sudo':'sudo') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809138]
('pam':'pam') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809140]
('ssh':'ssh') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809142]
('pac':'pac') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809143]
('nss':'nss') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809144]
('ifp':'ifp') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809145]
('sudo':'sudo') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809147]
('ssh':'ssh') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809146]
('pam':'pam') exited with code [3]
(2021-02-16 15:13:27): [sssd] [svc_child_info] (0x0040): Child [809148]
('pac':'pac') exited with code [3]
(2021-02-16 15:13:28): [sssd] [svc_child_info] (0x0040): Child [809153] ('
ourdomain.edu':'%BE_ourdomain.edu') exited with code [3]
(2021-02-16 15:13:28): [sssd] [monitor_restart_service] (0x0010): Process [
], definitely stopped!
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0040): Returned with: 1
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Terminating
[pac][809148]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Couldn't kill
[pac][809148]: [No such process]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Terminating
[ssh][809147]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Couldn't kill
[ssh][809147]: [No such process]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Terminating
[pam][809146]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Couldn't kill
[pam][809146]: [No such process]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Terminating
[sudo][809145]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Couldn't kill
[sudo][809145]: [No such process]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Terminating
[ifp][809144]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Couldn't kill
[ifp][809144]: [No such process]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Terminating
[nss][809143]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Couldn't kill
[nss][809143]: [No such process]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Terminating
[implicit_files][809125]
(2021-02-16 15:13:28): [sssd] [monitor_quit] (0x0020): Child
[implicit_files] exited gracefully
(2021-02-16 15:13:28): [sssd] [monitor_cleanup] (0x0010): Error removing
pidfile! (2 [No such file or directory])
In /var/log/sssd/sssd_pam.log, /var/log/sssd/sssd_sudo.log,
/var/log/sssd/sssd_ifp.log, /var/log/sssd/sssd_pac.log &
/var/log/sssd/sssd_nss.log all these logs end with:
(2021-02-16 15:08:30): [pam] [server_setup] (0x0040): Starting with debug
level = 0x0070
(2021-02-16 15:08:30): [pam] [sss_iface_connect_address] (0x0020):
check_file failed for [/var/lib/sss/pipes/private/sbus-dp_ourdomain.edu].
(2021-02-16 15:08:30): [pam] [sss_dp_init] (0x0010): Failed to connect to
backend server.
(2021-02-16 15:08:30): [pam] [sss_process_init] (0x0010): fatal error
setting up backend connector
(2021-02-16 15:08:30): [pam] [pam_process_init] (0x0010):
sss_process_init() failed
/var/log/sssd/sssd_implicit_files.log
(2021-02-16 15:12:24): [be[implicit_files]] [sysdb_set_cache_entry_attr]
(0x0040): Error: 17 (File exists)
(2021-02-16 15:12:24): [be[implicit_files]] [sysdb_set_cache_entry_attr]
(0x0040): Error: 17 (File exists)
(2021-02-16 15:12:24): [be[implicit_files]] [sysdb_store_new_group]
(0x0040): sysdb_add_group failed (while renaming group) for:
wireshark@implicit_files [1630].
(2021-02-16 15:12:24): [be[implicit_files]] [sysdb_store_group] (0x0040):
Cache update failed: 17
(2021-02-16 15:12:24): [be[implicit_files]] [save_file_group] (0x0040):
Could not add group to cache
(2021-02-16 15:12:26): [be[implicit_files]] [orderly_shutdown] (0x0010):
SIGTERM: killing children
(2021-02-16 15:12:26): [be[implicit_files]] [orderly_shutdown] (0x0040):
Shutting down (status = 0)
(2021-02-16 15:12:26): [be[implicit_files]] [server_setup] (0x0040):
Starting with debug level = 0x0070
However ipactl status does not show any errors:
Directory Service: RUNNING
krb5kdc Service: RUNNING
kadmin Service: RUNNING
named Service: RUNNING
httpd Service: RUNNING
ipa-custodia Service: RUNNING
pki-tomcatd Service: RUNNING
ipa-otpd Service: RUNNING
ipa-dnskeysyncd Service: RUNNING
ipa: INFO: The ipactl command was successful
Anything sticking out?
On Thu, Feb 11, 2021 at 4:51 PM Robert Kudyba <rkudyba(a)fordham.edu> wrote:
What is ourserver.edu? In order to log in using Kerberos/GSSAPI then
the
> machine acting as the server needs to be enrolled as an IPA client so it
> has a keytab.
> rob
OK I added a Fedora server as a client. From ipa host-show
client.ourserver.edu
Host name:
client.ourserver.edu
Platform: x86_64
Operating system: 5.10.13-200.fc33.x86_64
Principal name: host/client.ourserver.edu(a)OLDDSM.DSM.FORDHAM.EDU
Principal alias: host/client.ourserver.edu(a)OLDDSM.DSM.FORDHAM.EDU
SSH public key fingerprint: SHA256:xxx(ecdsa-sha2-nistp256),
SHA256:xxx (ssh-ed25519),
SHA256:xxx (ssh-rsa)
Password: False
Keytab: True
Managed by:
client.ourserver.edu
ssh -k still fails.
I created a new user in via ipa user-add and that user also fails even
with a su -:
su: user testuser does not exist or the user entry does not contain all
the required fields
Feb 11 15:07:21 ourserver sshd[609424]: debug1: rekey out after 4294967296
blocks [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: SSH2_MSG_NEWKEYS sent
[preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: Sending SSH2_MSG_EXT_INFO
[preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: expecting SSH2_MSG_NEWKEYS
[preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: SSH2_MSG_NEWKEYS received
[preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: rekey in after 4294967296
blocks [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: KEX done [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: userauth-request for user
yume service ssh-connection method none [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: attempt 0 failures 0
[preauth]
Feb 11 15:07:21 ourserver sshd[609424]: Invalid user testuser from x.x.x.x
port 36264
Feb 11 15:07:21 ourserver sshd[609424]: debug1: PAM: initializing for
"testuser"
Feb 11 15:07:21 ourserver sshd[609424]: debug1: PAM: setting PAM_RHOST to
"x.x.x.x"
Feb 11 15:07:21 ourserver sshd[609424]: debug1: PAM: setting PAM_TTY to
"ssh"
Feb 11 15:07:21 ourserver sshd[609424]: debug1: userauth-request for user
testuser service ssh-connection method keyboard-interactive [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: attempt 1 failures 0
[preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: keyboard-interactive devs
[preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: auth2_challenge:
user=testuser devs= [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: kbdint_alloc: devices
'pam' [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: debug1: auth2_challenge_start:
trying authentication method 'pam' [preauth]
Feb 11 15:07:21 ourserver sshd[609424]: Postponed keyboard-interactive for
invalid user testuser from x.x.x.x port 36264 ssh2 [preauth]
Feb 11 15:07:24 ourserver sshd[609424]: Connection closed by invalid user
testuser x.x.x.x port 36264 [preauth]
are you sure the sssd.conf you have send earlier it the right one?
> SSSD'S 'proxy_child' should be only be called if the proxy provider is
> configured?
>
> bye,
> Sumit
>
Sorry, you are correct. I'm testing between 2 test NIS servers to see if
there's a difference in behavior but the same problem, ssh -k never works
with the FreeIPA/Kerberos password
>
> > Feb 10 14:36:31 ourserver sshd[3084344]: pam_sss(sshd:auth):
> authentication
> > failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x user=ouruser
> > Feb 10 14:36:31 ourserver sshd[3084344]: pam_sss(sshd:auth): received
> for
> > user ouruser: 7 (Authentication failure)
> > Feb 10 14:36:33 ourserver sshd[3084339]: error: PAM: Authentication
> failure
> > for ouruser from x.x.x.x
> > Feb 10 14:36:33 ourserver sshd[3084339]: Failed keyboard-interactive/pam
> > for ouruser from x.x.x.x port 34160 ssh2
> > Feb 10 14:36:33 ourserver sshd[3084339]: debug1: userauth-request for
> user
> > ouruser service ssh-connection method keyboard-interactive [preauth]
> > Feb 10 14:36:33 ourserver sshd[3084339]: debug1: attempt 3 failures 1
> > [preauth]
> > Feb 10 14:36:33 ourserver sshd[3084339]: debug1: keyboard-interactive
> devs
> > [preauth]
> > Feb 10 14:36:33 ourserver sshd[3084339]: debug1: auth2_challenge:
> > user=ouruser devs= [preauth]
> > Feb 10 14:36:33 ourserver sshd[3084339]: debug1: kbdint_alloc: devices
> > 'pam' [preauth]
> > Feb 10 14:36:33 ourserver sshd[3084339]: debug1: auth2_challenge_start:
> > trying authentication method 'pam' [preauth]
> > Feb 10 14:36:33 ourserver sshd[3084339]: Postponed keyboard-interactive
> for
> > ouruser from x.x.x.x port 34160 ssh2 [preauth]
> >
> > I verified the FreeIPA password in both the GUI and via ipa user-mod.
> The
> > only time the user is able to log in is using the NIS password.
> ldapsearch
> > -x -D and kinit username work successfully. klist displays the user
> details
> > correctly.
> >
> > I can see that the installation script edits /etc/ssh/sshd_config with:
> > Include /etc/ssh/sshd_config.d/04-ipa.conf
> >
> > which has:
> > PubkeyAuthentication yes
> > KerberosAuthentication no
> > GSSAPIAuthentication yes
> > UsePAM yes
> > ChallengeResponseAuthentication yes
> > AuthorizedKeysCommand /usr/bin/sss_ssh_authorizedkeys
> > AuthorizedKeysCommandUser nobody
> >
> > When the NIS password is used successfully here are the server logs:
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: userauth-request for
> user
> > ouruser service ssh-connection method none [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: attempt 0 failures 0
> > [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: connection from x.x.x.x
> > matched 'Address 192.168.0.*,127.0.0.1,10.10.1.*' at line 158
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: PAM: initializing for
> > "ouruser"
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: PAM: setting PAM_RHOST
> to
> > "x.x.x.x"
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: PAM: setting PAM_TTY to
> > "ssh"
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: userauth-request for
> user
> > ouruser service ssh-connection method gssapi-with-mic [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: attempt 1 failures 0
> > [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: userauth-request for
> user
> > ouruser service ssh-connection method keyboard-interactive [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: attempt 2 failures 0
> > [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: keyboard-interactive
> devs
> > [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: auth2_challenge:
> > user=ouruser devs= [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: kbdint_alloc: devices
> > 'pam' [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: debug1: auth2_challenge_start:
> > trying authentication method 'pam' [preauth]
> > Feb 10 14:56:39 ourserver sshd[3085147]: Postponed keyboard-interactive
> for
> > ouruser from x.x.x.x port 35046 ssh2 [preauth]
> > Feb 10 14:56:42 ourserver sshd[3085152]: debug1: do_pam_account: called
> > Feb 10 14:56:42 ourserver sshd[3085147]: debug1: PAM: num PAM env
> strings 2
> > Feb 10 14:56:42 ourserver sshd[3085147]: Postponed
> keyboard-interactive/pam
> > for ouruser from x.x.x.x port 35046 ssh2 [preauth]
> > Feb 10 14:56:42 ourserver sshd[3085147]: debug1: do_pam_account: called
> >
> > I do see the error that sticks out is " Server host/
> > ourserver.edu(a)ourserver.edu not found in Kerberos database" but we have
> > students that log in from all over the world so do all clients need to
> be
> > added? iptables, firewalld, and nftables are off and disabled. No hbac
> > rules:
> > ipa hbacrule-find
> > --------------------
> > 2 HBAC rules matched
> > --------------------
> > Rule name: allow_all
> > User category: all
> > Host category: all
> > Service category: all
> > Description: Allow all users to access any host from any host
> > Enabled: TRUE
> >
> > Rule name: allow_systemd-user
> > User category: all
> > Host category: all
> > Description: Allow pam_systemd to run user@.service to create a
> system
> > user session
> > Enabled: TRUE
> > ----------------------------
> > Number of entries returned 2
> >
> > Am I missing something obvious to regulars?
> >
> >
> > On Tue, Feb 9, 2021 at 12:34 PM Robert Kudyba <rkudyba(a)fordham.edu>
> wrote:
> >
> > > On Tue, Feb 9, 2021 at 12:20 PM Sumit Bose via FreeIPA-users <
> > > freeipa-users(a)lists.fedorahosted.org> wrote:
> > >
> > >> On Tue, Feb 09, 2021 at 11:33:15AM -0500, Robert Kudyba via
> FreeIPA-users
> > >> wrote:
> > >> > >
> > >> > > looks like sshd is trying to read
> /home/ouruser/.ssh/authorized_keys
> > >> and
> > >> > > is stuck. Can you read this file from the command line? Is
it
> e.g. on
> > >> > > NFS which might not be properly mounted?
> > >> > >
> > >> > > Does it work if you skip pubkey authentication
> > >> > >
> > >> > > ssh -o PubkeyAuthentication=no -vv -k ouruser@ourserver
> > >> > >
> > >> > > bye,
> > >> > > Sumit
> > >> > >
> > >> >
> > >> > Thanks for the suggestion. What happens is the NIS password
works.
> The
> > >> > FreeIPA password, which I update with:
> > >> > ipa user-mod ouruser --setattr "userpassword=xxxx",
fails with the
> below
> > >> > errors/logs
> > >> >
> > >> > Feb 9 11:10:34 ourserver sshd[381563]: debug1: Forked child
> 536086.
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: Set
> > >> > /proc/self/oom_score_adj to 0
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: rexec start in 5
> out 5
> > >> > newsock 5 pipe 7 sock 8
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: inetd sockets
after
> > >> > dupping: 4, 4
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: Connection from x.x.x.x
> port
> > >> 53332
> > >> > on 150.108.64.156 port 22 rdomain ""
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: Local version
> string
> > >> > SSH-2.0-OpenSSH_8.4
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: Remote protocol
> version
> > >> > 2.0, remote software version OpenSSH_8.4
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: match:
OpenSSH_8.4
> pat
> > >> > OpenSSH* compat 0x04000000
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SELinux support
> disabled
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
> permanently_set_uid:
> > >> 74/74
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
list_hostkey_types:
> > >> > rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519
> > >> [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_KEXINIT
> sent
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_KEXINIT
> > >> received
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex: algorithm:
> > >> > curve25519-sha256 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex: host key
> algorithm:
> > >> > ecdsa-sha2-nistp256 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
client->server
> > >> cipher:
> > >> > aes256-gcm(a)openssh.com MAC: <implicit> compression: none
[preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
server->client
> > >> cipher:
> > >> > aes256-gcm(a)openssh.com MAC: <implicit> compression: none
[preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
> curve25519-sha256
> > >> > need=32 dh_need=32 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
> curve25519-sha256
> > >> > need=32 dh_need=32 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: expecting
> > >> > SSH2_MSG_KEX_ECDH_INIT [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: rekey out after
> > >> 4294967296
> > >> > blocks [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_NEWKEYS
> sent
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: Sending
> > >> SSH2_MSG_EXT_INFO
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: expecting
> > >> SSH2_MSG_NEWKEYS
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_NEWKEYS
> > >> received
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: rekey in after
> > >> 4294967296
> > >> > blocks [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: KEX done
[preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: userauth-request
> for
> > >> user
> > >> > ouruser service ssh-connection method none [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: attempt 0
failures
> 0
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: PAM: initializing
> for
> > >> > "ouruser"
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: PAM: setting
> PAM_RHOST
> > >> to
> > >> > "x.x.x.x"
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: PAM: setting
> PAM_TTY to
> > >> > "ssh"
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: userauth-request
> for
> > >> user
> > >> > ouruser service ssh-connection method keyboard-interactive
> [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: attempt 1
failures
> 0
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
> keyboard-interactive
> > >> devs
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: auth2_challenge:
> > >> > user=ouruser devs= [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kbdint_alloc:
> devices
> > >> 'pam'
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
> auth2_challenge_start:
> > >> > trying authentication method 'pam' [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: Postponed
> keyboard-interactive
> > >> for
> > >> > ouruser from x.x.x.x port 53332 ssh2 [preauth]
> > >> > Feb 9 11:10:39 ourserver sshd[536091]: pam_unix(sshd:auth):
> > >> authentication
> > >> > failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x
> > >> user=ouruser
> > >> > Feb 9 11:10:39 ourserver sshd[536091]: pam_sss(sshd:auth):
> > >> authentication
> > >> > failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x
> user=ouruser
> > >> > Feb 9 11:10:39 ourserver sshd[536091]: pam_sss(sshd:auth):
> received for
> > >> > user ouruser: 9 (Authentication service cannot retrieve
> authentication
> > >> info)
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: error: PAM:
Authentication
> > >> failure
> > >> > for ouruser from x.x.x.x
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: Failed
> keyboard-interactive/pam
> > >> for
> > >> > ouruser from x.x.x.x port 53332 ssh2
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: userauth-request
> for
> > >> user
> > >> > ouruser service ssh-connection method keyboard-interactive
> [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: attempt 2
failures
> 1
> > >> > [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1:
> keyboard-interactive
> > >> devs
> > >> > [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: auth2_challenge:
> > >> > user=ouruser devs= [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: kbdint_alloc:
> devices
> > >> 'pam'
> > >> > [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1:
> auth2_challenge_start:
> > >> > trying authentication method 'pam' [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: Postponed
> keyboard-interactive
> > >> for
> > >> > ouruser from x.x.x.x port 53332 ssh2 [preauth]
> > >> >
> > >> >
> > >> > Feb 9 11:10:34 ourserver sshd[381563]: debug1: Forked child
> 536086.
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: Set
> > >> > /proc/self/oom_score_adj to 0
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: rexec start in 5
> out 5
> > >> > newsock 5 pipe 7 sock 8
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: inetd sockets
after
> > >> > dupping: 4, 4
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: Connection from x.x.x.x
> port
> > >> 53332
> > >> > on 150.108.64.156 port 22 rdomain ""
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: Local version
> string
> > >> > SSH-2.0-OpenSSH_8.4
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: Remote protocol
> version
> > >> > 2.0, remote software version OpenSSH_8.4
> > >> > Feb 9 11:10:34 ourserver sshd[536086]: debug1: match:
OpenSSH_8.4
> pat
> > >> > OpenSSH* compat 0x04000000
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SELinux support
> disabled
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
> permanently_set_uid:
> > >> 74/74
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
list_hostkey_types:
> > >> > rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519
> > >> [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_KEXINIT
> sent
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_KEXINIT
> > >> received
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex: algorithm:
> > >> > curve25519-sha256 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex: host key
> algorithm:
> > >> > ecdsa-sha2-nistp256 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
client->server
> > >> cipher:
> > >> > aes256-gcm(a)openssh.com MAC: <implicit> compression: none
[preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
server->client
> > >> cipher:
> > >> > aes256-gcm(a)openssh.com MAC: <implicit> compression: none
[preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
> curve25519-sha256
> > >> > need=32 dh_need=32 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kex:
> curve25519-sha256
> > >> > need=32 dh_need=32 [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: expecting
> > >> > SSH2_MSG_KEX_ECDH_INIT [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: rekey out after
> > >> 4294967296
> > >> > blocks [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_NEWKEYS
> sent
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: Sending
> > >> SSH2_MSG_EXT_INFO
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: expecting
> > >> SSH2_MSG_NEWKEYS
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: SSH2_MSG_NEWKEYS
> > >> received
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: rekey in after
> > >> 4294967296
> > >> > blocks [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: KEX done
[preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: userauth-request
> for
> > >> user
> > >> > ouruser service ssh-connection method none [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: attempt 0
failures
> 0
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: PAM: initializing
> for
> > >> > "ouruser"
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: PAM: setting
> PAM_RHOST
> > >> to
> > >> > "x.x.x.x"
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: PAM: setting
> PAM_TTY to
> > >> > "ssh"
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: userauth-request
> for
> > >> user
> > >> > ouruser service ssh-connection method keyboard-interactive
> [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: attempt 1
failures
> 0
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
> keyboard-interactive
> > >> devs
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: auth2_challenge:
> > >> > user=ouruser devs= [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1: kbdint_alloc:
> devices
> > >> 'pam'
> > >> > [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: debug1:
> auth2_challenge_start:
> > >> > trying authentication method 'pam' [preauth]
> > >> > Feb 9 11:10:35 ourserver sshd[536086]: Postponed
> keyboard-interactive
> > >> for
> > >> > ouruser from x.x.x.x port 53332 ssh2 [preauth]
> > >> > Feb 9 11:10:39 ourserver sshd[536091]: pam_unix(sshd:auth):
> > >> authentication
> > >> > failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x
> > >> user=ouruser
> > >> > Feb 9 11:10:39 ourserver sshd[536091]: pam_sss(sshd:auth):
> > >> authentication
> > >> > failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x
> user=ouruser
> > >> > Feb 9 11:10:39 ourserver sshd[536091]: pam_sss(sshd:auth):
> received for
> > >> > user ouruser: 9 (Authentication service cannot retrieve
> authentication
> > >> info)
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: error: PAM:
Authentication
> > >> failure
> > >> > for ouruser from x.x.x.x
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: Failed
> keyboard-interactive/pam
> > >> for
> > >> > ouruser from x.x.x.x port 53332 ssh2
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: userauth-request
> for
> > >> user
> > >> > ouruser service ssh-connection method keyboard-interactive
> [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: attempt 2
failures
> 1
> > >> > [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1:
> keyboard-interactive
> > >> devs
> > >> > [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: auth2_challenge:
> > >> > user=ouruser devs= [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1: kbdint_alloc:
> devices
> > >> 'pam'
> > >> > [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: debug1:
> auth2_challenge_start:
> > >> > trying authentication method 'pam' [preauth]
> > >> > Feb 9 11:10:41 ourserver sshd[536086]: Postponed
> keyboard-interactive
> > >> for
> > >> > ouruser from x.x.x.x port 53332 ssh2 [preauth]
> > >> >
> > >> > With the NIS password the logs show this:
> > >>
> > >> Hi,
> > >>
> > >> did you drop what happened before or is this the only debug output
> for
> > >> the NIS password?
> > >>
> > >
> > > The below here are just logs from /var/log/secure for the user that
> > > successfully logs in with his/her NIS password.
> > >
> > > By "drop what happened before" do you mean the original log snip?
Yes
> I
> > > removed those in an attempt to shorten the message content.
> > >
> > > > Feb 9 11:16:57 debug1: do_pam_account: called
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1: PAM: num PAM env
> > >> strings 2
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: Postponed
> > >> keyboard-interactive/pam
> > >> > for cai from 150.108.68.26 port 53646 ssh2 [preauth]
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1: do_pam_account:
> called
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: Accepted
> > >> keyboard-interactive/pam
> > >> > for cai from 150.108.68.26 port 53646 ssh2
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1:
> monitor_child_preauth:
> > >> cai
> > >> > has been authenticated by privileged process
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1: monitor_read_log:
> child
> > >> log
> > >> > fd closed
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1: audit_event:
> unhandled
> > >> > event 2
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1:
> temporarily_use_uid:
> > >> > 5879/200 (e=0/0)
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1:
> ssh_gssapi_storecreds:
> > >> Not
> > >> > a GSSAPI mechanism
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1: restore_uid: 0/0
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1: SELinux support
> disabled
> > >> > Feb 9 11:16:57 ourserver sshd[536226]: debug1: PAM: establishing
> > >> > credentials
> > >> > Feb 9 11:16:57 ourserver systemd[536237]:
> > >> pam_unix(systemd-user:session):
> > >> > session opened for user cai(uid=5879) by (uid=0)
> > >> >
> > >> > What options should be set in /etc/ssh/sshd_config? Is sssd
> necessary
> > >> for
> > >> > this to work with the FreeIPA password
> > >>
> > >
> > >
> > > Yes, SSSD must be configured and runnnig. ssd does appear to be
> working
> > > fine and in /etc/ipa/ca.crt and the service is running correctly:
> > >
> > > [
domain/ourdomain.edu]
> > >
> > > id_provider = ipa
> > > ipa_server_mode = True
> > > ipa_server =
ourdomain.edu
> > > ipa_domain =
ourdomain.edu
> > > ipa_hostname =
ourdomain.edu
> > > auth_provider = ipa
> > > chpass_provider = ipa
> > > access_provider = ipa
> > > cache_credentials = True
> > > ldap_tls_cacert = /etc/ipa/ca.crt
> > > krb5_store_password_if_offline = True
> > > [sssd]
> > > services = nss, pam, ifp, ssh, sudo
> > >
> > > domains =
ourdomain.edu
> > > [nss]
> > > homedir_substring = /home
> > > memcache_timeout = 600
> > >
> > > [ifp]
> > > allowed_uids = ipaapi, root
> > >
> > > systemctl status sssd
> > > * sssd.service - System Security Services Daemon
> > > Loaded: loaded (/usr/lib/systemd/system/sssd.service; enabled;
> vendor
> > > preset: enabled)
> > > Active: active (running) since Fri 2021-01-29 14:31:34 EST; 1
> weeks 3
> > > days ago
> > >
> > >
>
> > _______________________________________________
> > FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
> > To unsubscribe send an email to
> freeipa-users-leave(a)lists.fedorahosted.org
> > Fedora Code of Conduct:
>
https://urldefense.proofpoint.com/v2/url?u=https-3A__docs.fedoraproject.o...
> > List Guidelines:
>
https://urldefense.proofpoint.com/v2/url?u=https-3A__fedoraproject.org_wi...
> > List Archives:
>
https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.fedorahosted.o...
> _______________________________________________
> FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
> To unsubscribe send an email to
> freeipa-users-leave(a)lists.fedorahosted.org
> Fedora Code of Conduct:
>
https://urldefense.proofpoint.com/v2/url?u=https-3A__docs.fedoraproject.o...
> List Guidelines:
>
https://urldefense.proofpoint.com/v2/url?u=https-3A__fedoraproject.org_wi...
> List Archives:
>
https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.fedorahosted.o...
> Do not reply to spam on the list, report it:
>
https://urldefense.proofpoint.com/v2/url?u=https-3A__pagure.io_fedora-2Di...
>