Bug 22486. Add TimeStamp function to track new message and reply performance. R=sspitzer, SR=bienvenu

git-svn-id: svn://10.0.0.236/trunk@88554 18797224-902f-48f8-a5cc-f745e15eee43

mozilla/mailnews/compose/public/nsIMsgComposeService.idl

@@ -61,6 +61,9 @@ interface nsIMsgComposeService : nsISupports {
                               in nsIMsgComposeParams params);
 
 	/* ... */
-	void DisposeCompose(in nsIMsgCompose compose);	
+ 	void DisposeCompose(in nsIMsgCompose compose);
+ 	
+ 	/* This function is use for debugging purpose only and may go away at anytime without warning */
+ 	void TimeStamp(in string label, in boolean resetTime);	
 };
 

mozilla/mailnews/compose/resources/content/MsgComposeCommands.js

@@ -627,6 +627,9 @@ function WaitFinishLoadingDocument(msgType)
 		try {
 		window.updateCommands("create");
 		} catch(e) {}
+		
+		if (msgComposeService)
+      msgComposeService.TimeStamp("addressing widget, windows title and focus are now set. The window is finally ready", false);
 	}
 	else
 		setTimeout("WaitFinishLoadingDocument(" + msgType + ");", 200);
@@ -830,6 +833,8 @@ function WizCallback(state)
 
 function ComposeLoad()
 {
+  if (msgComposeService)
+    msgComposeService.TimeStamp("Start Initializing the compose window (ComposeLoad)", false);
   gComposeMsgsBundle = document.getElementById("bundle_composeMsgs");
 	
   try {
@@ -866,6 +871,8 @@ function ComposeLoad()
     return;
   }
 	window.tryToClose=ComposeCanClose;
+	if (msgComposeService)
+    msgComposeService.TimeStamp("Done with the initialization (ComposeLoad). Waiting on editor to load about::blank", false);
 }
 
 function ComposeUnload(calledFromExit)

mozilla/mailnews/compose/src/nsMsgCompose.cpp

@@ -74,6 +74,7 @@
 #include "nsIMsgMailSession.h"
 #include "nsMsgBaseCID.h"
 #include "nsIPrompt.h"
+#include "nsMsgComposeService.h"
 
 // Defines....
 static NS_DEFINE_CID(kHeaderParserCID, NS_MSGHEADERPARSER_CID);
@@ -367,6 +368,10 @@ nsresult nsMsgCompose::ConvertAndLoadComposeWindow(nsIEditorShell *aEditorShell,
     editor->EnableUndo(PR_TRUE);
   SetBodyModified(PR_FALSE);
 
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+  nsCOMPtr<nsIMsgComposeService> composeService (do_GetService(NS_MSGCOMPOSESERVICE_CONTRACTID));
+  composeService->TimeStamp("Finished inserting data into the editor. The window is almost ready!", PR_FALSE);
+#endif
   return NS_OK;
 }
 
@@ -1333,6 +1338,10 @@ NS_IMETHODIMP QuotingOutputStreamListener::OnStopRequest(nsIRequest *request, ns
       }
     }
     
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+    nsCOMPtr<nsIMsgComposeService> composeService (do_GetService(NS_MSGCOMPOSESERVICE_CONTRACTID));
+    composeService->TimeStamp("done with mime. Time to insert the body", PR_FALSE);
+#endif
     if (! mHeadersOnly)
       mMsgBody.AppendWithConversion("</html>");
     
@@ -1786,6 +1795,12 @@ nsMsgDocumentStateListener::NotifyDocumentCreated(void)
 
   // Now, do the appropriate startup operation...signature only
   // or quoted message and signature...
+
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+  nsCOMPtr<nsIMsgComposeService> composeService (do_GetService(NS_MSGCOMPOSESERVICE_CONTRACTID));
+  composeService->TimeStamp("Editor is done loading about::blank. Now let mime do its job", PR_FALSE);
+#endif
+
   if ( mComposeObj->QuotingToFollow() )
     return mComposeObj->BuildQuotedMessageAndSignature();
   else
@@ -1940,7 +1955,7 @@ nsMsgCompose::ProcessSignature(nsIMsgIdentity *identity, nsString *aMsgBody)
       nsCOMPtr<nsILocalFile> sigFile;
       rv = identity->GetSignature(getter_AddRefs(sigFile));
       if (NS_SUCCEEDED(rv) && sigFile)
-        rv = sigFile->GetPath(getter_Copies(sigNativePath));
+         rv = sigFile->GetPath(getter_Copies(sigNativePath));
       else
         useSigFile = PR_FALSE;  //No signature file! therefore turn it off.
     }

mozilla/mailnews/compose/src/nsMsgComposeService.cpp

@@ -18,6 +18,7 @@
  * Rights Reserved.
  *
  * Contributor(s): 
+ *  Jean-Francois Ducarroz <ducarroz@netscape.com>
  *   Pierre Phaneuf <pp@ludusdesign.com>
  */
 
@@ -36,11 +37,52 @@
 #include "nsIMsgComposeParams.h"
 #include "nsEscape.h"
 
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+#include "prlog.h"
+#include "nsIPref.h"
+#include "nsIMessage.h"
+#include "nsMsgCreate.h" 
+#endif
+
 static NS_DEFINE_CID(kAppShellServiceCID, NS_APPSHELL_SERVICE_CID);
 static NS_DEFINE_CID(kMsgComposeCID, NS_MSGCOMPOSE_CID);
 
