479 hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLogLevel.java
View file
@@ -17,99 +17,404 @@
*/
package org.apache.hadoop.log;

import java.io.*;
import java.net.*;
import java.io.File;
import java.net.SocketException;
import java.net.URI;
import java.util.concurrent.Callable;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.apache.commons.logging.impl.Log4JLogger;
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.http.HttpServer2;
import org.apache.hadoop.log.LogLevel.CLI;
import org.apache.hadoop.minikdc.KerberosSecurityTestcase;
import org.apache.hadoop.net.NetUtils;
import org.apache.hadoop.security.UserGroupInformation;
import org.apache.hadoop.security.authentication.KerberosTestUtils;
import org.apache.hadoop.security.authentication.client.KerberosAuthenticator;
import org.apache.hadoop.security.authorize.AccessControlList;
import org.apache.hadoop.security.ssl.KeyStoreTestUtil;
import org.junit.Assert;

import junit.framework.TestCase;
import org.apache.hadoop.test.GenericTestUtils;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.junit.AfterClass;
import org.junit.Before;
import org.junit.BeforeClass;
import org.junit.Test;
import org.slf4j.LoggerFactory;

import org.apache.commons.logging.*;
import org.apache.commons.logging.impl.*;
import org.apache.log4j.*;
import org.junit.Assert;
import javax.net.ssl.SSLException;

import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;
import static org.junit.Assert.fail;

