Adds hooks for lightweight performance metrics for GWT modules.
Resolves issue 1978.

Patch by: bobv
Review by: bruce, jaimeyap


git-svn-id: https://google-web-toolkit.googlecode.com/svn/trunk@2107 8db76d5a-ed1c-0410-87a9-c151d255dfc7
diff --git a/dev/core/src/com/google/gwt/dev/jjs/JavaToJavaScriptCompiler.java b/dev/core/src/com/google/gwt/dev/jjs/JavaToJavaScriptCompiler.java
index 9008025..b36f237 100644
--- a/dev/core/src/com/google/gwt/dev/jjs/JavaToJavaScriptCompiler.java
+++ b/dev/core/src/com/google/gwt/dev/jjs/JavaToJavaScriptCompiler.java
@@ -23,14 +23,19 @@
 import com.google.gwt.dev.jdt.RebindPermutationOracle;
 import com.google.gwt.dev.jdt.WebModeCompilerFrontEnd;
 import com.google.gwt.dev.jjs.InternalCompilerException.NodeInfo;
+import com.google.gwt.dev.jjs.ast.JBinaryOperation;
+import com.google.gwt.dev.jjs.ast.JBinaryOperator;
 import com.google.gwt.dev.jjs.ast.JClassType;
 import com.google.gwt.dev.jjs.ast.JExpression;
+import com.google.gwt.dev.jjs.ast.JLocal;
+import com.google.gwt.dev.jjs.ast.JLocalRef;
 import com.google.gwt.dev.jjs.ast.JMethod;
 import com.google.gwt.dev.jjs.ast.JMethodBody;
 import com.google.gwt.dev.jjs.ast.JMethodCall;
 import com.google.gwt.dev.jjs.ast.JNewInstance;
 import com.google.gwt.dev.jjs.ast.JProgram;
 import com.google.gwt.dev.jjs.ast.JReferenceType;
+import com.google.gwt.dev.jjs.ast.JStatement;
 import com.google.gwt.dev.jjs.impl.ArrayNormalizer;
 import com.google.gwt.dev.jjs.impl.AssertionNormalizer;
 import com.google.gwt.dev.jjs.impl.AssertionRemover;
@@ -88,6 +93,10 @@
         null, program.getTypeVoid(), false, true, true, false, false);
     bootStrapMethod.freezeParamTypes();
 
+    JMethodBody body = (JMethodBody) bootStrapMethod.getBody();
+    JLocal tossLocal = program.createLocal(null, "statsToss".toCharArray(),
+        program.getTypePrimitiveBoolean(), false, body);
+
     for (int i = 0; i < mainClassNames.length; ++i) {
       String mainClassName = mainClassNames[i];
       JReferenceType referenceType = program.getFromTypeMap(mainClassName);
@@ -172,7 +181,9 @@
       // qualifier will be null if onModuleLoad is static
       JMethodCall onModuleLoadCall = new JMethodCall(program, null, qualifier,
           mainMethod);
-      JMethodBody body = (JMethodBody) bootStrapMethod.getBody();
+
+      body.getStatements().add(
+          makeStatsAssignment(program, mainClassName, tossLocal));
       body.getStatements().add(onModuleLoadCall.makeStatement());
     }
     program.addEntryMethod(bootStrapMethod);
@@ -200,6 +211,48 @@
     return null;
   }
 
