changeset 15359:551f7617b2c0

8087144: sun/security/krb5/auto/MaxRetries.java fails with Retry count is -1 less 8153146: sun/security/krb5/auto/MaxRetries.java failed with timeout Reviewed-by: xuelei
author weijun
date Wed, 17 Aug 2016 10:08:18 +0800
parents 8ac7cd5006c8
children 508f985a1f6c b6849a26ac51
files test/sun/security/krb5/auto/CommMatcher.java test/sun/security/krb5/auto/MaxRetries.java
diffstat 2 files changed, 184 insertions(+), 35 deletions(-) [+]
line wrap: on
line diff
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/sun/security/krb5/auto/CommMatcher.java	Wed Aug 17 10:08:18 2016 +0800
@@ -0,0 +1,86 @@
+/*
+ * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
+
+/**
+ * Matches the krb5 debug output:
+ * >>> KDCCommunication: kdc=host UDP:11555, timeout=100,Attempt =1, #bytes=138
+ *
+ * Example:
+ *   CommMatcher cm = new CommMatcher();
+ *   cm.addPort(12345).addPort(23456);
+ *   for (String line : debugOutput) {
+ *       if (cm.match(line)) {
+ *           println("KDC: %c, %s, Timeout: %d\n",
+ *              cm.kdc(), cm.protocol(), cm.timeout());
+ *       }
+ *   }
+ */
+public class CommMatcher {
+
+    static final Pattern re = Pattern.compile(
+            ">>> KDCCommunication: kdc=\\S+ (TCP|UDP):(\\d+), " +
+                    "timeout=(\\d+),Attempt\\s*=(\\d+)");
+
+    List<Integer> kdcPorts = new ArrayList<>();
+    Matcher matcher;
+
+    /**
+     * Add KDC ports one by one. The 1st KDC will be 'a' in {@link #kdc()},
+     * 2nd is 'b', etc, etc.
+     */
+    public CommMatcher addPort(int port) {
+        if (port > 0) {
+            kdcPorts.add(port);
+        } else {
+            kdcPorts.clear();
+        }
+        return this;
+    }
+
+    public boolean match(String line) {
+        matcher = re.matcher(line);
+        return matcher.find();
+    }
+
+    public String protocol() {
+        return matcher.group(1);
+    }
+
+    public char kdc() {
+        int port = Integer.parseInt(matcher.group(2));
+        return (char)(kdcPorts.indexOf(port) + 'a');
+    }
+
+    public int timeout() {
+        return BadKdc.toSymbolicSec(Integer.parseInt(matcher.group(3)));
+    }
+
+    public int attempt() {
+        return Integer.parseInt(matcher.group(4));
+    }
+}
--- a/test/sun/security/krb5/auto/MaxRetries.java	Tue Aug 16 21:28:10 2016 +0800
+++ b/test/sun/security/krb5/auto/MaxRetries.java	Wed Aug 17 10:08:18 2016 +0800
@@ -30,6 +30,7 @@
  * @summary support max_retries in krb5.conf
  */
 
+import javax.security.auth.login.LoginException;
 import java.io.*;
 import java.net.DatagramSocket;
 import java.security.Security;
