[asterisk-bugs] [JIRA] (ASTERISK-19853) CDR(custom_field) field set in a DYNAMIC_FEATURE is reverted to the previous value when the call is terminated.

Matt Jordan (JIRA) noreply at issues.asterisk.org
Tue Nov 5 17:16:03 CST 2013


    [ https://issues.asterisk.org/jira/browse/ASTERISK-19853?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=211541#comment-211541 ] 

Matt Jordan commented on ASTERISK-19853:
----------------------------------------

So, there's no question this is a bug, and a strange one to boot.

This problem can be reproduced by doing the following:

# In any mid-call event (such as a dynamic feature), set a CDR property on a channel
# After the call, the CDR property will be gone in the {{h}} extension
# After the {{h}} extension, the CDR property set on the channel during the mid-call event will be written out to the CDR logs

The reason for all of this is murky at best, but almost assuredly involves logic attempting to clean up the affects of masquerades. In {{features.c}}, the following occurs:

# Prior to the channels being bridged, the CDR on the channel is dup'd into {{bridge_cdr}}. Any forked CDRs are removed from {{bridge_cdr}}:
{noformat}
			ast_set_flag(chan_cdr, AST_CDR_FLAG_MAIN);
			ast_cdr_update(chan);
			bridge_cdr = ast_cdr_dup_unique_swap(chan_cdr);
			/* rip any forked CDR's off of the chan_cdr and attach
			 * them to the bridge_cdr instead */
			bridge_cdr->next = chan_cdr->next;
			chan_cdr->next = NULL;
{noformat}
# The CDR on the channel is manipulated during the in call event. The {{bridge_cdr}} is not updated as a result.
# Things get really weird when the bridge breaks. If we're going to run an {{h}} extension on the channel - or a hangup handler - we put the {{bridge_cdr}} back on the channel, restoring its CDR state prior to it entering into the bridge while it is in the handler.
{noformat}
	/* run the hangup exten on the chan object IFF it was NOT involved in a parking situation
	 * if it were, then chan belongs to a different thread now, and might have been hung up long
	 * ago.
	 */
	if (!(ast_channel_softhangup_internal_flag(chan) & (AST_SOFTHANGUP_ASYNCGOTO | AST_SOFTHANGUP_UNBRIDGE))
			&& !ast_test_flag(&config->features_caller, AST_FEATURE_NO_H_EXTEN)) {

		ast_channel_lock(chan);
		if (bridge_cdr) {
			/*
			 * Swap the bridge_cdr and the chan cdr for a moment, and let
			 * the hangup dialplan code operate on it.
			 */
			swapper = ast_channel_cdr(chan);
			ast_channel_cdr_set(chan, bridge_cdr);

			/* protect the lastapp/lastdata against the effects of the hangup/dialplan code */
			ast_copy_string(savelastapp, bridge_cdr->lastapp, sizeof(bridge_cdr->lastapp));
			ast_copy_string(savelastdata, bridge_cdr->lastdata, sizeof(bridge_cdr->lastdata));
		}
{noformat}
# Finally, once the {{h}} extension and hangup handlers have run, we put the original CDR back onto the channel:
{noformat}
		ast_channel_lock(chan);

		/* swap it back */
		ast_channel_context_set(chan, save_context);
		ast_channel_exten_set(chan, save_exten);
		ast_channel_priority_set(chan, save_prio);
		if (bridge_cdr) {
			if (ast_channel_cdr(chan) == bridge_cdr) {
				ast_channel_cdr_set(chan, swapper);

				/* Restore the lastapp/lastdata */
				ast_copy_string(bridge_cdr->lastapp, savelastapp, sizeof(bridge_cdr->lastapp));
				ast_copy_string(bridge_cdr->lastdata, savelastdata, sizeof(bridge_cdr->lastdata));
			} else {
				bridge_cdr = NULL;
			}
		}
		ast_channel_unlock(chan);
{noformat}
This results in the wrong value being in the {{h}} extension and/or hangup handlers, but the correct value being written to the CDR backends.

I'm pretty sure this incredibly stupid logic was put in place to handle the case where a channel is transferred and a masquerade occurs on the channel that originally had the CDR. In that case, the original CDR would have been copied over to the new channel and the channel being run in the {{h}} extension/hangup handler would have no CDR information - so the {{bridge_cdr}} - which was the original state - was put on it. Unfortunately, it's a bad solution at best, as it doesn't contain information that occurred during the bridge.

It's also incredibly brittle. Either we don't do this swapping - in which case, someone depending on its behavior will break (and we'll probably also break CDRs in blind/attended transfers) - or we copy the variables explicitly so that the values are present in the hangup logic. The problem with the second approach is that there could *still* conceivably be a conflict, if someone did masquerade the channel after we changed the variable mid-bridge. You'd end up with the values from some channel that didn't really belong to you.

To quote the code just a few lines later:

{noformat}
	/*
	 * If the channel CDR has been modified during the call, record
	 * the changes in the bridge cdr, BUT, if hangup_run, the CDR
	 * got swapped so don't overwrite what was done in the
	 * h-extension or hangup handlers.  What a mess.  This is why
	 * you never touch CDR code.
	 */
{noformat}

As it is, this problem doesn't exist in Asterisk 12. In that version, none of this crap happens. Channels don't get masqueraded, and we don't attempt to move channel CDR information around from one channel to another. A CDR is associated with a channel that is the Party A in the record, and that's it. Period.

As such, given the risk of this change - and the fact that you already successfully worked around it - I'm inclined to close this as "fixed" in Asterisk 12. Let me know if that's okay - if not, I can analyze this some more and try to find a patch that doesn't break this behavior in 1.8/11.
                
> CDR(custom_field) field set in a DYNAMIC_FEATURE is reverted to the previous value when the call is terminated.
> ---------------------------------------------------------------------------------------------------------------
>
>                 Key: ASTERISK-19853
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-19853
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Applications/app_cdr
>    Affects Versions: 1.8.11.1, 10.2.1
>         Environment: FreePBX 2.10 or later system
>            Reporter: Philippe Lindheimer
>            Assignee: Matt Jordan
>            Severity: Minor
>
> FreePBX uses it's own DYNAMIC_FEATURE for doing on-demand call recording, "*1" which previously used automixmon.
> The specific bug is that a value set in a dynamic feature using the CDR(variable)=xyz function reverts back to the value that was set prior to the call being bridged when the call is hung up even though after the dynamic feature is pressed it can be confirmed that the value has in fact been properly set and present in the channel.
> Repro:
>  - Enable on-demand recording on an extension but no record always settings
>  - Make a call
>  - press the *1 'start recording' button and confirm it started (check the CLI)
>  - now check the channel contents - 'core show channel SIP/702-xxxxxx' to confirm that CDR(recordingfile) was set properly.
>  - now hangup, check the DB and no value is set
> The specific variable in question is CDR(recordingfile) and here are some snap-shot examples to demonstrate the behavior:
> Partial Dialplan before call is bridged:
> {noformat}
>     -- Executing [s at sub-record-check:12] Set("SIP/702-000002c0", "__REC_STATUS=INITIALIZED") in new stack
>     -- Executing [s at sub-record-check:13] Set("SIP/702-000002c0", "CDR(recordingfile)=INITIALIZED") in new stack
> {noformat}
> Partial dump of channel after call is bridged:
> {noformat}
>   CDR Variables:
> level 1: dnid=9203760286
> level 1: recordingfile=INITIALIZED
> level 1: clid=702
> level 1: src=702
> {noformat}
> Partial dialplan when DYNAMIC_FEATURE is being executed:
> {noformat}
>     -- Executing [s at macro-one-touch-record:16] Set("SIP/702-000002c0", "MASTER_CHANNEL(CDR(recordingfile))=out-9203761234-702-20120508-141552-1336511752.1205.wav") in new stack
>     -- Executing [s at macro-one-touch-record:17] Set("SIP/702-000002c0", "CDR(recordingfile)=out-9203761234-702-20120508-141552-1336511752.1205.wav") in new stack
> {noformat}
> Now confirmation from a dump of the channel while the call is still active after the feature is pressed:
> {noformat}
>   CDR Variables:
> level 1: recordingfile=out-9203761234-702-20120508-141552-1336511752.1205.wav
> level 1: dnid=9203760286
> level 1: clid=702
> {noformat}
> Now some debug code in the hangup macro showing what is in the CDR(recordingfile):
> {noformat}
>     -- Executing [h at macro-dialout-trunk:1] Macro("SIP/702-000002c0", "hangupcall,") in new stack
>     -- Executing [s at macro-hangupcall:1] NoOp("SIP/702-000002c0", "recordingfile: INITIALIZED") in new stack
>     -- Executing [s at macro-hangupcall:2] GotoIf("SIP/702-000002c0", "1?theend") in new stack
>     -- Goto (macro-hangupcall,s,5)
>     -- Executing [s at macro-hangupcall:5] Hangup("SIP/702-000002c0", "") in new stack
> {noformat}
> As can be seen it has reverted.
> Further testing shows that IF we set a different channel variable during the dynamic feature execution and then IN the hangup macro we set CDR(recordingfile) to that variable, that it is then properly stored in the database, and also confirms that the channel variable survives the hangup macro and does not revert unlike the CDR(recordingfile)

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.asterisk.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira



More information about the asterisk-bugs mailing list