SIP Destruction

Hello Everyone,

What does this mean?

Does it mean that my server (3.1.193.59 didnt receive a response from a given time that’s why the server sends a bye signal?

[Sep 26 15:27:21] VERBOSE[4072][C-0000a5d9] chan_sip.c: Scheduling destruction of SIP dialog ‘683ef8e478cb5ad75cbc76e068767b3a@3.1.193.59:5060’ in 13824 ms (Method: BYE

The call leg has been terminated and the normal cleanup is happening. It is perfectly normal.

Hello david… does it mean that my server 3.1.193.59 terminated the call since no response from the trunk where the call was routed to?

Also is there a way we can adjust or have a timeout to destruct the call leg after certain minutes without response from the called party? Instead of waiting it to be destructed automatically by asterisk. We want to avoid long call hours of call without the actual interaction with the customer.

there is the ‘rtptimeout’ setting that will end dialogs if there is no RTP received in the amount of time you specify.

rtptimeout was set to 60. However based from this, it took 3 hours to end the entire call.

:15] VERBOSE[4072][C-0000a5d9] sip/route.c: sip_route_dump: route/path hop: <sip:168.215.247.130:5060;lr>
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] sip/route.c: sip_route_dump: route/path hop: <sip:sansay1773336743rdb162415@67.221.11.67:5060;lr;transport=udp>
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] chan_sip.c: Found RTP audio format 0
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] chan_sip.c: Found RTP audio format 101
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] chan_sip.c: Found audio description format PCMU for ID 0
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] chan_sip.c: Found audio description format telephone-event for ID 101
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] chan_sip.c: Capabilities: us - (ulaw), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] res_rtp_asterisk.c: 0x7f1e880e5e40 -- Strict RTP learning after remote address set to: 192.40.216.125:12312
[Sep 26 12:27:15] VERBOSE[4072][C-0000a5d9] chan_sip.c: Peer audio RTP is at port 192.40.216.125:12312
[Sep 26 12:27:15] VERBOSE[29974][C-0000a5d9] app_dial.c: SIP/magna1-00004da0 is making progress passing it to Local/817194159096@default-00005ac4;2
[Sep 26 12:27:19] VERBOSE[4072][C-0000a5d9] sip/route.c: sip_route_dump: route/path hop: <sip:168.215.247.130:5060;lr>
[Sep 26 12:27:19] VERBOSE[4072][C-0000a5d9] sip/route.c: sip_route_dump: route/path hop: <sip:sansay1773336743rdb162415@67.221.11.67:5060;lr;transport=udp>
[Sep 26 12:27:19] VERBOSE[4072][C-0000a5d9] chan_sip.c: Transmitting (NAT) to 168.215.247.130:5060:
[Sep 26 12:27:19] VERBOSE[29974][C-0000a5d9] app_dial.c: SIP/magna1-00004da0 answered Local/817194159096@default-00005ac4;2
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] bridge_channel.c: Channel SIP/magna1-00004da0 joined 'simple_bridge' basic-bridge <f0a91fb9-839f-41b7-b611-634166647178>
[Sep 26 12:27:19] VERBOSE[29974][C-0000a5d9] bridge_channel.c: Channel Local/817194159096@default-00005ac4;2 joined 'simple_bridge' basic-bridge <f0a91fb9-839f-41b7-b611-634166647178>
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] bridge_channel.c: Channel SIP/magna1-00004da0 left 'simple_bridge' basic-bridge <f0a91fb9-839f-41b7-b611-634166647178>
[Sep 26 12:27:19] VERBOSE[29974][C-0000a5d9] bridge_channel.c: Channel Local/817194159096@default-00005ac4;2 left 'simple_bridge' basic-bridge <f0a91fb9-839f-41b7-b611-634166647178>
[Sep 26 12:27:19] VERBOSE[29974][C-0000a5d9] pbx.c: Spawn extension (default, 817194159096, 5) exited non-zero on 'Local/817194159096@default-00005ac4;2'
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] pbx.c: Executing [8387@default:1] Playback("SIP/magna1-00004da0", "sip-silence") in new stack
[Sep 26 12:27:19] VERBOSE[29974][C-0000a5d9] pbx.c: Executing [h@default:1] AGI("Local/817194159096@default-00005ac4;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----22-----0-----SIP 200 OK)") in new stack
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] file.c: <SIP/magna1-00004da0> Playing 'sip-silence.gsm' (language 'en')
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] pbx.c: Executing [8387@default:2] AGI("SIP/magna1-00004da0", "agi://127.0.0.1:4577/call_log") in new stack
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] res_agi.c: AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=OUTSOURC))
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] res_agi.c: <SIP/magna1-00004da0>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] pbx.c: Executing [8387@default:3] AMD("SIP/magna1-00004da0", "2000,2000,1000,5000,120,50,4,256") in new stack
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] app_amd.c: AMD: SIP/magna1-00004da0 (N/A) (N/A) (Fmt: slin)
[Sep 26 12:27:19] VERBOSE[31234][C-0000a5d9] app_amd.c: AMD: initialSilence [2000] greeting [2000] afterGreetingSilence [1000] totalAnalysisTime [5000] minimumWordLength [120] betweenWordsSilence [50] maximumNumberOfWords [4] silenceThreshold [256] maximumWordLength [5000]
[Sep 26 12:27:20] VERBOSE[29974][C-0000a5d9] res_agi.c: <Local/817194159096@default-00005ac4;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----22-
[Sep 26 15:27:21] VERBOSE[4072][C-0000a5d9] chan_sip.c: Sending to 168.215.247.130:5060 (NAT)
[Sep 26 15:27:21] VERBOSE[4072][C-0000a5d9] chan_sip.c: Scheduling destruction of SIP dialog '683ef8e478cb5ad75cbc76e068767b3a@3.1.193.59:5060' in 13824 ms (Method: BYE)
[Sep 26 15:27:21] VERBOSE[4072][C-0000a5d9] chan_sip.c:
[Sep 26 15:27:21] VERBOSE[31234][C-0000a5d9] app_amd.c: AMD: Channel [SIP/magna1-00004da0]. HANGUP
[Sep 26 15:27:21] VERBOSE[31234][C-0000a5d9] pbx.c: Executing [h@default:1] AGI("SIP/magna1-00004da0", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------SIP 200 OK)") in new stack
[Sep 26 15:27:21] VERBOSE[31234][C-0000a5d9] res_agi.c: <SIP/magna1-00004da0>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------SIP 200 OK) completed, returning 0

