Bug 581930: Add an async "spam test" and make output more readable. r=NPOTB (alas!)

ipc/ipdl/test/cxx/PTestLatency.ipdl

@@ -10,6 +10,8 @@ child:
     Ping();
     Ping5();
     rpc Rpc();
+    Spam();
+    rpc Synchro();
 
 parent:
     Pong();
@@ -45,8 +47,16 @@ state PONG3: recv Pong5 goto PONG4;
 state PONG4: recv Pong5 goto PONG5;
 state PONG5: recv Pong5 goto PING5;
 
+    // Trial 3: lotsa RPC
 state RPC:
     call Rpc goto RPC;
+    send Spam goto SPAM;
+
+state SPAM:
+    send Spam goto SPAM;
+    call Synchro goto DONE;
+
+state DONE:
     send __delete__;
 };
 

ipc/ipdl/test/cxx/TestLatency.cpp

@@ -18,7 +18,8 @@ TestLatencyParent::TestLatencyParent() :
     mPP5TimeTotal(),
     mRpcTimeTotal(),
     mPPTrialsToGo(NR_TRIALS),
-    mPP5TrialsToGo(NR_TRIALS)
+    mPP5TrialsToGo(NR_TRIALS),
+    mSpamsToGo(NR_TRIALS)
 {
     MOZ_COUNT_CTOR(TestLatencyParent);
 }
@@ -68,12 +69,6 @@ TestLatencyParent::Ping5Pong5Trial()
         fail("sending Ping5()");
 }
 
-void
-TestLatencyParent::Exit()
-{
-    Close();
-}
-
 bool
 TestLatencyParent::RecvPong()
 {
@@ -115,23 +110,47 @@ TestLatencyParent::RecvPong5()
 void
 TestLatencyParent::RpcTrials()
 {
+    TimeStamp start = TimeStamp::Now();
     for (int i = 0; i < NR_TRIALS; ++i) {
-        TimeStamp start = TimeStamp::Now();
-
         if (!CallRpc())
             fail("can't call Rpc()");
-
-        TimeDuration thisTrial = (TimeStamp::Now() - start);
-
         if (0 == (i % 1000))
-            printf("  Rpc trial %d: %g\n", i, thisTrial.ToSecondsSigDigits());
+            printf("  Rpc trial %d\n", i);
+    }
+    mRpcTimeTotal = (TimeStamp::Now() - start);
 
-        mRpcTimeTotal += thisTrial;
+    SpamTrial();
+}
+
+void
+TestLatencyParent::SpamTrial()
+{
+    TimeStamp start = TimeStamp::Now();
+    for (int i = 0; i < NR_SPAMS - 1; ++i) {
+        if (!SendSpam())
+            fail("sending Spam()");
+        if (0 == (i % 10000))
+            printf("  Spam trial %d\n", i);
     }
 
+    // Synchronize with the child process to ensure all messages have
+    // been processed.  This adds the overhead of a reply message from
+    // child-->here, but should be insignificant compared to >>
+    // NR_SPAMS.
+    if (!CallSynchro())
+        fail("calling Synchro()");
+
+    mSpamTimeTotal = (TimeStamp::Now() - start);
+
     Exit();
 }
 
+void
+TestLatencyParent::Exit()
+{
+    Close();
+}
+
 //-----------------------------------------------------------------------------
 // child
 
@@ -174,5 +193,18 @@ TestLatencyChild::AnswerRpc()
     return true;
 }
 
+bool
+TestLatencyChild::RecvSpam()
+{
+    // no-op
+    return true;
+}
+
+bool
+TestLatencyChild::AnswerSynchro()
+{
+    return true;
+}
+
 } // namespace _ipdltest
 } // namespace mozilla

ipc/ipdl/test/cxx/TestLatency.h

@@ -9,6 +9,7 @@
 #include "mozilla/TimeStamp.h"
 
 #define NR_TRIALS 10000
+#define NR_SPAMS  50000
 
 namespace mozilla {
 namespace _ipdltest {
@@ -38,12 +39,15 @@ protected:
         if (NormalShutdown != why)
             fail("unexpected destruction!");  
 
-        passed("average ping/pong latency: %g sec, "
-               "average ping5/pong5 latency: %g sec, "
-               "average RPC call/answer: %g sec",
-               mPPTimeTotal.ToSecondsSigDigits() / (double) NR_TRIALS,
-               mPP5TimeTotal.ToSecondsSigDigits() / (double) NR_TRIALS,
-               mRpcTimeTotal.ToSecondsSigDigits() / (double) NR_TRIALS);
+        passed("\n"
+               "  average #ping-pong/sec:        %g\n"
+               "  average #ping5-pong5/sec:      %g\n"
+               "  average #RPC call-answer/sec:  %g\n"
+               "  average #spams/sec:            %g\n",
+               double(NR_TRIALS) / mPPTimeTotal.ToSecondsSigDigits(),
+               double(NR_TRIALS) / mPP5TimeTotal.ToSecondsSigDigits(),
+               double(NR_TRIALS) / mRpcTimeTotal.ToSecondsSigDigits(),
+               double(NR_SPAMS) / mSpamTimeTotal.ToSecondsSigDigits());
 
         QuitParent();
     }
@@ -52,15 +56,18 @@ private:
     void PingPongTrial();
     void Ping5Pong5Trial();
     void RpcTrials();
+    void SpamTrial();
     void Exit();
 
     TimeStamp mStart;
     TimeDuration mPPTimeTotal;
     TimeDuration mPP5TimeTotal;
     TimeDuration mRpcTimeTotal;
+    TimeDuration mSpamTimeTotal;
 
     int mPPTrialsToGo;
     int mPP5TrialsToGo;
+    int mSpamsToGo;
 };
 
 
@@ -78,6 +85,10 @@ protected:
     virtual bool RecvPing5();
     NS_OVERRIDE
     virtual bool AnswerRpc();
+    NS_OVERRIDE
+    virtual bool RecvSpam();
+    NS_OVERRIDE
+    virtual bool AnswerSynchro();
 
     NS_OVERRIDE
     virtual void ActorDestroy(ActorDestroyReason why)