/**
* Test LogLevel.
*/
public class TestLogLevel extends KerberosSecurityTestcase {
private static final File BASEDIR = GenericTestUtils.getRandomizedTestDir();
private static String keystoresDir;
private static String sslConfDir;
private static Configuration conf;
private static Configuration sslConf;
private final String logName = TestLogLevel.class.getName();
private String clientPrincipal;
private String serverPrincipal;
private final Log testlog = LogFactory.getLog(logName);
private final Logger log = ((Log4JLogger)testlog).getLogger();
private final static String PRINCIPAL = "loglevel.principal";
private final static String KEYTAB = "loglevel.keytab";

public class TestLogLevel extends TestCase {
static final PrintStream out = System.out;

public void testDynamicLogLevel() throws Exception {
String logName = TestLogLevel.class.getName();
Log testlog = LogFactory.getLog(logName);

//only test Log4JLogger
if (testlog instanceof Log4JLogger) {
Logger log = ((Log4JLogger)testlog).getLogger();
log.debug("log.debug1");
log.info("log.info1");
log.error("log.error1");
Assert.assertNotEquals("Get default Log Level which shouldn't be ERROR.",
Level.ERROR, log.getEffectiveLevel());

HttpServer2 server = new HttpServer2.Builder().setName("..")
.addEndpoint(new URI("http://localhost:0")).setFindPort(true)
.build();

server.start();
String authority = NetUtils.getHostPortString(server
.getConnectorAddress(0));

//servlet
URL url = new URL("http://" + authority + "/logLevel?log=" + logName
+ "&level=" + Level.ERROR);
out.println("*** Connecting to " + url);
URLConnection connection = url.openConnection();
connection.connect();

BufferedReader in = new BufferedReader(new InputStreamReader(
connection.getInputStream()));
for(String line; (line = in.readLine()) != null; out.println(line));
in.close();

log.debug("log.debug2");
log.info("log.info2");
log.error("log.error2");
assertEquals("Try setting log level: ERROR from servlet.", Level.ERROR,
log.getEffectiveLevel());

//command line
String[] args = {"-setlevel", authority, logName, Level.DEBUG.toString()};
LogLevel.main(args);
log.debug("log.debug3");
log.info("log.info3");
log.error("log.error3");
assertEquals("Try setting log level: DEBUG via command line", Level.DEBUG,
log.getEffectiveLevel());

// Test mixed upper case and lower case in level string.
String[] args2 = {"-setlevel", authority, logName, "Info"};
LogLevel.main(args2);
log.debug("log.debug4");
log.info("log.info4");
log.error("log.error4");
assertEquals("Try setting log level: Info via command line.", Level.INFO,
log.getEffectiveLevel());

// Test "Error" instead of "ERROR" should work for servlet
URL newUrl = new URL("http://" + authority + "/logLevel?log=" + logName
+ "&level=" + "Error");
out.println("*** Connecting to " + newUrl);
connection = newUrl.openConnection();
connection.connect();

BufferedReader in2 = new BufferedReader(new InputStreamReader(
connection.getInputStream()));
for(String line; (line = in2.readLine()) != null; out.println(line));
in2.close();

log.debug("log.debug5");
log.info("log.info5");
log.error("log.error5");
assertEquals("Try setting log level: Error via servlet.", Level.ERROR,
log.getEffectiveLevel());
@BeforeClass
public static void setUp() throws Exception {
org.slf4j.Logger logger =
LoggerFactory.getLogger(KerberosAuthenticator.class);
GenericTestUtils.setLogLevel(logger, Level.DEBUG);
FileUtil.fullyDelete(BASEDIR);
if (!BASEDIR.mkdirs()) {
throw new Exception("unable to create the base directory for testing");
}
else {
out.println(testlog.getClass() + " not tested.");
conf = new Configuration();

setupSSL(BASEDIR);
}

static private void setupSSL(File base) throws Exception {
keystoresDir = base.getAbsolutePath();
sslConfDir = KeyStoreTestUtil.getClasspathDir(TestLogLevel.class);
KeyStoreTestUtil.setupSSLConfig(keystoresDir, sslConfDir, conf, false);

sslConf = KeyStoreTestUtil.getSslConfig();
}

@Before
public void setupKerberos() throws Exception {
File keytabFile = new File(KerberosTestUtils.getKeytabFile());
clientPrincipal = KerberosTestUtils.getClientPrincipal();
serverPrincipal = KerberosTestUtils.getServerPrincipal();
clientPrincipal = clientPrincipal.substring(0,
clientPrincipal.lastIndexOf("@"));
serverPrincipal = serverPrincipal.substring(0,
serverPrincipal.lastIndexOf("@"));
getKdc().createPrincipal(keytabFile, clientPrincipal, serverPrincipal);
}

@AfterClass
public static void tearDown() throws Exception {
KeyStoreTestUtil.cleanupSSLConfig(keystoresDir, sslConfDir);
FileUtil.fullyDelete(BASEDIR);
}

/**
* Test client command line options. Does not validate server behavior.
* @throws Exception
*/
@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, "-protocol",
"http" }));
assertTrue(validateCommand(
new String[] {"-getlevel", "foo.bar:8080", className, "-protocol",
"https" }));
assertTrue(validateCommand(
new String[] {"-setlevel", "foo.bar:8080", className, "DEBUG",
"-protocol", "http" }));
assertTrue(validateCommand(
new String[] {"-setlevel", "foo.bar:8080", className, "DEBUG",
"-protocol", "https" }));

// fail due to the extra argument
assertFalse(validateCommand(
new String[] {"-getlevel", "foo.bar:8080", className, "-protocol",
"https", "blah" }));
assertFalse(validateCommand(
new String[] {"-setlevel", "foo.bar:8080", className, "DEBUG",
"-protocol", "https", "blah" }));
assertFalse(validateCommand(
new String[] {"-getlevel", "foo.bar:8080", className, "-protocol",
"https", "-protocol", "https" }));
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) throws Exception {
CLI cli = new CLI(sslConf);
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 protocol "http" or "https"
* @param isSpnego true if SPNEGO is enabled
* @return a created HttpServer2 object
* @throws Exception if unable to create or start a Jetty server
*/
private HttpServer2 createServer(String protocol, boolean isSpnego)
throws Exception {
HttpServer2.Builder builder = new HttpServer2.Builder()
.setName("..")
.addEndpoint(new URI(protocol + "://localhost:0"))
.setFindPort(true)
.setConf(conf);
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(clientPrincipal));
}

// if using HTTPS, configure keystore/truststore properties.
if (protocol.equals(LogLevel.PROTOCOL_HTTPS)) {
builder = builder.
keyPassword(sslConf.get("ssl.server.keystore.keypassword"))
.keyStore(sslConf.get("ssl.server.keystore.location"),
sslConf.get("ssl.server.keystore.password"),
sslConf.get("ssl.server.keystore.type", "jks"))
.trustStore(sslConf.get("ssl.server.truststore.location"),
sslConf.get("ssl.server.truststore.password"),
sslConf.get("ssl.server.truststore.type", "jks"));
}
HttpServer2 server = builder.build();
// Enable SPNEGO for LogLevel servlet
if (isSpnego) {
server.addInternalServlet("logLevel", "/logLevel", LogLevel.Servlet.class,
true);
}
server.start();
return server;
}

private void testDynamicLogLevel(final String bindProtocol,
final String connectProtocol, final boolean isSpnego)
throws Exception {
testDynamicLogLevel(bindProtocol, connectProtocol, isSpnego,
Level.DEBUG.toString());
}

