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-0600 | Date Closed: | 2014-02-26 07:36:04.000-0600 |
Priority: | Major | Regression? | |
Status: | Closed/Complete | Components: | 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. |