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    // Changed to "" as ".." moves it a steps back in path because the path is relative to the
239    // current working directory. throws "java.lang.IllegalArgumentException: Base Resource is not
240    // valid: hbase-http/target/test-classes/static" as it is not able to find the static folder.
241    HttpServer.Builder builder = new HttpServer.Builder().setName("")
242      .addEndpoint(new URI(protocol + "://localhost:0")).setFindPort(true).setConf(serverConf);
243    if (isSpnego) {
244      // Set up server Kerberos credentials.
245      // Since the server may fall back to simple authentication,
246      // use ACL to make sure the connection is Kerberos/SPNEGO authenticated.
247      builder.setSecurityEnabled(true).setUsernameConfKey(PRINCIPAL).setKeytabConfKey(KEYTAB)
248        .setACL(new AccessControlList("client"));
249    }
250
251    // if using HTTPS, configure keystore/truststore properties.
252    if (protocol.equals(LogLevel.PROTOCOL_HTTPS)) {
253      builder = builder.keyPassword(sslConf.get("ssl.server.keystore.keypassword"))
254        .keyStore(sslConf.get("ssl.server.keystore.location"),
255          sslConf.get("ssl.server.keystore.password"),
256          sslConf.get("ssl.server.keystore.type", "jks"))
257        .trustStore(sslConf.get("ssl.server.truststore.location"),
258          sslConf.get("ssl.server.truststore.password"),
259          sslConf.get("ssl.server.truststore.type", "jks"));
260    }
261
262    HttpServer server = builder.build();
263    server.start();
264    return server;
265  }
266
267  private void testDynamicLogLevel(final String bindProtocol, final String connectProtocol,
268    final boolean isSpnego) throws Exception {
269    testDynamicLogLevel(bindProtocol, connectProtocol, isSpnego, logName,
270      org.apache.logging.log4j.Level.DEBUG.toString());
271  }
272
273  private void testDynamicLogLevel(final String bindProtocol, final String connectProtocol,
274    final boolean isSpnego, final String newLevel) throws Exception {
275    testDynamicLogLevel(bindProtocol, connectProtocol, isSpnego, logName, newLevel);
276  }
277
278  /**
279   * Run both client and server using the given protocol.
280   * @param bindProtocol    specify either http or https for server
281   * @param connectProtocol specify either http or https for client
282   * @param isSpnego        true if SPNEGO is enabled
283   * @throws Exception if client can't accesss server.
284   */
285  private void testDynamicLogLevel(final String bindProtocol, final String connectProtocol,
286    final boolean isSpnego, final String loggerName, final String newLevel) throws Exception {
287    if (!LogLevel.isValidProtocol(bindProtocol)) {
288      throw new Exception("Invalid server protocol " + bindProtocol);
289    }
290    if (!LogLevel.isValidProtocol(connectProtocol)) {
291      throw new Exception("Invalid client protocol " + connectProtocol);
292    }
293    org.apache.logging.log4j.Logger log = org.apache.logging.log4j.LogManager.getLogger(loggerName);
294    org.apache.logging.log4j.Level oldLevel = log.getLevel();
295    assertNotEquals("Get default Log Level which shouldn't be ERROR.",
296      org.apache.logging.log4j.Level.ERROR, oldLevel);
297
298    // configs needed for SPNEGO at server side
299    if (isSpnego) {
300      serverConf.set(PRINCIPAL, HTTP_PRINCIPAL);
301      serverConf.set(KEYTAB, keyTabFile.getAbsolutePath());
302      serverConf.set(CommonConfigurationKeysPublic.HADOOP_SECURITY_AUTHENTICATION, "kerberos");
303      serverConf.setBoolean(CommonConfigurationKeys.HADOOP_SECURITY_AUTHORIZATION, true);
304      UserGroupInformation.setConfiguration(serverConf);
305    } else {
306      serverConf.set(CommonConfigurationKeysPublic.HADOOP_SECURITY_AUTHENTICATION, "simple");
307      serverConf.setBoolean(CommonConfigurationKeys.HADOOP_SECURITY_AUTHORIZATION, false);
308      UserGroupInformation.setConfiguration(serverConf);
309    }
310
311    final HttpServer server = createServer(bindProtocol, isSpnego);
312    // get server port
313    final String authority = NetUtils.getHostPortString(server.getConnectorAddress(0));
314
315    String keytabFilePath = keyTabFile.getAbsolutePath();
316
317    UserGroupInformation clientUGI =
318      UserGroupInformation.loginUserFromKeytabAndReturnUGI(clientPrincipal, keytabFilePath);
319    try {
320      clientUGI.doAs((PrivilegedExceptionAction<Void>) () -> {
321        // client command line
322        getLevel(connectProtocol, authority, loggerName);
323        setLevel(connectProtocol, authority, loggerName, newLevel);
324        return null;
325      });
326    } finally {
327      clientUGI.logoutUserFromKeytab();
328      server.stop();
329    }
330
331    // restore log level
332    org.apache.logging.log4j.core.config.Configurator.setLevel(log.getName(), oldLevel);
333  }
334
335  /**
336   * Run LogLevel command line to start a client to get log level of this test class.
337   * @param protocol  specify either http or https
338   * @param authority daemon's web UI address
339   * @throws Exception if unable to connect
340   */
341  private void getLevel(String protocol, String authority, String logName) throws Exception {
342    String[] getLevelArgs = { "-getlevel", authority, logName, "-protocol", protocol };
343    CLI cli = new CLI(protocol.equalsIgnoreCase("https") ? sslConf : clientConf);
344    cli.run(getLevelArgs);
345  }
346
347  /**
348   * Run LogLevel command line to start a client to set log level of this test class to debug.
349   * @param protocol  specify either http or https
350   * @param authority daemon's web UI address
351   * @throws Exception if unable to run or log level does not change as expected
352   */
353  private void setLevel(String protocol, String authority, String logName, String newLevel)
354    throws Exception {
355    String[] setLevelArgs = { "-setlevel", authority, logName, newLevel, "-protocol", protocol };
356    CLI cli = new CLI(protocol.equalsIgnoreCase("https") ? sslConf : clientConf);
357    cli.run(setLevelArgs);
358
359    org.apache.logging.log4j.Logger logger = org.apache.logging.log4j.LogManager.getLogger(logName);
360
361    assertEquals("new level not equal to expected: ", newLevel.toUpperCase(),
362      logger.getLevel().toString());
363  }
364
365  @Test
366  public void testSettingProtectedLogLevel() throws Exception {
367    try {
368      testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true, protectedLogName,
369        "DEBUG");
370      fail("Expected IO exception due to protected logger");
371    } catch (IOException e) {
372      assertTrue(e.getMessage().contains("" + HttpServletResponse.SC_PRECONDITION_FAILED));
373      assertTrue(e.getMessage().contains(
374        "Modification of logger " + protectedLogName + " is disallowed in configuration."));
375    }
376  }
377
378  /**
379   * Test setting log level to "Info".
380   * @throws Exception if client can't set log level to INFO.
381   */
382  @Test
383  public void testInfoLogLevel() throws Exception {
384    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true, "INFO");
385  }
386
387  /**
388   * Test setting log level to "Error".
389   * @throws Exception if client can't set log level to ERROR.
390   */
391  @Test
392  public void testErrorLogLevel() throws Exception {
393    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true, "ERROR");
394  }
395
396  /**
397   * Server runs HTTP, no SPNEGO.
398   * @throws Exception if http client can't access http server, or http client can access https
399   *                   server.
400   */
401  @Test
402  public void testLogLevelByHttp() throws Exception {
403    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, false);
404    try {
405      testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTPS, false);
406      fail("An HTTPS Client should not have succeeded in connecting to a " + "HTTP server");
407    } catch (SSLException e) {
408      exceptionShouldContains("Unrecognized SSL message", e);
409    }
410  }
411
412  /**
413   * Server runs HTTP + SPNEGO.
414   * @throws Exception if http client can't access http server, or http client can access https
415   *                   server.
416   */
417  @Test
418  public void testLogLevelByHttpWithSpnego() throws Exception {
419    testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true);
420    try {
421      testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTPS, true);
422      fail("An HTTPS Client should not have succeeded in connecting to a " + "HTTP server");
423    } catch (SSLException e) {
424      exceptionShouldContains("Unrecognized SSL message", e);
425    }
426  }
427
428  /**
429   * Server runs HTTPS, no SPNEGO.
430   * @throws Exception if https client can't access https server, or https client can access http
431   *                   server.
432   */
433  @Test
434  public void testLogLevelByHttps() throws Exception {
435    testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTPS, false);
436    try {
437      testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTP, false);
438      fail("An HTTP Client should not have succeeded in connecting to a " + "HTTPS server");
439    } catch (SocketException e) {
440      exceptionShouldContains("Unexpected end of file from server", e);
441    }
442  }
443
444  /**
445   * Server runs HTTPS + SPNEGO.
446   * @throws Exception if https client can't access https server, or https client can access http
447   *                   server.
448   */
449  @Test
450  public void testLogLevelByHttpsWithSpnego() throws Exception {
451    testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTPS, true);
452    try {
453      testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTP, true);
454      fail("An HTTP Client should not have succeeded in connecting to a " + "HTTPS server");
455    } catch (SocketException e) {
456      exceptionShouldContains("Unexpected end of file from server", e);
457    }
458  }
459
460  /**
461   * Assert that a throwable or one of its causes should contain the substr in its message. Ideally
462   * we should use {@link GenericTestUtils#assertExceptionContains(String, Throwable)} util method
463   * which asserts t.toString() contains the substr. As the original throwable may have been wrapped
464   * in Hadoop3 because of HADOOP-12897, it's required to check all the wrapped causes. After stop
465   * supporting Hadoop2, this method can be removed and assertion in tests can use t.getCause()
466   * directly, similar to HADOOP-15280.
467   */
468  private static void exceptionShouldContains(String substr, Throwable throwable) {
469    Throwable t = throwable;
470    while (t != null) {
471      String msg = t.toString();
472      if (msg != null && msg.toLowerCase().contains(substr.toLowerCase())) {
473        return;
474      }
475      t = t.getCause();
476    }
477    throw new AssertionError("Expected to find '" + substr + "' but got unexpected exception:"
478      + StringUtils.stringifyException(throwable), throwable);
479  }
480}