svn commit: r290523 - in /webservices/wss4j/trunk/src: ./ org/apache/ws/axis/security/ org/apache/ws/security/ org/apache/ws/security/action/ org/apache/ws/security/handler/ org/apache/ws/security/message/

Author: werner
Date: Tue Sep 20 11:46:23 2005
New Revision: 290523

URL: http://svn.apache.org/viewcvs?rev=290523&view=rev
Log:
Added some logj4 statements to support performance timing.

Modified:
    webservices/wss4j/trunk/src/log4j.properties
    webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllReceiver.java
    webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllSender.java
    webservices/wss4j/trunk/src/org/apache/ws/security/WSSecurityEngine.java
    
webservices/wss4j/trunk/src/org/apache/ws/security/action/SignatureConfirmationAction.java
    webservices/wss4j/trunk/src/org/apache/ws/security/handler/WSHandler.java
    
webservices/wss4j/trunk/src/org/apache/ws/security/message/EnvelopeIdResolver.java
    
webservices/wss4j/trunk/src/org/apache/ws/security/message/WSEncryptBody.java

Modified: webservices/wss4j/trunk/src/log4j.properties
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/log4j.properties?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- webservices/wss4j/trunk/src/log4j.properties (original)
+++ webservices/wss4j/trunk/src/log4j.properties Tue Sep 20 11:46:23 2005
@@ -5,7 +5,7 @@
 # Set the enterprise logger category to FATAL and its only appender to CONSOLE.
 # log4j.logger.org.apache.axis.enterprise=FATAL, CONSOLE
 # log4j.logger.org.apache.axis.i18n.ProjectResourceBundle=INFO
-# log4j.logger.org.apache.ws.security.TIME=INFO
+log4j.logger.org.apache.ws.security.TIME=DEBUG
 # log4j.logger.org.apache.ws.security.message.EnvelopeIdResolver=DEBUG
 # log4j.logger.org.apache.ws.security.message.WSEncryptBody=INFO
 # log4j.logger.org.apache.ws.security.message.WSSignEnvelope=DEBUG

