[asterisk-commits] murf: branch murf/bug11210 r93535 - in /team/murf/bug11210: channels/ main/
SVN commits to the Asterisk project
asterisk-commits at lists.digium.com
Mon Dec 17 23:50:16 CST 2007
Author: murf
Date: Mon Dec 17 23:50:15 2007
New Revision: 93535
URL: http://svn.digium.com/view/asterisk?view=rev&rev=93535
Log:
Good. the dialog callids change, hadn't known that. Now I do. Unlink and relink in the hash table under new name. Sip works better now.
Modified:
team/murf/bug11210/channels/chan_sip.c
team/murf/bug11210/main/sched.c
Modified: team/murf/bug11210/channels/chan_sip.c
URL: http://svn.digium.com/view/asterisk/team/murf/bug11210/channels/chan_sip.c?view=diff&rev=93535&r1=93534&r2=93535
==============================================================================
--- team/murf/bug11210/channels/chan_sip.c (original)
+++ team/murf/bug11210/channels/chan_sip.c Mon Dec 17 23:50:15 2007
@@ -1483,8 +1483,6 @@
{
struct sip_peer *peer = obj, *peer2 = arg;
- ast_log(LOG_NOTICE,"peer %s == peer %s ? %d\n", peer->name, peer2->name, !strcasecmp(peer->name, peer2->name) ? CMP_MATCH : 0);
-
return !strcasecmp(peer->name, peer2->name) ? CMP_MATCH : 0;
}
@@ -1542,7 +1540,6 @@
{
struct sip_user *user = obj, *user2 = arg;
- ast_log(LOG_NOTICE,"user %s == user %s ? %d\n", user->name, user2->name, !strcasecmp(user->name, user2->name) ? CMP_MATCH : 0);
return !strcasecmp(user->name, user2->name) ? CMP_MATCH : 0;
}
@@ -1562,7 +1559,8 @@
static int dialog_cmp_cb(void *obj, void *arg, int flags)
{
struct sip_pvt *pvt = obj, *pvt2 = arg;
- ast_log(LOG_NOTICE,"dialog %s == obj %s ? %d\n", pvt->callid, pvt2->callid, !strcasecmp(pvt->callid, pvt2->callid) ? CMP_MATCH : 0);
+ ast_log(LOG_NOTICE, "dialog_cmp_cb(%s,%s) ? %d\n", pvt->callid, pvt2->callid, !strcasecmp(pvt->callid, pvt2->callid) ? CMP_MATCH : 0);
+
return !strcasecmp(pvt->callid, pvt2->callid) ? CMP_MATCH : 0;
}
@@ -2109,12 +2107,14 @@
dialog->registry = registry_unref(dialog->registry, "delete dialog->registry");
}
if (dialog->initid > -1) {
+ ast_log(LOG_WARNING,"About to sched_del autocongest for dialog %s in dialog_unlink_all\n", dialog->callid);
if (ast_sched_del(sched, dialog->initid)==0)
dialog_unref(dialog,"when you delete the initid sched, you should dec the refcount for the stored dialog ptr");
dialog->initid = -1;
}
if (dialog->autokillid > -1) {
+ ast_log(LOG_WARNING,"About to sched_del autokill for dialog %s in dialog_unlink_all\n", dialog->callid);
if (ast_sched_del(sched, dialog->autokillid)==0)
dialog_unref(dialog,"when you delete the autokillid sched, you should dec the refcount for the stored dialog ptr");
dialog->autokillid = -1;
@@ -2483,7 +2483,8 @@
struct sip_pkt *pkt = (struct sip_pkt *)data, *prev, *cur = NULL;
int reschedule = DEFAULT_RETRANS;
int xmitres = 0;
-
+ ast_log(LOG_NOTICE,"SCHED: Retrans_pkt called---\n");
+
/* Lock channel PVT */
sip_pvt_lock(pkt->owner);
@@ -2637,6 +2638,7 @@
if (xmitres == XMIT_ERROR) { /* Serious network trouble, no need to try again */
append_history(pkt->owner, "XmitErr", "%s", pkt->is_fatal ? "(Critical)" : "(Non-critical)");
+ ast_log(LOG_WARNING,"About to sched_del pkt->retransid (%d) in __sip_reliable_xmit\n", pkt->retransid);
ast_sched_del(sched, pkt->retransid); /* No more retransmission */
pkt->retransid = -1;
return AST_FAILURE;
@@ -2653,6 +2655,7 @@
{
struct sip_pvt *p = (struct sip_pvt *)data;
+ ast_log(LOG_NOTICE,"SCHED: __sip_autodestruct called--- kill dialog\n");
/* 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 */
@@ -2674,7 +2677,7 @@
p->relatedpeer = unref_peer(p->relatedpeer,"__sip_autodestruct: unref peer p->relatedpeer"); /* Remove link to peer. If it's realtime, make sure it's gone from memory) */
/* Reset schedule ID */
- p->autokillid = -1;
+ p->autokillid = -1; /* HUH? Won't this cause problems? the event is still scheduled? */
if (p->owner) {
ast_log(LOG_WARNING, "Autodestruct on dialog '%s' with owner in place (Method: %s)\n", p->callid, sip_methods[p->method].text);
@@ -2713,6 +2716,7 @@
sip_cancel_destroy(p);
if (p->do_history)
append_history(p, "SchedDestroy", "%d ms", ms);
+ ast_log(LOG_WARNING,"About to sched_add sip_autodestruct for dialog %s in sip_scheddestroy\n", p->callid);
p->autokillid = ast_sched_add(sched, ms, __sip_autodestruct, dialog_ref(p,"sip_scheddestroy: setting ref as passing into ast_sched_add"));
}
@@ -2723,7 +2727,9 @@
static void sip_cancel_destroy(struct sip_pvt *p)
{
if (p->autokillid > -1) {
- int res3 = ast_sched_del(sched, p->autokillid);
+ int res3;
+ ast_log(LOG_WARNING,"About to sched_del autokillid(%d) for dialog %s in sip_cancel_destroy\n", p->autokillid, p->callid);
+ res3 = ast_sched_del(sched, p->autokillid);
append_history(p, "CancelDestroy", "");
p->autokillid = -1;
if (res3 == 0)
@@ -2759,6 +2765,7 @@
if (cur->retransid > -1) {
if (sipdebug)
ast_debug(4, "** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #%d\n", cur->retransid);
+ ast_log(LOG_WARNING,"About to sched_del retransid=%d in __sip_ack\n", cur->retransid);
ast_sched_del(sched, cur->retransid);
cur->retransid = -1;
}
@@ -2804,6 +2811,7 @@
if (cur->retransid > -1) {
if (sipdebug)
ast_debug(4, "*** SIP TIMER: Cancelling retransmission #%d - %s (got response)\n", cur->retransid, sip_methods[sipmethod].text);
+ ast_log(LOG_WARNING,"About to sched_del retransid=%d in __sip_semi_ack\n", cur->retransid);
ast_sched_del(sched, cur->retransid);
cur->retransid = -1;
}
@@ -3216,9 +3224,11 @@
ast_variables_destroy(peer->chanvars);
peer->chanvars = NULL;
}
- if (peer->expire > -1)
+ if (peer->expire > -1) {
+ ast_log(LOG_WARNING,"About to sched_del peer->expire = %d in __sip_destroy_peer\n", peer->expire);
ast_sched_del(sched, peer->expire);
-
+ }
+
if (peer->pokeexpire > -1)
ast_sched_del(sched, peer->pokeexpire);
register_peer_exten(peer, FALSE);
@@ -3414,6 +3424,7 @@
/* Cache peer */
ast_copy_flags(&peer->flags[1],&global_flags[1], SIP_PAGE2_RTAUTOCLEAR|SIP_PAGE2_RTCACHEFRIENDS);
if (ast_test_flag(&global_flags[1], SIP_PAGE2_RTAUTOCLEAR)) {
+ ast_log(LOG_WARNING,"About to sched_replace peer->expire = %d in realtime_peer\n", peer->expire);
peer->expire = ast_sched_replace(peer->expire, sched,
global_rtautoclear * 1000, expire_register, (void *) peer);
}
@@ -3686,11 +3697,14 @@
if (!dialog->initreq.headers) {
char *c;
char *tmpcall = ast_strdupa(dialog->callid);
-
+ /* this sure looks to me like we are going to change the callid on this dialog!! */
c = strchr(tmpcall, '@');
if (c) {
*c = '\0';
+ ao2_unlink(dialogs,dialog,"About to change the callid -- remove the old name");
ast_string_field_build(dialog, callid, "%s@%s", tmpcall, peer->fromdomain);
+ ao2_link(dialogs,dialog,"New dialog callid -- inserted back into table");
+ ast_log(LOG_NOTICE,"============================================================Changed Dialog name to %s\n", dialog->callid);
}
}
}
@@ -3798,6 +3812,7 @@
{
struct sip_pvt *p = (struct sip_pvt *)arg;
+ ast_log(LOG_NOTICE,"SCHED: auto_congest called for dialog %s---\n", p->callid);
sip_pvt_lock(p);
p->initid = -1; /* event gone, will not be rescheduled */
if (p->owner) {
@@ -3897,6 +3912,7 @@
p->invitestate = INV_CALLING;
/* Initialize auto-congest time */
+ ast_log(LOG_WARNING,"About to sched_replace autocongest for dialog %s in sip_call\n", p->callid);
p->initid = ast_sched_replace(p->initid, sched, p->timer_b,
auto_congest, dialog_ref(p,"this is a pointer for the autocongest callback to use"));
}
@@ -3922,10 +3938,16 @@
reg->call = dialog_unref(reg->call,"unref reg->call");
/* reg->call = sip_destroy(reg->call); */
}
- if (reg->expire > -1)
+ if (reg->expire > -1) {
+ ast_log(LOG_WARNING,"About to sched_del reg->expire in sip_registry_destroy\n");
ast_sched_del(sched, reg->expire);
- if (reg->timeout > -1)
+ }
+
+ if (reg->timeout > -1) {
+ ast_log(LOG_WARNING,"About to sched_del reg->timeout in sip_registry_destroy\n");
ast_sched_del(sched, reg->timeout);
+ }
+
ast_string_field_free_memory(reg);
regobjs--;
ast_free(reg);
@@ -3966,15 +3988,21 @@
if (p->stateid > -1)
ast_extension_state_del(p->stateid, NULL);
if (p->waitid > -1)
+ {
+ ast_log(LOG_WARNING,"About to sched_del waitid(%d) for dialog %s in __sip_destroy\n", p->waitid, p->callid);
ast_sched_del(sched, p->waitid);
+ }
+
if (p->initid > -1) {
/* Don't auto congest anymore since we've gotten something useful back */
+ ast_log(LOG_WARNING,"About to sched_del p->initid for dialog %s in __sip_destroy\n", p->callid);
if (ast_sched_del(sched, p->initid) == 0)
dialog_unref(p,"when you delete the initid sched, you should dec the refcount for the stored dialog ptr");
p->initid = -1;
}
if (p->autokillid > -1) {
+ ast_log(LOG_WARNING,"About to sched_del autokillid(%d) for dialog %s in __sip_destroy\n", p->autokillid, p->callid);
if (ast_sched_del(sched, p->autokillid)==0)
dialog_unref(p,"when you delete the autokillid sched, you should dec the refcount for the stored dialog ptr");
p->autokillid = -1;
@@ -4009,8 +4037,11 @@
/* remove all current packets in this dialog */
while((cp = p->packets)) {
p->packets = p->packets->next;
- if (cp->retransid > -1)
+ if (cp->retransid > -1) {
+ ast_log(LOG_WARNING,"About to sched_del retransid(%d) in __sip_destroy\n", cp->retransid);
ast_sched_del(sched, cp->retransid); /* HUH??? */
+ }
+
cp->owner = dialog_unref(cp->owner,"free cp->owner dialog before freeing the pkt");
ast_free(cp);
}
@@ -4435,6 +4466,7 @@
if ( p->initid != -1 ) {
/* channel still up - reverse dec of inUse counter
only if the channel is not auto-congested */
+ ast_log(LOG_WARNING,"About to update_call_counter autocongest for dialog %s in sip_hangup\n", p->callid);
update_call_counter(p, INC_CALL_LIMIT);
}
} else { /* Incoming call, not up */
@@ -4479,8 +4511,11 @@
but we can't send one while we have "INVITE" outstanding. */
ast_set_flag(&p->flags[0], SIP_PENDINGBYE);
ast_clear_flag(&p->flags[0], SIP_NEEDREINVITE);
- if (p->waitid)
+ if (p->waitid) {
+ ast_log(LOG_WARNING,"About to sched_del waitid(%d) for dialog %s in sip_hangup\n", p->waitid, p->callid);
ast_sched_del(sched, p->waitid);
+ }
+
p->waitid = -1;
sip_cancel_destroy(p);
}
@@ -5311,7 +5346,6 @@
{
struct sip_pvt *p;
struct sip_pvt *p2;
- int rc;
ast_log(LOG_NOTICE,"allocating PVT for %s\n", callid);
if (!(p = ao2_alloc(sizeof(*p), sip_destroy_fn, "allocate a dialog(pvt) struct")))
@@ -5445,9 +5479,9 @@
}
ao2_link(dialogs, p, "link pvt into dialogs table");
- rc = ao2_ref(p, 0,"");
+ ast_log(LOG_NOTICE,"***Just linked %s into dialogs table\n", p->callid);
- ast_debug(1, "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_debug(1, "Allocating new SIP dialog for %s - %s (%s)\n", callid ? callid : p->callid, sip_methods[intended_method].text, p->rtp ? "With RTP" : "No RTP");
return p;
}
@@ -5512,10 +5546,12 @@
ast_log(LOG_NOTICE,"Found CALL dialog %s, refcount = %d\n", tmp_dialog.callid, rc);
if (!(!pedanticsipchecking || !tag || ast_strlen_zero(sip_pvt_ptr->theirtag) || !strcmp(sip_pvt_ptr->theirtag, tag)))
{
+ ast_log(LOG_NOTICE,"Pedantic Zero of dialog %s (1)\n", callid);
+
ao2_ref(sip_pvt_ptr,-1,"pedantic failure, pointer erase"); /* basically, if the extra pedanticssipchecking constraints don't pan out,
the the match is defeated. There should be no other entry that matches
the callid */
- sip_pvt_ptr = 0;
+ sip_pvt_ptr = NULL;
}
/* If we get a new request within an existing to-tag - check the to tag as well */
if (pedanticsipchecking && sip_pvt_ptr && req->method != SIP_RESPONSE) { /* SIP Request */
@@ -5523,10 +5559,12 @@
/* We have no to tag, but they have. Wrong dialog */
ao2_ref(sip_pvt_ptr,-1,"pedantic failure, pointer erased 2");
sip_pvt_ptr = NULL;
+ ast_log(LOG_NOTICE,"Pedantic Zero of dialog %s (2)\n", callid);
} else if (totag[0]) { /* Both have tags, compare them */
if (strcmp(totag, sip_pvt_ptr->tag)) {
ao2_ref(sip_pvt_ptr,-1, "pedantic totag failure, pointer erased 3");
sip_pvt_ptr = NULL; /* This is not our packet */
+ ast_log(LOG_NOTICE,"Pedantic Zero of dialog %s (3)\n", callid);
}
}
if (!sip_pvt_ptr)
@@ -5535,6 +5573,19 @@
}
ast_string_field_free_memory(&tmp_dialog);
+ if (!sip_pvt_ptr) {
+ struct ao2_iterator i;
+ struct sip_pvt *d2;
+
+ ast_log(LOG_NOTICE,"Dialog %s not found\n", callid);
+ i = ao2_iterator_init(dialogs, 0);
+
+ while ((d2 = ao2_iterator_next(&i,"iterate thru dialogs "))) {
+ ast_log(LOG_NOTICE, "Dialogs: %s\n", d2->callid);
+ ao2_ref(d2,-1,"done with d2 pointer");
+ }
+ }
+
if (sip_pvt_ptr) {
/* Found the call */
sip_pvt_lock(sip_pvt_ptr);
@@ -5556,9 +5607,6 @@
} else {
/* Ok, time to create a new SIP dialog object, a pvt */
if ((p = sip_alloc(callid, sin, 1, intended_method))) {
- int rc = ao2_ref(p,0,"");
- ast_log(LOG_NOTICE,"Couldn't find call %s, so CREATED dialog, refcount = %d\n",
- callid, rc);
/* Ok, we've created a dialog, let's go and process it */
sip_pvt_lock(p);
} else {
@@ -8503,6 +8551,7 @@
/* if we are here, we know that we need to reregister. */
struct sip_registry *r= registry_addref((struct sip_registry *) data,"reg_addref from sip_reregister");
+ ast_log(LOG_NOTICE,"SCHED: sip_reregister called---\n");
/* if we couldn't get a reference to the registry object, punt */
if (!r)
return 0;
@@ -8543,6 +8592,7 @@
struct sip_pvt *p;
int res;
+ ast_log(LOG_NOTICE,"SCHED: sip_reg_timeout called---\n");
/* if we couldn't get a reference to the registry object, punt */
if (!r)
return 0;
@@ -8636,11 +8686,13 @@
dialog_unref(p, "unref dialog after unlink_all");
/* sip_destroy(p); */
if (r->timeout > -1) {
+ ast_log(LOG_WARNING,"About to sched_replace reg timeout(%d) for reg in transmit_register\n", r->timeout);
r->timeout = ast_sched_replace(r->timeout, sched,
global_reg_timeout * 1000, sip_reg_timeout, r);
ast_log(LOG_WARNING, "Still have a registration timeout for %s@%s (create_addr() error), %d\n", r->username, r->hostname, r->timeout);
} else {
r->timeout = ast_sched_add(sched, global_reg_timeout*1000, sip_reg_timeout, r);
+ ast_log(LOG_WARNING,"Just did sched_add reg timeout(%d) for reg in transmit_register\n", r->timeout);
ast_log(LOG_WARNING, "Probably a DNS error for registration to %s@%s, trying REGISTER again (after %d seconds)\n", r->username, r->hostname, global_reg_timeout);
}
r->regattempts++;
@@ -8689,6 +8741,7 @@
if (auth == NULL) {
if (r->timeout > -1)
ast_log(LOG_WARNING, "Still have a registration timeout, #%d - deleting it\n", r->timeout);
+ ast_log(LOG_WARNING,"About to sched_replace reg timeout(%d) for reg in transmit_register\n", r->timeout);
r->timeout = ast_sched_replace(r->timeout, sched, global_reg_timeout * 1000, sip_reg_timeout, r);
ast_debug(1, "Scheduled a registration timeout for %s id #%d \n", r->hostname, r->timeout);
}
@@ -8995,6 +9048,7 @@
{
struct sip_peer *peer = (struct sip_peer *)data;
+ ast_log(LOG_NOTICE,"SCHED: expire_register called---\n");
if (!peer) /* Hmmm. We have no peer. Weird. */
return 0;
@@ -9032,6 +9086,7 @@
{
struct sip_peer *peer = (struct sip_peer *)data;
+ ast_log(LOG_NOTICE,"SCHED: sip_poke_peer_s called---\n");
peer->pokeexpire = -1;
sip_poke_peer(peer);
return 0;
@@ -9085,10 +9140,12 @@
peer->addr.sin_port = htons(port);
if (sipsock < 0) {
/* SIP isn't up yet, so schedule a poke only, pretty soon */
+ ast_log(LOG_WARNING,"About to sched_replace peer pokeexpire(%d) for peer in reg_source_db\n", peer->pokeexpire);
peer->pokeexpire = ast_sched_replace(peer->pokeexpire, sched,
ast_random() % 5000 + 1, sip_poke_peer_s, peer);
} else
sip_poke_peer(peer);
+ ast_log(LOG_WARNING,"About to sched_replace peer expire(%d) for peer in reg_source_db\n", peer->expire);
peer->expire = ast_sched_replace(peer->expire, sched,
(expiry + 10) * 1000, expire_register, peer);
register_peer_exten(peer, TRUE);
@@ -9203,8 +9260,11 @@
} else if (!strcasecmp(curi, "*") || !expiry) { /* Unregister this peer */
/* This means remove all registrations and return OK */
memset(&peer->addr, 0, sizeof(peer->addr));
- if (peer->expire > -1)
+ if (peer->expire > -1) {
+ ast_log(LOG_WARNING,"About to sched_del peer expire(%d) for peer in parse_register_result\n", peer->expire);
ast_sched_del(sched, peer->expire);
+ }
+
peer->expire = -1;
destroy_association(peer);
@@ -9254,6 +9314,7 @@
ast_copy_string(peer->username, curi, sizeof(peer->username));
if (peer->expire > -1) {
+ ast_log(LOG_WARNING,"About to sched_del peer expire(%d) for peer in parse_register_result\n", peer->expire);
ast_sched_del(sched, peer->expire);
peer->expire = -1;
}
@@ -9263,6 +9324,7 @@
expiry = min_expiry;
peer->expire = peer->is_realtime ? -1 :
ast_sched_add(sched, (expiry + 10) * 1000, expire_register, peer);
+ ast_log(LOG_WARNING,"Just did sched_add peer expire(%d) for peer in parse_register_result\n", peer->expire);
pvt->expiry = expiry;
snprintf(data, sizeof(data), "%s:%d:%d:%s:%s", ast_inet_ntoa(peer->addr.sin_addr), ntohs(peer->addr.sin_port), expiry, peer->username, peer->fullcontact);
if (!peer->rt_fromcontact)
@@ -13219,7 +13281,11 @@
/* Recalculate our side, and recalculate Call ID */
ast_sip_ouraddrfor(&p->sa.sin_addr, &p->ourip);
build_via(p);
+ ast_log(LOG_NOTICE,"====================================About to build callid for %s\n", p->callid);
+ ao2_unlink(dialogs,p,"About to change the callid -- remove the old name");
build_callid_pvt(p);
+ ao2_link(dialogs,p,"Linking in new name");
+ ast_log(LOG_NOTICE,"====================================New callid: %s\n", p->callid);
ast_cli(a->fd, "Sending NOTIFY of type '%s' to '%s'\n", a->argv[2], a->argv[i]);
dialog_ref(p,"bump the count of p, which transmit_sip_request will decrement.");
transmit_sip_request(p, &req);
@@ -13821,6 +13887,7 @@
{
struct sip_pvt *p = (struct sip_pvt *) data;
+ ast_log(LOG_NOTICE,"SCHED: sip_reinvite_retry called---\n");
ast_set_flag(&p->flags[0], SIP_NEEDREINVITE);
p->waitid = -1;
return 0;
@@ -13849,6 +13916,7 @@
/* Acknowledge sequence number - This only happens on INVITE from SIP-call */
if (p->initid > -1) {
/* Don't auto congest anymore since we've gotten something useful back */
+ ast_log(LOG_WARNING,"About to sched_del initd (autocongest) for dialog %s in handle_response_invite\n", p->callid);
if (ast_sched_del(sched, p->initid) == 0)
dialog_unref(p,"when you delete the initid sched, you should dec the refcount for the stored dialog ptr");
p->initid = -1;
@@ -14129,6 +14197,7 @@
*/
int wait = 3 + ast_random() % 5;
p->waitid = ast_sched_add(sched, wait, sip_reinvite_retry, p);
+ ast_log(LOG_WARNING,"just did sched_add waitid(%d) for sip_reinvite_retry for dialog %s in handle_response_invite\n", p->waitid, p->callid);
ast_debug(2, "Reinvite race. Waiting %d secs before retry\n", wait);
}
}
@@ -14219,6 +14288,7 @@
break;
case 403: /* Forbidden */
ast_log(LOG_WARNING, "Forbidden - wrong password on authentication for REGISTER for '%s' to '%s'\n", p->registry->username, p->registry->hostname);
+ ast_log(LOG_WARNING,"About to sched_del registry timeout(%d) for reg in handle_response_register state 403\n", r->timeout);
ast_sched_del(sched, r->timeout);
r->timeout = -1;
r->regstate = REG_STATE_NOAUTH;
@@ -14230,6 +14300,7 @@
if (r->call)
r->call = dialog_unref(r->call,"unsetting registry->call pointer-- case 404");
r->regstate = REG_STATE_REJECTED;
+ ast_log(LOG_WARNING,"About to sched_del registry timeout(%d) for reg in handle_response_register state 404\n", r->timeout);
ast_sched_del(sched, r->timeout);
r->timeout = -1;
break;
@@ -14245,12 +14316,14 @@
p->needdestroy = 1;
if (r->call)
r->call = dialog_unref(r->call,"unsetting registry->call pointer-- case 408");
+ ast_log(LOG_WARNING,"About to sched_del registry timeout(%d) for reg in handle_response_register state 408\n", r->timeout);
ast_sched_del(sched, r->timeout);
r->timeout = -1;
break;
case 423: /* Interval too brief */
r->expiry = atoi(get_header(req, "Min-Expires"));
ast_log(LOG_WARNING, "Got 423 Interval too brief for service %s@%s, minimum is %d seconds\n", p->registry->username, p->registry->hostname, r->expiry);
+ ast_log(LOG_WARNING,"About to sched_del registry timeout(%d) for reg in handle_response_register state 423\n", r->timeout);
ast_sched_del(sched, r->timeout);
r->timeout = -1;
if (r->call) {
@@ -14273,6 +14346,7 @@
if (r->call)
r->call = dialog_unref(r->call,"unsetting registry->call pointer-- case 479");
r->regstate = REG_STATE_REJECTED;
+ ast_log(LOG_WARNING,"About to sched_del registry timeout(%d) for reg in handle_response_register state 479\n", r->timeout);
ast_sched_del(sched, r->timeout);
r->timeout = -1;
break;
@@ -14290,6 +14364,7 @@
ast_debug(1, "Registration successful\n");
if (r->timeout > -1) {
ast_debug(1, "Cancelling timeout %d\n", r->timeout);
+ ast_log(LOG_WARNING,"About to sched_del registry timeout(%d) for reg in handle_response_register state 200\n", r->timeout);
ast_sched_del(sched, r->timeout);
}
r->timeout=-1;
@@ -14302,8 +14377,11 @@
/* set us up for re-registering */
/* figure out how long we got registered for */
- if (r->expire > -1)
+ if (r->expire > -1){
+ ast_log(LOG_WARNING,"About to sched_del registry expire(%d) for reg in handle_response_register state 200\n", r->expire);
ast_sched_del(sched, r->expire);
+ }
+
/* according to section 6.13 of RFC, contact headers override
expires headers, so check those first */
expires = 0;
@@ -14347,6 +14425,7 @@
r->refresh= (int) expires_ms / 1000;
/* Schedule re-registration before we expire */
+ ast_log(LOG_WARNING,"About to sched_replace registry expire(%d) for reg in handle_response_register near end\n", r->expire);
r->expire = ast_sched_replace(r->expire, sched, expires_ms, sip_reregister, r);
registry_unref(r,"unref registry ptr r"); /* HUH? if this gets deleted, p->registry will be a bad pointer! */
/* shouldn't this be:
@@ -14399,6 +14478,7 @@
p->needdestroy = 1;
/* Try again eventually */
+ ast_log(LOG_WARNING,"About to sched_replace peer pokeexpire(%d) for peer in handle_response_peerpoke\n", peer->pokeexpire);
peer->pokeexpire = ast_sched_replace(peer->pokeexpire, sched,
is_reachable ? DEFAULT_FREQ_OK : DEFAULT_FREQ_NOTOK,
sip_poke_peer_s, peer);
@@ -17357,8 +17437,12 @@
}
/* Recalculate our side, and recalculate Call ID */
ast_sip_ouraddrfor(&p->sa.sin_addr, &p->ourip);
+ ast_log(LOG_NOTICE,"====================================About to build callid for %s\n", p->callid);
build_via(p);
+ ao2_unlink(dialogs,p,"About to change the callid -- remove the old name");
build_callid_pvt(p);
+ ao2_link(dialogs,p,"Linking in under new name");
+ ast_log(LOG_NOTICE,"====================================New callid: %s\n", p->callid);
/* Destroy this session after 32 secs */
sip_scheddestroy(p, DEFAULT_TRANS_TIMEOUT);
}
@@ -17535,6 +17619,7 @@
{
struct sip_peer *peer = (struct sip_peer *)data;
+ ast_log(LOG_NOTICE,"SCHED: sip_poke_noanswer called---\n");
peer->pokeexpire = -1;
if (peer->lastms > -1) {
ast_log(LOG_NOTICE, "Peer '%s' is now UNREACHABLE! Last qualify: %d\n", peer->name, peer->lastms);
@@ -17552,6 +17637,7 @@
peer->lastms = -1;
ast_device_state_changed("SIP/%s", peer->name);
/* Try again quickly */
+ ast_log(LOG_WARNING,"About to sched_replace peer pokeexpire(%d) for peer in sip_poke_noanswer\n", peer->pokeexpire);
peer->pokeexpire = ast_sched_replace(peer->pokeexpire, sched,
DEFAULT_FREQ_NOTOK, sip_poke_peer_s, peer);
return 0;
@@ -17568,8 +17654,11 @@
if (!peer->maxms || !peer->addr.sin_addr.s_addr) {
/* IF we have no IP, or this isn't to be monitored, return
imeediately after clearing things out */
- if (peer->pokeexpire > -1)
+ if (peer->pokeexpire > -1) {
+ ast_log(LOG_WARNING,"About to sched_del peer pokeexpire(%d) for peer in sip_poke_peer\n", peer->pokeexpire);
ast_sched_del(sched, peer->pokeexpire);
+ }
+
peer->lastms = 0;
peer->pokeexpire = -1;
peer->call = NULL;
@@ -17602,12 +17691,19 @@
ast_string_field_set(p, tohost, ast_inet_ntoa(peer->addr.sin_addr));
/* Recalculate our side, and recalculate Call ID */
+ ast_log(LOG_NOTICE,"====================================About to build callid for %s\n", p->callid);
ast_sip_ouraddrfor(&p->sa.sin_addr, &p->ourip);
build_via(p);
+ ao2_unlink(dialogs,p,"About to change the callid -- remove the old name");
build_callid_pvt(p);
-
- if (peer->pokeexpire > -1)
+ ao2_link(dialogs,p,"Linking in under new name");
+ ast_log(LOG_NOTICE,"====================================New callid: %s\n", p->callid);
+
+ if (peer->pokeexpire > -1) {
+ ast_log(LOG_WARNING,"About to sched_del peer pokeexpire(%d) for peer in sip_poke_peer\n", peer->pokeexpire);
ast_sched_del(sched, peer->pokeexpire);
+ }
+
p->relatedpeer = ref_peer(peer,"setting the relatedpeer field in the dialog");
ast_set_flag(&p->flags[0], SIP_OUTGOING);
#ifdef VOCAL_DATA_HACK
@@ -17620,6 +17716,7 @@
if (xmitres == XMIT_ERROR)
sip_poke_noanswer(peer); /* Immediately unreachable, network problems */
else {
+ ast_log(LOG_WARNING,"About to sched_replace peer pokeexpire(%d) for peer in sip_poke_peer near end\n", peer->pokeexpire);
peer->pokeexpire = ast_sched_replace(peer->pokeexpire, sched,
peer->maxms * 2, sip_poke_noanswer, peer);
}
@@ -17798,9 +17895,13 @@
if (ast_strlen_zero(p->peername) && ext)
ast_string_field_set(p, peername, ext);
/* Recalculate our side, and recalculate Call ID */
+ ast_log(LOG_NOTICE,"====================================About to build callid for %s\n", p->callid);
ast_sip_ouraddrfor(&p->sa.sin_addr, &p->ourip);
build_via(p);
+ ao2_unlink(dialogs,p,"About to change the callid -- remove the old name");
build_callid_pvt(p);
+ ao2_link(dialogs,p,"Linking in under new name");
+ ast_log(LOG_NOTICE,"====================================New callid: %s\n", p->callid);
/* We have an extension to call, don't use the full contact here */
/* This to enable dialing registered peers with extension dialling,
@@ -18484,7 +18585,11 @@
} else {
/* Non-dynamic. Make sure we become that way if we're not */
if (peer->expire > -1)
+ {
+ ast_log(LOG_WARNING,"About to sched_del peer expire(%d) for peer in build_peer near end\n", peer->expire);
ast_sched_del(sched, peer->expire);
+ }
+
peer->expire = -1;
peer->host_dynamic = FALSE;
if (ast_get_ip_or_srv(&peer->addr, v->value, global_srvlookup ? "_sip._udp" : NULL)) {
@@ -19796,6 +19901,7 @@
while ((peer = ao2_iterator_next(&i, "iterate thru peers table"))) {
ms += 100;
+ ast_log(LOG_WARNING,"About to sched_replace peer pokeexpire(%d) for peer in sip_poke_all_peers\n", peer->pokeexpire);
peer->pokeexpire = ast_sched_replace(peer->pokeexpire,
sched, ms, sip_poke_peer_s, peer);
unref_peer(peer,"toss iterator peer ptr");
@@ -19816,6 +19922,7 @@
ASTOBJ_CONTAINER_TRAVERSE(®l, 1, do {
ASTOBJ_WRLOCK(iterator); /* was WRLOCK */
ms += regspacing;
+ ast_log(LOG_WARNING,"About to sched_replace reg expire(%d) for reg in sip_send_all_registers\n", iterator->expire);
iterator->expire = ast_sched_replace(iterator->expire,
sched, ms, sip_reregister, iterator);
ASTOBJ_UNLOCK(iterator);
Modified: team/murf/bug11210/main/sched.c
URL: http://svn.digium.com/view/asterisk/team/murf/bug11210/main/sched.c?view=diff&rev=93535&r1=93534&r2=93535
==============================================================================
--- team/murf/bug11210/main/sched.c (original)
+++ team/murf/bug11210/main/sched.c Mon Dec 17 23:50:15 2007
@@ -236,6 +236,7 @@
res = tmp->id;
}
}
+ ast_log(LOG_ERROR,"SCHED: add schedule entry in %d! ID=%d\n", when, res);
#ifdef DUMP_SCHEDULER
/* Dump contents of the context while we have the lock so nothing gets screwed up by accident. */
if (option_debug)
@@ -268,6 +269,7 @@
struct sched *s;
DEBUG(ast_debug(1, "ast_sched_del()\n"));
+ ast_log(LOG_ERROR,"SCHED: delete schedule entry %d!\n", id);
ast_mutex_lock(&con->lock);
AST_LIST_TRAVERSE_SAFE_BEGIN(&con->schedq, s, list) {
@@ -292,6 +294,7 @@
#ifdef DO_CRASH
CRASH;
#endif
+ ast_log(LOG_ERROR,"Attempted to delete nonexistent schedule entry %d!\n", id);
return -1;
}
More information about the asterisk-commits
mailing list