001/*
002 * Licensed to the Apache Software Foundation (ASF) under one
003 * or more contributor license agreements.  See the NOTICE file
004 * distributed with this work for additional information
005 * regarding copyright ownership.  The ASF licenses this file
006 * to you under the Apache License, Version 2.0 (the
007 * "License"); you may not use this file except in compliance
008 * with the License.  You may obtain a copy of the License at
009 *
010 *     http://www.apache.org/licenses/LICENSE-2.0
011 *
012 * Unless required by applicable law or agreed to in writing, software
013 * distributed under the License is distributed on an "AS IS" BASIS,
014 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
015 * See the License for the specific language governing permissions and
016 * limitations under the License.
017 */
018package org.apache.hadoop.hbase.http.log;
019
020import static org.junit.Assert.assertEquals;
021import static org.junit.Assert.assertFalse;
022import static org.junit.Assert.assertNotEquals;
023import static org.junit.Assert.assertTrue;
024import static org.junit.Assert.fail;
025
026import java.io.File;
027import java.io.IOException;
028import java.net.BindException;
029import java.net.SocketException;
030import java.net.URI;
031import java.security.PrivilegedExceptionAction;
032import java.util.Properties;
033import javax.net.ssl.SSLException;
034import javax.servlet.http.HttpServletResponse;
035import org.apache.commons.io.FileUtils;
036import org.apache.hadoop.HadoopIllegalArgumentException;
037import org.apache.hadoop.conf.Configuration;
038import org.apache.hadoop.fs.CommonConfigurationKeys;
039import org.apache.hadoop.fs.CommonConfigurationKeysPublic;
040import org.apache.hadoop.fs.FileUtil;
041import org.apache.hadoop.hbase.HBaseClassTestRule;
042import org.apache.hadoop.hbase.HBaseCommonTestingUtil;
043import org.apache.hadoop.hbase.http.HttpConfig;
044import org.apache.hadoop.hbase.http.HttpServer;
045import org.apache.hadoop.hbase.http.log.LogLevel.CLI;
046import org.apache.hadoop.hbase.http.ssl.KeyStoreTestUtil;
047import org.apache.hadoop.hbase.testclassification.MiscTests;
048import org.apache.hadoop.hbase.testclassification.SmallTests;
049import org.apache.hadoop.hdfs.DFSConfigKeys;
050import org.apache.hadoop.minikdc.MiniKdc;
051import org.apache.hadoop.net.NetUtils;
052import org.apache.hadoop.security.UserGroupInformation;
053import org.apache.hadoop.security.authorize.AccessControlList;
054import org.apache.hadoop.security.ssl.SSLFactory;
055import org.apache.hadoop.test.GenericTestUtils;
056import org.apache.hadoop.util.StringUtils;
057import org.junit.AfterClass;
058import org.junit.BeforeClass;
059import org.junit.ClassRule;
060import org.junit.Test;
061import org.junit.experimental.categories.Category;
062
063/**
064 * Test LogLevel.
065 */
066@Category({ MiscTests.class, SmallTests.class })
067public class TestLogLevel {
068  @ClassRule
069  public static final HBaseClassTestRule CLASS_RULE =
070    HBaseClassTestRule.forClass(TestLogLevel.class);
071
072  private static String keystoresDir;
073  private static String sslConfDir;
074  private static Configuration serverConf;
075  private static Configuration clientConf;
076  private static Configuration sslConf;
077  private static final String logName = TestLogLevel.class.getName();
078  private static final String protectedPrefix = "protected";
079  private static final String protectedLogName = protectedPrefix + "." + logName;
080  private static final org.apache.logging.log4j.Logger log =
081    org.apache.logging.log4j.LogManager.getLogger(logName);
082  private final static String PRINCIPAL = "loglevel.principal";
083  private final static String KEYTAB = "loglevel.keytab";
084
085  private static MiniKdc kdc;
086
087  private static final String LOCALHOST = "localhost";
088  private static final String clientPrincipal = "client/" + LOCALHOST;
089  private static String HTTP_PRINCIPAL = "HTTP/" + LOCALHOST;
090  private static HBaseCommonTestingUtil HTU;
091  private static File keyTabFile;
092
093  @BeforeClass
094  public static void setUp() throws Exception {
095    serverConf = new Configuration();
096    serverConf.setStrings(LogLevel.READONLY_LOGGERS_CONF_KEY, protectedPrefix);
097    HTU = new HBaseCommonTestingUtil(serverConf);
098
099    File keystoreDir = new File(HTU.getDataTestDir("keystore").toString());
100    keystoreDir.mkdirs();
101    keyTabFile = new File(HTU.getDataTestDir("keytab").toString(), "keytabfile");
102    keyTabFile.getParentFile().mkdirs();
103    clientConf = new Configuration();
104
105    setupSSL(keystoreDir);
106
107    kdc = setupMiniKdc();
108    // Create two principles: a client and an HTTP principal
109    kdc.createPrincipal(keyTabFile, clientPrincipal, HTTP_PRINCIPAL);
110  }
111
112  /**
113   * Sets up {@link MiniKdc} for testing security. Copied from HBaseTestingUtility#setupMiniKdc().
114   */
115  static private MiniKdc setupMiniKdc() throws Exception {
116    Properties conf = MiniKdc.createConf();
117    conf.put(MiniKdc.DEBUG, true);
118    MiniKdc kdc = null;
119    File dir = null;
120    // There is time lag between selecting a port and trying to bind with it. It's possible that
121    // another service captures the port in between which'll result in BindException.
122    boolean bindException;
123    int numTries = 0;
124    do {
125      try {
126        bindException = false;
127        dir = new File(HTU.getDataTestDir("kdc").toUri().getPath());
128        kdc = new MiniKdc(conf, dir);
129        kdc.start();
130      } catch (BindException e) {
131        FileUtils.deleteDirectory(dir); // clean directory
132        numTries++;
133        if (numTries == 3) {
134          log.error("Failed setting up MiniKDC. Tried " + numTries + " times.");
135          throw e;
136        }
137        log.error("BindException encountered when setting up MiniKdc. Trying again.");
138        bindException = true;
139      }
140    } while (bindException);
141    return kdc;
142  }
143
144  static private void setupSSL(File base) throws Exception {
145    clientConf.set(DFSConfigKeys.DFS_HTTP_POLICY_KEY, HttpConfig.Policy.HTTPS_ONLY.name());
146    clientConf.set(DFSConfigKeys.DFS_NAMENODE_HTTPS_ADDRESS_KEY, "localhost:0");
147    clientConf.set(DFSConfigKeys.DFS_DATANODE_HTTPS_ADDRESS_KEY, "localhost:0");
148
149    keystoresDir = base.getAbsolutePath();
150    sslConfDir = KeyStoreTestUtil.getClasspathDir(TestLogLevel.class);
151    KeyStoreTestUtil.setupSSLConfig(keystoresDir, sslConfDir, serverConf, false);
152
153    sslConf = getSslConfig(serverConf);
154  }
155
156  /**
157   * Get the SSL configuration. This method is copied from KeyStoreTestUtil#getSslConfig() in
158   * Hadoop.
159   * @return {@link Configuration} instance with ssl configs loaded.
160   * @param conf to pull client/server SSL settings filename from
161   */
162  private static Configuration getSslConfig(Configuration conf) {
163    Configuration sslConf = new Configuration(false);
164    String sslServerConfFile = conf.get(SSLFactory.SSL_SERVER_CONF_KEY);
165    String sslClientConfFile = conf.get(SSLFactory.SSL_CLIENT_CONF_KEY);
166    sslConf.addResource(sslServerConfFile);
167    sslConf.addResource(sslClientConfFile);
168    sslConf.set(SSLFactory.SSL_SERVER_CONF_KEY, sslServerConfFile);
169    sslConf.set(SSLFactory.SSL_CLIENT_CONF_KEY, sslClientConfFile);
170    return sslConf;
171  }
172
173  @AfterClass
174  public static void tearDown() {
175    if (kdc != null) {
176      kdc.stop();
177    }
178
179    FileUtil.fullyDelete(new File(HTU.getDataTestDir().toString()));
180  }
181
182  /**
183   * Test client command line options. Does not validate server behavior.
184   * @throws Exception if commands return unexpected results.
185   */
186  @Test
187  public void testCommandOptions() throws Exception {
188    final String className = this.getClass().getName();
189
190    assertFalse(validateCommand(new String[] { "-foo" }));
191    // fail due to insufficient number of arguments
192    assertFalse(validateCommand(new String[] {}));
193    assertFalse(validateCommand(new String[] { "-getlevel" }));
194    assertFalse(validateCommand(new String[] { "-setlevel" }));
195    assertFalse(validateCommand(new String[] { "-getlevel", "foo.bar:8080" }));
196
197    // valid command arguments
198    assertTrue(validateCommand(new String[] { "-getlevel", "foo.bar:8080", className }));
199    assertTrue(validateCommand(new String[] { "-setlevel", "foo.bar:8080", className, "DEBUG" }));
200    assertTrue(validateCommand(new String[] { "-getlevel", "foo.bar:8080", className }));
201    assertTrue(validateCommand(new String[] { "-setlevel", "foo.bar:8080", className, "DEBUG" }));
202
203    // fail due to the extra argument
204    assertFalse(validateCommand(new String[] { "-getlevel", "foo.bar:8080", className, "blah" }));
205    assertFalse(
206      validateCommand(new String[] { "-setlevel", "foo.bar:8080", className, "DEBUG", "blah" }));
207    assertFalse(validateCommand(new String[] { "-getlevel", "foo.bar:8080", className, "-setlevel",
208      "foo.bar:8080", className }));
209  }
210
211  /**
212   * Check to see if a command can be accepted.
213   * @param args a String array of arguments
214   * @return true if the command can be accepted, false if not.
215   */
216  private boolean validateCommand(String[] args) {
217    CLI cli = new CLI(clientConf);
218    try {
219      cli.parseArguments(args);
220    } catch (HadoopIllegalArgumentException e) {
221      return false;
222    } catch (Exception e) {
223      // this is used to verify the command arguments only.
224      // no HadoopIllegalArgumentException = the arguments are good.
225      return true;
226    }
227    return true;
228  }
229
230  /**
231   * Creates and starts a Jetty server binding at an ephemeral port to run LogLevel servlet.
232   * @param protocol "http" or "https"
233   * @param isSpnego true if SPNEGO is enabled
234   * @return a created HttpServer object
235   * @throws Exception if unable to create or start a Jetty server
236   */
237  private HttpServer createServer(String protocol, boolean isSpnego) throws Exception {
238    HttpServer.Builder builder = new HttpServer.Builder().setName("..")
239      .addEndpoint(new URI(protocol + "://localhost:0")).setFindPort(true).setConf(serverConf);
240    if (isSpnego) {
241      // Set up server Kerberos credentials.
242      // Since the server may fall back to simple authentication,
243      // use ACL to make sure the connection is Kerberos/SPNEGO authenticated.
244      builder.setSecurityEnabled(true).setUsernameConfKey(PRINCIPAL).setKeytabConfKey(KEYTAB)
245        .setACL(new AccessControlList("client"));
246    }
247
248    // if using HTTPS, configure keystore/truststore properties.
249    if (protocol.equals(LogLevel.PROTOCOL_HTTPS)) {
250      builder = builder.keyPassword(sslConf.get("ssl.server.keystore.keypassword"))
251        .keyStore(sslConf.get("ssl.server.keystore.location"),
252          sslConf.get("ssl.server.keystore.password"),
253          sslConf.get("ssl.server.keystore.type", "jks"))
254        .trustStore(sslConf.get("ssl.server.truststore.location"),
255          sslConf.get("ssl.server.truststore.password"),
256          sslConf.get("ssl.server.truststore.type", "jks"));
257    }
258
259    HttpServer server = builder.build();
260    server.start();
261    return server;
262  }
263
264  private void testDynamicLogLevel(final String bindProtocol, final String connectProtocol,
265    final boolean isSpnego) throws Exception {
266    testDynamicLogLevel(bindProtocol, connectProtocol, isSpnego, logName,
267      org.apache.logging.log4j.Level.DEBUG.toString());
268  }
269
270  private void testDynamicLogLevel(final String bindProtocol, final String connectProtocol,
271    final boolean isSpnego, final String newLevel) throws Exception {
272    testDynamicLogLevel(bindProtocol, connectProtocol, isSpnego, logName, newLevel);
273  }
274
275  /**
276   * Run both client and server using the given protocol.
277   * @param bindProtocol    specify either http or https for server
278   * @param connectProtocol specify either http or https for client
279   * @param isSpnego        true if SPNEGO is enabled
280   * @throws Exception if client can't accesss server.
281   */
282  private void testDynamicLogLevel(final String bindProtocol, final String connectProtocol,
283    final boolean isSpnego, final String loggerName, final String newLevel) throws Exception {
284    if (!LogLevel.isValidProtocol(bindProtocol)) {
285      throw new Exception("Invalid server protocol " + bindProtocol);
286    }
287    if (!LogLevel.isValidProtocol(connectProtocol)) {
288      throw new Exception("Invalid client protocol " + connectProtocol);
289    }
290    org.apache.logging.log4j.Logger log = org.apache.logging.log4j.LogManager.getLogger(loggerName);
291    org.apache.logging.log4j.Level oldLevel = log.getLevel();
292    assertNotEquals("Get default Log Level which shouldn't be ERROR.",
293      org.apache.logging.log4j.Level.ERROR, oldLevel);
294
295    // configs needed for SPNEGO at server side
296    if (isSpnego) {
297      serverConf.set(PRINCIPAL, HTTP_PRINCIPAL);
298      serverConf.set(KEYTAB, keyTabFile.getAbsolutePath());
299      serverConf.set(CommonConfigurationKeysPublic.HADOOP_SECURITY_AUTHENTICATION, "kerberos");
300      serverConf.setBoolean(CommonConfigurationKeys.HADOOP_SECURITY_AUTHORIZATION, true);
301      UserGroupInformation.setConfiguration(serverConf);
302    } else {
303      serverConf.set(CommonConfigurationKeysPublic.HADOOP_SECURITY_AUTHENTICATION, "simple");
304      serverConf.setBoolean(CommonConfigurationKeys.HADOOP_SECURITY_AUTHORIZATION, false);
305      UserGroupInformation.setConfiguration(serverConf);
306    }
307
308    final HttpServer server = createServer(bindProtocol, isSpnego);
309    // get server port
310    final String authority = NetUtils.getHostPortString(server.getConnectorAddress(0));
311
312    String keytabFilePath = keyTabFile.getAbsolutePath();
313
314    UserGroupInformation clientUGI =
315      UserGroupInformation.loginUserFromKeytabAndReturnUGI(clientPrincipal, keytabFilePath);
316    try {
317      clientUGI.doAs((PrivilegedExceptionAction<Void>) () -> {
318        // client command line
319        getLevel(connectProtocol, authority, loggerName);
320        setLevel(connectProtocol, authority, loggerName, newLevel);
321        return null;
322      });
323    } finally {
324      clientUGI.logoutUserFromKeytab();
325      server.stop();
326    }
327
328    // restore log level
329    org.apache.logging.log4j.core.config.Configurator.setLevel(log.getName(), oldLevel);
330  }
331
332  /**
333   * Run LogLevel command line to start a client to get log level of this test class.
334   * @param protocol  specify either http or https
335   * @param authority daemon's web UI address
336   * @throws Exception if unable to connect
337   */
338  private void getLevel(String protocol, String authority, String logName) throws Exception {
339    String[] getLevelArgs = { "-getlevel", authority, logName, "-protocol", protocol };
340    CLI cli = new CLI(protocol.equalsIgnoreCase("https") ? sslConf : clientConf);
341    cli.run(getLevelArgs);
342  }
343
344  /**
345   * Run LogLevel command line to start a client to set log level of this test class to debug.
346   * @param protocol  specify either http or https
347   * @param authority daemon's web UI address
348   * @throws Exception if unable to run or log level does not change as expected
349   */
350  private void setLevel(String protocol, String authority, String logName, String newLevel)
351    throws Exception {
352    String[] setLevelArgs = { "-setlevel", authority, logName, newLevel, "-protocol", protocol };
353    CLI cli = new CLI(protocol.equalsIgnoreCase("https") ? sslConf : clientConf);
354    cli.run(setLevelArgs);
355
356    org.apache.logging.log4j.Logger logger = org.apache.logging.log4j.LogManager.getLogger(logName);
357
358    assertEquals("new level not equal to expected: ", newLevel.toUpperCase(),
359      logger.getLevel().toString());
360  }
361
362  @Test
363  public void testSettingProtectedLogLevel() throws Exception {
364    try {
365      testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true, protectedLogName,
366        "DEBUG");
367      fail("Expected IO exception due to protected logger");
368    } catch (IOException e) {
369      assertTrue(e.getMessage().contains("" + HttpServletResponse.SC_PRECONDITION_FAILED));
370      assertTrue(e.getMessage().contains(
371        "Modification of logger " + protectedLogName + " is disallowed in configuration."));
372    }
373  }
374
375  /**
376   * Test setting log level to "Info".
377   * @throws Exception if client can't set log level to INFO.
378   */
379  @Test
380  public void testInfoLogLevel() throws Exception {
381    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true, "INFO");
382  }
383
384  /**
385   * Test setting log level to "Error".
386   * @throws Exception if client can't set log level to ERROR.
387   */
388  @Test
389  public void testErrorLogLevel() throws Exception {
390    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true, "ERROR");
391  }
392
393  /**
394   * Server runs HTTP, no SPNEGO.
395   * @throws Exception if http client can't access http server, or http client can access https
396   *                   server.
397   */
398  @Test
399  public void testLogLevelByHttp() throws Exception {
400    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, false);
401    try {
402      testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTPS, false);
403      fail("An HTTPS Client should not have succeeded in connecting to a " + "HTTP server");
404    } catch (SSLException e) {
405      exceptionShouldContains("Unrecognized SSL message", e);
406    }
407  }
408
409  /**
410   * Server runs HTTP + SPNEGO.
411   * @throws Exception if http client can't access http server, or http client can access https
412   *                   server.
413   */
414  @Test
415  public void testLogLevelByHttpWithSpnego() throws Exception {
416    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true);
417    try {
418      testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTPS, true);
419      fail("An HTTPS Client should not have succeeded in connecting to a " + "HTTP server");
420    } catch (SSLException e) {
421      exceptionShouldContains("Unrecognized SSL message", e);
422    }
423  }
424
425  /**
426   * Server runs HTTPS, no SPNEGO.
427   * @throws Exception if https client can't access https server, or https client can access http
428   *                   server.
429   */
430  @Test
431  public void testLogLevelByHttps() throws Exception {
432    testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTPS, false);
433    try {
434      testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTP, false);
435      fail("An HTTP Client should not have succeeded in connecting to a " + "HTTPS server");
436    } catch (SocketException e) {
437      exceptionShouldContains("Unexpected end of file from server", e);
438    }
439  }
440
441  /**
442   * Server runs HTTPS + SPNEGO.
443   * @throws Exception if https client can't access https server, or https client can access http
444   *                   server.
445   */
446  @Test
447  public void testLogLevelByHttpsWithSpnego() throws Exception {
448    testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTPS, true);
449    try {
450      testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTP, true);
451      fail("An HTTP Client should not have succeeded in connecting to a " + "HTTPS server");
452    } catch (SocketException e) {
453      exceptionShouldContains("Unexpected end of file from server", e);
454    }
455  }
456
457  /**
458   * Assert that a throwable or one of its causes should contain the substr in its message. Ideally
459   * we should use {@link GenericTestUtils#assertExceptionContains(String, Throwable)} util method
460   * which asserts t.toString() contains the substr. As the original throwable may have been wrapped
461   * in Hadoop3 because of HADOOP-12897, it's required to check all the wrapped causes. After stop
462   * supporting Hadoop2, this method can be removed and assertion in tests can use t.getCause()
463   * directly, similar to HADOOP-15280.
464   */
465  private static void exceptionShouldContains(String substr, Throwable throwable) {
466    Throwable t = throwable;
467    while (t != null) {
468      String msg = t.toString();
469      if (msg != null && msg.toLowerCase().contains(substr.toLowerCase())) {
470        return;
471      }
472      t = t.getCause();
473    }
474    throw new AssertionError("Expected to find '" + substr + "' but got unexpected exception:"
475      + StringUtils.stringifyException(throwable), throwable);
476  }
477}