Was the far end continuing to send RTP during the call? They could be generating comfort noise which would keep the RTP timeout from triggering.

The message doesn’t say why the call was terminated, only that BYE was used.

The timeout is no the timeout before termination is started but the timeout from when the call is terminated to when the call is forgotten. Messages can get lost, and retransmitted. They delay means that retransmitted messages are correctly understood.

Hmm actually the call is 0 second therefore we cannot see if there’s a noise on the recording.

This is my server IP 3.1.193.59.

We are sending the call to this trunk 168.215.247.130.

Does this mean Scheduling destruction of SIP dialog ‘683ef8e478cb5ad75cbc76e068767b3a@3.1.193.59:5060’ in 13824 ms (Method: BYE) that my server ended or destructed the call due to no rtp response from 168.215.247.130?

Thanks in advance.

I repeat that the message does not tell you why the call was terminated. You should basically ignore it and look further back in the logs to identify the reason for termination.

I’m not sure if the BYE inbound or outbound, but it could well be that the peer is the one that initiated termination.

Enabling SIP debugging will tell you more.

We cannot just ignore it because that’s the time we sent the BYE signal to our provider. Any idea? Do you think it is because of the AMD application?

It is the effect of the BYE transaction, not the cause. There is always a delayed destruction after a BYE.

Is this something to do with AMD? Seemed like it didnt go through to step 4 of prefix 8387?

  '8387' =>         1. Playback(sip-silence)                      [pbx_config]
                    2. AGI(agi://127.0.0.1:4577/call_log)         [pbx_config]
                    3. AMD(2000,2000,1000,5000,120,50,4,256)      [pbx_config]
                    4. AGI(VD_amd.agi,${EXTEN})                   [pbx_config]
                    5. AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----LO) [pbx_config]
                    6. Hangup()                                   [pbx_config]

No AMD not going onto step 4 is the result of the BYE transaction.

You seem to be trying to spend a lot of tiem on a red herring.

Hello David,

Okay so if 8387 didit process the step 4… What does it mean? So it is not related to AMD? Based from the console log, seemed like the step# 3 didnt finish that’s why it didnt go through to step# 4.

It means the incoming all was termianted, which generally means that the caller sent a BYE. There is no way of refusing a BYE.

It is also possible that Asterisk closed the call down, because it had failed to receive any audio, but that should produce its own log entry.

You need at least verbose 5, debug 5, sip set debut on, and the full log uncommented in logger.conf to fully understand why Asterisk termianted the call, but, if the peer sent BYE, that won’t tell you why they did it.

The callee could also be doing some sort of telemarketing detection, or simply have a black list , but deliberately answer the call so that you get charged.