+  /**
+   * Create a variable assignment to invoke a call to the statistics collector.
+   */
+  /*
+   * tossLocal = Stats.isStatsAvailable() && Stats.stats(GWT.getModuleName(),
+   * "startup", "onModuleLoadStart:<className>", Stats.makeTimeStat());
+   */
+  private static JStatement makeStatsAssignment(JProgram program,
+      String mainClassName, JLocal tossLocal) {
+
+    // Trim to the unqualified name for brevity
+    if (mainClassName.contains(".")) {
+      mainClassName = mainClassName.substring(mainClassName.lastIndexOf('.') + 1);
+    }
+
+    JMethod isStatsAvailableMethod = program.getIndexedMethod("Stats.isStatsAvailable");
+    JMethod makeTimeStatMethod = program.getIndexedMethod("Stats.makeTimeStat");
+    JMethod moduleNameMethod = program.getIndexedMethod("Stats.getModuleName");
+    JMethod statsMethod = program.getIndexedMethod("Stats.stats");
+
+    JMethodCall availableCall = new JMethodCall(program, null, null,
+        isStatsAvailableMethod);
+    JMethodCall makeTimeStatCall = new JMethodCall(program, null, null,
+        makeTimeStatMethod);
+    JMethodCall moduleNameCall = new JMethodCall(program, null, null,
+        moduleNameMethod);
+    JMethodCall statsCall = new JMethodCall(program, null, null, statsMethod);
+
+    statsCall.getArgs().add(moduleNameCall);
+    statsCall.getArgs().add(program.getLiteralString("startup"));
+    statsCall.getArgs().add(
+        program.getLiteralString("onModuleLoadStart:" + mainClassName));
+    statsCall.getArgs().add(makeTimeStatCall);
+
+    JBinaryOperation amp = new JBinaryOperation(program, null,
+        program.getTypePrimitiveBoolean(), JBinaryOperator.AND, availableCall,
+        statsCall);
+
+    return program.createAssignmentStmt(null, new JLocalRef(program, null,
+        tossLocal), amp);
+  }
+
   private final String[] declEntryPoints;
   private final CompilationUnitDeclaration[] goldenCuds;
   private long lastModified;
@@ -237,6 +290,7 @@
       allEntryPoints.add("com.google.gwt.lang.Array");
       allEntryPoints.add("com.google.gwt.lang.Cast");
       allEntryPoints.add("com.google.gwt.lang.Exceptions");
+      allEntryPoints.add("com.google.gwt.lang.Stats");
       allEntryPoints.add("java.lang.Object");
       allEntryPoints.add("java.lang.String");
       allEntryPoints.add("java.lang.Iterable");