+#ifdef NS_DEBUG
+static PRBool _just_to_be_sure_we_create_only_on_compose_service_ = PR_FALSE;
+#endif
+
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+static PRLogModuleInfo *MsgComposeLogModule = nsnull;
+
+static PRUint32 GetMessageSizeFromURI(const PRUnichar * originalMsgURI)
+{
+  PRUint32 msgSize = 0;
+
+  if (originalMsgURI && *originalMsgURI)
+  {
+    nsCOMPtr<nsIMessage> message = getter_AddRefs(GetIMessageFromURI(originalMsgURI));
+    if (message)
+      message->GetMessageSize(&msgSize);
+  }
+  
+  return msgSize;
+}
+#endif
+
 nsMsgComposeService::nsMsgComposeService()
 {
+#ifdef NS_DEBUG
+  NS_ASSERTION(!_just_to_be_sure_we_create_only_on_compose_service_, "You cannot create several message compose service!");
+  _just_to_be_sure_we_create_only_on_compose_service_ = PR_TRUE;
+#endif
+
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+  if (!MsgComposeLogModule)
+      MsgComposeLogModule = PR_NewLogModule("msgcompose");
+
+  mStartTime = PR_IntervalNow();
+  mPreviousTime = mStartTime;
+#endif
 	NS_INIT_REFCNT();
 }
 
@@ -159,6 +201,11 @@ nsresult nsMsgComposeService::OpenComposeWindow(const PRUnichar *msgComposeWindo
       pMsgComposeParams->SetComposeFields(pMsgCompFields);
 
 
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+      char buff[256];
+      sprintf(buff, "Start opening the window, message size = %d", GetMessageSizeFromURI(originalMsgURI));
+      TimeStamp(buff, PR_TRUE);
+#endif
 	    if (msgComposeWindowURL && *msgComposeWindowURL)
         rv = openWindow(msgComposeWindowURL, pMsgComposeParams);
 	    else
@@ -265,6 +312,9 @@ nsresult nsMsgComposeService::OpenComposeWindowWithCompFields(const PRUnichar *m
       pMsgComposeParams->SetIdentity(identity);
       pMsgComposeParams->SetComposeFields(compFields);    
 
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+      TimeStamp("Start opening the window", PR_TRUE);
+#endif
 	    if (msgComposeWindowURL && *msgComposeWindowURL)
         rv = openWindow(msgComposeWindowURL, pMsgComposeParams);
 	    else
@@ -300,5 +350,36 @@ nsresult nsMsgComposeService::DisposeCompose(nsIMsgCompose *compose)
 	return NS_OK;
 }
 
+
+NS_IMETHODIMP nsMsgComposeService::TimeStamp(const char * label, PRBool resetTime)
+{
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+
+  PRIntervalTime now;
+
+  if (resetTime)
+  {      
+    PR_LOG(MsgComposeLogModule, PR_LOG_ALWAYS, ("\r\n\r\n--------------------\r\n"));
+
+    mStartTime = PR_IntervalNow();
+    mPreviousTime = mStartTime;
+    now = mStartTime;
+  }
+  else
+    now = PR_IntervalNow();
+
+  PRIntervalTime totalTime = PR_IntervalToMilliseconds(now - mStartTime);
+  PRIntervalTime deltaTime = PR_IntervalToMilliseconds(now - mPreviousTime);
+
+#if defined(DEBUG_ducarroz)
+  printf(">>> Time Stamp: [%5d][%5d] - %s\n", totalTime, deltaTime, label);
+#endif
+  PR_LOG(MsgComposeLogModule, PR_LOG_ALWAYS, ("[%5d][%5d] - %s\r\n", totalTime, deltaTime, label));
+
+  mPreviousTime = now;
+#endif
+  return NS_OK;
+}
+
 CMDLINEHANDLER_IMPL(nsMsgComposeService,"-compose","general.startup.messengercompose","chrome://messenger/content/messengercompose/messengercompose.xul","Start with messenger compose.",NS_MSGCOMPOSESTARTUPHANDLER_CONTRACTID,"Messenger Compose Startup Handler", PR_TRUE, "about:blank", PR_TRUE)
 

mozilla/mailnews/compose/src/nsMsgComposeService.h

@@ -18,8 +18,11 @@
  * Rights Reserved.
  *
  * Contributor(s): 
+ *  Jean-Francois Ducarroz <ducarroz@netscape.com>
  */
 
+#define MSGCOMP_TRACE_PERFORMANCE 1
+
 #include "nsIMsgComposeService.h"
 #include "nsISupportsArray.h"
 #include "nsCOMPtr.h"
@@ -36,4 +39,10 @@ public:
 
   NS_DECL_NSICMDLINEHANDLER
   CMDLINEHANDLER_REGISTERPROC_DECLS 
+
+#ifdef MSGCOMP_TRACE_PERFORMANCE
+private:
+  PRIntervalTime            mStartTime;
+  PRIntervalTime            mPreviousTime;
+#endif
 };