Added Rpc tracing capabilities with the log4j changes.

CASA-auth-token/server-java/Svc/linux/log4j.properties

@@ -18,3 +18,20 @@ log4j.appender.DefaultAppender.MaxFileSize=100KB
 log4j.appender.DefaultAppender.MaxBackupIndex=2
 log4j.appender.DefaultAppender.layout=org.apache.log4j.PatternLayout
 log4j.appender.DefaultAppender.layout.ConversionPattern=%d{ISO8601} %p %C{2} %m%n
+
+#
+# ATS_Trace logger configuration.
+#
+log4j.logger.ATS_Trace=info, TraceAppender
+log4j.additivity.ATS_Trace=false
+
+#
+# TraceAppender configuration.
+#
+log4j.appender.TraceAppender=org.apache.log4j.RollingFileAppender
+log4j.appender.TraceAppender.File=/srv/www/casaats/logs/ats.trace
+log4j.appender.TraceAppender.MaxFileSize=100KB
+log4j.appender.TraceAppender.MaxBackupIndex=2
+log4j.appender.TraceAppender.layout=org.apache.log4j.PatternLayout
+log4j.appender.TraceAppender.layout.ConversionPattern=%d{ISO8601} %p [%x] %m%n
+

CASA-auth-token/server-java/Svc/src/com/novell/casa/authtoksvc/Authenticate.java