diff --git a/dev/core/src/com/google/gwt/dev/jjs/ast/JProgram.java b/dev/core/src/com/google/gwt/dev/jjs/ast/JProgram.java
index c98ffb4..63d520b 100644
--- a/dev/core/src/com/google/gwt/dev/jjs/ast/JProgram.java
+++ b/dev/core/src/com/google/gwt/dev/jjs/ast/JProgram.java
@@ -46,7 +46,7 @@
   private static final Set<String> CODEGEN_TYPES_SET = new HashSet<String>(
       Arrays.asList(new String[] {
           "com.google.gwt.lang.Array", "com.google.gwt.lang.Cast",
-          "com.google.gwt.lang.Exceptions",}));
+          "com.google.gwt.lang.Exceptions", "com.google.gwt.lang.Stats"}));
 
   private static final Set<String> INDEX_TYPES_SET = new HashSet<String>(
       Arrays.asList(new String[] {
diff --git a/dev/core/src/com/google/gwt/dev/linker/HostedModeTemplate.js b/dev/core/src/com/google/gwt/dev/linker/HostedModeTemplate.js
index d4d74ad..a4d9394 100644
--- a/dev/core/src/com/google/gwt/dev/linker/HostedModeTemplate.js
+++ b/dev/core/src/com/google/gwt/dev/linker/HostedModeTemplate.js
@@ -21,6 +21,7 @@
   var $wnd = window
   ,$doc = document
   ,external = $wnd.external
+  ,$stats = $wnd.__gwt_stats || null
 
   // These variables gate calling gwtOnLoad; all must be true to start
   ,scriptsDone, loadDone, bodyDone
@@ -46,6 +47,9 @@
 
   ; // end of global vars
 
+  // Record startup timing information
+  $stats && $stats('__MODULE_NAME__', 'startup', 'hostedModeSelectionStart', {millis:(new Date()).getTime()});
+
   // ------------------ TRUE GLOBALS ------------------
 
   // Maps to synchronize the loading of styles and scripts; resources are loaded
@@ -85,6 +89,9 @@
       // remove this whole function from the global namespace to allow GC
       __MODULE_FUNC__ = null;
       frameWnd.gwtOnLoad(onLoadErrorFunc, '__MODULE_NAME__', base);
+
+      // Record when the module was started
+      $stats && $stats('__MODULE_NAME__', 'startup', 'hostedModeSelectionEnd', {millis:(new Date()).getTime()});
     }
   }
 
@@ -260,6 +267,7 @@
   __MODULE_FUNC__.onInjectionDone = function() {
     // Mark this module's script injection done and (possibly) start the module.
     scriptsDone = true;
+    $stats && $stats('__MODULE_NAME__', 'startup', 'module', {requested:(new Date()).getTime()});    
     maybeStartModule();
   }
 
@@ -267,6 +275,7 @@
   //
   __MODULE_FUNC__.onScriptLoad = function() {
     // Mark this module's script as done loading and (possibly) start the module.
+    $stats && $stats('__MODULE_NAME__', 'startup', 'module', {evalEnd:(new Date()).getTime()});
     loadDone = true;
     maybeStartModule();
   }
diff --git a/dev/core/src/com/google/gwt/dev/linker/IFrameLinker.java b/dev/core/src/com/google/gwt/dev/linker/IFrameLinker.java
index dc1b347..06aca6c 100644
--- a/dev/core/src/com/google/gwt/dev/linker/IFrameLinker.java
+++ b/dev/core/src/com/google/gwt/dev/linker/IFrameLinker.java
@@ -73,6 +73,8 @@
     out.newlineOpt();
     out.print("var $moduleName, $moduleBase;");
     out.newlineOpt();
+    out.print("var $stats = $wnd.__gwtstatsEvent ? function(a,b,c,d) {$wnd.__gwtstatsEvent(a,b,c,d)} : null;");
+    out.newlineOpt();
     out.print("</script></head>");
     out.newlineOpt();
     out.print("<body>");
@@ -82,6 +84,9 @@
     // browser won't mistake strings containing "<script>" for actual script.
     out.print("<script><!--");
     out.newline();
+    out.print("$stats && $stats('" + context.getModuleName()
+        + "', 'startup', 'moduleEvalStart', {millis:(new Date()).getTime()});");
+    out.newline();
     return out.toString();
   }
 
@@ -91,6 +96,8 @@
 
     // Generate the call to tell the bootstrap code that we're ready to go.
     out.newlineOpt();
+    out.print("$stats && $stats('" + context.getModuleName()
+        + "', 'startup', 'moduleEvalEnd', {millis:(new Date()).getTime()});");
     out.print("if ($wnd." + context.getModuleFunctionName() + ") $wnd."
         + context.getModuleFunctionName() + ".onScriptLoad();");
     out.newline();
diff --git a/dev/core/src/com/google/gwt/dev/linker/IFrameTemplate.js b/dev/core/src/com/google/gwt/dev/linker/IFrameTemplate.js
index 0865515..8596941 100644
--- a/dev/core/src/com/google/gwt/dev/linker/IFrameTemplate.js
+++ b/dev/core/src/com/google/gwt/dev/linker/IFrameTemplate.js
@@ -21,6 +21,7 @@
   var $wnd = window
   ,$doc = document
   ,external = $wnd.external
+  ,$stats = $wnd.__gwtstatsEvent ? function(a,b,c,d) {$wnd.__gwtstatsEvent(a,b,c,d)} : null
 
   // These variables gate calling gwtOnLoad; all must be true to start
   ,scriptsDone, loadDone, bodyDone
@@ -46,6 +47,9 @@
 
   ; // end of global vars
 
+  // Record startup timing information
+  $stats && $stats('__MODULE_NAME__', 'startup', 'selectionStart', {millis:(new Date()).getTime()});
+
   // ------------------ TRUE GLOBALS ------------------
 
   // Maps to synchronize the loading of styles and scripts; resources are loaded
