[asterisk-dev] (SOLUTION) CDR edge-case causes different results in 1.6.2

[Steve Davies]

On 16 April 2010 19:06, Steve Davies <davies147 at gmail.com> wrote:
> Hi,
>
> I hope this is not out of dev-list scope. I am posting here because
> I've been deep into the code to discover this and assume it qualifies.
> I posted on the users list yesterday regarding this but have now done
> much more investigating/debugging.
>
> Basically I have a case where chan_local optimise/masq itself away
> before we are finished with its channel data, and another "equivalent"
> case where it does not, and I am looking for hints on how to solve it:
>
> Case 1)
>    SIP/100 causes a Dial(Local/1234 at default), which calls out via DAHDI.
> This correctly creates 2 CDR records for the 2 legs. These CDR records
> correctly indicate the Local/ channel indirection, for example:
>    Leg 1, channel = SIP/100                  dest-channel = Local/1234 at default;1
>    Leg 2, channel = Local/1234 at default;2     dest-channel = DAHDI/1-1
>
> Case 2)
> SIP/100 calls SIP/101 which sends a call_forward indication to 1234.
> app_dial takes this to mean that it should replace the outbound call
> object for SIP/101 with Local/1234 at default. At this point, I think we
> are back where we started in Case 1, but the CDR records are
> different:
>    Leg 1, channel = SIP/100                  dest-channel = DAHDI/1-1
>    Leg 2, channel = Local/1234 at default;2     dest-channel = DAHDI/1-1
>
> The reason for the difference seems to be down to when chan_local is
> allowed to optimise/masq itself out of the chain.
>
> In case 1, it seems that there is something in the chan_local owner's
> readq for long enough that call-leg 1 receives its 'answered' signal,
> and its CDR data is updated from chan_local before it vanishes.
>
> In case 2, there is no frame in the readq, so the optimisation of the
> chan_local can happen immediately that leg 2 is answered, not waiting
> for leg 1 to be answered. When leg 1 is answered, immediately after
> the chan_local is masq'ed away, the dest channel data has been lost,
> and the CDR is updated with the wrong data.
>
> Can someone recommend a way to sensibly delay the optimising out of
> chan_local in the second scenario to allow the answer indication to
> the first leg of the call to complete?
>

Found it! It took me 2 elapsed days, and it is really small and silly :)

In chan_local:local_queue_frame(), there is a test to see whether
there is a channel or app to forward data to before frames are passed
on:

                if (other->pbx || other->_bridge ||
!ast_strlen_zero(other->appl)) {
                        ast_queue_frame(other, f);
                }

For a call that is being dialled, there is no pbx or bridge object, so
chan_local will only forward data if 'appl' is correctly set.

In app_dial:do_forward(), the original channel is replaced with a new
"forward" channel, but 'appl' is never set on this channel - The
effectively kills frame passing on the new Local/ channel created by
do_forward, and it stays that way until it is optimized away.

The fix is below - I will allow an "expert" to determine if there is a
better solution.

--- asterisk-1.6.2.5.orig/apps/app_dial.c       2010-04-19
14:03:35.000000000 +0100
+++ asterisk-1.6.2.5/apps/app_dial.c    2010-04-19 14:04:14.000000000 +0100
@@ -783,6 +783,8 @@
                        S_REPLACE(c->cid.cid_ani, ast_strdup(in->cid.cid_ani));
                }
                S_REPLACE(c->cid.cid_rdnis,
ast_strdup(S_OR(in->macroexten, in->exten)));
+               c->appl = "AppDial";
+               c->data = "(Outgoing Line)";
                if (ast_call(c, tmpchan, 0)) {
                        ast_log(LOG_NOTICE, "Failed to dial on local
channel for call forward to '%s'\n", tmpchan);
                        ast_clear_flag64(o, DIAL_STILLGOING);


Regards,
Steve