[Freeipa-users] Troubleshooting SSO

Tue Apr 7 20:17:30 UTC 2015

On 4/6/15, 2:26 PM, "Gould, Joshua" <Joshua.Gould at osumc.edu> wrote:

On 4/4/15, 9:57 AM, "Sumit Bose" <sbose at redhat.com> wrote:

Really strange but SSO is working from the test Windows box to both the
IPA server and client. No changes were made other than I added the linux
client to the IPA domain. (It was with ipa-client-install, it
auto-discovered the values, which I used and I enrolled it with the admin
ad-user).

Note: ssh connection from Windows test machine to IPA client and IPA
server used the exact same saved putty config other than changing the
hostname.

SSO from Windows to our two IPA clients seems to work intermittently
today. (no config changes on either end)

In both cases, the first attempted to connect via Putty/SSO failed but
signin to password worked. We then disconnected the ssh session and
immediately tried SSO via SSH to the same client SSO worked. We were able
to replicate this for both clients.

SSH output from the failed SSO logins: (Sorry but the kvno and other
command were not captured)

To Test Client01:
-sh-4.2$ export KRB5_TRACE=/dev/stdout
-sh-4.2$ kinit ad-user at TEST.OSUWMC
[23557] 1428416095.525107: Getting initial credentials for
ad-user at TEST.OSUWMC
[23557] 1428416095.527977: Sending request (170 bytes) to TEST.OSUWMC
[23557] 1428416095.529496: Resolving hostname test-dc-vt01.test.osuwmc.
[23557] 1428416095.530694: Sending initial UDP request to dgram
10.0.0.239:88
[23557] 1428416095.531745: Received answer (187 bytes) from dgram
10.0.0.239:88
[23557] 1428416095.531978: Response was not from master KDC
[23557] 1428416095.532006: Received error from KDC: -1765328359/Additional
pre-authentication required
[23557] 1428416095.532039: Processing preauth types: 16, 15, 19, 2
[23557] 1428416095.532053: Selected etype info: etype aes256-cts, salt
"TEST.OSUWMCad-user", params ""
[23557] 1428416095.532094: PKINIT client has no configured identity;
giving up
[23557] 1428416095.532111: PKINIT client has no configured identity;
giving up
[23557] 1428416095.532122: Preauth module pkinit (16) (real) returned:
22/Invalid argument
[23557] 1428416095.532132: PKINIT client has no configured identity;
giving up
[23557] 1428416095.532139: Preauth module pkinit (14) (real) returned:
22/Invalid argument
Password for ad-user at TEST.OSUWMC:
[23557] 1428416098.700510: AS key obtained for encrypted timestamp:
aes256-cts/BA80
[23557] 1428416098.700574: Encrypted timestamp (for 1428416098.622522):
plain 301AA011180F32303135303430373134313435385AA1050203097FBA, encrypted
DDE7C80B8F1F1B5877E7E05764895E024E65D83CA6BFB633E4281384E03D60F27AB6A6EDF68
C161720933FD481FF881BE203238F816D4393
[23557] 1428416098.700600: Preauth module encrypted_timestamp (2) (real)
returned: 0/Success
[23557] 1428416098.700605: Produced preauth for next request: 2
[23557] 1428416098.700626: Sending request (248 bytes) to TEST.OSUWMC
[23557] 1428416098.701350: Resolving hostname test-dc-vt01.test.osuwmc.
[23557] 1428416098.701661: Sending initial UDP request to dgram
10.0.0.239:88
[23557] 1428416098.703161: Received answer (94 bytes) from dgram
10.0.0.239:88
[23557] 1428416098.703374: Response was not from master KDC
[23557] 1428416098.703397: Received error from KDC: -1765328332/Response
too big for UDP, retry with TCP
[23557] 1428416098.703403: Request or response is too big for UDP;
retrying with TCP
[23557] 1428416098.703408: Sending request (248 bytes) to TEST.OSUWMC (tcp
only)
[23557] 1428416098.703735: Resolving hostname test-dc-vt01.test.osuwmc.
[23557] 1428416098.704667: Initiating TCP connection to stream
10.0.0.239:88
[23557] 1428416098.705090: Sending TCP request to stream 10.0.0.239:88
[23557] 1428416098.706260: Received answer (1649 bytes) from stream
10.0.0.239:88
[23557] 1428416098.706268: Terminating TCP connection to stream
10.0.0.239:88
[23557] 1428416098.706486: Response was not from master KDC
[23557] 1428416098.706522: Processing preauth types: 19
[23557] 1428416098.706530: Selected etype info: etype aes256-cts, salt
"TEST.OSUWMCad-user", params ""
[23557] 1428416098.706538: Produced preauth for next request: (empty)
[23557] 1428416098.706546: AS key determined by preauth: aes256-cts/BA80
[23557] 1428416098.706600: Decrypted AS reply; session key is:
aes256-cts/21BF
[23557] 1428416098.706605: FAST negotiation: unavailable
[23557] 1428416098.706629: Initializing
KEYRING:persistent:2398410:krb_ccache_v8K2ML2 with default princ
ad-user at TEST.OSUWMC
[23557] 1428416098.706675: Removing ad-user at TEST.OSUWMC ->
krbtgt/TEST.OSUWMC at TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_v8K2ML2
[23557] 1428416098.706683: Storing ad-user at TEST.OSUWMC ->
krbtgt/TEST.OSUWMC at TEST.OSUWMC in
KEYRING:persistent:2398410:krb_ccache_v8K2ML2
[23557] 1428416098.706754: Storing config in
KEYRING:persistent:2398410:krb_ccache_v8K2ML2 for
krbtgt/TEST.OSUWMC at TEST.OSUWMC: pa_type: 2
[23557] 1428416098.706771: Removing ad-user at TEST.OSUWMC ->
krb5_ccache_conf_data/pa_type/krbtgt\/TEST.OSUWMC\@TEST.OSUWMC at X-CACHECONF:
from KEYRING:persistent:2398410:krb_ccache_v8K2ML2
[23557] 1428416098.706778: Storing ad-user at TEST.OSUWMC ->
krb5_ccache_conf_data/pa_type/krbtgt\/TEST.OSUWMC\@TEST.OSUWMC at X-CACHECONF:
in KEYRING:persistent:2398410:krb_ccache_v8K2ML2
-sh-4.2$ kvno host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[23558] 1428416110.253431: Getting credentials ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC using ccache
KEYRING:persistent:2398410:krb_ccache_v8K2ML2
[23558] 1428416110.253762: Retrieving ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_v8K2ML2 with result:
-1765328243/Matching credential not found
[23558] 1428416110.253818: Retrieving ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at UNIX.TEST.OSUWMCfrom
KEYRING:persistent:2398410:krb_ccache_v8K2ML2 with result:
-1765328243/Matching credential not found
[23558] 1428416110.253884: Retrieving ad-user at TEST.OSUWMC ->
krbtgt/TEST.OSUWMC at TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_v8K2ML2 with result: 0/Success
[23558] 1428416110.253893: Starting with TGT for client realm:
ad-user at TEST.OSUWMC -> krbtgt/TEST.OSUWMC at TEST.OSUWMC
[23558] 1428416110.253938: Retrieving ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at UNIX.TEST.OSUWMCfrom
KEYRING:persistent:2398410:krb_ccache_v8K2ML2 with result:
-1765328243/Matching credential not found
[23558] 1428416110.253950: Requesting TGT
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC using TGT
krbtgt/TEST.OSUWMC at TEST.OSUWMC
[23558] 1428416110.253993: Generated subkey for TGS request:
aes256-cts/254A
[23558] 1428416110.254042: etypes requested in TGS request: aes256-cts,
aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts
[23558] 1428416110.254198: Encoding request body and padata into FAST
request
[23558] 1428416110.254278: Sending request (1847 bytes) to TEST.OSUWMC
[23558] 1428416110.255292: Resolving hostname test-dc-vt01.test.osuwmc.
[23558] 1428416110.255979: Sending initial UDP request to dgram
10.0.0.239:88
[23558] 1428416110.257177: Received answer (99 bytes) from dgram
10.0.0.239:88
[23558] 1428416110.257431: Response was not from master KDC
[23558] 1428416110.257454: Request or response is too big for UDP;
retrying with TCP
[23558] 1428416110.257460: Sending request (1847 bytes) to TEST.OSUWMC
(tcp only)
[23558] 1428416110.257728: Resolving hostname test-dc-vt02.test.osuwmc.
[23558] 1428416110.258043: Initiating TCP connection to stream
10.0.0.240:88
[23558] 1428416110.258388: Sending TCP request to stream 10.0.0.240:88
[23558] 1428416110.259470: Received answer (1581 bytes) from stream
10.0.0.240:88
[23558] 1428416110.259479: Terminating TCP connection to stream
10.0.0.240:88
[23558] 1428416110.259733: Response was not from master KDC
[23558] 1428416110.259763: Decoding FAST response
[23558] 1428416110.259866: TGS reply is for ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMCwith session key aes256-cts/B18C
[23558] 1428416110.259892: TGS request result: 0/Success
[23558] 1428416110.259902: Removing ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_v8K2ML2
[23558] 1428416110.259909: Storing ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC in
KEYRING:persistent:2398410:krb_ccache_v8K2ML2
[23558] 1428416110.259993: Received TGT for service realm:
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC
[23558] 1428416110.260000: Requesting tickets for
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC, referrals on
[23558] 1428416110.260017: Generated subkey for TGS request:
aes256-cts/7B9B
[23558] 1428416110.260048: etypes requested in TGS request: aes256-cts,
aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts
[23558] 1428416110.260112: Encoding request body and padata into FAST
request
[23558] 1428416110.260175: Sending request (1883 bytes) to
UNIX.TEST.OSUWMC (tcp only)
[23558] 1428416110.260222: Initiating TCP connection to stream
10.127.26.73:88
[23558] 1428416110.260275: Sending TCP request to stream 10.127.26.73:88
[23558] 1428416110.270716: Received answer (1837 bytes) from stream
10.127.26.73:88
[23558] 1428416110.270731: Terminating TCP connection to stream
10.127.26.73:88
[23558] 1428416110.270787: Response was from master KDC
[23558] 1428416110.270802: Decoding FAST response
[23558] 1428416110.270883: FAST reply key: aes256-cts/84BD
[23558] 1428416110.270917: TGS reply is for ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC with session key
aes256-cts/52FE
[23558] 1428416110.270938: TGS request result: 0/Success
[23558] 1428416110.270943: Received creds for desired service
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[23558] 1428416110.270951: Removing ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_v8K2ML2
[23558] 1428416110.270958: Storing ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC in
KEYRING:persistent:2398410:krb_ccache_v8K2ML2
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC: kvno = 2
-sh-4.2$ ssh -v -l ad-user at test.osuwmc ipa-vp01.unix.test.osuwmc
OpenSSH_6.6.1, OpenSSL 1.0.1e-fips 11 Feb 2013
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 56: Applying options for *
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p
22 ipa-vp01.unix.test.osuwmc
debug1: SELinux support enabled
debug1: permanently_drop_suid: 2398410
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_rsa type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_rsa-cert type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_dsa type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_dsa-cert type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ecdsa type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ecdsa-cert type
-1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ed25519 type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ed25519-cert
type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.6.1
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.6.1
debug1: match: OpenSSH_6.6.1 pat OpenSSH_6.6.1* compat 0x04000000
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-ctr hmac-md5-etm at openssh.com none
debug1: kex: client->server aes128-ctr hmac-md5-etm at openssh.com none
debug1: kex: curve25519-sha256 at libssh.org need=16 dh_need=16
debug1: kex: curve25519-sha256 at libssh.org need=16 dh_need=16
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA
a2:57:a3:0f:09:87:d3:de:d5:9f:34:30:55:7b:2b:2f
The authenticity of host 'ipa-vp01.unix.test.osuwmc (<no hostip for
proxy command>)' can't be established.
ECDSA key fingerprint is a2:57:a3:0f:09:87:d3:de:d5:9f:34:30:55:7b:2b:2f.
Are you sure you want to continue connecting (yes/no)?
Host key verification failed.
-sh-4.2$