/**
* Run both client and server using the given protocol.
*
* @param bindProtocol specify either http or https for server
* @param connectProtocol specify either http or https for client
* @param isSpnego true if SPNEGO is enabled
* @throws Exception
*/
private void testDynamicLogLevel(final String bindProtocol,
final String connectProtocol, final boolean isSpnego,
final String newLevel) throws Exception {
if (!LogLevel.isValidProtocol(bindProtocol)) {
throw new Exception("Invalid server protocol " + bindProtocol);
}
if (!LogLevel.isValidProtocol(connectProtocol)) {
throw new Exception("Invalid client protocol " + connectProtocol);
}
Level oldLevel = log.getEffectiveLevel();
Assert.assertNotEquals("Get default Log Level which shouldn't be ERROR.",
Level.ERROR, oldLevel);

// configs needed for SPNEGO at server side
if (isSpnego) {
conf.set(PRINCIPAL, KerberosTestUtils.getServerPrincipal());
conf.set(KEYTAB, KerberosTestUtils.getKeytabFile());
conf.set(CommonConfigurationKeysPublic.HADOOP_SECURITY_AUTHENTICATION,
"kerberos");
conf.setBoolean(CommonConfigurationKeys.HADOOP_SECURITY_AUTHORIZATION,
true);
UserGroupInformation.setConfiguration(conf);
}

final HttpServer2 server = createServer(bindProtocol, isSpnego);
// get server port
final String authority = NetUtils.getHostPortString(server
.getConnectorAddress(0));

KerberosTestUtils.doAsClient(new Callable<Void>() {
@Override
public Void call() throws Exception {
// client command line
getLevel(connectProtocol, authority);
setLevel(connectProtocol, authority, newLevel);
return null;
}
});
server.stop();
// restore log level
GenericTestUtils.setLogLevel(log, oldLevel);
}

/**
* Run LogLevel command line to start a client to get log level of this test
* class.
*
* @param protocol specify either http or https
* @param authority daemon's web UI address
* @throws Exception if unable to connect
*/
private void getLevel(String protocol, String authority) throws Exception {
String[] getLevelArgs = {"-getlevel", authority, logName, "-protocol",
protocol};
CLI cli = new CLI(sslConf);
cli.run(getLevelArgs);
}

/**
* Run LogLevel command line to start a client to set log level of this test
* class to debug.
*
* @param protocol specify either http or https
* @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 protocol, String authority, String newLevel)
throws Exception {
String[] setLevelArgs = {"-setlevel", authority, logName,
newLevel, "-protocol", protocol};
CLI cli = new CLI(sslConf);
cli.run(setLevelArgs);

assertEquals("new level not equal to expected: ", newLevel.toUpperCase(),
log.getEffectiveLevel().toString());
}

/**
* Test setting log level to "Info".
*
* @throws Exception
*/
@Test(timeout=60000)
public void testInfoLogLevel() throws Exception {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, false,
"Info");
}

/**
* Test setting log level to "Error".
*
* @throws Exception
*/
@Test(timeout=60000)
public void testErrorLogLevel() throws Exception {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, false,
"Error");
}

/**
* Server runs HTTP, no SPNEGO.
*
* @throws Exception
*/
@Test(timeout=60000)
public void testLogLevelByHttp() throws Exception {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, false);
try {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTPS,
false);
fail("A HTTPS Client should not have succeeded in connecting to a " +
"HTTP server");
} catch (SSLException e) {
GenericTestUtils.assertExceptionContains("Unrecognized SSL message", e);
}
}

/**
* Server runs HTTP + SPNEGO.
*
* @throws Exception
*/
@Test(timeout=60000)
public void testLogLevelByHttpWithSpnego() throws Exception {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTP, true);
try {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTP, LogLevel.PROTOCOL_HTTPS,
true);
fail("A HTTPS Client should not have succeeded in connecting to a " +
"HTTP server");
} catch (SSLException e) {
GenericTestUtils.assertExceptionContains("Unrecognized SSL message", e);
}
}

/**
* Server runs HTTPS, no SPNEGO.
*
* @throws Exception
*/
@Test(timeout=60000)
public void testLogLevelByHttps() throws Exception {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTPS,
false);
try {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTP,
false);
fail("A HTTP Client should not have succeeded in connecting to a " +
"HTTPS server");
} catch (SocketException e) {
GenericTestUtils.assertExceptionContains(
"Unexpected end of file from server", e);
}
}

/**
* Server runs HTTPS + SPNEGO.
*
* @throws Exception
*/
@Test(timeout=60000)
public void testLogLevelByHttpsWithSpnego() throws Exception {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTPS,
true);
try {
testDynamicLogLevel(LogLevel.PROTOCOL_HTTPS, LogLevel.PROTOCOL_HTTP,
true);
fail("A HTTP Client should not have succeeded in connecting to a " +
"HTTPS server");
} catch (SocketException e) {
GenericTestUtils.assertExceptionContains(
"Unexpected end of file from server", e);
}
}
}
}