Skip to Content
0
Former Member
Jul 10, 2012 at 08:08 PM

Intermittent/Strange/Kerberos Authentication Issue

522 Views

We're running BO 4 SP2.16 and have an issue where SSO & Manual authentication will stop working. After much worry/thought/testing I believe it is an issue between Tomcat & SIA. When the issue occurs restarting only Tomcat has no affect - authentication both manual and SSO is broken. However, if restart the SIA service authentication begins to work. The only difference I can see between the log excerpts below is near the end with line that starts "** application request ..." The next line is a debug dump of configuration settings and "[Krb5LoginModule] user entered username: @NA.DOMAIN.COM" with the user name missing. I'm really at a loss here and am hoping someone can point me in the right direction. Thank you. /Greg

This excerpt is from when authentication is NOT working.

GSS: Acceptor supports: KRB5

Ticket service name is: HTTP/sapbop2.DOMAIN.COM@NA.DOMAIN.COM

GSS name is: j2ee-bop1@NA.DOMAIN.COM

Using keytab entry for: j2ee-bop1@NA.DOMAIN.COM

** decrypting ticket .. **

with key

Principal: j2ee-bop1@NA.DOMAIN.COM

Type: 1

TimeStamp: Tue Jul 10 13:58:31 CDT 2012

KVNO: -1

Key: [23, f1 1d 74 e2 de 4c cf ac bd 54 4d f1 6d b9 ce 7e ]

decrypted ticket:

Ticket:

encryption type: 23 (DECRYPTED OK)

service principal: HTTP/sapbop2.DOMAIN.COM@NA.DOMAIN.COM

TransitedEncoding:

client: gpre7086@NA.DOMAIN.COM

session key: [ ... ]

[ ... ]

Checking ticket is valid at: Tue Jul 10 14:00:13 CDT 2012 with acceptable clock skew: 300000

Ticket valid from: Tue Jul 10 13:55:58 CDT 2012 till: Tue Jul 10 23:25:55 CDT 2012

Setting context expiry to [1341980755000]

Current wall time is [1341946813096]

** decrypting application request .. **

with key

[23, e9 22 f7 d1 10 22 e4 9d 6f 74 2c d2 33 65 68 cf ]

decrypted application request:

++++ KRB-AP-REQ Message ++++

encryption type: 23 (DECRYPTED OK)

ap options: mutual-required

Ticket:

encryption type: 23

service principal: HTTP/sapbop2.DOMAIN.COM@NA.DOMAIN.COM

client: gpre7086@NA.DOMAIN.COM

subkey: [23, fd 98 1c 6a 68 64 92 c5 b7 90 c ad 4 f b7 12 ]

client time: Tue Jul 10 14:00:13 CDT 2012

cusec: 837

sequence number: 1019012444

++++++++++++++++++++++++++++

Got delegated credential

Delegated credential:

++++ KRB-CRED Message ++++

encryption type: 23 (DECRYPTED OK)

sender address: null

receiver address: null

nonce: -1

timestamp: null

credentials:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, 4d 4e 7d f2 7b 1c 77 74 35 53 b0 7b d1 96 36 83 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 13:26:03 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

renewable till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded renewable preauthent

valid for: all addresses

++++++++++++++++++++++++++++

** creating application response .. **

with key

[23, e9 22 f7 d1 10 22 e4 9d 6f 74 2c d2 33 65 68 cf ]

created application response:

++++ KRB-AP-REP Message ++++

encryption type: 23

sequence number: 70968119

sub session key: null

client time: Tue Jul 10 14:00:13 CDT 2012

cusec: 837

++++++++++++++++++++++++++++

GSS: Initiator supports: KRB5

GSS: Initiator TGS key type:

23

Found acceptor realm: null

GSS: Initiator getting service ticket for: BICMS/spwsbop1-dal.intervoice.int

** requesting service ticket .. **

