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");