HBASE-21048 Get LogLevel is not working from console in secure environment

Signed-off-by: Reid Chan <reidchan@apache.org>
Amend author: Reid Chan <reidchan@apache.org>

hbase-http/pom.xml

@@ -298,6 +298,11 @@
       <artifactId>mockito-core</artifactId>
       <scope>test</scope>
     </dependency>
+    <dependency>
+      <groupId>org.apache.hadoop</groupId>
+      <artifactId>hadoop-minikdc</artifactId>
+      <scope>test</scope>
+    </dependency>
   </dependencies>
   <profiles>
     <!-- Needs to make the profile in apache parent pom -->

hbase-http/src/main/java/org/apache/hadoop/hbase/http/log/LogLevel.java

@@ -26,63 +26,232 @@ import java.net.URL;
 import java.net.URLConnection;
 import java.util.Objects;
 import java.util.regex.Pattern;
+
 import javax.servlet.ServletException;
 import javax.servlet.http.HttpServlet;
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
+
 import org.apache.commons.logging.impl.Jdk14Logger;
 import org.apache.commons.logging.impl.Log4JLogger;
+import org.apache.hadoop.HadoopIllegalArgumentException;
+import org.apache.hadoop.conf.Configuration;
+import org.apache.hadoop.conf.Configured;
 import org.apache.hadoop.hbase.http.HttpServer;
+import org.apache.hadoop.security.authentication.client.AuthenticatedURL;
+import org.apache.hadoop.security.authentication.client.KerberosAuthenticator;
 import org.apache.hadoop.util.ServletUtil;
+import org.apache.hadoop.util.Tool;
 import org.apache.log4j.LogManager;
 import org.apache.yetus.audience.InterfaceAudience;
 import org.apache.yetus.audience.InterfaceStability;
+
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import org.slf4j.impl.Log4jLoggerAdapter;
 
