[svn-commits] murf: branch murf/mtxprof r126114 - in /team/murf/mtxprof: ./ channels/ inclu...
SVN commits to the Digium repositories
svn-commits at lists.digium.com
Fri Jun 27 18:11:40 CDT 2008
Author: murf
Date: Fri Jun 27 18:11:39 2008
New Revision: 126114
URL: http://svn.digium.com/view/asterisk?view=rev&rev=126114
Log:
Todays little experiments added. Cut down some of the output from the device_state calls using channel_find_locked(), just report the 199-failures msg instead.
Modified:
team/murf/mtxprof/Makefile
team/murf/mtxprof/channels/chan_sip.c
team/murf/mtxprof/include/asterisk/lock.h
team/murf/mtxprof/main/channel.c
team/murf/mtxprof/main/pbx.c
team/murf/mtxprof/main/utils.c
Modified: team/murf/mtxprof/Makefile
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/Makefile?view=diff&rev=126114&r1=126113&r2=126114
==============================================================================
--- team/murf/mtxprof/Makefile (original)
+++ team/murf/mtxprof/Makefile Fri Jun 27 18:11:39 2008
@@ -116,8 +116,8 @@
OVERWRITE=y
# Include debug and macro symbols in the executables (-g) and profiling info (-pg)
-DEBUG=-g3
-
+DEBUG=-g3 -pg
+ASTLDFLAGS += -pg
# Define standard directories for various platforms
# These apply if they are not redefined in asterisk.conf
Modified: team/murf/mtxprof/channels/chan_sip.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/channels/chan_sip.c?view=diff&rev=126114&r1=126113&r2=126114
==============================================================================
--- team/murf/mtxprof/channels/chan_sip.c (original)
+++ team/murf/mtxprof/channels/chan_sip.c Fri Jun 27 18:11:39 2008
@@ -1176,7 +1176,11 @@
};
-
+/*! this array will store the invocation counts for the 10
+ funcs that the sched facility initiates. To see if one is
+ going nuts */
+
+int sched_invocation_counts[10] = {0};
/*! \brief sip_pvt: structures used for each SIP dialog, ie. a call, a registration, a subscribe.
* Created and initialized by sip_alloc(), the descriptor goes into the list of
@@ -2920,6 +2924,7 @@
int reschedule = DEFAULT_RETRANS;
int xmitres = 0;
+ sched_invocation_counts[0]++;
/* Lock channel PVT */
sip_pvt_lock(pkt->owner);
@@ -3119,6 +3124,7 @@
{
struct sip_pvt *p = (struct sip_pvt *)data;
+ sched_invocation_counts[1]++;
/* If this is a subscription, tell the phone that we got a timeout */
if (p->subscribed) {
transmit_state_notify(p, AST_EXTENSION_DEACTIVATED, 1, TRUE); /* Send last notification */
@@ -4452,6 +4458,7 @@
{
struct sip_pvt *p = (struct sip_pvt *)arg;
+ sched_invocation_counts[3]++;
sip_pvt_lock(p);
p->initid = -1; /* event gone, will not be rescheduled */
if (p->owner) {
@@ -4804,6 +4811,7 @@
ast_log(LOG_ERROR, "update_call_counter(%s, %d) called with no event!\n", name, event);
}
if (p) {
+ ast_log(LOG_NOTICE,"device state changed called from here 1\n");
ast_device_state_changed("SIP/%s", p->name);
unref_peer(p, "update_call_counter: unref_peer from call counter");
} else /* u must be set */
@@ -9647,6 +9655,7 @@
/* if we are here, we know that we need to reregister. */
struct sip_registry *r= (struct sip_registry *) data;
+ sched_invocation_counts[7]++;
/* if we couldn't get a reference to the registry object, punt */
if (!r)
return 0;
@@ -9687,6 +9696,7 @@
struct sip_pvt *p;
int res;
+ sched_invocation_counts[4]++;
/* if we couldn't get a reference to the registry object, punt */
if (!r)
return 0;
@@ -10154,6 +10164,7 @@
{
struct sip_peer *peer = (struct sip_peer *)data;
+ sched_invocation_counts[2]++;
if (!peer) /* Hmmm. We have no peer. Weird. */
return 0;
@@ -10164,6 +10175,7 @@
manager_event(EVENT_FLAG_SYSTEM, "PeerStatus", "ChannelType: SIP\r\nPeer: SIP/%s\r\nPeerStatus: Unregistered\r\nCause: Expired\r\n", peer->name);
register_peer_exten(peer, FALSE); /* Remove regexten */
+ ast_log(LOG_NOTICE,"device state changed called from here 2\n");
ast_device_state_changed("SIP/%s", peer->name);
/* Do we need to release this peer from memory?
@@ -10189,6 +10201,7 @@
{
struct sip_peer *peer = (struct sip_peer *)data;
+ sched_invocation_counts[5]++;
peer->pokeexpire = -1;
sip_poke_peer(peer, 0);
return 0;
@@ -10786,6 +10799,7 @@
ast_atomic_fetchadd_int(&peer->onHold, (hold ? +1 : -1));
/* Request device state update */
+ ast_log(LOG_NOTICE,"device state changed called from here 3\n");
ast_device_state_changed("SIP/%s", peer->name);
unref_peer(peer, "sip_peer_hold: from find_peer operation");
@@ -11037,6 +11051,7 @@
}
}
if (!res) {
+ ast_log(LOG_NOTICE,"device state changed called from here 4\n");
ast_device_state_changed("SIP/%s", peer->name);
}
if (res < 0) {
@@ -13944,6 +13959,8 @@
static char *sip_show_sched(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
{
char cbuf[2256];
+ int i;
+
struct ast_cb_names cbnames = {9, { "retrans_pkt",
"__sip_autodestruct",
"expire_register",
@@ -13976,6 +13993,14 @@
ast_cli(a->fd, "\n");
ast_sched_report(sched, cbuf, sizeof(cbuf), &cbnames);
ast_cli(a->fd, "%s", cbuf);
+
+ ast_cli(a->fd, "Invocation counts:\n");
+ for(i=0; i<9; i++) {
+ char buf2[200];
+ sprintf(buf2,"%s : %d\n", cbnames.list[i], sched_invocation_counts[i]);
+ ast_cli(a->fd, "%s", buf2);
+ }
+
return CLI_SUCCESS;
}
@@ -15804,6 +15829,7 @@
{
struct sip_pvt *p = (struct sip_pvt *) data;
+ sched_invocation_counts[8]++;
ast_set_flag(&p->flags[0], SIP_NEEDREINVITE);
p->waitid = -1;
dialog_unref(p, "unref the dialog ptr from sip_reinvite_retry, because it held a dialog ptr");
@@ -19985,14 +20011,17 @@
}
if (monitor_thread != AST_PTHREADT_NULL) {
/* Wake up the thread */
+ ast_log(LOG_NOTICE,"Waking SIP monitor thread\n");
pthread_kill(monitor_thread, SIGURG);
} else {
/* Start a new monitor */
+ ast_log(LOG_NOTICE,"Creating SIP monitor background thread\n");
if (ast_pthread_create_background(&monitor_thread, NULL, do_monitor, NULL) < 0) {
ast_mutex_unlock(&monlock);
ast_log(LOG_ERROR, "Unable to start monitor thread.\n");
return -1;
}
+ ast_log(LOG_NOTICE,"SIP monitor background thread Created\n");
}
ast_mutex_unlock(&monlock);
return 0;
@@ -20339,6 +20368,7 @@
{
struct sip_peer *peer = (struct sip_peer *)data;
+ sched_invocation_counts[6]++;
peer->pokeexpire = -1;
if (peer->lastms > -1) {
ast_log(LOG_NOTICE, "Peer '%s' is now UNREACHABLE! Last qualify: %d\n", peer->name, peer->lastms);
@@ -20353,6 +20383,7 @@
}
peer->lastms = -1;
+ ast_log(LOG_NOTICE,"device state changed called from here 5\n");
ast_device_state_changed("SIP/%s", peer->name);
/* Try again quickly */
AST_SCHED_REPLACE(peer->pokeexpire, sched,
@@ -23017,7 +23048,7 @@
/*! \brief PBX load module - initialization */
static int load_module(void)
{
- ast_verbose("SIP channel loading...\n");
+ ast_log(LOG_NOTICE,"SIP channel loading...\n");
/* the fact that ao2_containers can't resize automatically is a major worry! */
/* if the number of objects gets above MAX_XXX_BUCKETS, things will slow down */
users = ao2_t_container_alloc(hash_user_size, user_hash_cb, user_cmp_cb, "allocate users");
@@ -23104,7 +23135,7 @@
"regserver", RQ_CHAR, 20,
"useragent", RQ_CHAR, 20,
SENTINEL);
-
+ ast_log(LOG_NOTICE,"SIP CHANNEL Finished Load\n");
return AST_MODULE_LOAD_SUCCESS;
}
Modified: team/murf/mtxprof/include/asterisk/lock.h
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/include/asterisk/lock.h?view=diff&rev=126114&r1=126113&r2=126114
==============================================================================
--- team/murf/mtxprof/include/asterisk/lock.h (original)
+++ team/murf/mtxprof/include/asterisk/lock.h Fri Jun 27 18:11:39 2008
@@ -1791,8 +1791,9 @@
#define ast_channel_unlock_comma(x) ast_log(LOG_NOTICE,"UnLockChan %s\n", x->name), ast_mutex_unlock(&x->lock_dont_use)
/*! \brief Try locking a channel. If DEBUG_CHANNEL_LOCKS is defined
in the Makefile, print relevant output for debugging */
-#define ast_channel_trylock(x) ast_log(LOG_NOTICE,"TryChan %s\n", x->name); ast_mutex_trylock(&x->lock_dont_use)
-#define ast_channel_trylock_assign(x, var) ast_log(LOG_NOTICE,"TryChan %s\n", x->name); var = ast_mutex_trylock(&x->lock_dont_use)
+#define ast_channel_trylock(x) if(!ast_mutex_trylock(&x->lock_dont_use))ast_log(LOG_NOTICE,"TryLockChan for %s success\n", x->name)
+#define ast_channel_trylock_assign(x, var) var = ast_mutex_trylock(&x->lock_dont_use); \
+ if(!var)ast_log(LOG_NOTICE,"TryChan %s success\n", x->name);
#else
#define ast_channel_lock(a) __ast_channel_lock(a, __FILE__, __LINE__, __PRETTY_FUNCTION__)
Modified: team/murf/mtxprof/main/channel.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/channel.c?view=diff&rev=126114&r1=126113&r2=126114
==============================================================================
--- team/murf/mtxprof/main/channel.c (original)
+++ team/murf/mtxprof/main/channel.c Fri Jun 27 18:11:39 2008
@@ -1159,7 +1159,6 @@
/* exit if chan not found or mutex acquired successfully */
/* this is slightly unsafe, as we _should_ hold the lock to access c->name */
if (c) {
- ast_log(LOG_NOTICE,"prev=%p; name=%s, len=%d; context=%s; exten=%s\n", prev, name, namelen, context, exten);
ast_channel_trylock_assign(c,lockret);
}
@@ -1170,6 +1169,7 @@
/* We are about to fail due to a deadlock, so report this
* while we still have the list lock.
*/
+ ast_log(LOG_NOTICE, "Failure, could not lock '%p' after %d retries!\n", c, retries);
ast_debug(1, "Failure, could not lock '%p' after %d retries!\n", c, retries);
/* As we have deadlocked, we will skip this channel and
* see if there is another match.
Modified: team/murf/mtxprof/main/pbx.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/pbx.c?view=diff&rev=126114&r1=126113&r2=126114
==============================================================================
--- team/murf/mtxprof/main/pbx.c (original)
+++ team/murf/mtxprof/main/pbx.c Fri Jun 27 18:11:39 2008
@@ -3798,7 +3798,8 @@
PBX has finished running on the channel
*/
struct ast_channel *c = data;
-
+ usleep(1);
+
__ast_pbx_run(c);
decrease_call_count();
Modified: team/murf/mtxprof/main/utils.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/utils.c?view=diff&rev=126114&r1=126113&r2=126114
==============================================================================
--- team/murf/mtxprof/main/utils.c (original)
+++ team/murf/mtxprof/main/utils.c Fri Jun 27 18:11:39 2008
@@ -1041,6 +1041,11 @@
void *data, size_t stacksize, const char *file, const char *caller,
int line, const char *start_fn)
{
+ struct timeval start9, end9;
+ static int totaltime = 0;
+ static int numtimes = 0;
+ int timediff, ret7;
+
#if !defined(LOW_MEMORY)
struct thr_arg *a;
#endif
@@ -1079,7 +1084,16 @@
}
#endif /* !LOW_MEMORY */
- return pthread_create(thread, attr, start_routine, data); /* We're in ast_pthread_create, so it's okay */
+ start9 = ast_tvnow();
+ ret7 = pthread_create(thread, attr, start_routine, data); /* We're in ast_pthread_create, so it's okay */
+ end9 = ast_tvnow();
+ timediff = ast_tvdiff_us(end9, start9);
+ totaltime += timediff;
+ numtimes++;
+
+ ast_log(LOG_NOTICE,"pthread_create took %d microseconds, avg=%d usec (%d times)\n", timediff, totaltime/numtimes, numtimes);
+
+ return ret7;
}
More information about the svn-commits
mailing list