@@ -37,46 +38,86 @@
 public class MaxRetries {
 
     static int idlePort = -1;
+    static CommMatcher cm = new CommMatcher();
 
     public static void main(String[] args)
             throws Exception {
 
         System.setProperty("sun.security.krb5.debug", "true");
-        new OneKDC(null).writeJAASConf();
+        OneKDC kdc = new OneKDC(null).writeJAASConf();
 
         // An idle UDP socket to prevent PortUnreachableException
         DatagramSocket ds = new DatagramSocket();
         idlePort = ds.getLocalPort();
 
+        cm.addPort(idlePort);
+        cm.addPort(kdc.getPort());
+
         System.setProperty("java.security.krb5.conf", "alternative-krb5.conf");
 
-        // For tryLast
         Security.setProperty("krb5.kdc.bad.policy", "trylast");
+
+        // We always make the real timeout to be 1 second
+        BadKdc.setRatio(0.25f);
         rewriteMaxRetries(4);
-        test1(4000, 6);         // 1 1 1 1 2 2
-        test1(4000, 2);         // 2 2
 
+        // Explanation: In this case, max_retries=4 and timeout=4s.
+        // For AS-REQ without preauth, we will see 4 4s timeout on kdc#1
+        // ("a4" repeat 4 times), and one 4s timeout on kdc#2 ("b4"). For
+        // AS-REQ with preauth, one 4s timeout on kdc#2 (second "b4").
+        // we tolerate 4 real timeout on kdc#2, so make it "(b4){2,6}".
+        test1("a4a4a4a4b4b4", "a4a4a4a4(b4){2,6}");
+        test1("b4b4", "(b4){2,6}");
+
+        BadKdc.setRatio(1f);
         rewriteMaxRetries(1);
-        test1(1000, 3);         // 1 2 2
-        test1(1000, 2);         // 2 2
+        // Explanation: Since max_retries=1 only, we could fail in 1st or 2nd
+        // AS-REQ to kdc#2.
+        String actual = test1("a1b1b1", "(a1b1b1|a1b1x|a1b1b1x)");
+        if (actual.endsWith("x")) {
+            // If 1st attempt fails, all bads are back available
+            test1("a1b1b1", "(a1b1b1|a1b1x|a1b1b1x)");
+        } else {
+            test1("b1b1", "(b1b1|b1x|b1b1x)");
+        }
 
+        BadKdc.setRatio(0.2f);
         rewriteMaxRetries(-1);
-        test1(5000, 4);         // 1 1 2 2
-        test1(5000, 2);         // 2 2
+        test1("a5a5a5b5b5", "a5a5a5(b5){2,4}");
+        test1("b5b5", "(b5){2,4}");
 
-        // For tryLess
-        Security.setProperty("krb5.kdc.bad.policy", "tryless:1," + BadKdc.toReal(5000));
+        BadKdc.setRatio(0.25f);
+        Security.setProperty("krb5.kdc.bad.policy",
+                "tryless:1,1000");
         rewriteMaxRetries(4);
-        test1(4000, 7);         // 1 1 1 1 2 1 2
-        test1(4000, 4);         // 1 2 1 2
+        test1("a4a4a4a4b4a4b4", "a4a4a4a4(b4){1,3}a4(b4){1,3}");
+        test1("a4b4a4b4", "a4(b4){1,3}a4(b4){1,3}");
 
+        BadKdc.setRatio(1f);
         rewriteMaxRetries(1);
-        test1(1000, 4);         // 1 2 1 2
-        test1(1000, 4);         // 1 2 1 2
+        actual = test1("a1b1a1b1", "(a1b1|a1b1x|a1b1a1b1|a1b1a1b1x)");
+        if (actual.endsWith("x")) {
+            test1("a1b1a1b1", "(a1b1|a1b1x|a1b1a1b1|a1b1a1b1x)");
+        } else {
+            test1("a1b1a1b1", "(a1b1|a1b1x|a1b1a1b1|a1b1a1b1x)");
+        }
 
+        BadKdc.setRatio(.2f);
         rewriteMaxRetries(-1);
-        test1(5000, 5);         // 1 1 2 1 2
-        test1(5000, 4);         // 1 2 1 2
+        test1("a5a5a5b5a5b5", "a5a5a5(b5){1,2}a5(b5){1,2}");
+        test1("a5b5a5b5", "a5(b5){1,2}a5(b5){1,2}");
+
+        BadKdc.setRatio(1f);
+        rewriteMaxRetries(2);
+        if (BadKdc.toReal(2000) > 1000) {
+            // Explanation: if timeout is longer than 1s in tryLess,
+            // we will see "a1" at 2nd kdc#1 access
+            test1("a2a2b2a1b2", "a2a2(b2){1,2}a1(b2){1,2}");
+        } else {
+            test1("a2a2b2a2b2", "a2a2(b2){1,2}a2(b2){1,2}");
+        }
+
+        BadKdc.setRatio(1f);
 
         rewriteUdpPrefLimit(-1, -1);    // default, no limit
         test2("UDP");
@@ -95,32 +136,52 @@
 
     /**
      * One round of test for max_retries and timeout.
-     * @param timeout the expected timeout
-     * @param count the expected total try
+     *
+     * @param exact the expected exact match, where no timeout
+     *              happens for real KDCs
+     * @param relaxed the expected relaxed match, where some timeout
+     *                could happen for real KDCs
+     * @return the actual result
      */
-    private static void test1(int timeout, int count) throws Exception {
-        String timeoutTag = "timeout=" + BadKdc.toReal(timeout);
+    private static String test1(String exact, String relaxed) throws Exception {
         ByteArrayOutputStream bo = new ByteArrayOutputStream();
         PrintStream oldout = System.out;
         System.setOut(new PrintStream(bo));
-        Context c = Context.fromJAAS("client");
+        boolean failed = false;
+        long start = System.nanoTime();
+        try {
+            Context c = Context.fromJAAS("client");
+        } catch (LoginException e) {
+            failed = true;
+        }
         System.setOut(oldout);
 
         String[] lines = new String(bo.toByteArray()).split("\n");
-        System.out.println("----------------- TEST (" + timeout + "," +
-                count + ") -----------------");
+        System.out.println("----------------- TEST (" + exact
+                + ") -----------------");
+
+        // Result, a series of timeout + kdc#
+        StringBuilder sb = new StringBuilder();
         for (String line: lines) {
-            if (line.startsWith(">>> KDCCommunication")) {
+            if (cm.match(line)) {
                 System.out.println(line);
-                if (line.indexOf(timeoutTag) < 0) {
-                    throw new Exception("Wrong timeout value" + timeoutTag);
-                }
-                count--;
+                sb.append(cm.kdc()).append(cm.timeout());
             }
         }
-        if (count != 0) {
-            throw new Exception("Retry count is " + count + " less");
+        if (failed) {
+            sb.append("x");
         }
+        System.out.println("Time: " + (System.nanoTime() - start) / 1000000000d);
+        String actual = sb.toString();
+        System.out.println("Actual: " + actual);
+        if (actual.equals(exact)) {
+            System.out.println("Exact match: " + exact);
+        } else if (actual.matches(relaxed)) {
+            System.out.println("!!!! Tolerant match: " + relaxed);
+        } else {
+            throw new Exception("Match neither " + exact + " nor " + relaxed);
+        }
+        return actual;
     }
 
     /**
@@ -138,11 +199,11 @@
         String[] lines = new String(bo.toByteArray()).split("\n");
         System.out.println("----------------- TEST -----------------");
         for (String line: lines) {
-            if (line.startsWith(">>> KDCCommunication")) {
+            if (cm.match(line)) {
                 System.out.println(line);
                 count--;
-                if (line.indexOf(proto) < 0) {
-                    throw new Exception("Wrong timeout value");
+                if (!cm.protocol().equals(proto)) {
+                    throw new Exception("Wrong protocol value");
                 }
             }
         }
@@ -165,6 +226,7 @@
             }
             if (s.startsWith("[realms]")) {
                 // Reconfig global setting
+                fw.write("kdc_timeout = 5000\n");
                 if (global != -1) {
                     fw.write("udp_preference_limit = " + global + "\n");
                 }
@@ -183,7 +245,8 @@
 
     /**
      * Set max_retries and timeout value for realm. The global value is always
-     * 2 and 5000.
+     * 3 and 5000.
+     *
      * @param value max_retries and timeout/1000 for a realm, -1 means none.
      */
     private static void rewriteMaxRetries(int value) throws Exception {
@@ -196,7 +259,7 @@
             }
             if (s.startsWith("[realms]")) {
                 // Reconfig global setting
-                fw.write("max_retries = 2\n");
+                fw.write("max_retries = 3\n");
                 fw.write("kdc_timeout = " + BadKdc.toReal(5000) + "\n");
             } else if (s.trim().startsWith("kdc = ")) {
                 if (value != -1) {