[SPARK-29580][TESTS] Add kerberos debug messages for Kafka secure tests

[gaborgsomogyi]

What changes were proposed in this pull request?

org.apache.spark.sql.kafka010.KafkaDelegationTokenSuite failed lately. After had a look at the logs it just shows the following fact without any details:

Caused by: sbt.ForkMain$ForkError: sun.security.krb5.KrbException: Server not found in Kerberos database (7) - Server not found in Kerberos database

Since the issue is intermittent and not able to reproduce it we should add more debug information and wait for reproduction with the extended logs.

Why are the changes needed?

Failing test doesn't give enough debug information.

Does this PR introduce any user-facing change?

No.

How was this patch tested?

I've started the test manually and checked that such additional debug messages show up:

>>> KrbApReq: APOptions are 00000000 00000000 00000000 00000000
>>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType
Looking for keys for: kafka/localhost@EXAMPLE.COM
Added key: 17version: 0
Added key: 23version: 0
Added key: 16version: 0
Found unsupported keytype (3) for kafka/localhost@EXAMPLE.COM
>>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType
Using builtin default etypes for permitted_enctypes
default etypes for permitted_enctypes: 17 16 23.
>>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType
MemoryCache: add 1571936500/174770/16C565221B70AAB2BEFE31A83D13A2F4/client/localhost@EXAMPLE.COM to client/localhost@EXAMPLE.COM|kafka/localhost@EXAMPLE.COM
MemoryCache: Existing AuthList:
#3: 1571936493/200803/8CD70D280B0862C5DA1FF901ECAD39FE/client/localhost@EXAMPLE.COM
#2: 1571936499/985009/BAD33290D079DD4E3579A8686EC326B7/client/localhost@EXAMPLE.COM
#1: 1571936499/995208/B76B9D78A9BE283AC78340157107FD40/client/localhost@EXAMPLE.COM

[gaborgsomogyi]

Please note this is not a solution to the problem, it just adds more debug information.

[gaborgsomogyi]

cc @dongjoon-hyun

[SparkQA]

Test build #112655 has finished for PR 26252 at commit b078116.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.

[SparkQA]

Test build #112657 has finished for PR 26252 at commit 3f27d31.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.

[HeartSaVioR]

Could you check the Jenkins CI build and confirm whether the console output contains all of debug messages you're expecting? The failure is intermittent and we would tend to see failures in CI build result, so would be nice if we can also get the same information from there.

[gaborgsomogyi]

I've double checked and as expected the newly added debug messages appear there:

