[Freeipa-users] Connection closed by UNKNOWN

Mon Feb 15 15:46:38 UTC 2016

On Mon, Feb 15, 2016 at 06:59:57PM +0530, Rakesh Rajasekharan wrote:
> this is what I have in /var/log/secure
> 
> Feb 15 12:22:33 ipa-xyz sshd[13499]: pam_unix(sshd:auth): authentication
> failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x  user=tempuser
> Feb 15 12:22:33 ipa-xyz sshd[13499]: pam_sss(sshd:auth): authentication
> failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x user=tempuser
> Feb 15 12:22:33 ipa-xyz sshd[13499]: pam_sss(sshd:auth): received for user
> tempuser: 7 (Authentication failure)
> Feb 15 12:22:33 ipa-xyz sshd[13499]: pam_ldap: ldap_simple_bind Can't
> contact LDAP server
> Feb 15 12:22:33 ipa-xyz sshd[13499]: pam_ldap: reconnecting to LDAP
> server...
> Feb 15 12:22:33 ipa-xyz sshd[13499]: pam_ldap: ldap_simple_bind Can't
> contact LDAP server

Why is both pam_ldap and pam_sss in the PAM stack? This seems a bit
wrong..

> Feb 15 12:22:35 ipa-xyz sshd[13499]: Failed password for tempuser from
> x.x.x.x port 34318 ssh2
> Feb 15 12:22:37 ipa-xyz sshd[13500]: Connection closed by x.x.x.x
> Feb 15 12:31:32 ipa-xyz sshd[13859]: Accepted publickey for root from
> x.x.x.x port 56275 ssh2
> Feb 15 12:31:32 ipa-xyz sshd[13859]: pam_unix(sshd:session): session opened
> for user root by (uid=0)
> Feb 15 13:01:32 ipa-xyz sshd[13859]: Received disconnect from x.x.x.x: 11:
> disconnected by user
> 
> but both 389 and 636 ports are listening
> # ] netstat -tunlp |grep 636
> tcp        0      0 :::636                      :::*
> LISTEN      9564/ns-slapd
> 
> #] netstat -tunlp |grep 389
> tcp        0      0 :::7389                     :::*
> LISTEN      9495/ns-slapd
> tcp        0      0 :::389                      :::*
> LISTEN      9564/ns-slapd
> 
> 
> And from /var/log/sssd/sssd_xyz.com.log
> 
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> command: PAM_AUTHENTICATE
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> domain: xyz.com
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> user: tempuser
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> service: sshd
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> tty: ssh
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> ruser:
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> rhost: x.x.x.x
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> authtok type: 1
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> newauthtok type: 0
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> priv: 1
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> cli_pid: 13499
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
> logon name: not set
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]]
> [krb5_auth_prepare_ccache_name] (0x1000): No ccache file for user
> [tempuser] found.
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [fo_resolve_service_send]
> (0x0100): Trying to resolve service 'IPA'
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [get_server_status]
> (0x1000): Status of server 'ipa.xyz.com' is 'working'
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [get_port_status] (0x1000):
> Port status of port 0 for server 'ipa.xyz.com' is 'working'
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [get_server_status]
> (0x1000): Status of server 'ipa.xyz.com' is 'working'
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
> (0x1000): Saving the first resolved server
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
> (0x0200): Found address for server ipa.xyz.com: [x.x.x.x] TTL 7200
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [write_pipe_handler]
> (0x0400): All data has been sent!
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [child_sig_handler]
> (0x1000): Waiting for child [13501].
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [child_sig_handler]
> (0x0100): child [13501] finished successfully.
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [read_pipe_handler]
> (0x0400): EOF received, client finished
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
> (0x0100): Backend returned: (0, 7, <NULL>) [Success]

I think you need to look into krb5_child.log with a high debug_level.

> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
> (0x0100): Sending result [7][xyz.com]
> (Mon Feb 15 12:22:33 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
> (0x0100): Sent result [7][xyz.com]
> 
> 
> 
> Thanks,
> Rakesh
> 
> 
> On Mon, Feb 15, 2016 at 3:45 PM, Jakub Hrozek <jhrozek at redhat.com> wrote:
> 
> > On Mon, Feb 15, 2016 at 10:24:23AM +0530, Rakesh Rajasekharan wrote:
> > > hbac seems to be fine
> > >
> > >
> > > ipa hbactest --user=q-temp --host=x.x.x.x --service=sshd
> > > --------------------
> > > Access granted: True
> > > --------------------
> > >   Matched rules: allow_all
> > >
> > >
> > > I see this in the sssd.log
> > >
> > > (Mon Feb 15 04:49:18 2016) [sssd[nss]] [sss_ncache_check_str] (0x2000):
> > > Checking negative cache for [NCE/USER/xyz.com/q-temp]
> > > (Mon Feb 15 04:49:18 2016) [sssd[nss]] [nss_cmd_getpwnam_search]
> > (0x0100):
> > > Requesting info for [q-temp at xyz.com]
> > > (Mon Feb 15 04:49:18 2016) [sssd[nss]] [check_cache] (0x0400): Cached
> > entry
> > > is valid, returning..
> > > (Mon Feb 15 04:49:18 2016) [sssd[nss]] [nss_cmd_getpwnam_search]
> > (0x0400):
> > > Returning info for user [q-temp at xyz.com]
> > > (Mon Feb 15 04:49:18 2016) [sssd[nss]] [client_recv] (0x0200): Client
> > > disconnected!
> > > (Mon Feb 15 04:49:18 2016) [sssd[nss]] [client_destructor] (0x2000):
> > > Terminated client [0x23d2f80][20]
> > > (Mon Feb 15 04:49:27 2016) [sssd[nss]] [sbus_get_sender_id_send]
> > (0x2000):
> > > Not a sysbus message, quit
> >
> > What does /var/log/secure say?
> >
> > Also you pasted the NSS log, the domain log would be more useful here.
> >