To Test Client 02:
-sh-4.2$ export KRB5_TRACE=/dev/stdout
-sh-4.2$ kinit ad-user at TEST.OSUWMC
[18737] 1428416089.475861: Getting initial credentials for
ad-user at TEST.OSUWMC
[18737] 1428416089.476283: Sending request (170 bytes) to TEST.OSUWMC
[18737] 1428416089.478142: Resolving hostname test-dc-vt01.test.osuwmc.
[18737] 1428416089.479506: Sending initial UDP request to dgram
10.0.0.239:88
[18737] 1428416089.481046: Received answer (187 bytes) from dgram
10.0.0.239:88
[18737] 1428416089.481416: Response was not from master KDC
[18737] 1428416089.481449: Received error from KDC: -1765328359/Additional
pre-authentication required
[18737] 1428416089.481502: Processing preauth types: 16, 15, 19, 2
[18737] 1428416089.481520: Selected etype info: etype aes256-cts, salt
"TEST.OSUWMCad-user", params ""
Password for ad-user at TEST.OSUWMC:
[18737] 1428416093.323345: AS key obtained for encrypted timestamp:
aes256-cts/BA80
[18737] 1428416093.323414: Encrypted timestamp (for 1428416093.258716):
plain 301AA011180F32303135303430373134313435335AA105020303F29C, encrypted
87E3A643A6E79049617EB83F143B6EA7A4D81E938FD9F1554BF168FB217D46A4D622D47E6CD
5A18F82835113BA3109900EACBBDEAEAE023E
[18737] 1428416093.323443: Preauth module encrypted_timestamp (2) (real)
returned: 0/Success
[18737] 1428416093.323448: Produced preauth for next request: 2
[18737] 1428416093.323569: Sending request (248 bytes) to TEST.OSUWMC
[18737] 1428416093.324696: Resolving hostname test-dc-vt02.test.osuwmc.
[18737] 1428416093.325245: Sending initial UDP request to dgram
10.0.0.240:88
[18737] 1428416093.328637: Received answer (94 bytes) from dgram
10.0.0.240:88
[18737] 1428416093.328999: Response was not from master KDC
[18737] 1428416093.329024: Received error from KDC: -1765328332/Response
too big for UDP, retry with TCP
[18737] 1428416093.329030: Request or response is too big for UDP;
retrying with TCP
[18737] 1428416093.329035: Sending request (248 bytes) to TEST.OSUWMC (tcp
only)
[18737] 1428416093.329431: Resolving hostname test-dc-vt02.test.osuwmc.
[18737] 1428416093.330588: Initiating TCP connection to stream
10.0.0.240:88
[18737] 1428416093.331004: Sending TCP request to stream 10.0.0.240:88
[18737] 1428416093.332070: Received answer (1649 bytes) from stream
10.0.0.240:88
[18737] 1428416093.332079: Terminating TCP connection to stream
10.0.0.240:88
[18737] 1428416093.332468: Response was not from master KDC
[18737] 1428416093.332523: Processing preauth types: 19
[18737] 1428416093.332532: Selected etype info: etype aes256-cts, salt
"TEST.OSUWMCad-user", params ""
[18737] 1428416093.332539: Produced preauth for next request: (empty)
[18737] 1428416093.332548: AS key determined by preauth: aes256-cts/BA80
[18737] 1428416093.332601: Decrypted AS reply; session key is:
aes256-cts/82EC
[18737] 1428416093.332605: FAST negotiation: unavailable
[18737] 1428416093.332630: Initializing
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 with default princ
ad-user at TEST.OSUWMC
[18737] 1428416093.332683: Removing ad-user at TEST.OSUWMC ->
krbtgt/TEST.OSUWMC at TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18737] 1428416093.332692: Storing ad-user at TEST.OSUWMC ->
krbtgt/TEST.OSUWMC at TEST.OSUWMC in
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18737] 1428416093.332764: Storing config in
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 for
krbtgt/TEST.OSUWMC at TEST.OSUWMC: pa_type: 2
[18737] 1428416093.332782: Removing ad-user at TEST.OSUWMC ->
krb5_ccache_conf_data/pa_type/krbtgt\/TEST.OSUWMC\@TEST.OSUWMC at X-CACHECONF:
from KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18737] 1428416093.332790: Storing ad-user at TEST.OSUWMC ->
krb5_ccache_conf_data/pa_type/krbtgt\/TEST.OSUWMC\@TEST.OSUWMC at X-CACHECONF:
in KEYRING:persistent:2398410:krb_ccache_6FRGCV2
-sh-4.2$ kvno host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[18738] 1428416107.49615: Getting credentials ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC using ccache
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18738] 1428416107.49815: Retrieving ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 with result:
-1765328243/Matching credential not found
[18738] 1428416107.49865: Retrieving ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at UNIX.TEST.OSUWMCfrom
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 with result:
-1765328243/Matching credential not found
[18738] 1428416107.49928: Retrieving ad-user at TEST.OSUWMC ->
krbtgt/TEST.OSUWMC at TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 with result: 0/Success
[18738] 1428416107.49937: Starting with TGT for client realm:
ad-user at TEST.OSUWMC -> krbtgt/TEST.OSUWMC at TEST.OSUWMC
[18738] 1428416107.49977: Retrieving ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at UNIX.TEST.OSUWMCfrom
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 with result:
-1765328243/Matching credential not found
[18738] 1428416107.49985: Requesting TGT
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC using TGT
krbtgt/TEST.OSUWMC at TEST.OSUWMC
[18738] 1428416107.50025: Generated subkey for TGS request: aes256-cts/F437
[18738] 1428416107.50074: etypes requested in TGS request: aes256-cts,
aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts
[18738] 1428416107.50201: Encoding request body and padata into FAST
request
[18738] 1428416107.50272: Sending request (1847 bytes) to TEST.OSUWMC
[18738] 1428416107.51530: Resolving hostname test-dc-vt01.test.osuwmc.
[18738] 1428416107.52259: Sending initial UDP request to dgram
10.0.0.239:88
[18738] 1428416107.53561: Received answer (99 bytes) from dgram
10.0.0.239:88
[18738] 1428416107.53964: Response was not from master KDC
[18738] 1428416107.53985: Request or response is too big for UDP; retrying
with TCP
[18738] 1428416107.53990: Sending request (1847 bytes) to TEST.OSUWMC (tcp
only)
[18738] 1428416107.54364: Resolving hostname test-dc-vt01.test.osuwmc.
[18738] 1428416107.54756: Initiating TCP connection to stream
10.0.0.239:88
[18738] 1428416107.55031: Sending TCP request to stream 10.0.0.239:88
[18738] 1428416107.56052: Received answer (1581 bytes) from stream
10.0.0.239:88
[18738] 1428416107.56063: Terminating TCP connection to stream
10.0.0.239:88
[18738] 1428416107.56436: Response was not from master KDC
[18738] 1428416107.56495: Decoding FAST response
[18738] 1428416107.56567: TGS reply is for ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMCwith session key aes256-cts/7E5C
[18738] 1428416107.56589: TGS request result: 0/Success
[18738] 1428416107.56598: Removing ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18738] 1428416107.56605: Storing ad-user at TEST.OSUWMC ->
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC in
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18738] 1428416107.56680: Received TGT for service realm:
krbtgt/UNIX.TEST.OSUWMC at TEST.OSUWMC
[18738] 1428416107.56687: Requesting tickets for
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC, referrals on
[18738] 1428416107.56702: Generated subkey for TGS request: aes256-cts/5751
[18738] 1428416107.56734: etypes requested in TGS request: aes256-cts,
aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts
[18738] 1428416107.56787: Encoding request body and padata into FAST
request
[18738] 1428416107.56845: Sending request (1883 bytes) to UNIX.TEST.OSUWMC
(tcp only)
[18738] 1428416107.56892: Initiating TCP connection to stream
10.127.26.73:88
[18738] 1428416107.57108: Sending TCP request to stream 10.127.26.73:88
[18738] 1428416107.72793: Received answer (1837 bytes) from stream
10.127.26.73:88
[18738] 1428416107.72806: Terminating TCP connection to stream
10.127.26.73:88
[18738] 1428416107.72874: Response was from master KDC
[18738] 1428416107.72892: Decoding FAST response
[18738] 1428416107.73008: FAST reply key: aes256-cts/24D0
[18738] 1428416107.73047: TGS reply is for ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC with session key
aes256-cts/7A6C
[18738] 1428416107.73071: TGS request result: 0/Success
[18738] 1428416107.73075: Received creds for desired service
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[18738] 1428416107.73083: Removing ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18738] 1428416107.73090: Storing ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC in
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC: kvno = 2
-sh-4.2$ ssh -v -l ad-user at test.osuwmc ipa-vp01.unix.test.osuwmc
OpenSSH_6.6.1, OpenSSL 1.0.1e-fips 11 Feb 2013
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 56: Applying options for *
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p
22 ipa-vp01.unix.test.osuwmc
debug1: SELinux support enabled
Could not create directory '/home/test.osuwmc/ad-user/.ssh'.
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_rsa type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_rsa-cert type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_dsa type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_dsa-cert type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ecdsa type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ecdsa-cert type
-1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ed25519 type -1
debug1: identity file /home/test.osuwmc/ad-user/.ssh/id_ed25519-cert
type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.6.1
debug1: permanently_drop_suid: 2398410
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.6.1
debug1: match: OpenSSH_6.6.1 pat OpenSSH_6.6.1* compat 0x04000000
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-ctr hmac-md5-etm at openssh.com none
debug1: kex: client->server aes128-ctr hmac-md5-etm at openssh.com none
debug1: kex: curve25519-sha256 at libssh.org need=16 dh_need=16
debug1: kex: curve25519-sha256 at libssh.org need=16 dh_need=16
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA
a2:57:a3:0f:09:87:d3:de:d5:9f:34:30:55:7b:2b:2f
debug1: Host 'ipa-vp01.unix.test.osuwmc' is known and matches the
ECDSA host key.
debug1: Found key in /var/lib/sss/pubconf/known_hosts:1
debug1: ssh_ecdsa_verify: signature correct
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue:
publickey,gssapi-keyex,gssapi-with-mic,password
debug1: Next authentication method: gssapi-keyex
debug1: No valid Key exchange context
debug1: Next authentication method: gssapi-with-mic
[18739] 1428416121.60316: Convert service host (service with host as
instance) on host ipa-vp01.unix.test.osuwmc to principal
[18739] 1428416121.63528: Remote host after forward canonicalization:
ipa-vp01.unix.test.osuwmc
[18739] 1428416121.63576: Remote host after reverse DNS processing:
ipa-vp01.unix.test.osuwmc
[18739] 1428416121.63615: Got service principal
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[18739] 1428416121.64537: ccselect can't find appropriate cache for server
principal host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[18739] 1428416121.64660: Getting credentials ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC using ccache
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18739] 1428416121.64760: Retrieving ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 with result: 0/Success
[18739] 1428416121.64860: Creating authenticator for
ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC, seqnum 357380851,
subkey aes256-cts/C722, session key aes256-cts/7A6C
[18739] 1428416121.68510: Convert service host (service with host as
instance) on host ipa-vp01.unix.test.osuwmc to principal
[18739] 1428416121.69117: Remote host after forward canonicalization:
ipa-vp01.unix.test.osuwmc
[18739] 1428416121.69131: Remote host after reverse DNS processing:
ipa-vp01.unix.test.osuwmc
[18739] 1428416121.69144: Got service principal
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[18739] 1428416121.69854: ccselect can't find appropriate cache for server
principal host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[18739] 1428416121.69921: Getting credentials ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC using ccache
KEYRING:persistent:2398410:krb_ccache_6FRGCV2
[18739] 1428416121.69983: Retrieving ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC from
KEYRING:persistent:2398410:krb_ccache_6FRGCV2 with result: 0/Success
[18739] 1428416121.70043: Creating authenticator for
ad-user at TEST.OSUWMC ->
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC, seqnum 103136204,
subkey aes256-cts/1442, session key aes256-cts/7A6C
[18739] 1428416123.217669: Convert service host (service with host as
instance) on host ipa-vp01.unix.test.osuwmc to principal
[18739] 1428416123.218358: Remote host after forward canonicalization:
ipa-vp01.unix.test.osuwmc
[18739] 1428416123.218373: Remote host after reverse DNS processing:
ipa-vp01.unix.test.osuwmc
[18739] 1428416123.218392: Got service principal
host/ipa-vp01.unix.test.osuwmc at UNIX.TEST.OSUWMC
[18739] 1428416123.218509: Read AP-REP, time 1428416121.70050, subkey
aes256-cts/519A, seqnum 855383497
debug1: Authentication succeeded (gssapi-with-mic).
Authenticated to ipa-vp01.unix.test.osuwmc (via proxy).
debug1: channel 0: new [client-session]
debug1: Requesting no-more-sessions at openssh.com
debug1: Entering interactive session.
debug1: Sending environment.
debug1: Sending env LANG = en_US.UTF-8
Last login: Tue Apr  7 10:14:30 2015 from 10.0.5
-sh-4.2$