@@ -48,6 +48,7 @@ import java.net.URLClassLoader;
 public final class Authenticate implements RpcMethod
 {
    private static final Logger   m_log = Logger.getLogger(Authenticate.class);
+   private Logger m_trace = null;
 
    private static final String   m_mechanismSettingsFileName = "mechanism.settings";
 
@@ -70,12 +71,16 @@ public final class Authenticate implements RpcMethod
     *
     * @param svcConfig           Service configuration object.
     * @param enabledSvcsConfig   Enabled services configuration object.
+    * @param traceLogger         Logger for tracing requests.
     * @throws Exception
     */
-   public final void init(SvcConfig svcConfig, EnabledSvcsConfig enabledSvcsConfig) throws Exception
+   public final void init(SvcConfig svcConfig,
+                          EnabledSvcsConfig enabledSvcsConfig,
+                          Logger traceLogger) throws Exception
    {
       m_svcConfig = svcConfig;
       m_enabledSvcsConfig = enabledSvcsConfig;
+      m_trace = traceLogger;
 
       // Now go through the configured authentication mechanisms, as we do so, instantiate
       // the mechanisms and place them in our map. Note that the mechanisms config folder
@@ -352,10 +357,17 @@ public final class Authenticate implements RpcMethod
                                                          sessionToken.toString(),
                                                          respLifetime);
                out.println(authRespMsg.toString());
+
+               m_trace.info("Authenticate Rpc, Mech=" + authReqMsg.getMechanismId()
+                            + ", Realm=" + authReqMsg.getRealm()
+                            + ", Status=SUCCESS");
             }
             else
             {
                m_log.info("invoke()- identId not resolved");
+               m_trace.info("Authenticate Rpc, Mech=" + authReqMsg.getMechanismId()
+                            + ", Realm=" + authReqMsg.getRealm()
+                            + ", Status=UNSUCCESSFUL");
 
                // Write out the response
                AuthRespMsg authRespMsg = new AuthRespMsg(ProtoDefs.httpUnauthorizedStatusMsg,
@@ -366,6 +378,9 @@ public final class Authenticate implements RpcMethod
          else
          {
             m_log.warn("invoke()- Unsupported mechanism " + authReqMsg.getMechanismId());
+            m_trace.info("Authenticate Rpc, Mech=" + authReqMsg.getMechanismId()
+                         + ", Realm=" + authReqMsg.getRealm()
+                         + ", Status=UNSUPPORTED_MECHANISM");
 
             // Write out the response
             AuthRespMsg authRespMsg = new AuthRespMsg(ProtoDefs.httpNotFoundStatusMsg,
@@ -376,6 +391,7 @@ public final class Authenticate implements RpcMethod
       catch (Exception e)
       {
          m_log.error("invoke()- Exception: " + e.toString());
+         m_trace.info("Authenticate Rpc, Status=INTERNAL_ERROR");
 
          // Write out the response
          try

CASA-auth-token/server-java/Svc/src/com/novell/casa/authtoksvc/GetAuthPolicy.java

@@ -39,6 +39,7 @@ import java.io.PrintWriter;
 public final class GetAuthPolicy implements RpcMethod
 {
    private static final Logger m_log = Logger.getLogger(GetAuthPolicy.class);
+   private Logger m_trace = null;
 
    private SvcConfig          m_svcConfig;
    private EnabledSvcsConfig  m_enabledSvcsConfig;
@@ -56,12 +57,16 @@ public final class GetAuthPolicy implements RpcMethod
     *
     * @param svcConfig           Service configuration object.
     * @param enabledSvcsConfig   Enabled services configuration object.
+    * @param traceLogger         Logger for tracing requests.
     * @throws Exception
     */
-   public void init(SvcConfig svcConfig, EnabledSvcsConfig enabledSvcsConfig) throws Exception
+   public void init(SvcConfig svcConfig,
+                    EnabledSvcsConfig enabledSvcsConfig,
+                    Logger traceLogger) throws Exception
    {
       m_svcConfig = svcConfig;
       m_enabledSvcsConfig = enabledSvcsConfig;
+      m_trace = traceLogger;
    }
 
    /**
@@ -93,13 +98,20 @@ public final class GetAuthPolicy implements RpcMethod
                                                                                     ProtoDefs.httpOkStatusCode,
                                                                                     new String(Base64Coder.encode(authPolicy)));
                out.println(getAuthPolicyRespMsg.toString());
+               m_trace.info("GetAuthPolicy Rpc, Host=" + getAuthPolicyReqMsg.getHostName()
+                            + ", Svc=" + getAuthPolicyReqMsg.getServiceName()
+                            + ", Status=SUCCESS");
             }
             else
             {
-               m_log.debug("invoke()- authPolicy is null for enabled service: " + getAuthPolicyReqMsg.getServiceName());
+               m_log.error("invoke()- authPolicy is null for enabled service: " + getAuthPolicyReqMsg.getServiceName());
                GetAuthPolicyRespMsg getAuthPolicyRespMsg = new GetAuthPolicyRespMsg(ProtoDefs.httpServerErrorStatusMsg,
                                                                                     ProtoDefs.httpServerErrorStatusCode);
                out.println(getAuthPolicyRespMsg.toString());
+
+               m_trace.info("GetAuthPolicy Rpc, Host=" + getAuthPolicyReqMsg.getHostName()
+                            + ", Svc=" + getAuthPolicyReqMsg.getServiceName()
+                            + ", Status=INTERNAL_ERROR");
             }
          }
          else
@@ -113,11 +125,16 @@ public final class GetAuthPolicy implements RpcMethod
                        + getAuthPolicyReqMsg.getServiceName()
                        + " at " + getAuthPolicyReqMsg.getHostName()
                        + " not enabled");
+
+            m_trace.info("GetAuthPolicy Rpc, Host=" + getAuthPolicyReqMsg.getHostName()
+                         + ", Svc=" + getAuthPolicyReqMsg.getServiceName()
+                         + ", Status=SERVICE_NOT_CONFIGURED");
          }
       }
       catch (Exception e)
       {
          m_log.error("invoke()- Exception: " + e.toString());
+         m_trace.error("GetAuthPolicy Rpc, Status=INTERNAL_ERROR");
 
          // Write out the response
          try

CASA-auth-token/server-java/Svc/src/com/novell/casa/authtoksvc/GetAuthToken.java

@@ -40,6 +40,7 @@ import java.io.PrintWriter;
 public final class GetAuthToken implements RpcMethod
 {
    private static final Logger m_log = Logger.getLogger(GetAuthToken.class);
+   private Logger m_trace = null;
 
    private SvcConfig          m_svcConfig;
    private EnabledSvcsConfig  m_enabledSvcsConfig;
@@ -57,12 +58,16 @@ public final class GetAuthToken implements RpcMethod
     *
     * @param svcConfig           Service configuration object.
     * @param enabledSvcsConfig   Enabled services configuration object.
+    * @param traceLogger         Logger for tracing requests.
     * @throws Exception
     */
-   public final void init(SvcConfig svcConfig, EnabledSvcsConfig enabledSvcsConfig) throws Exception
+   public final void init(SvcConfig svcConfig,
+                          EnabledSvcsConfig enabledSvcsConfig,
+                          Logger traceLogger) throws Exception
    {
       m_svcConfig = svcConfig;
       m_enabledSvcsConfig = enabledSvcsConfig;
+      m_trace = traceLogger;
    }
 
    /**
@@ -105,10 +110,16 @@ public final class GetAuthToken implements RpcMethod
                                                                            authToken.toString(),
                                                                            authToken.getLifetime());
                out.println(getAuthTokRespMsg.toString());
+               m_trace.info("GetAuthToken Rpc, Host=" + getAuthTokReqMsg.getHostName()
+                            + ", Svc=" + getAuthTokReqMsg.getServiceName()
+                            + ", Status=SUCCESS");
             }
             catch (Exception e)
             {
                m_log.info("invoke()- Exception: " + e.toString());
+               m_trace.info("GetAuthToken Rpc, Host=" + getAuthTokReqMsg.getHostName()
+                            + ", Svc=" + getAuthTokReqMsg.getServiceName()
+                            + ", Status=UNAUTHORIZED");
 
                // Write out the response
                try
@@ -129,11 +140,16 @@ public final class GetAuthToken implements RpcMethod
             GetAuthTokRespMsg getAuthTokRespMsg = new GetAuthTokRespMsg(ProtoDefs.httpNotFoundStatusMsg,
                                                                         ProtoDefs.httpNotFoundStatusCode);
             out.println(getAuthTokRespMsg.toString());
+
+            m_trace.info("GetAuthToken Rpc, Host=" + getAuthTokReqMsg.getHostName()
+                         + ", Svc=" + getAuthTokReqMsg.getServiceName()
+                         + ", Status=SERVICE_NOT_CONFIGURED");
          }
       }
       catch (Exception e)
       {
          m_log.error("invoke()- Exception: " + e.toString());
+         m_trace.info("GetAuthToken Rpc, Status=INTERNAL_ERROR");
 
          // Write out the response
          try

CASA-auth-token/server-java/Svc/src/com/novell/casa/authtoksvc/Rpc.java

@@ -26,6 +26,7 @@ package com.novell.casa.authtoksvc;
 
 import org.bandit.ia.IAContext;
 import org.apache.log4j.Logger;
+import org.apache.log4j.NDC;
 
 import java.util.*;
 
@@ -49,6 +50,7 @@ public final class Rpc extends javax.servlet.http.HttpServlet implements javax.s
    private static final long serialVersionUID = -8264027868130334613L;
 
    private static final Logger m_log = Logger.getLogger(Rpc.class);
+   private static final Logger m_trace = Logger.getLogger("ATS_Trace");
 
    private     String               m_appFolderPath = null;
    private     String               m_configFolderPath = null;
@@ -167,15 +169,15 @@ public final class Rpc extends javax.servlet.http.HttpServlet implements javax.s
 
       // Instantiate the Rpc Methods
       RpcMethod getAuthPolicy = new GetAuthPolicy();
-      getAuthPolicy.init(svcConfig, enabledSvcsConfig);
+      getAuthPolicy.init(svcConfig, enabledSvcsConfig, m_trace);
       methodsMap.put(getAuthPolicy.getId(), getAuthPolicy);
 
       RpcMethod authenticate = new Authenticate();
-      authenticate.init(svcConfig, enabledSvcsConfig);
+      authenticate.init(svcConfig, enabledSvcsConfig, m_trace);
       methodsMap.put(authenticate.getId(), authenticate);
 
       RpcMethod getAuthToken = new GetAuthToken();
-      getAuthToken.init(svcConfig, enabledSvcsConfig);
+      getAuthToken.init(svcConfig, enabledSvcsConfig, m_trace);
       methodsMap.put(getAuthToken.getId(), getAuthToken);
 
       // Set the map as the methods map used by the servlet
@@ -291,6 +293,9 @@ public final class Rpc extends javax.servlet.http.HttpServlet implements javax.s
       {
          m_log.debug("doPost()");
 
+         // Get ready to trace request
+         NDC.push("ClientAddr=" + request.getRemoteAddr());
+
          // Get ready to send back a reply
          response.setContentType("text/html");
          out = response.getWriter();
@@ -312,6 +317,7 @@ public final class Rpc extends javax.servlet.http.HttpServlet implements javax.s
             {
                // Unsupported method
                m_log.warn("doPost()- Unsupported method");
+               m_trace.warn("Rpc, Method=" + requestedMethod + ", Status=UNSUPPORTED");
                response.sendError(HttpServletResponse.SC_BAD_REQUEST);
             }
          }
@@ -319,18 +325,21 @@ public final class Rpc extends javax.servlet.http.HttpServlet implements javax.s
          {
             // Missing method parameter
             m_log.warn("doPost()- Missing method parameter");
+            m_trace.warn("Rpc, Status=INVALID_REQUEST");
             response.sendError(HttpServletResponse.SC_BAD_REQUEST);
          }
       }
       catch (Exception e)
       {
          m_log.error("doPost()- Exception caught: " + e.toString());
+         m_trace.warn("Rpc, Status=INTERNAL_ERROR");
          e.printStackTrace();
          response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR);
       }
       catch (Error e)
       {
          m_log.error("doPost()- Error caught: " + e.toString());
+         m_trace.warn("Rpc, Status=INTERNAL_ERROR");
          e.printStackTrace();
          response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR);
       }
@@ -360,6 +369,8 @@ public final class Rpc extends javax.servlet.http.HttpServlet implements javax.s
                // Do nothing
             }
          }
+
+         NDC.pop();
       }
    }
 }

CASA-auth-token/server-java/Svc/src/com/novell/casa/authtoksvc/RpcMethod.java

@@ -24,6 +24,8 @@
 
 package com.novell.casa.authtoksvc;
 
+import org.apache.log4j.Logger;
+
 import java.io.*;
 import java.io.PrintWriter;
 
@@ -40,9 +42,12 @@ public interface RpcMethod
     *
     * @param svcConfig           Service configuration object.
     * @param enabledSvcsConfig   Enabled services configuration object.
+    * @param traceLogger         Logger for tracing requests.
     * @throws Exception
     */
-   void init(SvcConfig svcConfig, EnabledSvcsConfig enabledSvcsConfig) throws Exception;
+   void init(SvcConfig svcConfig,
+             EnabledSvcsConfig enabledSvcsConfig,
+             Logger traceLogger) throws Exception;
 
    /**
     * Process Rpc.