with credentials:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, 4d 4e 7d f2 7b 1c 77 74 35 53 b0 7b d1 96 36 83 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 13:26:03 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

renewable till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded renewable preauthent

valid for: all addresses

and KDC options: forwardable

for service principal (nt=1): BICMS/spwsbop1-dal.intervoice.int

at realm: NA.DOMAIN.COM

Resolving KDC for realm: NA.DOMAIN.COM

Available KDC found: /10.163.1.15:88

Sending message to KDC: /10.163.1.15:88

Sending TCP request: /10.163.1.15:88

connected; sending length and request...

sent request; reading response length...

read length; reading 4004-byte response...

--- got 4004-byte response, initial byte = 0x6d

Message sent sucessfully to KDC: /10.163.1.15:88

** credentials obtained .. **

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, ca 47 39 8c c3 36 2d 47 cc cd c0 df cf 1e 3a 12 ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:00:14 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

Service ticket obtained:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, ca 47 39 8c c3 36 2d 47 cc cd c0 df cf 1e 3a 12 ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:00:14 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

Setting context expiry to [1341980755000]

Current wall time is [1341946814799]

Doing delegation because of OK_AS_DELEGATE flag

** requesting service ticket .. **

with credentials:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, 4d 4e 7d f2 7b 1c 77 74 35 53 b0 7b d1 96 36 83 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 13:26:03 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

renewable till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded renewable preauthent

valid for: all addresses

and KDC options: forwardable forwarded

for service principal (nt=3): krbtgt/NA.DOMAIN.COM

at realm: NA.DOMAIN.COM

Resolving KDC for realm: NA.DOMAIN.COM

Available KDC found: /10.172.2.5:88

Sending message to KDC: /10.172.2.5:88

Sending TCP request: /10.172.2.5:88

connected; sending length and request...

sent request; reading response length...

read length; reading 3544-byte response...

--- got 3544-byte response, initial byte = 0x6d

Message sent sucessfully to KDC: /10.172.2.5:88

** credentials obtained .. **

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, bc 47 88 19 ed 8 74 d3 74 6a cd 2e 16 a7 8b 74 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 14:00:14 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded preauthent

valid for: all addresses

** creating application request .. **

with credentials

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, ca 47 39 8c c3 36 2d 47 cc cd c0 df cf 1e 3a 12 ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:00:14 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

** application request .. **

++++ KRB-AP-REQ Message ++++

encryption type: 23

ap options: mutual-required

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

client: gpre7086@NA.DOMAIN.COM

subkey: null

client time: Tue Jul 10 14:00:15 CDT 2012

cusec: 0

sequence number: 75250067

++++++++++++++++++++++++++++

Debug is true storeKey false useTicketCache false useKeyTab false doNotPrompt false ticketCache is null isInitiator true KeyTab is null refreshKrb5Config is false principal is null tryFirstPass is false useFirstPass is false storePass is false clearPass is false

[Krb5LoginModule] user entered username: @NA.DOMAIN.COM

default etypes for default_tkt_enctypes: 23.

Acquire TGT using AS Exchange

default etypes for default_tkt_enctypes: 23.

>>> KrbAsReq calling createMessage

>>> KrbAsReq in createMessage

>>> KrbKdcReq send: kdc=148.181.151.115 TCP:88, timeout=30000, number of retries =3, #bytes=135

>>>DEBUG: TCPClient reading 104 bytes

>>> KrbKdcReq send: #bytes read=104

>>> KrbKdcReq send: #bytes read=104

>>> KDCRep: init() encoding tag is 126 req type is 11

>>>KRBError:

sTime is Tue Jul 10 14:00:19 CDT 2012 1341946819000

suSec is 487708

error code is 60

error Message is Generic error (description in e-text)

realm is NA.DOMAIN.COM

sname is krbtgt/NA.DOMAIN.COM

msgType is 30

[Krb5LoginModule] authentication failed

Generic error (description in e-text) (60)

Working log excerpt :