[info] KafkaDelegationTokenSuite:
Found KeyTab /home/jenkins/workspace/SparkPullRequestBuilder/target/tmp/spark-db895f43-478e-4b8f-8456-d41642cc62d8/zookeeper.keytab for zookeeper/localhost@EXAMPLE.COM
Found ticket for zookeeper/localhost@EXAMPLE.COM to go to krbtgt/EXAMPLE.COM@EXAMPLE.COM expiring on Sat Oct 26 01:54:14 PDT 2019
Found ticket for zkclient/localhost@EXAMPLE.COM to go to krbtgt/EXAMPLE.COM@EXAMPLE.COM expiring on Sat Oct 26 01:54:14 PDT 2019
Entered Krb5Context.initSecContext with state=STATE_NEW
Found ticket for zkclient/localhost@EXAMPLE.COM to go to krbtgt/EXAMPLE.COM@EXAMPLE.COM expiring on Sat Oct 26 01:54:14 PDT 2019
Service ticket not found in the subject
Krb5Context setting mySeqNumber to: 758009537
Krb5Context setting peerSeqNumber to: 0
Created InitSecContextToken:
0000: 01 00 6E 82 01 F9 30 82   01 F5 A0 03 02 01 05 A1  ..n...0.........
0010: 03 02 01 0E A2 07 03 05   00 00 00 00 00 A3 82 01  ................
0020: 0F 61 82 01 0B 30 82 01   07 A0 03 02 01 05 A1 0D  .a...0..........
0030: 1B 0B 45 58 41 4D 50 4C   45 2E 43 4F 4D A2 21 30  ..EXAMPLE.COM.!0
0040: 1F A0 03 02 01 00 A1 18   30 16 1B 09 7A 6F 6F 6B  ........0...zook
0050: 65 65 70 65 72 1B 09 6C   6F 63 61 6C 68 6F 73 74  eeper..localhost
0060: A3 81 CD 30 81 CA A0 03   02 01 11 A2 81 C2 04 81  ...0............
0070: BF A6 DF 93 1A B7 CD DC   B6 45 E6 62 D6 A5 92 09  .........E.b....
0080: 45 3E B7 E4 22 DB 8F 6A   27 3F 08 10 46 1F EE E8  E>.."..j'?..F...
0090: F1 6A 4C 3D 88 46 E8 AD   58 A4 A6 95 11 53 2F B8  .jL=.F..X....S/.
00A0: B7 17 BC 18 71 CF 9E F0   23 4D 0E A0 7A AB 6C 30  ....q...#M..z.l0
00B0: B5 E1 E1 28 6E 24 2D F9   C2 A4 F9 0B D1 DE 00 70  ...(n$-........p
00C0: 71 DE F4 31 1C 1E EE 1C   8B 8C 80 AF 44 D6 19 DB  q..1........D...
00D0: 39 A2 05 EA 98 A5 11 84   63 F3 74 ED 70 BF C0 49  9.......c.t.p..I
00E0: 18 17 DE EB AE 52 C9 80   85 52 7B 0D AF 4D 45 78  .....R...R...MEx
00F0: 67 4E 8C 79 65 9F 82 2F   8D A3 69 89 14 69 9C C4  gN.ye../..i..i..
0100: 49 15 E3 F3 24 E7 B5 85   E6 23 15 4B FA 08 9F 21  I...$....#.K...!
0110: 87 66 EE 27 D7 29 B8 79   BB 5F BF 96 77 40 10 D6  .f.'.).y._..w@..
0120: AC 61 30 FB C0 1D 4D 47   C0 1D 99 82 A9 9F 40 4B  .a0...MG......@K
0130: A4 81 CC 30 81 C9 A0 03   02 01 11 A2 81 C1 04 81  ...0............
0140: BE 87 33 25 BC 4E 8B DE   36 1D FD F3 02 6D 7E 04  ..3%.N..6....m..
0150: C5 7F 54 1E 25 AE AB EE   7A B2 99 3C DB 4C B7 60  ..T.%...z..<.L.`
0160: F0 B6 99 73 CB D4 50 73   1C EE EA D1 F3 F1 FE 49  ...s..Ps.......I
0170: 69 DB 90 2F C5 80 F2 C4   BD 36 9F 05 16 61 50 D5  i../.....6...aP.
0180: 86 3E 01 7A 82 F6 A4 C1   61 0B B2 E3 77 85 91 A7  .>.z....a...w...
0190: F6 3B 4C B6 D1 4E 36 42   D1 38 4F BC 73 9D A0 61  .;L..N6B.8O.s..a
01A0: E3 C4 82 BE 89 6C 87 B7   94 0C 71 9C BE 37 F9 95  .....l....q..7..
01B0: 92 31 68 9E 77 6B D4 EE   EF 8B 8E D2 85 8F DF B5  .1h.wk..........
01C0: D0 3A 35 EF 7D 1A 74 43   13 7D 6F 2D 3F 4B 88 38  .:5...tC..o-?K.8
01D0: D9 DD 6A 98 64 FA B8 9A   4C DC 6A 59 D7 C9 4C 1E  ..j.d...L.jY..L.
01E0: 32 3D DB 05 FF B2 72 56   4B 9A 84 71 E6 39 20 20  2=....rVK..q.9  
01F0: 61 FB 77 02 3E 3D 02 45   94 3D 31 1D BF 03 87     a.w.>=.E.=1....

[HeartSaVioR]

Thanks for the double-check! LGTM.

[dongjoon-hyun]

+1, LGTM.
Thank you for adding this to stabilize Jenkins, @gaborgsomogyi .
Thank you, @srowen and @HeartSaVioR !
Merged to master.