Modified: 
webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllReceiver.java
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllReceiver.java?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- 
webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllReceiver.java 
(original)
+++ 
webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllReceiver.java 
Tue Sep 20 11:46:23 2005
@@ -55,6 +55,8 @@
 public class WSDoAllReceiver extends WSDoAllHandler {
 
     protected static Log log = 
LogFactory.getLog(WSDoAllReceiver.class.getName());
+    private static Log tlog =
+        LogFactory.getLog("org.apache.ws.security.TIME");
 
     /**
      * Axis calls invoke to handle a message.
@@ -71,6 +73,10 @@
             log.debug("WSDoAllReceiver: enter invoke() with msg type: "
                     + msgContext.getCurrentMessage().getMessageType());
         }
+        long t0 = 0, t1 = 0, t2 = 0, t3 = 0, t4 = 0;
+        if (tlog.isDebugEnabled()) {
+            t0 = System.currentTimeMillis();
+        }        
 
         RequestData reqData = new RequestData();
         /*
@@ -143,8 +149,12 @@
             * they may be used for encryption too.
             */
             doReceiverAction(doAction, reqData);
-
+            
             Vector wsResult = null;
+            if (tlog.isDebugEnabled()) {
+                t1 = System.currentTimeMillis();
+            }        
+
             try {
                 wsResult = secEngine.processSecurityHeader(doc, actor,
                         cbHandler, reqData.getSigCrypto(), 
reqData.getDecCrypto());
@@ -153,6 +163,11 @@
                 throw new AxisFault(
                         "WSDoAllReceiver: security processing failed", ex);
             }
+
+            if (tlog.isDebugEnabled()) {
+                t2 = System.currentTimeMillis();
+            }        
+
             if (wsResult == null) { // no security header found
                 if (doAction == WSConstants.NO_SECURITY) {
                     return;
@@ -193,6 +208,9 @@
                 log.debug(org.apache.axis.utils.XMLUtils
                         .PrettyDocumentToString(doc));
             }
+            if (tlog.isDebugEnabled()) {
+                t3 = System.currentTimeMillis();
+            }        
 
             /*
             * set the original processed-header flags
@@ -315,6 +333,16 @@
             }
             WSHandlerResult rResult = new WSHandlerResult(actor, wsResult);
             results.add(0, rResult);
+            if (tlog.isDebugEnabled()) {
+                t4 = System.currentTimeMillis();
+                tlog.debug("Receive request: total= " + (t4 - t0) +
+                        " request preparation= " + (t1 - t0) +
+                        " request processing= " + (t2 - t1) +
+                        " request to Axis= " + (t3 - t2) + 
+                        " header, cert verify, timestamp= " + (t4 - t3) +
+                        "\n");                                
+            }        
+
             if (doDebug) {
                 log.debug("WSDoAllReceiver: exit invoke()");
             }

Modified: 
webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllSender.java
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllSender.java?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllSender.java 
(original)
+++ webservices/wss4j/trunk/src/org/apache/ws/axis/security/WSDoAllSender.java 
Tue Sep 20 11:46:23 2005
@@ -42,6 +42,9 @@
 public class WSDoAllSender extends WSDoAllHandler {
 
     protected static Log log = 
LogFactory.getLog(WSDoAllSender.class.getName());
+    private static Log tlog =
+        LogFactory.getLog("org.apache.ws.security.TIME");
+    
     /**
      * Axis calls invoke to handle a message. <p/>
      *
@@ -51,6 +54,12 @@
     public void invoke(MessageContext mc) throws AxisFault {
 
         boolean doDebug = log.isDebugEnabled();
+        
+        long t0 = 0, t1 = 0, t2 = 0, t3 = 0;
+        if (tlog.isDebugEnabled()) {
+            t0 = System.currentTimeMillis();
+        }
+
         if (doDebug && mc.getCurrentMessage() != null
                 && mc.getCurrentMessage().getMessageType() != null) {
             log.debug("WSDoAllSender: enter invoke() with msg type: "
@@ -158,7 +167,15 @@
                                     + e);
                 }
             }
+            if (tlog.isDebugEnabled()) {
+                t1 = System.currentTimeMillis();
+            }
+
             doSenderAction(doAction, doc, reqData, actions, 
!mc.getPastPivot());
+            
+            if (tlog.isDebugEnabled()) {
+                t2 = System.currentTimeMillis();
+            }
 
             /*
                 * If required convert the resulting document into a message 
first.
@@ -194,6 +211,15 @@
                 
((MessageContext)reqData.getMsgContext()).setProperty(WSHandlerConstants.SND_SECURITY,
                         null);
             }
+            if (tlog.isDebugEnabled()) {
+                t3 = System.currentTimeMillis();
+                tlog.debug("Send request: total= " + (t3 - t0) +
+                        " request preparation= " + (t1 - t0) +
+                        " request processing= " + (t2 - t1) +
+                        " request to Axis= " + (t3 - t2) +
+                        "\n");                
+            }
+
             if (doDebug) {
                 log.debug("WSDoAllSender: exit invoke()");
             }

Modified: 
webservices/wss4j/trunk/src/org/apache/ws/security/WSSecurityEngine.java
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/org/apache/ws/security/WSSecurityEngine.java?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- webservices/wss4j/trunk/src/org/apache/ws/security/WSSecurityEngine.java 
(original)
+++ webservices/wss4j/trunk/src/org/apache/ws/security/WSSecurityEngine.java 
Tue Sep 20 11:46:23 2005
@@ -47,11 +47,6 @@
 
     private static WSSecurityEngine engine = null;
     private static WSSConfig wssConfig = WSSConfig.getDefaultWSConfig();
-    /**
-     * The symmetric key.
-     */
-    private byte[] decryptedBytes = null;
-
     private boolean doDebug = false;
     /**
      * <code>wsse:BinarySecurityToken</code> as defined by WS Security 
specification
@@ -188,13 +183,17 @@
 
     /**
      * Process the security header given the <code>wsse:Security</code> DOM
-     * Element. <p/>This function loops over all direct child elements of the
+     * Element. 
+     * 
+     * This function loops over all direct child elements of the
      * <code>wsse:Security</code> header. If it finds a knwon element, it
-     * transfers control to the appropriate handling function. The mehtod
+     * transfers control to the appropriate handling function. The method
      * processes the known child elements in the same order as they appear in
      * the <code>wsse:Security</code> element. This is in accordance to the WS
-     * Security specification. <p/>Currently the functions can handle the
-     * following child elements: here:
+     * Security specification. <p/>
+     * 
+     * Currently the functions can handle the following child elements:
+     * 
      * <ul>
      * <li>{@link #SIGNATURE <code>ds:Signature</code>}</li>
      * <li>{@link #ENCRYPTED_KEY <code>xenc:EncryptedKey</code>}</li>
@@ -202,7 +201,6 @@
      * <li>{@link #usernameToken <code>wsse:UsernameToken</code>}</li>
      * <li>{@link #timeStamp <code>wsu:Timestamp</code>}</li>
      * </ul>
-     * <p/>
      *
      * @param securityHeader the <code>wsse:Security</code> header element
      * @param cb             a callback hander to the caller to resolve 
passwords during
@@ -265,9 +263,9 @@
         }
         if (tlog.isDebugEnabled()) {
             t2 = System.currentTimeMillis();
-            tlog.debug("processHeader: total= " + (t2 - t0) +
-                    ", prepare= " + (t1 - t0) +
-                    ", handle= " + (t2 - t1));
+            tlog.debug("processHeader: total " + (t2 - t0) +
+                    ", prepare " + (t1 - t0) +
+                    ", handle " + (t2 - t1));
         }
         return returnResults;
     }

Modified: 
webservices/wss4j/trunk/src/org/apache/ws/security/action/SignatureConfirmationAction.java
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/org/apache/ws/security/action/SignatureConfirmationAction.java?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- 
webservices/wss4j/trunk/src/org/apache/ws/security/action/SignatureConfirmationAction.java
 (original)
+++ 
webservices/wss4j/trunk/src/org/apache/ws/security/action/SignatureConfirmationAction.java
 Tue Sep 20 11:46:23 2005
@@ -86,6 +86,6 @@
             signatureParts.add(new WSEncryptionPart(id));

         }

         handler.setProperty(reqData.getMsgContext(), 
WSHandlerConstants.SIG_CONF_DONE,

-                handler.DONE);

+                WSHandler.DONE);

     }

 }


Modified: 
webservices/wss4j/trunk/src/org/apache/ws/security/handler/WSHandler.java
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/org/apache/ws/security/handler/WSHandler.java?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- webservices/wss4j/trunk/src/org/apache/ws/security/handler/WSHandler.java 
(original)
+++ webservices/wss4j/trunk/src/org/apache/ws/security/handler/WSHandler.java 
Tue Sep 20 11:46:23 2005
@@ -25,14 +25,6 @@
 import org.apache.ws.security.WSSecurityEngine;
 import org.apache.ws.security.WSSecurityEngineResult;
 import org.apache.ws.security.WSSecurityException;
-import org.apache.ws.security.action.EncryptionAction;
-import org.apache.ws.security.action.SAMLTokenSignedAction;
-import org.apache.ws.security.action.SAMLTokenUnsignedAction;
-import org.apache.ws.security.action.SignatureAction;
-import org.apache.ws.security.action.SignatureConfirmationAction;
-import org.apache.ws.security.action.TimestampAction;
-import org.apache.ws.security.action.UsernameTokenAction;
-import org.apache.ws.security.action.UsernameTokenSignedAction;
 import org.apache.ws.security.components.crypto.Crypto;
 import org.apache.ws.security.components.crypto.CryptoFactory;
 import org.apache.ws.security.message.token.Timestamp;

Modified: 
webservices/wss4j/trunk/src/org/apache/ws/security/message/EnvelopeIdResolver.java
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/org/apache/ws/security/message/EnvelopeIdResolver.java?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- 
webservices/wss4j/trunk/src/org/apache/ws/security/message/EnvelopeIdResolver.java
 (original)
+++ 
webservices/wss4j/trunk/src/org/apache/ws/security/message/EnvelopeIdResolver.java
 Tue Sep 20 11:46:23 2005
@@ -46,7 +46,6 @@
 public class EnvelopeIdResolver extends ResourceResolverSpi {
     private static Log log =
             LogFactory.getLog(EnvelopeIdResolver.class.getName());
-    private static Log tlog = LogFactory.getLog("org.apache.ws.security.TIME");
 
     private static EnvelopeIdResolver resolver = null;
 
@@ -82,11 +81,6 @@
 
         doDebug = log.isDebugEnabled();
 
-        long t0 = 0, t1 = 0;
-        if (tlog.isDebugEnabled()) {
-            t0 = System.currentTimeMillis();
-        }
-
         String uriNodeValue = uri.getNodeValue();
 
         if (doDebug) {
@@ -150,10 +144,6 @@
             result.setSourceURI(uriNew.toString());
         } catch (URI.MalformedURIException ex) {
             result.setSourceURI(BaseURI);
-        }
-        if (tlog.isDebugEnabled()) {
-            t1 = System.currentTimeMillis();
-            tlog.debug("engineResolve= " + (t1 - t0));
         }
         if (doDebug) {
             log.debug("exit engineResolve, result: " + result);

Modified: 
webservices/wss4j/trunk/src/org/apache/ws/security/message/WSEncryptBody.java
URL: 
http://svn.apache.org/viewcvs/webservices/wss4j/trunk/src/org/apache/ws/security/message/WSEncryptBody.java?rev=290523&r1=290522&r2=290523&view=diff
==============================================================================
--- 
webservices/wss4j/trunk/src/org/apache/ws/security/message/WSEncryptBody.java 
(original)
+++ 
webservices/wss4j/trunk/src/org/apache/ws/security/message/WSEncryptBody.java 
Tue Sep 20 11:46:23 2005
@@ -435,11 +435,11 @@
         log.debug("Encryption complete.");
         if (tlog.isDebugEnabled()) {
             t3 = System.currentTimeMillis();
-            tlog.debug("EncryptBody: symm-enc= "
+            tlog.debug("EncryptBody: symm-enc "
                     + (t1 - t0)
-                    + ", cert= "
+                    + " cert "
                     + (t2 - t1)
-                    + ", key-encrypt= "
+                    + " key-encrypt "
                     + (t3 - t2));
         }
         return doc;
@@ -597,7 +597,7 @@
         WSSecurityUtil.prependChildElement(doc, wsseSecurity, refList, true);
 
         if (tlog.isDebugEnabled()) {
-            tlog.debug("EncryptBody embedded: symm-enc= " + (t1 - t0));
+            tlog.debug("EncryptBody embedded: symm-enc " + (t1 - t0));
         }
         return doc;
     }