GSS: Acceptor supports: KRB5

Ticket service name is: HTTP/sapbop2.DOMAIN.COM@NA.DOMAIN.COM

GSS name is: j2ee-bop1@NA.DOMAIN.COM

Using keytab entry for: j2ee-bop1@NA.DOMAIN.COM

** decrypting ticket .. **

with key

Principal: j2ee-bop1@NA.DOMAIN.COM

Type: 1

TimeStamp: Tue Jul 10 13:58:31 CDT 2012

KVNO: -1

Key: [23, f1 1d 74 e2 de 4c cf ac bd 54 4d f1 6d b9 ce 7e ]

decrypted ticket:

Ticket:

encryption type: 23 (DECRYPTED OK)

service principal: HTTP/sapbop2.DOMAIN.COM@NA.DOMAIN.COM

TransitedEncoding:

client: gpre7086@NA.DOMAIN.COM

session key: [ ... ]

[ ...]

Checking ticket is valid at: Tue Jul 10 14:03:18 CDT 2012 with acceptable clock skew: 300000

Ticket valid from: Tue Jul 10 13:55:58 CDT 2012 till: Tue Jul 10 23:25:55 CDT 2012

Setting context expiry to [1341980755000]

Current wall time is [1341946998889]

** decrypting application request .. **

with key

[23, e9 22 f7 d1 10 22 e4 9d 6f 74 2c d2 33 65 68 cf ]

decrypted application request:

++++ KRB-AP-REQ Message ++++

encryption type: 23 (DECRYPTED OK)

ap options: mutual-required

Ticket:

encryption type: 23

service principal: HTTP/sapbop2.DOMAIN.COM@NA.DOMAIN.COM

client: gpre7086@NA.DOMAIN.COM

subkey: [23, 9f 2a 11 d0 83 4f 8b 7f c 85 98 42 94 bc 58 33 ]

client time: Tue Jul 10 14:03:19 CDT 2012

cusec: 839

sequence number: 729583105

++++++++++++++++++++++++++++

Got delegated credential

Delegated credential:

++++ KRB-CRED Message ++++

encryption type: 23 (DECRYPTED OK)

sender address: null

receiver address: null

nonce: -1

timestamp: null

credentials:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, 4d 4e 7d f2 7b 1c 77 74 35 53 b0 7b d1 96 36 83 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 13:26:03 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

renewable till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded renewable preauthent

valid for: all addresses

++++++++++++++++++++++++++++

** creating application response .. **

with key

[23, e9 22 f7 d1 10 22 e4 9d 6f 74 2c d2 33 65 68 cf ]

created application response:

++++ KRB-AP-REP Message ++++

encryption type: 23

sequence number: 133013641

sub session key: null

client time: Tue Jul 10 14:03:19 CDT 2012

cusec: 839

++++++++++++++++++++++++++++

GSS: Initiator supports: KRB5

GSS: Initiator TGS key type:

23

Found acceptor realm: null

GSS: Initiator getting service ticket for: BICMS/spwsbop1-dal.intervoice.int

** requesting service ticket .. **

with credentials:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, 4d 4e 7d f2 7b 1c 77 74 35 53 b0 7b d1 96 36 83 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 13:26:03 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

renewable till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded renewable preauthent

valid for: all addresses

and KDC options: forwardable

for service principal (nt=1): BICMS/spwsbop1-dal.intervoice.int

at realm: NA.DOMAIN.COM

Resolving KDC for realm: NA.DOMAIN.COM

Available KDC found: /170.14.149.31:88

Sending message to KDC: /170.14.149.31:88

Sending TCP request: /170.14.149.31:88

connected; sending length and request...

sent request; reading response length...

read length; reading 4004-byte response...

--- got 4004-byte response, initial byte = 0x6d

Message sent sucessfully to KDC: /170.14.149.31:88

** credentials obtained .. **

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, b 16 64 f5 b8 1b 98 9e c1 35 f8 14 82 a3 ab 2b ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:03:33 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

