Merge pull request #101 from hazendaz/master

Enhance Logging Usage / Formatting

Source/JNA/waffle-jetty/src/test/java/waffle/jetty/StartEmbeddedJetty.java

@@ -17,63 +17,66 @@
 import java.io.FileNotFoundException;
 
 import org.apache.jasper.servlet.JspServlet;
-import org.eclipse.jetty.server.Connector;
+// import org.eclipse.jetty.server.Connector;
 import org.eclipse.jetty.server.Server;
 //import org.eclipse.jetty.server.bio.SocketConnector;
 import org.eclipse.jetty.servlet.ServletHolder;
 import org.eclipse.jetty.webapp.WebAppContext;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 
 /**
  * A simple embedded server that lets us run directly within Eclipse
  */
-public class StartEmbeddedJetty
-{
-  public static void main(String[] args) throws Exception
-  {
-    String path = "../waffle-demo-parent/waffle-filter";
-
-    File dir = new File( path );
-    if(!dir.exists()) {
-      throw new FileNotFoundException("Can not find webapp: "+dir.getAbsolutePath());
-    }
-
-    Server server = new Server(8080);
-    //SocketConnector connector = new SocketConnector();
+public class StartEmbeddedJetty {
 
-    // Set some timeout options to make debugging easier.
-//    connector.setMaxIdleTime(1000 * 60 * 60);
-//    connector.setSoLingerTime(-1);
-//    connector.setPort(8080);
-//    connector.setRequestHeaderSize(20*1044); // 20K for big request headers
-//    server.setConnectors(new Connector[] { connector });
+	private static Logger logger = LoggerFactory.getLogger(StartEmbeddedJetty.class);
 
-    WebAppContext context = new WebAppContext();
-    context.setServer(server);
-    context.setContextPath("/");
-    context.setWar(path);
-
-    // Try adding JSP
-    try {
-      ServletHolder jsp = context.addServlet(JspServlet.class, "*.jsp");
-      jsp.setInitParameter("classpath", context.getClassPath());
-    }
-    catch( Exception ex) {
-      System.err.println("Error adding JSP Support: "+ex.toString());
-    }
+	public static void main(String[] args) throws Exception {
+		String path = "../waffle-demo-parent/waffle-filter";
 
-    server.setHandler(context);
+		File dir = new File( path );
+		if(!dir.exists()) {
+			throw new FileNotFoundException("Can not find webapp: "+ dir.getAbsolutePath());
+		}
+
+		Server server = new Server(8080);
+		// SocketConnector connector = new SocketConnector();
+
+		// Set some timeout options to make debugging easier.
+		// connector.setMaxIdleTime(1000 * 60 * 60);
+		// connector.setSoLingerTime(-1);
+		// connector.setPort(8080);
+		// connector.setRequestHeaderSize(20*1044); // 20K for big request headers
+		// server.setConnectors(new Connector[] { connector });
+
+		WebAppContext context = new WebAppContext();
+		context.setServer(server);
+		context.setContextPath("/");
+		context.setWar(path);
+
+		// Try adding JSP
+		try {
+			ServletHolder jsp = context.addServlet(JspServlet.class, "*.jsp");
+			jsp.setInitParameter("classpath", context.getClassPath());
+		} catch( Exception e) {
+			StartEmbeddedJetty.logger.error("{}", e);
+		}
+
+		server.setHandler(context);
+
+		try {
+		    StartEmbeddedJetty.logger.info(">>> STARTING EMBEDDED JETTY SERVER, PRESS ANY KEY TO STOP");
+			server.start();
+			System.in.read();
+			StartEmbeddedJetty.logger.info(">>> STOPPING EMBEDDED JETTY SERVER");
+			server.stop();
+			server.join();
+		} catch (Exception e) {
+			StartEmbeddedJetty.logger.error("{}", e);
+			System.exit(100);
+		}
+	}
 
-    try {
-      System.out.println(">>> STARTING EMBEDDED JETTY SERVER, PRESS ANY KEY TO STOP");
-      server.start();
-      System.in.read();
-      System.out.println(">>> STOPPING EMBEDDED JETTY SERVER");
-      server.stop();
-      server.join();
-    } catch (Exception e) {
-      e.printStackTrace();
-      System.exit(100);
-    }
-  }
 }

Source/JNA/waffle-jna/pom.xml

@@ -38,6 +38,12 @@
       <artifactId>slf4j-api</artifactId>
       <version>${slf4j.version}</version>
     </dependency>
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>slf4j-simple</artifactId>
+      <version>${slf4j.version}</version>
+      <optional>true</optional>
+    </dependency>
     <dependency>
       <groupId>com.google.guava</groupId>
       <artifactId>guava</artifactId>

Source/JNA/waffle-jna/src/main/java/waffle/jaas/WindowsLoginModule.java

@@ -31,6 +31,9 @@
 import javax.security.auth.login.LoginException;
 import javax.security.auth.spi.LoginModule;
 
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
 import waffle.windows.auth.IWindowsAccount;
 import waffle.windows.auth.IWindowsAuthProvider;
 import waffle.windows.auth.IWindowsIdentity;
@@ -45,6 +48,8 @@
  */
 public class WindowsLoginModule implements LoginModule {
 
+	private Logger _log = LoggerFactory.getLogger(WindowsLoginModule.class);
+
 	private String _username = null;
 	private boolean _debug = false;
 	private Subject _subject = null;
@@ -93,8 +98,8 @@ public boolean login() throws LoginException {
 		callbacks[0] = usernameCallback;
 		callbacks[1] = passwordCallback;
 
-		String username = null;
-		String password = null;
+		String username;
+		String password;
 
 		try {
 			_callbackHandler.handle(callbacks);
@@ -121,7 +126,7 @@ public boolean login() throws LoginException {
 		try {
 			// disable guest login
 			if (!_allowGuestLogin && windowsIdentity.isGuest()) {
-				debug("guest login disabled: " + windowsIdentity.getFqn());
+				_log.debug("guest login disabled: {}", windowsIdentity.getFqn());
 				throw new LoginException("Guest login disabled");
 			}
 
@@ -135,8 +140,8 @@ public boolean login() throws LoginException {
 			}
 
 			_username = windowsIdentity.getFqn();
-			debug("successfully logged in " + _username + " ("
-					+ windowsIdentity.getSidString() + ")");
+			_log.debug("successfully logged in {} ({})", _username,
+					windowsIdentity.getSidString());
 		} finally {
 			windowsIdentity.dispose();
 		}
@@ -168,10 +173,10 @@ public boolean commit() throws LoginException {
 		Set<Principal> principals = _subject.getPrincipals();
 		principals.addAll(_principals);
 
-		debug("committing " + _subject.getPrincipals().size() + " principals");
+		_log.debug("committing {} principals", Integer.valueOf(_subject.getPrincipals().size()));
 		if (_debug) {
 			for (Principal principal : principals) {
-				debug(" principal: " + principal.getName());
+				_log.debug(" principal: {}", principal.getName());
 			}
 		}
 
@@ -187,18 +192,12 @@ public boolean logout() throws LoginException {
 		_subject.getPrincipals().clear();
 
 		if (_username != null) {
-			debug("logging out " + _username);
+			_log.debug("logging out {}", _username);
 		}
 
 		return true;
 	}
 
-	private void debug(String message) {
-		if (_debug) {
-			System.out.println("[waffle.jaas.WindowsLoginModule] " + message);
-		}
-	}
-
 	/**
 	 * True if Debug is enabled.
 	 * 

Source/JNA/waffle-jna/src/main/java/waffle/servlet/NegotiateSecurityFilter.java

@@ -77,8 +77,8 @@ public void doFilter(ServletRequest sreq, ServletResponse sres,
 		HttpServletRequest request = (HttpServletRequest) sreq;
 		HttpServletResponse response = (HttpServletResponse) sres;
 
-		_log.debug(request.getMethod() + " " + request.getRequestURI()
-				+ ", contentlength: " + request.getContentLength());
+		_log.debug("{} {}, contentlength: {}", request.getMethod(), request.getRequestURI(),
+				Integer.valueOf(request.getContentLength()));
 
 		if (doFilterPrincipal(request, response, chain)) {
 			// previously authenticated user
@@ -102,22 +102,22 @@ public void doFilter(ServletRequest sreq, ServletResponse sres,
 				}
 
 			} catch (Exception e) {
-				_log.warn("error logging in user: " + e.getMessage());
+				_log.warn("error logging in user: {}", e.getMessage());
+				_log.trace("{}", e);
 				sendUnauthorized(response, true);
 				return;
 			}
 
 			IWindowsImpersonationContext ctx = null;
 			try {
 				if (!_allowGuestLogin && windowsIdentity.isGuest()) {
-					_log.warn("guest login disabled: "
-							+ windowsIdentity.getFqn());
+					_log.warn("guest login disabled: {}", windowsIdentity.getFqn());
 					sendUnauthorized(response, true);
 					return;
 				}
 
-				_log.debug("logged in user: " + windowsIdentity.getFqn() + " ("
-						+ windowsIdentity.getSidString() + ")");
+				_log.debug("logged in user: {} ({})", windowsIdentity.getFqn(),
+						windowsIdentity.getSidString());
 
 				HttpSession session = request.getSession(true);
 				if (session == null) {
@@ -139,12 +139,12 @@ public void doFilter(ServletRequest sreq, ServletResponse sres,
 							_principalFormat, _roleFormat);
 				}
 
-				_log.debug("roles: " + windowsPrincipal.getRolesString());
+				_log.debug("roles: {}", windowsPrincipal.getRolesString());
 				subject.getPrincipals().add(windowsPrincipal);
 				session.setAttribute("javax.security.auth.subject", subject);
 
-				_log.info("successfully logged in user: "
-						+ windowsIdentity.getFqn());
+				_log.info("successfully logged in user: {}",
+						windowsIdentity.getFqn());
 
 				request.getSession().setAttribute(PRINCIPAL_SESSION_KEY,
 						windowsPrincipal);
@@ -284,8 +284,8 @@ public void init(FilterConfig filterConfig) throws ServletException {
 				_auth = (IWindowsAuthProvider) Class.forName(authProvider)
 						.getConstructor().newInstance();
 			} catch (Exception e) {
-				_log.error("error loading '" + authProvider + "': "
-						+ e.getMessage());
+				_log.error("error loading '{}': {}", authProvider, e.getMessage());
+				_log.trace("{}", e);
 				throw new ServletException(e);
 			}
 		}
@@ -311,26 +311,26 @@ public void init(FilterConfig filterConfig) throws ServletException {
 			if (classAndParameter.length == 2) {
 				try {
 
-					_log.debug("setting " + classAndParameter[0] + ", "
-							+ classAndParameter[1] + "="
-							+ implParameter.getValue());
+					_log.debug("setting {}, {}={}", classAndParameter[0],
+							classAndParameter[1], implParameter.getValue());
 
 					SecurityFilterProvider provider = _providers
 							.getByClassName(classAndParameter[0]);
 					provider.initParameter(classAndParameter[1],
 							implParameter.getValue());
 
 				} catch (ClassNotFoundException e) {
-					_log.error("invalid class: " + classAndParameter[0]
-							+ " in " + implParameter.getKey());
+					_log.error("invalid class: {} in {}", classAndParameter[0],
+							implParameter.getKey());
 					throw new ServletException(e);
 				} catch (Exception e) {
-					_log.error(classAndParameter[0] + ": error setting '"
-							+ classAndParameter[1] + "': " + e.getMessage());
+					_log.error("{}: error setting '{}': {}", classAndParameter[0],
+							classAndParameter[1], e.getMessage());
+					_log.trace("{}", e);
 					throw new ServletException(e);
 				}
 			} else {
-				_log.error("Invalid parameter: " + implParameter.getKey());
+				_log.error("Invalid parameter: {}", implParameter.getKey());
 				throw new ServletException("Invalid parameter: "
 						+ implParameter.getKey());
 			}
@@ -347,7 +347,7 @@ public void init(FilterConfig filterConfig) throws ServletException {
 	 */
 	public void setPrincipalFormat(String format) {
 		_principalFormat = PrincipalFormat.valueOf(format);
-		_log.info("principal format: " + _principalFormat);
+		_log.info("principal format: {}", _principalFormat);
 	}
 
 	/**
@@ -367,7 +367,7 @@ public PrincipalFormat getPrincipalFormat() {
 	 */
 	public void setRoleFormat(String format) {
 		_roleFormat = PrincipalFormat.valueOf(format);
-		_log.info("role format: " + _roleFormat);
+		_log.info("role format: {}", _roleFormat);
 	}
 
 	/**

Source/JNA/waffle-jna/src/main/java/waffle/servlet/spi/BasicSecurityFilterProvider.java

@@ -55,7 +55,7 @@ public IWindowsIdentity doFilter(HttpServletRequest request,
 			throw new RuntimeException(
 					"Invalid username:password in Authorization header.");
 		}
-		_log.debug("logging in user: " + usernamePasswordArray[0]);
+		_log.debug("logging in user: {}", usernamePasswordArray[0]);
 		return _auth.logonUser(usernamePasswordArray[0],
 				usernamePasswordArray[1]);
 	}

Source/JNA/waffle-jna/src/main/java/waffle/servlet/spi/NegotiateSecurityFilterProvider.java

@@ -72,8 +72,8 @@ public boolean isPrincipalException(HttpServletRequest request) {
 				request);
 		boolean ntlmPost = authorizationHeader
 				.isNtlmType1PostAuthorizationHeader();
-		_log.debug("authorization: " + authorizationHeader.toString()
-				+ ", ntlm post: " + ntlmPost);
+		_log.debug("authorization: {}, ntlm post: {}", authorizationHeader,
+				Boolean.valueOf(ntlmPost));
 		return ntlmPost;
 	}
 
@@ -89,23 +89,23 @@ public IWindowsIdentity doFilter(HttpServletRequest request,
 		// maintain a connection-based session for NTLM tokns
 		String connectionId = NtlmServletRequest.getConnectionId(request);
 		String securityPackage = authorizationHeader.getSecurityPackage();
-		_log.debug("security package: " + securityPackage + ", connection id: "
-				+ connectionId);
+		_log.debug("security package: {}, connection id: {}", securityPackage,
+				connectionId);
 
 		if (ntlmPost) {
 			// type 2 NTLM authentication message received
 			_auth.resetSecurityToken(connectionId);
 		}
 
 		byte[] tokenBuffer = authorizationHeader.getTokenBytes();
-		_log.debug("token buffer: " + tokenBuffer.length + " byte(s)");
+		_log.debug("token buffer: {} byte(s)", Integer.valueOf(tokenBuffer.length));
 		IWindowsSecurityContext securityContext = _auth.acceptSecurityToken(
 				connectionId, tokenBuffer, securityPackage);
 
 		byte[] continueTokenBytes = securityContext.getToken();
 		if (continueTokenBytes != null && continueTokenBytes.length > 0) {
-			String continueToken = new String(Base64.encode(continueTokenBytes));
-			_log.debug("continue token: " + continueToken);
+			String continueToken = Base64.encode(continueTokenBytes);
+			_log.debug("continue token: {}", continueToken);
 			response.addHeader("WWW-Authenticate", securityPackage + " "
 					+ continueToken);
 		}
@@ -141,7 +141,7 @@ public void initParameter(String parameterName, String parameterValue) {
 			for (String protocolName : protocolNames) {
 				protocolName = protocolName.trim();
 				if (protocolName.length() > 0) {
-					_log.debug("init protocol: " + protocolName);
+					_log.debug("init protocol: {}", protocolName);
 					if (protocolName.equals("Negotiate")
 							|| protocolName.equals("NTLM")) {
 						_protocols.add(protocolName);