+import org.apache.hbase.thirdparty.com.google.common.annotations.VisibleForTesting;
+import org.apache.hbase.thirdparty.com.google.common.base.Charsets;
+
 /**
  * Change log level in runtime.
  */
 @InterfaceAudience.Private
 public final class LogLevel {
   private static final String USAGES = "\nUsage: General options are:\n"
-      + "\t[-getlevel <host:httpPort> <name>]\n"
+      + "\t[-getlevel <host:port> <classname>\n"
-      + "\t[-setlevel <host:httpPort> <name> <level>]\n";
+      + "\t[-setlevel <host:port> <classname> <level> ";
 
+  public static final String PROTOCOL_HTTP = "http";
   /**
    * A command line implementation
    */
-  public static void main(String[] args) {
+  public static void main(String[] args) throws Exception {
-    if (args.length == 3 && "-getlevel".equals(args[0])) {
+    CLI cli = new CLI(new Configuration());
-      process("http://" + args[1] + "/logLevel?log=" + args[2]);
+    System.exit(cli.run(args));
-      return;
-    }
-    else if (args.length == 4 && "-setlevel".equals(args[0])) {
-      process("http://" + args[1] + "/logLevel?log=" + args[2]
-              + "&level=" + args[3]);
-      return;
   }
 
+  /**
+   * Valid command line options.
+   */
+  private enum Operations {
+    GETLEVEL,
+    SETLEVEL,
+    UNKNOWN
+  }
+
+  private static void printUsage() {
     System.err.println(USAGES);
     System.exit(-1);
   }
 
-  private static void process(String urlstring) {
+  @VisibleForTesting
+  static class CLI extends Configured implements Tool {
+    private Operations operation = Operations.UNKNOWN;
+    private String hostName;
+    private String className;
+    private String level;
+
+    CLI(Configuration conf) {
+      setConf(conf);
+    }
+
+    @Override
+    public int run(String[] args) throws Exception {
       try {
-      URL url = new URL(urlstring);
+        parseArguments(args);
-      System.out.println("Connecting to " + url);
+        sendLogLevelRequest();
-      URLConnection connection = url.openConnection();
+      } catch (HadoopIllegalArgumentException e) {
+        printUsage();
+      }
+      return 0;
+    }
+
+    /**
+     * Send HTTP request to the daemon.
+     * @throws HadoopIllegalArgumentException if arguments are invalid.
+     * @throws Exception if unable to connect
+     */
+    private void sendLogLevelRequest()
+        throws HadoopIllegalArgumentException, Exception {
+      switch (operation) {
+        case GETLEVEL:
+          doGetLevel();
+          break;
+        case SETLEVEL:
+          doSetLevel();
+          break;
+        default:
+          throw new HadoopIllegalArgumentException(
+              "Expect either -getlevel or -setlevel");
+      }
+    }
+
+    public void parseArguments(String[] args) throws
+        HadoopIllegalArgumentException {
+      if (args.length == 0) {
+        throw new HadoopIllegalArgumentException("No arguments specified");
+      }
+      int nextArgIndex = 0;
+      while (nextArgIndex < args.length) {
+        switch (args[nextArgIndex]) {
+          case "-getlevel":
+            nextArgIndex = parseGetLevelArgs(args, nextArgIndex);
+            break;
+          case "-setlevel":
+            nextArgIndex = parseSetLevelArgs(args, nextArgIndex);
+            break;
+          default:
+            throw new HadoopIllegalArgumentException(
+                "Unexpected argument " + args[nextArgIndex]);
+        }
+      }
+
+      // if operation is never specified in the arguments
+      if (operation == Operations.UNKNOWN) {
+        throw new HadoopIllegalArgumentException(
+            "Must specify either -getlevel or -setlevel");
+      }
+    }
+
+    private int parseGetLevelArgs(String[] args, int index) throws
+        HadoopIllegalArgumentException {
+      // fail if multiple operations are specified in the arguments
+      if (operation != Operations.UNKNOWN) {
+        throw new HadoopIllegalArgumentException("Redundant -getlevel command");
+      }
+      // check number of arguments is sufficient
+      if (index + 2 >= args.length) {
+        throw new HadoopIllegalArgumentException("-getlevel needs two parameters");
+      }
+      operation = Operations.GETLEVEL;
+      hostName = args[index + 1];
+      className = args[index + 2];
+      return index + 3;
+    }
+
+    private int parseSetLevelArgs(String[] args, int index) throws
+        HadoopIllegalArgumentException {
+      // fail if multiple operations are specified in the arguments
+      if (operation != Operations.UNKNOWN) {
+        throw new HadoopIllegalArgumentException("Redundant -setlevel command");
+      }
+      // check number of arguments is sufficient
+      if (index + 3 >= args.length) {
+        throw new HadoopIllegalArgumentException("-setlevel needs three parameters");
+      }
+      operation = Operations.SETLEVEL;
+      hostName = args[index + 1];
+      className = args[index + 2];
+      level = args[index + 3];
+      return index + 4;
+    }
+
+    /**
+     * Send HTTP request to get log level.
+     *
+     * @throws HadoopIllegalArgumentException if arguments are invalid.
+     * @throws Exception if unable to connect
+     */
+    private void doGetLevel() throws Exception {
+      process(PROTOCOL_HTTP + "://" + hostName + "/logLevel?log=" + className);
+    }
+
+    /**
+     * Send HTTP request to set log level.
+     *
+     * @throws HadoopIllegalArgumentException if arguments are invalid.
+     * @throws Exception if unable to connect
+     */
+    private void doSetLevel() throws Exception {
+      process(PROTOCOL_HTTP + "://" + hostName + "/logLevel?log=" + className
+          + "&level=" + level);
+    }
+
+    /**
+     * Connect to the URL. Supports HTTP and supports SPNEGO
+     * authentication. It falls back to simple authentication if it fails to
+     * initiate SPNEGO.
+     *
+     * @param url the URL address of the daemon servlet
+     * @return a connected connection
+     * @throws Exception if it can not establish a connection.
+     */
+    private URLConnection connect(URL url) throws Exception {
+      AuthenticatedURL.Token token = new AuthenticatedURL.Token();
+      AuthenticatedURL aUrl;
+      URLConnection connection;
+
+      aUrl = new AuthenticatedURL(new KerberosAuthenticator());
+      connection = aUrl.openConnection(url, token);
       connection.connect();
-      try (InputStreamReader streamReader = new InputStreamReader(connection.getInputStream());
+      return connection;
+    }
+
+    /**
+     * Configures the client to send HTTP request to the URL.
+     * Supports SPENGO for authentication.
+     * @param urlString URL and query string to the daemon's web UI
+     * @throws Exception if unable to connect
+     */
+    private void process(String urlString) throws Exception {
+      URL url = new URL(urlString);
+      System.out.println("Connecting to " + url);
+
+      URLConnection connection = connect(url);
+
+      // read from the servlet
+
+      try (InputStreamReader streamReader =
+            new InputStreamReader(connection.getInputStream(), Charsets.UTF_8);
            BufferedReader bufferedReader = new BufferedReader(streamReader)) {
         bufferedReader.lines().filter(Objects::nonNull).filter(line -> line.startsWith(MARKER))
             .forEach(line -> System.out.println(TAG.matcher(line).replaceAll("")));
-      }
       } catch (IOException ioe) {
         System.err.println("" + ioe);
       }
     }
+  }
 
   private static final String MARKER = "<!-- OUTPUT -->";
   private static final Pattern TAG = Pattern.compile("<[^>]*>");

hbase-http/src/test/java/org/apache/hadoop/hbase/http/log/TestLogLevel.java

@@ -17,87 +17,335 @@
  */
 package org.apache.hadoop.hbase.http.log;
 
+import static org.apache.hadoop.hbase.http.log.LogLevel.PROTOCOL_HTTP;
 import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertFalse;
+import static org.junit.Assert.assertNotEquals;
 import static org.junit.Assert.assertTrue;
 
-import java.io.BufferedReader;
+import java.io.File;
-import java.io.InputStreamReader;
+import java.net.BindException;
-import java.io.PrintStream;
 import java.net.URI;
-import java.net.URL;
+import java.security.PrivilegedExceptionAction;
-import java.util.Objects;
+import java.util.Properties;
+
+import org.apache.commons.io.FileUtils;
+import org.apache.hadoop.HadoopIllegalArgumentException;
+import org.apache.hadoop.conf.Configuration;
+import org.apache.hadoop.fs.CommonConfigurationKeys;
+import org.apache.hadoop.fs.CommonConfigurationKeysPublic;
+import org.apache.hadoop.fs.FileUtil;
 import org.apache.hadoop.hbase.HBaseClassTestRule;
+import org.apache.hadoop.hbase.HBaseCommonTestingUtility;
 import org.apache.hadoop.hbase.http.HttpServer;
+import org.apache.hadoop.hbase.http.log.LogLevel.CLI;
 import org.apache.hadoop.hbase.testclassification.MiscTests;
 import org.apache.hadoop.hbase.testclassification.SmallTests;
+import org.apache.hadoop.minikdc.MiniKdc;
 import org.apache.hadoop.net.NetUtils;
+import org.apache.hadoop.security.UserGroupInformation;
+import org.apache.hadoop.security.authorize.AccessControlList;
+import org.apache.hadoop.test.GenericTestUtils;
 import org.apache.log4j.Level;
 import org.apache.log4j.LogManager;
 import org.apache.log4j.Logger;
+
+import org.junit.AfterClass;
+import org.junit.BeforeClass;
 import org.junit.ClassRule;
 import org.junit.Test;
 import org.junit.experimental.categories.Category;
-import org.slf4j.LoggerFactory;
-import org.slf4j.impl.Log4jLoggerAdapter;
 
+/**
+ * Test LogLevel.
+ */
 @Category({MiscTests.class, SmallTests.class})
 public class TestLogLevel {
   @ClassRule
   public static final HBaseClassTestRule CLASS_RULE =
       HBaseClassTestRule.forClass(TestLogLevel.class);
 
-  private static final PrintStream out = System.out;
+  private static File BASEDIR;
+  private static Configuration serverConf;
+  private static Configuration clientConf;
+  private static final String logName = TestLogLevel.class.getName();
+  private static final Logger log = LogManager.getLogger(logName);
+  private final static String PRINCIPAL = "loglevel.principal";
+  private final static String KEYTAB  = "loglevel.keytab";
 
-  @Test
+  private static MiniKdc kdc;
-  @SuppressWarnings("deprecation")
+  private static HBaseCommonTestingUtility htu = new HBaseCommonTestingUtility();
-  public void testDynamicLogLevel() throws Exception {
-    String logName = TestLogLevel.class.getName();
-    org.slf4j.Logger testlog = LoggerFactory.getLogger(logName);
 
-    // only test Log4JLogger
+  private static final String LOCALHOST = "localhost";
-    if (testlog instanceof Log4jLoggerAdapter) {
+  private static final String clientPrincipal = "client/" + LOCALHOST;
-      Logger log = LogManager.getLogger(logName);
+  private static String HTTP_PRINCIPAL = "HTTP/" + LOCALHOST;
-      log.debug("log.debug1");
-      log.info("log.info1");
-      log.error("log.error1");
-      assertTrue(!Level.ERROR.equals(log.getEffectiveLevel()));
 
-      HttpServer server = null;
+  private static final File KEYTAB_FILE = new File(
-      try {
+      htu.getDataTestDir("keytab").toUri().getPath());
-        server = new HttpServer.Builder().setName("..")
-            .addEndpoint(new URI("http://localhost:0")).setFindPort(true)
-            .build();
 
-        server.start();
+  @BeforeClass
-        String authority = NetUtils.getHostPortString(server
+  public static void setUp() throws Exception {
-            .getConnectorAddress(0));
+    BASEDIR = new File(htu.getDataTestDir().toUri().getPath());
 
-        // servlet
+    FileUtil.fullyDelete(BASEDIR);
-        URL url =
+    if (!BASEDIR.mkdirs()) {
-            new URL("http://" + authority + "/logLevel?log=" + logName + "&level=" + Level.ERROR);
+      throw new Exception("unable to create the base directory for testing");
-        out.println("*** Connecting to " + url);
-        try (BufferedReader in = new BufferedReader(new InputStreamReader(url.openStream()))) {
-          in.lines().filter(Objects::nonNull).forEach(out::println);
     }
-        log.debug("log.debug2");
+    serverConf = new Configuration();
-        log.info("log.info2");
+    clientConf = new Configuration();
-        log.error("log.error2");
-        assertEquals(Level.ERROR, log.getEffectiveLevel());
 
-        //command line
+    kdc = setupMiniKdc();
-        String[] args = {"-setlevel", authority, logName, Level.DEBUG.toString()};
+    // Create two principles: a client and a HTTP principal
-        LogLevel.main(args);
+    kdc.createPrincipal(KEYTAB_FILE, clientPrincipal, HTTP_PRINCIPAL);
-        log.debug("log.debug3");
+  }
-        log.info("log.info3");
+
-        log.error("log.error3");
+  /**
-        assertEquals(Level.DEBUG, log.getEffectiveLevel());
+   * Sets up {@link MiniKdc} for testing security.
+   * Copied from HBaseTestingUtility#setupMiniKdc().
+   */
+  static private MiniKdc setupMiniKdc() throws Exception {
+    Properties conf = MiniKdc.createConf();
+    conf.put(MiniKdc.DEBUG, true);
+    MiniKdc kdc = null;
+    File dir = null;
+    // There is time lag between selecting a port and trying to bind with it. It's possible that
+    // another service captures the port in between which'll result in BindException.
+    boolean bindException;
+    int numTries = 0;
+    do {
+      try {
+        bindException = false;
+        dir = new File(htu.getDataTestDir("kdc").toUri().getPath());
+        kdc = new MiniKdc(conf, dir);
+        kdc.start();
+      } catch (BindException e) {
+        FileUtils.deleteDirectory(dir);  // clean directory
+        numTries++;
+        if (numTries == 3) {
+          log.error("Failed setting up MiniKDC. Tried " + numTries + " times.");
+          throw e;
+        }
+        log.error("BindException encountered when setting up MiniKdc. Trying again.");
+        bindException = true;
+      }
+    } while (bindException);
+    return kdc;
+  }
+
+  @AfterClass
+  public static void tearDown() {
+    if (kdc != null) {
+      kdc.stop();
+    }
+
+    FileUtil.fullyDelete(BASEDIR);
+  }
+
+  /**
+   * Test client command line options. Does not validate server behavior.
+   * @throws Exception if commands return unexpected results.
+   */
+  @Test(timeout=120000)
+  public void testCommandOptions() throws Exception {
+    final String className = this.getClass().getName();
+
+    assertFalse(validateCommand(new String[] {"-foo" }));
+    // fail due to insufficient number of arguments
+    assertFalse(validateCommand(new String[] {}));
+    assertFalse(validateCommand(new String[] {"-getlevel" }));
+    assertFalse(validateCommand(new String[] {"-setlevel" }));
+    assertFalse(validateCommand(new String[] {"-getlevel", "foo.bar:8080" }));
+
+    // valid command arguments
+    assertTrue(validateCommand(
+        new String[] {"-getlevel", "foo.bar:8080", className }));
+    assertTrue(validateCommand(
+        new String[] {"-setlevel", "foo.bar:8080", className, "DEBUG" }));
+    assertTrue(validateCommand(
+        new String[] {"-getlevel", "foo.bar:8080", className }));
+    assertTrue(validateCommand(
+        new String[] {"-setlevel", "foo.bar:8080", className, "DEBUG" }));
+
+    // fail due to the extra argument
+    assertFalse(validateCommand(
+        new String[] {"-getlevel", "foo.bar:8080", className, "blah" }));
+    assertFalse(validateCommand(
+        new String[] {"-setlevel", "foo.bar:8080", className, "DEBUG", "blah" }));
+    assertFalse(validateCommand(
+        new String[] {"-getlevel", "foo.bar:8080", className, "-setlevel", "foo.bar:8080",
+          className }));
+  }
+
+  /**
+   * Check to see if a command can be accepted.
+   *
+   * @param args a String array of arguments
+   * @return true if the command can be accepted, false if not.
+   */
+  private boolean validateCommand(String[] args) {
+    CLI cli = new CLI(clientConf);
+    try {
+      cli.parseArguments(args);
+    } catch (HadoopIllegalArgumentException e) {
+      return false;
+    } catch (Exception e) {
+      // this is used to verify the command arguments only.
+      // no HadoopIllegalArgumentException = the arguments are good.
+      return true;
+    }
+    return true;
+  }
+
+  /**
+   * Creates and starts a Jetty server binding at an ephemeral port to run
+   * LogLevel servlet.
+   * @param isSpnego true if SPNEGO is enabled
+   * @return a created HttpServer object
+   * @throws Exception if unable to create or start a Jetty server
+   */
+  private HttpServer createServer(boolean isSpnego)
+      throws Exception {
+    HttpServer.Builder builder = new HttpServer.Builder()
+        .setName("..")
+        .addEndpoint(new URI(PROTOCOL_HTTP + "://localhost:0"))
+        .setFindPort(true)
+        .setConf(serverConf);
+    if (isSpnego) {
+      // Set up server Kerberos credentials.
+      // Since the server may fall back to simple authentication,
+      // use ACL to make sure the connection is Kerberos/SPNEGO authenticated.
+      builder.setSecurityEnabled(true)
+          .setUsernameConfKey(PRINCIPAL)
+          .setKeytabConfKey(KEYTAB)
+          .setACL(new AccessControlList("client"));
+    }
+
+    HttpServer server = builder.build();
+    server.start();
+    return server;
+  }
+
+  private void testDynamicLogLevel(final boolean isSpnego)
+      throws Exception {
+    testDynamicLogLevel(isSpnego, Level.DEBUG.toString());
+  }
+
+  /**
+   * Run both client and server using the given protocol.
+   *
+   * @param isSpnego true if SPNEGO is enabled
+   * @throws Exception if client can't accesss server.
+   */
+  private void testDynamicLogLevel(final boolean isSpnego, final String newLevel)
+      throws Exception {
+    Level oldLevel = log.getEffectiveLevel();
+    assertNotEquals("Get default Log Level which shouldn't be ERROR.",
+        Level.ERROR, oldLevel);
+
+    // configs needed for SPNEGO at server side
+    if (isSpnego) {
+      serverConf.set(PRINCIPAL, HTTP_PRINCIPAL);
+      serverConf.set(KEYTAB, KEYTAB_FILE.getAbsolutePath());
+      serverConf.set(CommonConfigurationKeysPublic.HADOOP_SECURITY_AUTHENTICATION, "kerberos");
+      serverConf.setBoolean(CommonConfigurationKeys.HADOOP_SECURITY_AUTHORIZATION, true);
+      UserGroupInformation.setConfiguration(serverConf);
+    } else {
+      serverConf.set(CommonConfigurationKeysPublic.HADOOP_SECURITY_AUTHENTICATION, "simple");
+      serverConf.setBoolean(CommonConfigurationKeys.HADOOP_SECURITY_AUTHORIZATION, false);
+      UserGroupInformation.setConfiguration(serverConf);
+    }
+
+    final HttpServer server = createServer(isSpnego);
+    // get server port
+    final String authority = NetUtils.getHostPortString(server.getConnectorAddress(0));
+
+    String keytabFilePath = KEYTAB_FILE.getAbsolutePath();
+
+    UserGroupInformation clientUGI = UserGroupInformation.
+        loginUserFromKeytabAndReturnUGI(clientPrincipal, keytabFilePath);
+    try {
+      clientUGI.doAs((PrivilegedExceptionAction<Void>) () -> {
+        // client command line
+        getLevel(authority);
+        setLevel(authority, newLevel);
+        return null;
+      });
     } finally {
-        if (server != null) {
+      clientUGI.logoutUserFromKeytab();
       server.stop();
     }
+
+    // restore log level
+    GenericTestUtils.setLogLevel(log, oldLevel);
   }
-    } else {
+
-      out.println(testlog.getClass() + " not tested.");
+  /**
+   * Run LogLevel command line to start a client to get log level of this test
+   * class.
+   *
+   * @param authority daemon's web UI address
+   * @throws Exception if unable to connect
+   */
+  private void getLevel(String authority) throws Exception {
+    String[] getLevelArgs = {"-getlevel", authority, logName};
+    CLI cli = new CLI(clientConf);
+    cli.run(getLevelArgs);
   }
+
+  /**
+   * Run LogLevel command line to start a client to set log level of this test
+   * class to debug.
+   *
+   * @param authority daemon's web UI address
+   * @throws Exception if unable to run or log level does not change as expected
+   */
+  private void setLevel(String authority, String newLevel)
+      throws Exception {
+    String[] setLevelArgs = {"-setlevel", authority, logName, newLevel};
+    CLI cli = new CLI(clientConf);
+    cli.run(setLevelArgs);
+
+    assertEquals("new level not equal to expected: ", newLevel.toUpperCase(),
+        log.getEffectiveLevel().toString());
+  }
+
+  /**
+   * Test setting log level to "Info".
+   *
+   * @throws Exception if client can't set log level to INFO.
+   */
+  @Test(timeout=60000)
+  public void testInfoLogLevel() throws Exception {
+    testDynamicLogLevel(true, "INFO");
+  }
+
+  /**
+   * Test setting log level to "Error".
+   *
+   * @throws Exception if client can't set log level to ERROR.
+   */
+  @Test(timeout=60000)
+  public void testErrorLogLevel() throws Exception {
+    testDynamicLogLevel(true, "ERROR");
+  }
+
+  /**
+   * Server runs HTTP, no SPNEGO.
+   *
+   * @throws Exception if http client can't access http server.
+   */
+  @Test(timeout=60000)
+  public void testLogLevelByHttp() throws Exception {
+    testDynamicLogLevel(false);
+  }
+
+  /**
+   * Server runs HTTP + SPNEGO.
+   *
+   * @throws Exception if http client can't access http server.
+   */
+  @Test(timeout=60000)
+  public void testLogLevelByHttpWithSpnego() throws Exception {
+    testDynamicLogLevel(true);
   }
 }