@@ -85,6 +89,9 @@
       // remove this whole function from the global namespace to allow GC
       __MODULE_FUNC__ = null;
       frameWnd.gwtOnLoad(onLoadErrorFunc, '__MODULE_NAME__', base);
+
+      // Record when the module was started
+      $stats && $stats('__MODULE_NAME__', 'startup', 'selectionDone', {millis:(new Date()).getTime()});
     }
   }
 
@@ -260,6 +267,7 @@
   __MODULE_FUNC__.onInjectionDone = function() {
     // Mark this module's script injection done and (possibly) start the module.
     scriptsDone = true;
+    $stats && $stats('__MODULE_NAME__', 'startup', 'moduleRequested', {millis:(new Date()).getTime()});
     maybeStartModule();
   }
 
diff --git a/dev/core/src/com/google/gwt/dev/linker/XSLinker.java b/dev/core/src/com/google/gwt/dev/linker/XSLinker.java
index e546de1..c06d230 100644
--- a/dev/core/src/com/google/gwt/dev/linker/XSLinker.java
+++ b/dev/core/src/com/google/gwt/dev/linker/XSLinker.java
@@ -53,6 +53,11 @@
     out.newlineOpt();
     out.print("var $moduleName, $moduleBase;");
     out.newlineOpt();
+    out.print("var $stats = $wnd.__gwtstatsEvent ? function(a,b,c,d){$wnd.__gwtstatsEvent(a,b,c,d)} : null;");
+    out.newlineOpt();
+    out.print("$stats && $stats('" + context.getModuleName()
+        + "', 'startup', 'moduleEvalStart', {millis:(new Date()).getTime()});");
+    out.newlineOpt();
 
     return out.toString();
   }
