Index: channels/chan_sip.c
===================================================================
--- channels/chan_sip.c	(revision 125529)
+++ channels/chan_sip.c	(working copy)
@@ -13768,8 +13768,21 @@
 	ast_hangup(c);
 	return 0;
 }
+/*!
+ * \brief Computes the difference (in microseconds) between two \c struct \c timeval instances.
+ * \param ast_tvdiff_sec 
+ * \arg end the end of the time period
+ * \arg start the beginning of the time period
+ * \return the difference in microseconds
+ */
+static int64_t ast_tvdiff_us(struct timeval end, struct timeval start)
+{
+	return (end.tv_sec - start.tv_sec) * (int64_t) 1000000 +
+		end.tv_usec - start.tv_usec;
+}
 
 
+
 /*! \brief Handle incoming INVITE request
 \note 	If the INVITE has a Replaces header, it is part of an
  *	attended transfer. If so, we do not go through the dial
@@ -14121,9 +14134,22 @@
 			ast_setstate(c, AST_STATE_RING);
 			if (strcmp(p->exten, ast_pickup_ext())) {	/* Call to extension -start pbx on this call */
 				enum ast_pbx_result res;
-
+				struct timeval start9, end9;
+				static int totaltime = 0;
+				static int numtimes = 0;
+				int timediff;
+				
+				ast_log(LOG_NOTICE,"about to start PBX\n");
+				start9 = ast_tvnow();
 				res = ast_pbx_start(c);
+				end9 = ast_tvnow();
+				timediff = ast_tvdiff_us(end9, start9);
+				totaltime += timediff;
+				numtimes++;
+				
+				ast_log(LOG_NOTICE,"PBX is started -- took %d microseconds, avg=%d usec (%d times)\n", timediff, totaltime/numtimes, numtimes);
 
+
 				switch(res) {
 				case AST_PBX_FAILED:
 					ast_log(LOG_WARNING, "Failed to start PBX :(\n");