[asterisk-commits] murf: branch murf/cdr-debug-1.4 r144133 - in /team/murf/cdr-debug-1.4: apps/ ...
SVN commits to the Asterisk project
asterisk-commits at lists.digium.com
Tue Sep 23 15:30:51 CDT 2008
Author: murf
Date: Tue Sep 23 15:30:50 2008
New Revision: 144133
URL: http://svn.digium.com/view/asterisk?view=rev&rev=144133
Log:
Here is all the current instrumentation, as I call it
Modified:
team/murf/cdr-debug-1.4/apps/app_dial.c
team/murf/cdr-debug-1.4/channels/chan_sip.c
team/murf/cdr-debug-1.4/include/asterisk/cdr.h
team/murf/cdr-debug-1.4/main/cdr.c
team/murf/cdr-debug-1.4/main/channel.c
team/murf/cdr-debug-1.4/main/pbx.c
team/murf/cdr-debug-1.4/res/res_features.c
Modified: team/murf/cdr-debug-1.4/apps/app_dial.c
URL: http://svn.digium.com/view/asterisk/team/murf/cdr-debug-1.4/apps/app_dial.c?view=diff&rev=144133&r1=144132&r2=144133
==============================================================================
--- team/murf/cdr-debug-1.4/apps/app_dial.c (original)
+++ team/murf/cdr-debug-1.4/apps/app_dial.c Tue Sep 23 15:30:50 2008
@@ -1324,7 +1324,7 @@
ds_callee_features->data = callee_features;
ast_channel_datastore_add(tmp->chan, ds_callee_features);
ast_channel_unlock(tmp->chan);
-
+
/* Place the call, but don't wait on the answer */
res = ast_call(tmp->chan, numsubst, 0);
@@ -1661,10 +1661,10 @@
ast_log(LOG_ERROR, "Could not stop autoservice on calling channel\n");
res = -1;
}
-
if (!res && (macro_result = pbx_builtin_getvar_helper(peer, "MACRO_RESULT"))) {
char *macro_transfer_dest;
+ ast_log(LOG_NOTICE,"MACRO result: MACRO_RESULT is %s\n", macro_result);
if (!strcasecmp(macro_result, "BUSY")) {
ast_copy_string(status, macro_result, sizeof(status));
if (ast_opt_priority_jumping || ast_test_flag(&opts, OPT_PRIORITY_JUMP)) {
@@ -1702,6 +1702,7 @@
}
if (!res) {
+ ast_log(LOG_NOTICE,"==== 1=====\n");
if (calldurationlimit > 0) {
peer->whentohangup = time(NULL) + calldurationlimit;
}
@@ -1720,6 +1721,7 @@
if (!res) {
struct ast_bridge_config config;
+ ast_log(LOG_NOTICE,"==== 2 =====\n");
memset(&config,0,sizeof(struct ast_bridge_config));
if (play_to_caller)
ast_set_flag(&(config.features_caller), AST_FEATURE_PLAY_WARNING);
@@ -1787,17 +1789,21 @@
pbx_builtin_setvar_helper(chan, "ANSWEREDTIME", toast);
}
} else {
+ ast_log(LOG_NOTICE,"==== 3 =====\n");
time(&end_time);
res = -1;
}
{
char toast[80];
+ ast_log(LOG_NOTICE,"==== 4 =====\n");
snprintf(toast, sizeof(toast), "%ld", (long)(end_time - start_time));
pbx_builtin_setvar_helper(chan, "DIALEDTIME", toast);
}
if (res != AST_PBX_NO_HANGUP_PEER) {
+ ast_log(LOG_NOTICE,"==== 5 =====\n");
if (!chan->_softhangup)
+ ast_log(LOG_NOTICE,"==== 6 =====\n");
chan->hangupcause = peer->hangupcause;
ast_hangup(peer);
}
@@ -1810,6 +1816,7 @@
sentringing = 0;
ast_indicate(chan, -1);
}
+ ast_log(LOG_NOTICE,"==== 7 =====\n");
ast_rtp_early_bridge(chan, NULL);
hanguptree(outgoing, NULL);
pbx_builtin_setvar_helper(chan, "DIALSTATUS", status);
@@ -1817,6 +1824,7 @@
ast_log(LOG_DEBUG, "Exiting with DIALSTATUS=%s.\n", status);
if ((ast_test_flag(peerflags, OPT_GO_ON)) && (!chan->_softhangup) && (res != AST_PBX_KEEPALIVE)) {
+ ast_log(LOG_NOTICE,"==== 8 =====\n");
if (calldurationlimit)
chan->whentohangup = 0;
res = 0;
Modified: team/murf/cdr-debug-1.4/channels/chan_sip.c
URL: http://svn.digium.com/view/asterisk/team/murf/cdr-debug-1.4/channels/chan_sip.c?view=diff&rev=144133&r1=144132&r2=144133
==============================================================================
--- team/murf/cdr-debug-1.4/channels/chan_sip.c (original)
+++ team/murf/cdr-debug-1.4/channels/chan_sip.c Tue Sep 23 15:30:50 2008
@@ -3899,10 +3899,11 @@
if (dest == NULL) /* functions below do not take a NULL */
dest = "";
ast_mutex_lock(&p->lock);
- if (ast->_state == AST_STATE_RING)
+ if (ast->_state == AST_STATE_RING) {
res = sip_sipredirect(p, dest);
- else
+ } else {
res = transmit_refer(p, dest);
+ }
ast_mutex_unlock(&p->lock);
return res;
}
@@ -11339,10 +11340,14 @@
} else if (!ast_strlen_zero(c = get_header(req, "X-ClientCode"))) {
/* Client code (from SNOM phone) */
if (ast_test_flag(&p->flags[0], SIP_USECLIENTCODE)) {
- if (p->owner && p->owner->cdr)
+ if (p->owner && p->owner->cdr) {
+ ast_log(LOG_NOTICE,"CDR set userfield\n");
ast_cdr_setuserfield(p->owner, c);
- if (p->owner && ast_bridged_channel(p->owner) && ast_bridged_channel(p->owner)->cdr)
+ }
+ if (p->owner && ast_bridged_channel(p->owner) && ast_bridged_channel(p->owner)->cdr) {
+ ast_log(LOG_NOTICE,"CDR set userfield\n");
ast_cdr_setuserfield(ast_bridged_channel(p->owner), c);
+ }
transmit_response(p, "200 OK", req);
} else {
transmit_response(p, "403 Unauthorized", req);
Modified: team/murf/cdr-debug-1.4/include/asterisk/cdr.h
URL: http://svn.digium.com/view/asterisk/team/murf/cdr-debug-1.4/include/asterisk/cdr.h?view=diff&rev=144133&r1=144132&r2=144133
==============================================================================
--- team/murf/cdr-debug-1.4/include/asterisk/cdr.h (original)
+++ team/murf/cdr-debug-1.4/include/asterisk/cdr.h Tue Sep 23 15:30:50 2008
@@ -26,17 +26,17 @@
#include <sys/time.h>
/*! Flags */
-#define AST_CDR_FLAG_KEEP_VARS (1 << 0)
-#define AST_CDR_FLAG_POSTED (1 << 1)
-#define AST_CDR_FLAG_LOCKED (1 << 2)
-#define AST_CDR_FLAG_CHILD (1 << 3)
-#define AST_CDR_FLAG_POST_DISABLED (1 << 4)
-#define AST_CDR_FLAG_BRIDGED (1 << 5)
-#define AST_CDR_FLAG_MAIN (1 << 6)
-#define AST_CDR_FLAG_ENABLE (1 << 7)
-#define AST_CDR_FLAG_ANSLOCKED (1 << 8)
-#define AST_CDR_FLAG_DONT_TOUCH (1 << 9)
-#define AST_CDR_FLAG_DIALED (1 << 10)
+#define AST_CDR_FLAG_KEEP_VARS (1 << 0) /* 1 0x001 */
+#define AST_CDR_FLAG_POSTED (1 << 1) /* 2 0x002 */
+#define AST_CDR_FLAG_LOCKED (1 << 2) /* 4 0x004 */
+#define AST_CDR_FLAG_CHILD (1 << 3) /* 8 0x008 */
+#define AST_CDR_FLAG_POST_DISABLED (1 << 4) /* 16 0x010 */
+#define AST_CDR_FLAG_BRIDGED (1 << 5) /* 32 0x020 */
+#define AST_CDR_FLAG_MAIN (1 << 6) /* 64 0x040 */
+#define AST_CDR_FLAG_ENABLE (1 << 7) /* 128 0x080 */
+#define AST_CDR_FLAG_ANSLOCKED (1 << 8) /* 256 0x100 */
+#define AST_CDR_FLAG_DONT_TOUCH (1 << 9) /* 512 0x200 */
+#define AST_CDR_FLAG_DIALED (1 << 10) /* 1024 0x400 */
/*! Disposition */
#define AST_CDR_NULL 0
Modified: team/murf/cdr-debug-1.4/main/cdr.c
URL: http://svn.digium.com/view/asterisk/team/murf/cdr-debug-1.4/main/cdr.c?view=diff&rev=144133&r1=144132&r2=144133
==============================================================================
--- team/murf/cdr-debug-1.4/main/cdr.c (original)
+++ team/murf/cdr-debug-1.4/main/cdr.c Tue Sep 23 15:30:50 2008
@@ -177,6 +177,7 @@
if (!cdr) /* don't die if we get a null cdr pointer */
return NULL;
newcdr = ast_cdr_alloc();
+ ast_log(LOG_NOTICE,"Dup CDR %s (%p) to (%p)\n", cdr->channel, cdr, newcdr);
if (!newcdr)
return NULL;
@@ -428,7 +429,7 @@
if (!cdr)
return;
if (ast_test_flag(cdr, AST_CDR_FLAG_POSTED))
- ast_log(LOG_NOTICE, "CDR on channel '%s' already posted\n", S_OR(cdr->channel, "<unknown>"));
+ ast_log(LOG_NOTICE, "CDR on channel '%s' (%p) already posted\n", S_OR(cdr->channel, "<unknown>"), cdr);
}
void ast_cdr_free(struct ast_cdr *cdr)
@@ -437,6 +438,7 @@
while (cdr) {
struct ast_cdr *next = cdr->next;
char *chan = S_OR(cdr->channel, "<unknown>");
+ ast_log(LOG_NOTICE,"Free CDR %s (%p)\n", cdr->channel, cdr);
if (option_verbose > 1 && !ast_test_flag(cdr, AST_CDR_FLAG_POSTED) && !ast_test_flag(cdr, AST_CDR_FLAG_POST_DISABLED))
ast_verbose(VERBOSE_PREFIX_2 "CDR on channel '%s' not posted\n", chan);
if (option_verbose > 1 && ast_tvzero(cdr->end))
@@ -456,6 +458,7 @@
while (cdr) {
struct ast_cdr *next = cdr->next;
+ ast_log(LOG_NOTICE,"discard CDR %s (%p)\n", cdr->channel, cdr);
ast_cdr_free_vars(cdr, 0);
free(cdr);
cdr = next;
@@ -516,6 +519,7 @@
if (!to || !from)
return;
+ ast_log(LOG_NOTICE,"merge CDR %s -> %s\n", from->channel, to->channel);
/* don't merge into locked CDR's -- it's bad business */
if (ast_test_flag(to, AST_CDR_FLAG_LOCKED)) {
zcdr = to; /* safety valve? */
@@ -694,6 +698,7 @@
chan = S_OR(cdr->channel, "<unknown>");
check_post(cdr);
cdr->start = ast_tvnow();
+ ast_log(LOG_NOTICE,"start CDR %s (%p) = %d\n", cdr->channel, cdr, (int)cdr->start.tv_sec);
}
}
}
@@ -707,10 +712,14 @@
if (ast_test_flag(cdr, AST_CDR_FLAG_DONT_TOUCH) && ast_test_flag(cdr, AST_CDR_FLAG_LOCKED))
continue;
check_post(cdr);
- if (cdr->disposition < AST_CDR_ANSWERED)
+ if (cdr->disposition < AST_CDR_ANSWERED) {
cdr->disposition = AST_CDR_ANSWERED;
- if (ast_tvzero(cdr->answer))
+ ast_log(LOG_NOTICE,"answer CDR %s (%p) disposition = ANSWERED(%d)\n", cdr->channel, cdr, (int)cdr->disposition);
+ }
+ if (ast_tvzero(cdr->answer)) {
+ ast_log(LOG_NOTICE,"answer CDR %s (%p) = %d\n", cdr->channel, cdr, (int)cdr->start.tv_sec);
cdr->answer = ast_tvnow();
+ }
}
}
@@ -720,8 +729,11 @@
for (; cdr; cdr = cdr->next) {
if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
check_post(cdr);
- if (cdr->disposition < AST_CDR_BUSY)
+ if (cdr->disposition < AST_CDR_BUSY) {
cdr->disposition = AST_CDR_BUSY;
+ ast_log(LOG_NOTICE,"busy CDR %s (%p)\n", cdr->channel, cdr);
+ }
+
}
}
}
@@ -731,8 +743,10 @@
for (; cdr; cdr = cdr->next) {
check_post(cdr);
if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
- if (cdr->disposition < AST_CDR_FAILED)
+ if (cdr->disposition < AST_CDR_FAILED) {
+ ast_log(LOG_NOTICE,"failed CDR %s (%p)\n", cdr->channel, cdr);
cdr->disposition = AST_CDR_FAILED;
+ }
}
}
}
@@ -746,8 +760,11 @@
if (ast_test_flag(cdr, AST_CDR_FLAG_POSTED))
ast_log(LOG_WARNING, "CDR on channel '%s' already posted\n", chan);
if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
- if (cdr->disposition < AST_CDR_NOANSWER)
+ if (cdr->disposition < AST_CDR_NOANSWER) {
+ ast_log(LOG_NOTICE,"noanswer CDR %s (%p)\n", cdr->channel, cdr);
cdr->disposition = AST_CDR_NOANSWER;
+ }
+
}
cdr = cdr->next;
}
@@ -779,8 +796,10 @@
{
for (; cdr; cdr = cdr->next) {
check_post(cdr);
- if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED))
+ if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
+ ast_log(LOG_NOTICE,"setdestchan CDR %s (%p) => %s\n", cdr->channel, cdr, chann);
ast_copy_string(cdr->dstchannel, chann, sizeof(cdr->dstchannel));
+ }
}
}
@@ -792,6 +811,7 @@
check_post(cdr);
ast_copy_string(cdr->lastapp, S_OR(app, ""), sizeof(cdr->lastapp));
ast_copy_string(cdr->lastdata, S_OR(data, ""), sizeof(cdr->lastdata));
+ ast_log(LOG_NOTICE,"setapp CDR %s (%p) => %s(%s)\n", cdr->channel, cdr, app, data);
}
}
}
@@ -804,16 +824,21 @@
if (!cdr)
return;
if (!ast_strlen_zero(c->cid.cid_name)) {
- if (!ast_strlen_zero(num)) /* both name and number */
+ if (!ast_strlen_zero(num)) { /* both name and number */
snprintf(cdr->clid, sizeof(cdr->clid), "\"%s\" <%s>", c->cid.cid_name, num);
- else /* only name */
+ } else { /* only name */
ast_copy_string(cdr->clid, c->cid.cid_name, sizeof(cdr->clid));
+ }
+ ast_log(LOG_NOTICE,"CDR %s (%p) => clid = %s\n", cdr->channel, cdr, cdr->clid);
} else if (!ast_strlen_zero(num)) { /* only number */
ast_copy_string(cdr->clid, num, sizeof(cdr->clid));
+ ast_log(LOG_NOTICE,"CDR %s (%p) => clid = %s\n", cdr->channel, cdr, cdr->clid);
} else { /* nothing known */
cdr->clid[0] = '\0';
+ ast_log(LOG_NOTICE,"CDR %s (%p) => clid = %s\n", cdr->channel, cdr, cdr->clid);
}
ast_copy_string(cdr->src, S_OR(num, ""), sizeof(cdr->src));
+ ast_log(LOG_NOTICE,"CDR.%s (%p) => src = %s\n", cdr->channel, cdr, cdr->src);
}
int ast_cdr_setcid(struct ast_cdr *cdr, struct ast_channel *c)
@@ -843,6 +868,7 @@
ast_copy_string(cdr->dcontext, S_OR(c->macrocontext,c->context), sizeof(cdr->dcontext));
/* Unique call identifier */
ast_copy_string(cdr->uniqueid, c->uniqueid, sizeof(cdr->uniqueid));
+ ast_log(LOG_NOTICE,"CDR %s (%p) => clid = %s amaflags= %ld; acctcode=%s; dst=%s; dcont=%s; uid=%s\n", cdr->channel, cdr, cdr->clid, cdr->amaflags, cdr->accountcode, cdr->dst, cdr->dcontext, cdr->uniqueid);
}
}
return 0;
@@ -866,20 +892,28 @@
if (ast_test_flag(cdr, AST_CDR_FLAG_DONT_TOUCH) && ast_test_flag(cdr, AST_CDR_FLAG_LOCKED))
continue;
check_post(cdr);
- if (ast_tvzero(cdr->end))
+ if (ast_tvzero(cdr->end)) {
cdr->end = ast_tvnow();
+ ast_log(LOG_NOTICE,"end CDR %s (%p) = %d\n", cdr->channel, cdr, (int)cdr->end.tv_sec);
+ }
if (ast_tvzero(cdr->start)) {
ast_log(LOG_WARNING, "CDR on channel '%s' has not started\n", S_OR(cdr->channel, "<unknown>"));
cdr->disposition = AST_CDR_FAILED;
- } else
+ ast_log(LOG_NOTICE,"end CDR %s (%p) => disposition = %ld\n", cdr->channel, cdr, cdr->disposition);
+ } else {
cdr->duration = cdr->end.tv_sec - cdr->start.tv_sec;
+ ast_log(LOG_NOTICE,"end CDR %s (%p) => duration = %ld\n", cdr->channel, cdr, cdr->duration);
+ }
+
if (ast_tvzero(cdr->answer)) {
if (cdr->disposition == AST_CDR_ANSWERED) {
ast_log(LOG_WARNING, "CDR on channel '%s' has no answer time but is 'ANSWERED'\n", S_OR(cdr->channel, "<unknown>"));
cdr->disposition = AST_CDR_FAILED;
}
- } else
+ } else {
cdr->billsec = cdr->end.tv_sec - cdr->answer.tv_sec;
+ ast_log(LOG_NOTICE,"end CDR %s (%p) => billsec = %ld\n", cdr->channel, cdr, cdr->billsec);
+ }
}
}
@@ -922,6 +956,7 @@
for ( ; cdr ; cdr = cdr->next) {
if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
ast_copy_string(cdr->accountcode, chan->accountcode, sizeof(cdr->accountcode));
+ ast_log(LOG_NOTICE,"acct CDR %s (%p) => accountcode = %s\n", cdr->channel, cdr, cdr->accountcode);
}
}
return 0;
@@ -935,6 +970,7 @@
for (cdr = chan->cdr; cdr; cdr = cdr->next) {
if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
cdr->amaflags = newflag;
+ ast_log(LOG_NOTICE,"set CDR %s (%p) => amaflags = %ld\n", cdr->channel, cdr, cdr->amaflags);
}
}
}
@@ -947,8 +983,10 @@
struct ast_cdr *cdr = chan->cdr;
for ( ; cdr ; cdr = cdr->next) {
- if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED))
+ if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
ast_copy_string(cdr->userfield, userfield, sizeof(cdr->userfield));
+ ast_log(LOG_NOTICE,"set CDR %s (%p) => userfield = %s\n", cdr->channel, cdr, cdr->userfield);
+ }
}
return 0;
@@ -961,8 +999,10 @@
for ( ; cdr ; cdr = cdr->next) {
int len = strlen(cdr->userfield);
- if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED))
+ if (!ast_test_flag(cdr, AST_CDR_FLAG_LOCKED)) {
ast_copy_string(cdr->userfield + len, userfield, sizeof(cdr->userfield) - len);
+ ast_log(LOG_NOTICE,"appendset CDR %s (%p) => userfield = %s\n", cdr->channel, cdr, cdr->userfield);
+ }
}
return 0;
@@ -982,6 +1022,7 @@
/* Destination information */ /* XXX privilege macro* ? */
ast_copy_string(cdr->dst, S_OR(c->macroexten, c->exten), sizeof(cdr->dst));
ast_copy_string(cdr->dcontext, S_OR(c->macrocontext, c->context), sizeof(cdr->dcontext));
+ ast_log(LOG_NOTICE,"update CDR %s (%p) => acctcode = %s; dst=%s; dcont=%s\n", cdr->channel, cdr, cdr->accountcode, cdr->dst, cdr->dcontext);
}
}
@@ -1009,6 +1050,7 @@
for ( ; cdr ; cdr = cdr->next) {
if (!unanswered && cdr->disposition < AST_CDR_ANSWERED && (ast_strlen_zero(cdr->channel) || ast_strlen_zero(cdr->dstchannel))) {
/* For people, who don't want to see unanswered single-channel events */
+ ast_log(LOG_NOTICE,"Marking Cdr '%s' to '%s' as DISABLED\n", cdr->channel, cdr->dstchannel);
ast_set_flag(cdr, AST_CDR_FLAG_POST_DISABLED);
continue;
}
@@ -1020,8 +1062,12 @@
if (option_verbose > 1 && ast_tvzero(cdr->start))
ast_verbose(VERBOSE_PREFIX_2 "CDR on channel '%s' lacks start\n", chan);
ast_set_flag(cdr, AST_CDR_FLAG_POSTED);
- if (ast_test_flag(cdr, AST_CDR_FLAG_POST_DISABLED))
+ if (ast_test_flag(cdr, AST_CDR_FLAG_POST_DISABLED)) {
+ ast_log(LOG_NOTICE,"POST CDR %s (%p) SKIPPED DUE TO DISABLED FLAG!!!!!\n", cdr->channel, cdr);
continue;
+ }
+
+ ast_log(LOG_NOTICE,"POST CDR %s (%p)\n", cdr->channel, cdr);
AST_LIST_LOCK(&be_list);
AST_LIST_TRAVERSE(&be_list, i, list) {
i->be(cdr);
@@ -1063,6 +1109,7 @@
cdr->duration = 0;
ast_cdr_start(cdr);
cdr->disposition = AST_CDR_NULL;
+ ast_log(LOG_NOTICE,"RESET CDR %s (%p) == start=%d; end=0; ans=0; billsec=0; duration=0; disp=0\n", cdr->channel, cdr, (int)cdr->start.tv_sec);
}
}
}
@@ -1089,6 +1136,7 @@
cdr->duration = 0;
ast_cdr_start(cdr);
cdr->disposition = AST_CDR_NULL;
+ ast_log(LOG_NOTICE,"specRESET CDR %s (%p) == start=%d; end=0; ans=0; billsec=0; duration=0; disp=0\n", cdr->channel, cdr, (int)cdr->start.tv_sec);
}
struct ast_cdr *ast_cdr_append(struct ast_cdr *cdr, struct ast_cdr *newcdr)
@@ -1216,6 +1264,7 @@
ast_log(LOG_DEBUG, "Dropping CDR !\n");
ast_set_flag(cdr, AST_CDR_FLAG_POST_DISABLED);
ast_cdr_free(cdr);
+ ast_log(LOG_NOTICE,"DETACH CDR %s (%p) == JUST DROP IT\n", cdr->channel, cdr);
return;
}
Modified: team/murf/cdr-debug-1.4/main/channel.c
URL: http://svn.digium.com/view/asterisk/team/murf/cdr-debug-1.4/main/channel.c?view=diff&rev=144133&r1=144132&r2=144133
==============================================================================
--- team/murf/cdr-debug-1.4/main/channel.c (original)
+++ team/murf/cdr-debug-1.4/main/channel.c Tue Sep 23 15:30:50 2008
@@ -856,7 +856,8 @@
strcpy(tmp->exten, "s");
tmp->priority = 1;
-
+
+ ast_log(LOG_NOTICE,"CDR for %s: alloc, init, start\n", tmp->name);
tmp->cdr = ast_cdr_alloc();
ast_cdr_init(tmp->cdr, tmp);
ast_cdr_start(tmp->cdr);
@@ -1522,9 +1523,18 @@
ast_cause2str(chan->hangupcause)
);
+ if (chan->cdr)
+ ast_log(LOG_WARNING,"Considering detaching/posting CDR for %s; BRIDGED=%d; DISABLED=%d; disposition=%ld, flags=%d\n",
+ chan->name,
+ ast_test_flag(chan->cdr, AST_CDR_FLAG_BRIDGED),
+ ast_test_flag(chan->cdr, AST_CDR_FLAG_POST_DISABLED),
+ chan->cdr->disposition,
+ chan->cdr->flags );
+
if (chan->cdr && !ast_test_flag(chan->cdr, AST_CDR_FLAG_BRIDGED) &&
!ast_test_flag(chan->cdr, AST_CDR_FLAG_POST_DISABLED) &&
(chan->cdr->disposition != AST_CDR_NULL || ast_test_flag(chan->cdr, AST_CDR_FLAG_DIALED))) {
+ ast_log(LOG_NOTICE,"CDR for %s: end, detach\n", chan->cdr->channel);
ast_cdr_end(chan->cdr);
ast_cdr_detach(chan->cdr);
@@ -1539,23 +1549,29 @@
int ast_answer(struct ast_channel *chan)
{
int res = 0;
+ ast_log(LOG_NOTICE,"chan state = %d\n", chan->_state);
ast_channel_lock(chan);
/* You can't answer an outbound call */
if (ast_test_flag(chan, AST_FLAG_OUTGOING)) {
+ ast_log(LOG_NOTICE,"will not set CDR answer, outgoing call on chan %s\n", chan->name);
ast_channel_unlock(chan);
return 0;
}
/* Stop if we're a zombie or need a soft hangup */
if (ast_test_flag(chan, AST_FLAG_ZOMBIE) || ast_check_hangup(chan)) {
+ ast_log(LOG_NOTICE,"will not set CDR answer, zombie call on chan %s\n", chan->name);
ast_channel_unlock(chan);
return -1;
}
+ ast_log(LOG_NOTICE,"chan state = %d\n", chan->_state);
+
switch(chan->_state) {
case AST_STATE_RINGING:
case AST_STATE_RING:
if (chan->tech->answer)
res = chan->tech->answer(chan);
ast_setstate(chan, AST_STATE_UP);
+ ast_log(LOG_NOTICE,"answer CDR %s (%p)\n", chan->cdr->channel, chan->cdr);
ast_cdr_answer(chan->cdr);
break;
case AST_STATE_UP:
@@ -2912,8 +2928,10 @@
ast_set_callerid(chan, oh->cid_num, oh->cid_name, oh->cid_num);
if (oh->parent_channel)
ast_channel_inherit_variables(oh->parent_channel, chan);
- if (oh->account)
+ if (oh->account) {
+ ast_log(LOG_NOTICE,"CDR setacct\n");
ast_cdr_setaccount(chan, oh->account);
+ }
}
ast_set_callerid(chan, cid_num, cid_name, cid_num);
@@ -2981,10 +2999,13 @@
if (res <= 0) {
if ( AST_CONTROL_RINGING == last_subclass )
chan->hangupcause = AST_CAUSE_NO_ANSWER;
- if (!chan->cdr && (chan->cdr = ast_cdr_alloc()))
+ if (!chan->cdr && (chan->cdr = ast_cdr_alloc())) {
+ ast_log(LOG_NOTICE,"init newly alloc'd CDR:\n");
ast_cdr_init(chan->cdr, chan);
+ }
if (chan->cdr) {
char tmp[256];
+ ast_log(LOG_NOTICE,"CDR: setapp, update, start, endi, maybe failed\n");
snprintf(tmp, sizeof(tmp), "%s/%s", type, (char *)data);
ast_cdr_setapp(chan->cdr,"Dial",tmp);
ast_cdr_update(chan);
Modified: team/murf/cdr-debug-1.4/main/pbx.c
URL: http://svn.digium.com/view/asterisk/team/murf/cdr-debug-1.4/main/pbx.c?view=diff&rev=144133&r1=144132&r2=144133
==============================================================================
--- team/murf/cdr-debug-1.4/main/pbx.c (original)
+++ team/murf/cdr-debug-1.4/main/pbx.c Tue Sep 23 15:30:50 2008
@@ -521,8 +521,10 @@
const char *saved_c_appl;
const char *saved_c_data;
- if (c->cdr && !ast_check_hangup(c))
+ if (c->cdr && !ast_check_hangup(c)) {
+ ast_log(LOG_NOTICE,"CDR setapp\n");
ast_cdr_setapp(c->cdr, app->name, data);
+ }
/* save channel values */
saved_c_appl= c->appl;
@@ -2430,8 +2432,10 @@
} else if (c->_softhangup == AST_SOFTHANGUP_TIMEOUT) {
/* atimeout, nothing bad */
} else {
- if (c->cdr)
+ if (c->cdr) {
+ ast_log(LOG_NOTICE,"CDR update\n");
ast_cdr_update(c);
+ }
error = 1;
break;
}
@@ -2531,6 +2535,7 @@
if (c->cdr) {
if (option_verbose > 2)
ast_verbose(VERBOSE_PREFIX_2 "CDR updated on %s\n",c->name);
+ ast_log(LOG_NOTICE,"CDR update\n");
ast_cdr_update(c);
}
}
@@ -2539,6 +2544,7 @@
ast_log(LOG_WARNING, "Don't know what to do with '%s'\n", c->name);
if (res != AST_PBX_KEEPALIVE)
ast_softhangup(c, c->hangupcause ? c->hangupcause : AST_CAUSE_NORMAL_CLEARING);
+ ast_log(LOG_NOTICE,"About to consider the H extension\n");
if ((res != AST_PBX_KEEPALIVE) && !ast_test_flag(c, AST_FLAG_BRIDGE_HANGUP_RUN) && ast_exists_extension(c, c->context, "h", 1, c->cid.cid_num)) {
set_ext_pri(c, "h", 1);
while(ast_exists_extension(c, c->context, c->exten, c->priority, c->cid.cid_num)) {
@@ -4600,6 +4606,7 @@
if (chan->cdr) {
ast_cdr_discard(tmpchan->cdr);
tmpchan->cdr = ast_cdr_dup(chan->cdr); /* share the love */
+ ast_log(LOG_NOTICE,"CDR discard (%p), dup chan %s's cdr (%p) to (%p) for chan %s before masquerade\n", tmpchan->cdr, chan->name, chan->cdr, tmpchan->cdr, tmpchan->name);
}
/* Make formats okay */
tmpchan->readformat = chan->readformat;
@@ -4973,6 +4980,8 @@
}
/* allocation of the cdr was successful */
+
+ ast_log(LOG_NOTICE,"CDR init, start, end, failed, detach\n");
ast_cdr_init(chan->cdr, chan); /* initilize our channel's cdr */
ast_cdr_start(chan->cdr); /* record the start and stop time */
ast_cdr_end(chan->cdr);
@@ -5036,8 +5045,10 @@
if (chan->cdr) { /* update the cdr */
/* here we update the status of the call, which sould be busy.
* if that fails then we set the status to failed */
- if (ast_cdr_disposition(chan->cdr, chan->hangupcause))
+ if (ast_cdr_disposition(chan->cdr, chan->hangupcause)) {
+ ast_log(LOG_NOTICE,"CDR fail\n");
ast_cdr_failed(chan->cdr);
+ }
}
if (channel) {
@@ -5071,8 +5082,10 @@
ast_set_variables(chan, vars);
snprintf(failed_reason, sizeof(failed_reason), "%d", *reason);
pbx_builtin_setvar_helper(chan, "REASON", failed_reason);
- if (account)
+ if (account){
+ ast_log(LOG_NOTICE,"CDR setacct\n");
ast_cdr_setaccount(chan, account);
+ }
if (ast_pbx_run(chan)) {
ast_log(LOG_ERROR, "Unable to run PBX on %s\n", chan->name);
ast_hangup(chan);
@@ -5102,8 +5115,10 @@
set_ext_pri(as->chan, exten, priority);
as->timeout = timeout;
ast_set_variables(chan, vars);
- if (account)
+ if (account) {
+ ast_log(LOG_NOTICE,"CDR setacct\n");
ast_cdr_setaccount(chan, account);
+ }
pthread_attr_init(&attr);
pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
if (ast_pthread_create(&as->p, &attr, async_wait, as)) {
@@ -5172,8 +5187,10 @@
chan = __ast_request_and_dial(type, format, data, timeout, reason, cid_num, cid_name, &oh);
if (chan) {
ast_set_variables(chan, vars);
- if (account)
+ if (account) {
+ ast_log(LOG_NOTICE,"CDR setacct\n");
ast_cdr_setaccount(chan, account);
+ }
if (chan->_state == AST_STATE_UP) {
res = 0;
if (option_verbose > 3)
@@ -5215,8 +5232,10 @@
if (chan->cdr) { /* update the cdr */
/* here we update the status of the call, which sould be busy.
* if that fails then we set the status to failed */
- if (ast_cdr_disposition(chan->cdr, chan->hangupcause))
+ if (ast_cdr_disposition(chan->cdr, chan->hangupcause)) {
+ ast_log(LOG_NOTICE,"CDR fail\n");
ast_cdr_failed(chan->cdr);
+ }
}
ast_hangup(chan);
}
@@ -5251,8 +5270,10 @@
ast_copy_string(as->appdata, appdata, sizeof(as->appdata));
as->timeout = timeout;
ast_set_variables(chan, vars);
- if (account)
+ if (account) {
+ ast_log(LOG_NOTICE,"CDR setacct\n");
ast_cdr_setaccount(chan, account);
+ }
/* Start a new thread, and get something handling this channel. */
pthread_attr_init(&attr);
pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
@@ -5453,6 +5474,7 @@
ast_app_parse_options(resetcdr_opts, &flags, NULL, args);
}
+ ast_log(LOG_NOTICE,"CDR reset\n");
ast_cdr_reset(chan->cdr, &flags);
return 0;
@@ -5464,6 +5486,7 @@
static int pbx_builtin_setamaflags(struct ast_channel *chan, void *data)
{
/* Copy the AMA Flags as specified */
+ ast_log(LOG_NOTICE,"CDR setamaflags\n");
ast_cdr_setamaflags(chan, data ? data : "");
return 0;
}
Modified: team/murf/cdr-debug-1.4/res/res_features.c
URL: http://svn.digium.com/view/asterisk/team/murf/cdr-debug-1.4/res/res_features.c?view=diff&rev=144133&r1=144132&r2=144133
==============================================================================
--- team/murf/cdr-debug-1.4/res/res_features.c (original)
+++ team/murf/cdr-debug-1.4/res/res_features.c Tue Sep 23 15:30:50 2008
@@ -766,11 +766,13 @@
if (!transferer->cdr) {
transferer->cdr=ast_cdr_alloc();
if (transferer) {
+ ast_log(LOG_NOTICE,"calling cdr_int, cdr_start\n");
ast_cdr_init(transferer->cdr, transferer); /* initilize our channel's cdr */
ast_cdr_start(transferer->cdr);
}
}
if (transferer->cdr) {
+ ast_log(LOG_NOTICE,"calling cdr_setdest, cdr_setapp\n");
ast_cdr_setdestchan(transferer->cdr, transferee->name);
ast_cdr_setapp(transferer->cdr, "BLINDTRANSFER","");
}
@@ -1419,6 +1421,20 @@
return chan;
}
+static void log_cdr(struct ast_cdr *cdr, char *label)
+{
+ int i=0;
+
+ while (cdr) {
+ ast_log(LOG_NOTICE,"%s [%d] (%p) = clid=%s; src=%s; dst=%s; dcontext=%s; chan=%s; dstchan=%s; lastapp=%s; lastdata=%s; start=%d; ans=%d; end=%d; dur=%ld; billsec=%ld; dispos=%ld; amaflags=%ld; acctcode=%s; flags=%x; uniq=%s; userf=%s;\n",
+ label, i++, cdr, cdr->clid,cdr->src,cdr->dst,cdr->dcontext,cdr->channel,
+ cdr->dstchannel,cdr->lastapp,cdr->lastdata,(int)cdr->start.tv_sec,(int)cdr->answer.tv_sec,
+ (int)cdr->end.tv_sec,cdr->duration,cdr->billsec,cdr->disposition,cdr->amaflags,
+ cdr->accountcode,cdr->flags,cdr->uniqueid,cdr->userfield);
+ cdr = cdr->next;
+ }
+}
+
static struct ast_cdr *pick_unlocked_cdr(struct ast_cdr *cdr)
{
struct ast_cdr *cdr_orig = cdr;
@@ -1429,7 +1445,6 @@
}
return cdr_orig; /* everybody LOCKED or some other weirdness, like a NULL */
}
-
int ast_bridge_call(struct ast_channel *chan,struct ast_channel *peer,struct ast_bridge_config *config)
{
@@ -1492,17 +1507,24 @@
ast_copy_string(orig_channame,chan->name,sizeof(orig_channame));
ast_copy_string(orig_peername,peer->name,sizeof(orig_peername));
orig_peer_cdr = peer_cdr;
+ ast_log(LOG_NOTICE,"Orig Chan (%p) name=%s\n", chan, orig_channame);
+ ast_log(LOG_NOTICE,"Orig Peer (%p) name=%s\n", peer, orig_peername);
+ log_cdr(chan_cdr, "Begin bridge CHAN CDR");
+ log_cdr(peer_cdr, "Begin bridge PEER CDR");
if (!chan_cdr || (chan_cdr && !ast_test_flag(chan_cdr, AST_CDR_FLAG_POST_DISABLED))) {
if (chan_cdr) {
ast_set_flag(chan_cdr, AST_CDR_FLAG_MAIN);
+ ast_log(LOG_NOTICE,"calling cdr_update, cdr_dup (for bridge cdr), setting bridge_cdr app, data\n");
ast_cdr_update(chan);
bridge_cdr = ast_cdr_dup(chan_cdr);
ast_copy_string(bridge_cdr->lastapp, chan->appl, sizeof(bridge_cdr->lastapp));
ast_copy_string(bridge_cdr->lastdata, chan->data, sizeof(bridge_cdr->lastdata));
+ ast_log(LOG_NOTICE,"PATH A\n");
} else {
/* better yet, in a xfer situation, find out why the chan cdr got zapped (pun unintentional) */
+ ast_log(LOG_NOTICE,"alloc new bridge cdr, set chan, dstchan, uniq, bridge_cdr app, data, cid, disp, ama, acctcode, dst, dcont\n");
bridge_cdr = ast_cdr_alloc(); /* this should be really, really rare/impossible? */
ast_copy_string(bridge_cdr->channel, chan->name, sizeof(bridge_cdr->channel));
ast_copy_string(bridge_cdr->dstchannel, peer->name, sizeof(bridge_cdr->dstchannel));
@@ -1518,9 +1540,13 @@
ast_copy_string(bridge_cdr->dcontext, chan->context, sizeof(bridge_cdr->dcontext));
if (peer_cdr) {
bridge_cdr->start = peer_cdr->start;
+ ast_log(LOG_NOTICE,"bridge cdr userfield, start set\n");
ast_copy_string(bridge_cdr->userfield, peer_cdr->userfield, sizeof(bridge_cdr->userfield));
+ ast_log(LOG_NOTICE,"PATH B\n");
} else {
+ ast_log(LOG_NOTICE,"bridge cdr start set\n");
ast_cdr_start(bridge_cdr);
+ ast_log(LOG_NOTICE,"PATH C\n");
}
}
/* peer_cdr->answer will be set when a macro runs on the peer;
@@ -1530,11 +1556,13 @@
this is billable time for the call, even tho the caller
hears nothing but ringing while the macro does its thing. */
if (peer_cdr && !ast_tvzero(peer_cdr->answer)) {
+ ast_log(LOG_NOTICE,"chan/bridge answer time set from peer answer time\n");
bridge_cdr->answer = peer_cdr->answer;
chan_cdr->answer = peer_cdr->answer;
bridge_cdr->disposition = peer_cdr->disposition;
chan_cdr->disposition = peer_cdr->disposition;
} else {
+ ast_log(LOG_NOTICE,"chan/bridge answer time being set.\n");
ast_cdr_answer(bridge_cdr);
ast_cdr_answer(chan_cdr); /* for the sake of cli status checks */
}
@@ -1548,6 +1576,7 @@
struct ast_channel *other; /* used later */
res = ast_channel_bridge(chan, peer, config, &f, &who);
+ ast_log(LOG_NOTICE,"ast_channel_bridge returns %d here\n", res);
if (config->feature_timer) {
/* Update time limit for next pass */
@@ -1617,6 +1646,7 @@
if (!f || (f->frametype == AST_FRAME_CONTROL &&
(f->subclass == AST_CONTROL_HANGUP || f->subclass == AST_CONTROL_BUSY ||
f->subclass == AST_CONTROL_CONGESTION ) ) ) {
+ ast_log(LOG_NOTICE,"res set to -1 here\n");
res = -1;
break;
}
@@ -1709,6 +1739,10 @@
}
before_you_go:
+ ast_log(LOG_NOTICE,"ChanNAME (%p)=%s\n", chan, chan->name);
+ ast_log(LOG_NOTICE,"PeerNAME (%p)=%s\n", peer, peer->name);
+ log_cdr(chan->cdr, "AFTER bridge CHAN CDR");
+ log_cdr(peer->cdr, "AFTER bridge PEER CDR");
new_chan_cdr = pick_unlocked_cdr(chan->cdr); /* the proper chan cdr, if there are forked cdrs */
new_peer_cdr = pick_unlocked_cdr(peer->cdr); /* the proper chan cdr, if there are forked cdrs */
@@ -1763,6 +1797,7 @@
if (!new_chan_cdr || (new_chan_cdr && !ast_test_flag(new_chan_cdr, AST_CDR_FLAG_POST_DISABLED))) {
struct ast_channel *chan_ptr = NULL;
+ ast_log(LOG_NOTICE,"bridge end, detach\n");
ast_cdr_end(bridge_cdr);
ast_cdr_detach(bridge_cdr);
@@ -2185,6 +2220,7 @@
ast_verbose(VERBOSE_PREFIX_3 "Channel %s connected to parked call %d\n", chan->name, park);
pbx_builtin_setvar_helper(chan, "PARKEDCHANNEL", peer->name);
+ ast_log(LOG_NOTICE,"setdestchan\n");
ast_cdr_setdestchan(chan->cdr, peer->name);
memset(&config, 0, sizeof(struct ast_bridge_config));
ast_set_flag(&(config.features_callee), AST_FEATURE_REDIRECT);
@@ -2192,6 +2228,7 @@
res = ast_bridge_call(chan, peer, &config);
pbx_builtin_setvar_helper(chan, "PARKEDCHANNEL", peer->name);
+ ast_log(LOG_NOTICE,"setdestchan\n");
ast_cdr_setdestchan(chan->cdr, peer->name);
/* Simulate the PBX hanging up */
More information about the asterisk-commits
mailing list