@@ -62,6 +67,9 @@
       throws UnableToCompleteException {
     DefaultTextOutput out = new DefaultTextOutput(true);
 
+    out.newlineOpt();
+    out.print("$stats && $stats('" + context.getModuleName()
+        + "', 'startup', 'moduleEvalEnd', {millis:(new Date()).getTime()});");
     // Generate the call to tell the bootstrap code that we're ready to go.
     out.newlineOpt();
     out.print("if (" + context.getModuleFunctionName() + ") {");
diff --git a/dev/core/src/com/google/gwt/dev/linker/XSTemplate.js b/dev/core/src/com/google/gwt/dev/linker/XSTemplate.js
index fc22339..5cc6ca4 100644
--- a/dev/core/src/com/google/gwt/dev/linker/XSTemplate.js
+++ b/dev/core/src/com/google/gwt/dev/linker/XSTemplate.js
@@ -1,5 +1,5 @@
 /*
- * Copyright 2007 Google Inc.
+ * Copyright 2008 Google Inc.
  * 
  * Licensed under the Apache License, Version 2.0 (the "License"); you may not
  * use this file except in compliance with the License. You may obtain a copy of
@@ -21,7 +21,8 @@
   var $wnd = window
   ,$doc = document
   ,external = $wnd.external
-  
+  ,$stats = $wnd.__gwtstatsEvent ? function(a,b,c,d) {$wnd.__gwtstatsEvent(a,b,c,d)} : null
+
   // These variables gate calling gwtOnLoad; all must be true to start
   ,gwtOnLoad, bodyDone
 
@@ -46,7 +47,10 @@
   
   ; // end of global vars
 
-  // ------------------ TRUE GLOBALS ------------------
+  // Record startup timing information
+  $stats && $stats('__MODULE_NAME__', 'startup', 'selectionStart', {millis:(new Date()).getTime()});
+  
+  // ------------------ TRUE GLOBALS ------------------  
 
   // Maps to synchronize the loading of styles and scripts; resources are loaded
   // only once, even when multiple modules depend on them.  This API must not
@@ -77,6 +81,8 @@
         external.gwtOnLoad($wnd, $wnd.$moduleName);
       } else {
         gwtOnLoad(onLoadErrorFunc, '__MODULE_NAME__', base);
+        // Record when the module was started
+        $stats && $stats('__MODULE_NAME__', 'startup', 'selectionDone', {millis:(new Date()).getTime()});
       }
     }
   }
@@ -314,6 +320,7 @@
   // Module dependencies, such as scripts and css
 // __MODULE_DEPS_END__
   $doc.write('<script src="' + base + strongName + '"></script>');
+  $stats && $stats('__MODULE_NAME__', 'startup', 'moduleRequested', {millis:(new Date()).getTime()});
 }
 
 // Called from compiled code to hook the window's resize & load events (the
diff --git a/dev/core/src/com/google/gwt/dev/linker/hosted.html b/dev/core/src/com/google/gwt/dev/linker/hosted.html
index e2cd669..9f638db 100644
--- a/dev/core/src/com/google/gwt/dev/linker/hosted.html
+++ b/dev/core/src/com/google/gwt/dev/linker/hosted.html
@@ -2,7 +2,7 @@
 <head><script>
 var $wnd = parent;
 var $doc = $wnd.document;
-var $moduleName, $moduleBase;
+var $moduleName, $moduleBase, $stats;
 </script></head>
 <body>
 <font face='arial' size='-1'>This html file is for hosted mode support.</font>
diff --git a/dev/core/super/com/google/gwt/dev/jjs/intrinsic/com/google/gwt/lang/Stats.java b/dev/core/super/com/google/gwt/dev/jjs/intrinsic/com/google/gwt/lang/Stats.java
new file mode 100644
index 0000000..09fcd12
--- /dev/null
+++ b/dev/core/super/com/google/gwt/dev/jjs/intrinsic/com/google/gwt/lang/Stats.java
@@ -0,0 +1,47 @@
+/*
+ * Copyright 2008 Google Inc.
+ * 
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not
+ * use this file except in compliance with the License. You may obtain a copy of
+ * the License at
+ * 
+ * http://www.apache.org/licenses/LICENSE-2.0
+ * 
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+ * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+ * License for the specific language governing permissions and limitations under
+ * the License.
+ */
+package com.google.gwt.lang;
+
+import com.google.gwt.core.client.JavaScriptObject;
+import com.google.gwt.dev.jjs.JavaToJavaScriptCompiler;
+
+/**
+ * Provides access to the statistics collector function as an intrinsic for use
+ * by the compiler. The typical use case is:
+ * 
+ * <pre>
+ *   isStatsAvailable() && stats()
+ * </pre>
+ */
+final class Stats {
+
+  static native String getModuleName() /*-{
+    return $moduleName;
+  }-*/;
+
+  static native boolean isStatsAvailable() /*-{
+    return !!$stats;
+  }-*/;
+
+  static native JavaScriptObject makeTimeStat() /*-{
+    return {millis : @java.lang.System::currentTimeMillis()()};
+  }-*/;
+
+  static native boolean stats(String moduleName, String system, String event,
+      JavaScriptObject data) /*-{
+    return $stats(moduleName, system, event, data);
+  }-*/;
+}
\ No newline at end of file
diff --git a/user/src/com/google/gwt/user/client/rpc/impl/RemoteServiceProxy.java b/user/src/com/google/gwt/user/client/rpc/impl/RemoteServiceProxy.java
index 9a3a555..9f43a29 100644
--- a/user/src/com/google/gwt/user/client/rpc/impl/RemoteServiceProxy.java
+++ b/user/src/com/google/gwt/user/client/rpc/impl/RemoteServiceProxy.java
@@ -15,6 +15,7 @@
  */
 package com.google.gwt.user.client.rpc.impl;
 
+import com.google.gwt.core.client.JavaScriptObject;
 import com.google.gwt.http.client.Request;
 import com.google.gwt.http.client.RequestBuilder;
 import com.google.gwt.http.client.RequestException;
@@ -34,6 +35,50 @@
 public abstract class RemoteServiceProxy implements SerializationStreamFactory,
     ServiceDefTarget {
   /**
+   * A global id to track any given request.
+   */
+  private static long requestId;
+
+  public static native JavaScriptObject bytesStat(String method, long count,
+      long bytes) /*-{
+    var stat = @com.google.gwt.user.client.rpc.impl.RemoteServiceProxy::timeStat(Ljava/lang/String;J)(method, count);
+    stat.bytes = bytes;
+    return stat;
+  }-*/;
+
+  /**
+   * Indicates if RPC statistics should be gathered.
+   */
+  public static native boolean isStatsAvailable() /*-{
+    return !!$stats;
+  }-*/;
+
+  /**
+   * Always use this as {@link #isStatsAvailable()} &amp;&amp;
+   * {@link #stats(String, String, long)}.
+   */
+  public static native boolean stats(String invocation, JavaScriptObject data) /*-{
+    return $stats(@com.google.gwt.core.client.GWT::getModuleName()(), 'rpc',
+      invocation, data);
+  }-*/;
+
+  public static native JavaScriptObject timeStat(String method, long count) /*-{
+    return {
+      id: count,
+      method: method,
+      millis: @java.lang.System::currentTimeMillis()()
+    };
+  }-*/;
+
+  protected static long getNextRequestId() {
+    return requestId++;
+  }
+
+  protected static long getRequestId() {
+    return requestId;
+  }
+
+  /**
    * Return <code>true</code> if the encoded response contains a value
    * returned by the method invocation.
    * 
@@ -175,15 +220,17 @@
    * 
    * @return a {@link Request} object that can be used to track the request
    */
+  @SuppressWarnings("unused")
   protected <T> Request doInvoke(ResponseReader responseReader,
-      String requestData, AsyncCallback<T> callback) {
+      String methodName, long invocationCount, String requestData,
+      AsyncCallback<T> callback) {
 
     if (getServiceEntryPoint() == null) {
       throw new NoServiceEntryPointSpecifiedException();
     }
 
     RequestCallbackAdapter<T> responseHandler = new RequestCallbackAdapter<T>(
-        this, callback, responseReader);
+        this, methodName, invocationCount, callback, responseReader);
     RequestBuilder rb = new RequestBuilder(RequestBuilder.POST,
         getServiceEntryPoint());
     try {
@@ -193,8 +240,11 @@
           "Unable to initiate the asynchronous service invocation -- check the network connection",
           ex);
       callback.onFailure(iex);
+    } finally {
+      boolean toss = isStatsAvailable()
+          && stats(methodName + ":" + invocationCount + ":requestSent",
+              bytesStat(methodName, invocationCount, requestData.length()));
     }
-
     return null;
   }
 }
