[svn-commits] rizzo: branch rizzo/astobj2 r47973 -
/team/rizzo/astobj2/channels/chan_sip.c
svn-commits at lists.digium.com
svn-commits at lists.digium.com
Thu Nov 23 13:22:27 MST 2006
Author: rizzo
Date: Thu Nov 23 14:22:26 2006
New Revision: 47973
URL: http://svn.digium.com/view/asterisk?view=rev&rev=47973
Log:
add some profiling to figure out where we are consuming time.
Not that it really belongs in a commit message, but since it is archived,
it may be interesting to see how the profiling output looks like and
what shows us:
*CLI> core show profile
profile values (13, allocated 30)
-------------------
ID Scale Events Value Average Name
0: [ 1000] 0 0 0 1 ms
1: [ 0] 107 166012 1551 ext_match
2: [ 0] 68 9735140 143163 sip_alloc
3: [ 0] 68 1554648 22862 sip_alloc-alloc
4: [ 0] 68 8137400 119667 sip_alloc-init
5: [ 0] 300 1358384 4527 sip_read-memset
6: [ 0] 300 3091912 10306 sip_read-recvfrom
7: [ 0] 300 2814960 9383 sip_read-parse
8: [ 0] 178 13761304 77310 sip_read-find_call
9: [ 0] 178 945952 5314 find_call-headers
10: [ 0] 178 2009652 11290 find_call-find
11: [ 0] 56 10493668 187386 find_call-tail
12: [ 0] 346 425788 1230 find_call_cb
(this is on a 2GHz box, so 2000 equals to 1 microsecond).
E.g. we see here that a lot of time is spent in the last part of find_call()
when a dialog is allocated calling sip_alloc(), and in turn, most
of the time there goes for initializing the various fields in the structure.
This is on an unloaded machine, so the cost of looking up stuff in containers
is relatively negligible, as it is the locking overhead.
Modified:
team/rizzo/astobj2/channels/chan_sip.c
Modified: team/rizzo/astobj2/channels/chan_sip.c
URL: http://svn.digium.com/view/asterisk/team/rizzo/astobj2/channels/chan_sip.c?view=diff&rev=47973&r1=47972&r2=47973
==============================================================================
--- team/rizzo/astobj2/channels/chan_sip.c (original)
+++ team/rizzo/astobj2/channels/chan_sip.c Thu Nov 23 14:22:26 2006
@@ -4470,7 +4470,16 @@
int useglobal_nat, const int intended_method)
{
struct sip_pvt *p;
-
+ static int prof_id = -1, prof_alloc = -1, prof_init = -1;
+
+ if (prof_id == -1) {
+ prof_id = ast_add_profile("sip_alloc", 0);
+ prof_alloc = ast_add_profile("sip_alloc-alloc", 0);
+ prof_init = ast_add_profile("sip_alloc-init", 0);
+ }
+
+ ast_mark(prof_id, 1);
+ ast_mark(prof_alloc, 1);
#ifdef USE_AO2
p = ao2_alloc(sizeof(*p), pvt_destructor);
#else
@@ -4482,6 +4491,8 @@
#ifndef USE_AO2
ast_mutex_init(&p->pvt_lock); /* XXX not necessary in ao2 */
#endif
+ ast_mark(prof_alloc, 0);
+ ast_mark(prof_init, 1);
/* initialize fields so that __sip_destroy() can handle them */
p->method = intended_method;
@@ -4592,6 +4603,8 @@
#endif
if (option_debug)
ast_log(LOG_DEBUG, "Allocating new SIP dialog for %s - %s (%s)\n", callid ? callid : "(No Call-ID)", sip_methods[intended_method].text, p->rtp ? "With RTP" : "No RTP");
+ ast_mark(prof_init, 0);
+ ast_mark(prof_id, 0);
return p;
}
@@ -4614,6 +4627,11 @@
struct find_call_cb_arg *arg = __arg;
/* In pedantic, we do not want packets with bad syntax to be connected to a PVT */
int found = FALSE;
+ static int prof_id = -1;
+ if (prof_id == -1)
+ prof_id = ast_add_profile("find_call_cb", 0);
+
+ ast_mark(prof_id, 1);
if (arg->method == SIP_REGISTER)
found = (!strcmp(p->callid, arg->callid));
else
@@ -4636,6 +4654,7 @@
if (!found && option_debug > 4)
ast_log(LOG_DEBUG, "= Being pedantic: This is not our match on request: Call ID: %s Ourtag <null> Totag %s Method %s\n", p->callid, arg->totag, sip_methods[arg->method].text);
}
+ ast_mark(prof_id, 0);
return found;
}
@@ -4650,10 +4669,23 @@
char totag[128]; /* not initialized, but not used if !pedantic */
char fromtag[128]; /* not initialized, but not used if !pedantic */
struct find_call_cb_arg arg;
- const char *callid = get_header(req, "Call-ID");
- const char *from = get_header(req, "From");
- const char *to = get_header(req, "To");
- const char *cseq = get_header(req, "Cseq");
+ const char *callid;
+ const char *from;
+ const char *to;
+ const char *cseq;
+ static int prof_head = -1, prof_find = -1, prof_tail = -1;
+ if (prof_head == -1) {
+ prof_head = ast_add_profile("find_call-headers", 0);
+ prof_find = ast_add_profile("find_call-find", 0);
+ prof_tail = ast_add_profile("find_call-tail", 0);
+ }
+
+ ast_mark(prof_head, 1);
+ callid = get_header(req, "Call-ID");
+ from = get_header(req, "From");
+ to = get_header(req, "To");
+ cseq = get_header(req, "Cseq");
+ ast_mark(prof_head, 0);
/* Call-ID, to, from and Cseq are required by RFC 3261. (Max-forwards and via too - ignored now) */
/* get_header always returns non-NULL so we must use ast_strlen_zero() */
@@ -4697,10 +4729,12 @@
}
}
+ ast_mark(prof_find, 1);
#ifdef USE_AO2
p = ao2_callback(dialogs, 0 /* single, data */, find_call_cb, &arg);
if (p) {
sip_pvt_lock(p);
+ ast_mark(prof_find, 0);
return p;
}
#else
@@ -4713,10 +4747,14 @@
}
}
dialoglist_unlock();
- if (p)
+ if (p) {
+ ast_mark(prof_find, 0);
return p;
+ }
#endif
+ ast_mark(prof_find, 0);
+ ast_mark(prof_tail, 1);
/* See if the method is capable of creating a dialog */
if (sip_methods[intended_method].can_create == CAN_CREATE_DIALOG) {
if (intended_method == SIP_REFER) {
@@ -4745,6 +4783,7 @@
ast_log(LOG_DEBUG, "Failed allocating SIP dialog, sending 500 Server internal error and giving up\n");
}
}
+ ast_mark(prof_tail, 0);
return p; /* can be NULL */
} else if( sip_methods[intended_method].can_create == CAN_CREATE_DIALOG_UNSUPPORTED_METHOD) {
/* A method we do not support, let's take it on the volley */
@@ -4762,6 +4801,7 @@
if (option_debug > 1 && intended_method == SIP_RESPONSE)
ast_log(LOG_DEBUG, "That's odd... Got a response on a call we dont know about. Callid %s\n", callid ? callid : "<unknown>");
+ ast_mark(prof_tail, 0);
return NULL;
}
@@ -15207,12 +15247,13 @@
int recount = 0;
int lockretry;
int buflen = sizeof(req.data) - 1; /* leave an extra byte at the end for '\0' */
- static int prof_memset = -1, prof_recv = -1, prof_parse = -1;
+ static int prof_memset = -1, prof_recv = -1, prof_parse = -1, prof_find = -1;
if (prof_memset == -1) { /* allocate profiling counters */
prof_memset = ast_add_profile("sip_read-memset", 0);
prof_recv = ast_add_profile("sip_read-recvfrom", 0);
prof_parse = ast_add_profile("sip_read-parse", 0);
+ prof_find = ast_add_profile("sip_read-find_call", 0);
}
ast_mark(prof_memset, 1);
memset(&req, 0, sizeof(req));
@@ -15261,7 +15302,9 @@
/* Process request with usual deadlock avoidance */
for (lockretry = 100; lockretry > 0; lockretry--) {
/* Find the active SIP dialog or create a new one */
+ ast_mark(prof_find, 1);
p = find_call(&req, &sin, req.method); /* returns p locked */
+ ast_mark(prof_find, 0);
if (p == NULL) {
if (option_debug)
ast_log(LOG_DEBUG, "Invalid SIP message - rejected , no callid, len %d\n", req.len);
More information about the svn-commits
mailing list