Service ticket obtained:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, b 16 64 f5 b8 1b 98 9e c1 35 f8 14 82 a3 ab 2b ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:03:33 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

Setting context expiry to [1341980755000]

Current wall time is [1341947013689]

Doing delegation because of OK_AS_DELEGATE flag

** requesting service ticket .. **

with credentials:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, 4d 4e 7d f2 7b 1c 77 74 35 53 b0 7b d1 96 36 83 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 13:26:03 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

renewable till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded renewable preauthent

valid for: all addresses

and KDC options: forwardable forwarded

for service principal (nt=3): krbtgt/NA.DOMAIN.COM

at realm: NA.DOMAIN.COM

Resolving KDC for realm: NA.DOMAIN.COM

Available KDC found: /10.192.1.107:88

Sending message to KDC: /10.192.1.107:88

Sending TCP request: /10.192.1.107:88

connected; sending length and request...

sent request; reading response length...

read length; reading 3544-byte response...

--- got 3544-byte response, initial byte = 0x6d

Message sent sucessfully to KDC: /10.192.1.107:88

** credentials obtained .. **

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, 42 37 4e 8c c 28 e0 1a 84 d6 66 dd 18 30 fc 95 ]

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

valid from: Tue Jul 10 14:03:33 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: krbtgt/NA.DOMAIN.COM@NA.DOMAIN.COM

ticket flags: forwardable forwarded preauthent

valid for: all addresses

** creating application request .. **

with credentials

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, b 16 64 f5 b8 1b 98 9e c1 35 f8 14 82 a3 ab 2b ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:03:33 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

** application request .. **

++++ KRB-AP-REQ Message ++++

encryption type: 23

ap options: mutual-required

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

client: gpre7086@NA.DOMAIN.COM

subkey: null

client time: Tue Jul 10 14:03:33 CDT 2012

cusec: 0

sequence number: 88896824

++++++++++++++++++++++++++++

GSS: Initiator supports: KRB5

GSS: Initiator TGS key type:

23

Found acceptor realm: null

GSS: Initiator getting service ticket for: BICMS/spwsbop1-dal.intervoice.int

Service ticket obtained:

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, b 16 64 f5 b8 1b 98 9e c1 35 f8 14 82 a3 ab 2b ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:03:33 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

Setting context expiry to [1341980755000]

Current wall time is [1341947022782]

Doing delegation because of OK_AS_DELEGATE flag

** creating application request .. **

with credentials

Credential

client: gpre7086@NA.DOMAIN.COM

session key: [23, b 16 64 f5 b8 1b 98 9e c1 35 f8 14 82 a3 ab 2b ]

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

valid from: Tue Jul 10 14:03:33 CDT 2012

valid till: Tue Jul 10 23:25:55 CDT 2012

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

ticket flags: forwardable forwarded ok-as-delegate preauthent

valid for: all addresses

** application request .. **

++++ KRB-AP-REQ Message ++++

encryption type: 23

ap options: mutual-required

Ticket:

encryption type: 23

service principal: BICMS/spwsbop1-dal.intervoice.int@NA.DOMAIN.COM

client: gpre7086@NA.DOMAIN.COM

subkey: null

client time: Tue Jul 10 14:03:42 CDT 2012

cusec: 0

sequence number: 7237059

++++++++++++++++++++++++++++

** decrypting application response .. **

with key

[23, b 16 64 f5 b8 1b 98 9e c1 35 f8 14 82 a3 ab 2b ]

decrypted application response:

++++ KRB-AP-REP Message ++++

encryption type: 23 (DECRYPTED OK)

sequence number: 975971548

sub session key: [23, b5 60 66 37 e6 83 8b e8 ef 77 8e a df 8 b0 0 ]

client time: Tue Jul 10 14:03:42 CDT 2012

cusec: 783000

++++++++++++++++++++++++++++