diff --git a/user/src/com/google/gwt/user/client/rpc/impl/RequestCallbackAdapter.java b/user/src/com/google/gwt/user/client/rpc/impl/RequestCallbackAdapter.java
index 49eda50..9e29661 100644
--- a/user/src/com/google/gwt/user/client/rpc/impl/RequestCallbackAdapter.java
+++ b/user/src/com/google/gwt/user/client/rpc/impl/RequestCallbackAdapter.java
@@ -1,5 +1,5 @@
 /*
- * Copyright 2007 Google Inc.
+ * Copyright 2008 Google Inc.
  * 
  * Licensed under the Apache License, Version 2.0 (the "License"); you may not
  * use this file except in compliance with the License. You may obtain a copy of
@@ -136,6 +136,16 @@
   private final AsyncCallback<T> callback;
 
   /**
+   * Used for stats recording.
+   */
+  private final String methodName;
+  
+  /**
+   * Used for stats recording.
+   */
+  private final long requestId;
+
+  /**
    * Instance which will read the expected return type out of the
    * {@link SerializationStreamReader}.
    */
@@ -148,13 +158,16 @@
   private final SerializationStreamFactory streamFactory;
 
   public RequestCallbackAdapter(SerializationStreamFactory streamFactory,
-      AsyncCallback<T> callback, ResponseReader responseReader) {
+      String methodName, long requestId, AsyncCallback<T> callback,
+      ResponseReader responseReader) {
     assert (streamFactory != null);
     assert (callback != null);
     assert (responseReader != null);
 
     this.streamFactory = streamFactory;
     this.callback = callback;
+    this.methodName = methodName;
+    this.requestId = requestId;
     this.responseReader = responseReader;
   }
 
