[Home]

Summary:ASTERISK-23287: res_pjsip_refer: Crash during attended transfer when attended->transferer_second channel is NULL
Reporter:Matt Jordan (mjordan)Labels:
Date Opened:2014-02-12 20:19:03.000-0600Date Closed:2014-02-26 07:36:04.000-0600
Priority:MajorRegression?
Status:Closed/CompleteComponents:Resources/res_pjsip_refer
Versions:12.0.0 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) backtrace_5214.txt
( 1) full.txt
Description:Note that this was caught by the Asterisk Test Suite during the ARI attended transfer event test. Backtrace is attached.

{noformat}
#0  0x000000000053da03 in ast_channel_name (chan=0x0) at channel_internal_api.c:464
464 DEFINE_STRINGFIELD_GETTER_FOR(name);
#0  0x000000000053da03 in ast_channel_name (chan=0x0) at channel_internal_api.c:464
No locals.
#1  0x00007f05e9000f08 in refer_attended (data=0x7f060c0523c8) at res_pjsip_refer.c:424
       attended = 0x7f060c0523c8
       response = 0
       __PRETTY_FUNCTION__ = "refer_attended"
{noformat}

This occurs because some channel is NULL that we weren't expecting. Looking at line 424:

{noformat}
ast_debug(3, "Performing a REFER attended transfer - Transferer #1: %s Transferer #2: %s\n",
ast_channel_name(attended->transferer_chan), ast_channel_name(attended->transferer_second->channel));
{noformat}

So we have either {{attended->transferer_chan}}, or {{attended->transferer_second->channel}}.

When we make the {{attended}} structure, we are ref bumping the {{ast_sip_session}} objects, but only the {{attended->transferer_chan}} channel is ref bumped:

{noformat}
struct refer_attended *attended = ao2_alloc(sizeof(*attended), refer_attended_destroy);

if (!attended) {
return NULL;
}

ao2_ref(transferer, +1);
attended->transferer = transferer;
ast_channel_ref(transferer->channel);
attended->transferer_chan = transferer->channel;
ao2_ref(transferer_second, +1);
attended->transferer_second = transferer_second;

if (progress) {
ao2_ref(progress, +1);
attended->progress = progress;
}
{noformat}

The most likely culprit for this failing is the attended->transferer_second channel getting nuked out while we serialize the task.
Comments:By: Matt Jordan (mjordan) 2014-02-12 20:28:02.577-0600

Actually, this may be masquerades screwing us:

{noformat}
[Feb 12 13:19:38] DEBUG[13416] res_pjsip_refer.c: Final response for REFER attended transfer - Transferer #1: PJSIP/bob-00000000 Transferer #2: PJSIP/bob-00000002 is '200'
[Feb 12 13:19:38] DEBUG[13416] res_pjsip_refer.c: Subscription '0x7f061002a508' is being terminated as a result of a NOTIFY, removing REFER progress structure early on progress monitor '0x7f0610029908'
[Feb 12 13:19:38] DEBUG[13416] res_pjsip_refer.c: Sending NOTIFY with response '200' and state '5' on subscription '0x7f061002a508' and progress monitor '0x7f0610029908'
[Feb 12 13:19:38] DEBUG[13416] pjsip: evsub0x7f06100 Subscription state changed ACTIVE --> TERMINATED
[Feb 12 13:19:38] DEBUG[13416] res_pjsip_session.c: Method is BYE
[Feb 12 13:19:38] DEBUG[13400] cdr.c: Finalized CDR for PJSIP/bob-00000002 - start 1392232778.120924 answer 1392232778.121202 end 1392232778.599795 dispo ANSWERED
[Feb 12 13:19:38] DEBUG[13469] manager.c: Examining event:
Event: AttendedTransfer
Privilege: call,all
Result: Success
OrigTransfererChannel: PJSIP/bob-00000000
OrigTransfererChannelState: 6
OrigTransfererChannelStateDesc: Up
OrigTransfererCallerIDNum: bob
OrigTransfererCallerIDName: <unknown>
OrigTransfererConnectedLineNum: alice
OrigTransfererConnectedLineName: <unknown>
OrigTransfererAccountCode:
OrigTransfererContext: default
OrigTransfererExten: stasis
OrigTransfererPriority: 3
OrigTransfererUniqueid: 1392232778.6
OrigBridgeUniqueid: b0bb9dd9-ac1f-4dab-9081-d9ed0878dd52
OrigBridgeType: base
OrigBridgeTechnology: native_rtp
OrigBridgeCreator: Stasis
OrigBridgeName: <unknown>
OrigBridgeNumChannels: 2
SecondTransfererChannel: Local/_attended@transfer-00000001;2
SecondTransfererChannelState: 6
SecondTransfererChannelStateDesc: Up
SecondTransfererCallerIDNum: <unknown>
SecondTransfererCallerIDName: <unknown>
SecondTransfererConnectedLineNum: <unknown>
SecondTransfererConnectedLineName: <unknown>
SecondTransfererAccountCode:
SecondTransfererContext: default
SecondTransfererExten: 1000
SecondTransfererPriority: 2
SecondTransfererUniqueid: 1392232778.24
IsExternal: Yes
DestType: App
DestApp: Echo
{noformat}

Notice that the channel during the final REFER response is PJSIP/bob-00000002; however, the final channel in the Attended Transfer event is the Local channel. Something else to consider.
By: Kinsey Moore (kmoore) 2014-02-24 12:22:28.521-0600

Doing a little debugging and looking at the resulting backtraces, this is not quite as simple as tossing an extra ref in there for that channel. Something appears to be consuming a ref that shouldn't be, so it's time to enable REF_DEBUG.
By: Kinsey Moore (kmoore) 2014-02-24 14:44:22.424-0600

It turns out this is a masquerade problem which REF_DEBUG allows me to reproduce nearly at will.
By: Kinsey Moore (kmoore) 2014-02-25 08:48:22.413-0600

After further digging, this is actually two bugs. The first is in the test where an extra REFER is being triggered when it really shouldn't be and the other is in Asterisk where the extra REFER is accepted and acted upon even though the channel is NULLed out and gone because the masquerade has hung up the channel.