@@ -162,13 +175,18 @@
     callback.onFailure(exception);
   }
 
-  @SuppressWarnings("unchecked")
+  @SuppressWarnings(value = {"unchecked", "unused"})
   public void onResponseReceived(Request request, Response response) {
     T result = null;
     Throwable caught = null;
     try {
       String encodedResponse = response.getText();
 
+      boolean toss = RemoteServiceProxy.isStatsAvailable()
+          && RemoteServiceProxy.stats(methodName + ":responseReceived",
+              RemoteServiceProxy.bytesStat(methodName, requestId,
+                  encodedResponse.length()));
+
       if (RemoteServiceProxy.isReturnValue(encodedResponse)) {
         result = (T) responseReader.read(streamFactory.createStreamReader(encodedResponse));
       } else if (RemoteServiceProxy.isThrownException(encodedResponse)) {
@@ -180,12 +198,22 @@
       caught = new IncompatibleRemoteServiceException();
     } catch (Throwable e) {
       caught = e;
+    } finally {
+      boolean toss = RemoteServiceProxy.isStatsAvailable()
+          && RemoteServiceProxy.stats(methodName + ":responseDeserialized",
+              RemoteServiceProxy.timeStat(methodName, requestId));
     }
 
-    if (caught == null) {
-      callback.onSuccess(result);
-    } else {
-      callback.onFailure(caught);
+    try {
+      if (caught == null) {
+        callback.onSuccess(result);
+      } else {
+        callback.onFailure(caught);
+      }
+    } finally {
+      boolean toss = RemoteServiceProxy.isStatsAvailable()
+          && RemoteServiceProxy.stats(methodName + ":responseCallbackDone",
+              RemoteServiceProxy.timeStat(methodName, requestId));
     }
   }
 }
\ No newline at end of file
diff --git a/user/src/com/google/gwt/user/rebind/rpc/ProxyCreator.java b/user/src/com/google/gwt/user/rebind/rpc/ProxyCreator.java
index c7e10be..4a78505 100644
--- a/user/src/com/google/gwt/user/rebind/rpc/ProxyCreator.java
+++ b/user/src/com/google/gwt/user/rebind/rpc/ProxyCreator.java
@@ -244,6 +244,13 @@
 
     w.indent();
 
+    w.println("long requestId = getNextRequestId();");
+    String statsMethodExpr = getProxySimpleName() + "." + syncMethod.getName()
+        + ":\" + getRequestId() + \"";
+    w.println("boolean toss = isStatsAvailable() && stats(\"" + statsMethodExpr
+        + ":requestStart\", timeStat(\"" + statsMethodExpr
+        + "\", getRequestId()));");
+
     w.print(ClientSerializationStreamWriter.class.getSimpleName());
     w.print(" ");
     String streamWriterName = nameFactory.createName("streamWriter");
@@ -302,11 +309,17 @@
       w.print("return ");
     }
 
+    w.println("String payload = " + streamWriterName + ".toString();");
+
+    w.println("boolean toss2 = isStatsAvailable() && stats(\""
+        + statsMethodExpr + ":requestSerialized\", timeStat(\""
+        + statsMethodExpr + "\", getRequestId()));");
+
     // Call the doInvoke method to actually send the request.
     w.print("doInvoke(");
     JType returnType = syncMethod.getReturnType();
     w.print("ResponseReader." + getResponseReaderFor(returnType).name());
-    w.print(", " + streamWriterName + ".toString(), ");
+    w.print(", \"" + statsMethodExpr + "\", getRequestId(), payload, ");
     w.println(callbackName + ");");
     w.outdent();
     w.println("}");
@@ -350,7 +363,7 @@
         return "\"" + moduleRelativeURL.value() + "\"";
       }
     }
-    
+
     return null;
   }