Inbound call hangup after 20 sec

nawikre · February 26, 2019, 10:06am

Hi there,

since this week ALL inbound calls hangup after about 20 seconds. I have a logg that says a lot, but i do not have the knowledge yet to fix it. Can soneone help me or send me in the correct direction.
We have not done anything to the freepbx server, no updates nothing, so i really do not know what the problam CAN be.

I have looked at the wiki adress that is stated in the error, looked/disabled the firewall, but that did not do anything. I am hoping that someone can help me.

[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] netsock2.c: Using SIP RTP TOS bits 184
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] netsock2.c: Using SIP RTP CoS mark 5
[2019-02-26 08:38:04] WARNING[3238][C-00000002] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] netsock2.c: Using SIP RTP TOS bits 184
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] netsock2.c: Using SIP RTP CoS mark 5
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_stack.c: SIP/402-00000005 Internal Gosub(func-apply-sipheaders,s,1) start
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/402-00000005", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/402-00000005", "Applying SIP Headers to channel SIP/402-00000005") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/402-00000005", "TECH=SIP") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/402-00000005", "SIPHEADERKEYS=") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/402-00000005", "0") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_while.c: Jumping to priority 12
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:13] Return("SIP/402-00000005", "") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_stack.c: Spawn extension (from-internal, 498, 1) exited non-zero on 'SIP/402-00000005'
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_stack.c: SIP/402-00000005 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_stack.c: SIP/405-00000006 Internal Gosub(func-apply-sipheaders,s,1) start
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/405-00000006", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/405-00000006", "Applying SIP Headers to channel SIP/405-00000006") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/405-00000006", "TECH=SIP") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/405-00000006", "SIPHEADERKEYS=") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/405-00000006", "0") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_while.c: Jumping to priority 12
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:13] Return("SIP/405-00000006", "") in new stack
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_stack.c: Spawn extension (from-internal, 498, 1) exited non-zero on 'SIP/405-00000006'
[2019-02-26 08:38:04] VERBOSE[3238][C-00000002] app_stack.c: SIP/405-00000006 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-02-26 08:38:05] VERBOSE[3238][C-00000002] app_dial.c: Called SIP/402
[2019-02-26 08:38:05] VERBOSE[3238][C-00000002] app_dial.c: Called SIP/405
[2019-02-26 08:38:05] VERBOSE[3238][C-00000002] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/31(****) – in-00000004'
[2019-02-26 08:38:05] VERBOSE[3238][C-00000002] app_dial.c: SIP/405-00000006 connected line has changed. Saving it until answer for SIP/31545796510 – in-00000004
[2019-02-26 08:38:05] VERBOSE[3238][C-00000002] app_dial.c: SIP/402-00000005 connected line has changed. Saving it until answer for SIP/31545796510 – in-00000004
[2019-02-26 08:38:05] VERBOSE[3238][C-00000002] app_dial.c: SIP/405-00000006 is ringing
[2019-02-26 08:38:05] VERBOSE[3238][C-00000002] app_dial.c: SIP/402-00000005 is ringing
[2019-02-26 08:38:08] VERBOSE[64685][C-00000003] netsock2.c: Using SIP RTP TOS bits 184
[2019-02-26 08:38:08] VERBOSE[64685][C-00000003] netsock2.c: Using SIP RTP CoS mark 5
[2019-02-26 08:38:08] NOTICE[3420] pickup.c: Pickup SIP/402-00000005 attempt by SIP/401-00000007
[2019-02-26 08:38:08] VERBOSE[3420] app_stack.c: SIP/402-00000005 Internal Gosub(crm-hangup,s,1) start
[2019-02-26 08:38:08] VERBOSE[3420] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/402-00000005", "Sending Hangup to CRM") in new stack
[2019-02-26 08:38:08] VERBOSE[3420] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/402-00000005", "HANGUP CAUSE: 26") in new stack
[2019-02-26 08:38:08] VERBOSE[3420] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/402-00000005", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2019-02-26 08:38:08] VERBOSE[3420] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/402-00000005", "MASTER CHANNEL: 1551170284.5 = 1551170276.4") in new stack
[2019-02-26 08:38:08] VERBOSE[3420] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/402-00000005", "1?return") in new stack
[2019-02-26 08:38:08] VERBOSE[3420] pbx_builtins.c: Goto (crm-hangup,s,8)
[2019-02-26 08:38:08] VERBOSE[3420] pbx.c: Executing [s@crm-hangup:8] Return("SIP/402-00000005", "") in new stack
[2019-02-26 08:38:08] VERBOSE[3420] app_stack.c: Spawn extension (from-internal, *8, 1) exited non-zero on 'SIP/402-00000005'
[2019-02-26 08:38:08] VERBOSE[3420] app_stack.c: SIP/402-00000005 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] app_dial.c: SIP/401-00000007 answered SIP/31(*****) – in-00000004
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] app_stack.c: SIP/405-00000006 Internal Gosub(crm-hangup,s,1) start
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/405-00000006", "Sending Hangup to CRM") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/405-00000006", "HANGUP CAUSE: 26") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/405-00000006", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/405-00000006", "MASTER CHANNEL: 1551170284.6 = 1551170276.4") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/405-00000006", "1?return") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx_builtins.c: Goto (crm-hangup,s,8)
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:8] Return("SIP/405-00000006", "") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] app_stack.c: Spawn extension (from-internal, 498, 1) exited non-zero on 'SIP/405-00000006'
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] app_stack.c: SIP/405-00000006 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:1] Set("SIP/401-00000007", "__MACRO_RESULT=") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:2] Set("SIP/401-00000007", "CFIGNORE=") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:3] Set("SIP/401-00000007", "MASTER_CHANNEL(CFIGNORE)=") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:4] Set("SIP/401-00000007", "FORWARD_CONTEXT=from-internal") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:5] Set("SIP/401-00000007", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:6] Macro("SIP/401-00000007", "blkvm-clr,") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-blkvm-clr:1] Set("SIP/401-00000007", "SHARED(BLKVM,SIP/31545796510 – in-00000004)=") in new stack
[2019-02-26 08:38:08] WARNING[3238][C-00000002] pbx_variables.c: Please avoid unnecessary spaces on variables as it may lead to unexpected results ('SHARED(BLKVM,SIP/31545796510 – in-00000004)' set to '').
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-blkvm-clr:2] Set("SIP/401-00000007", "GOSUB_RETVAL=") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("SIP/401-00000007", "") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:7] ExecIf("SIP/401-00000007", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=402)") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-auto-blkvm:8] ExecIf("SIP/401-00000007", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=402 LDR Tim)") in new stack
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] res_musiconhold.c: Stopped music on hold on SIP/31(*****) – in-00000004
[2019-02-26 08:38:08] VERBOSE[3422][C-00000002] bridge_channel.c: Channel SIP/401-00000007 joined 'simple_bridge' basic-bridge <651a768f-30e9-4a2d-a5a3-2e702e4fccd7>
[2019-02-26 08:38:08] VERBOSE[3238][C-00000002] bridge_channel.c: Channel SIP/31545796510 – in-00000004 joined 'simple_bridge' basic-bridge <651a768f-30e9-4a2d-a5a3-2e702e4fccd7>
[2019-02-26 08:38:28] WARNING[64685] chan_sip.c: Retransmission timeout reached on transmission SBC32.473.6436695 for seqno 769 (Critical Response) -- See (*** i cannot use a link in my post)
Packet timed out after 32004ms with no response
[2019-02-26 08:38:28] WARNING[64685] chan_sip.c: Hanging up call SBC32.473.6436695 - no reply to our critical packet (see *********** i am not allowed to use link in the text).
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] bridge_channel.c: Channel SIP/31(****) – in-00000004 left 'simple_bridge' basic-bridge <651a768f-30e9-4a2d-a5a3-2e702e4fccd7>
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] app_macro.c: Spawn extension (macro-dial, s, 23) exited non-zero on 'SIP/31(****) – in-00000004' in macro 'dial'
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Spawn extension (ext-group, 498, 22) exited non-zero on 'SIP/31(****) – in-00000004'
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [h@ext-group:1] Macro("SIP/31(*****) – in-00000004", "hangupcall,") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/31(****) – in-00000004", "1?theend") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2019-02-26 08:38:28] VERBOSE[3422][C-00000002] bridge_channel.c: Channel SIP/401-00000007 left 'simple_bridge' basic-bridge <651a768f-30e9-4a2d-a5a3-2e702e4fccd7>
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/31(****) – in-00000004", "0?Set(CDR(recordingfile)=)") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/31(*****) – in-00000004", "SIP/401-00000007 monior file= ") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-hangupcall:5] AGI("SIP/31(****) – in-00000004", "attendedtransfer-rec-restart.php,SIP/401-00000007,") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] res_agi.c: <SIP/31(*****) – in-00000004>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@macro-hangupcall:6] Hangup("SIP/31(****) – in-00000004", "") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/31(*****) – in-00000004' in macro 'hangupcall'
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/31(*****) – in-00000004'
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] app_stack.c: SIP/31(****) – in-00000004 Internal Gosub(crm-hangup,s,1) start
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/31(******) – in-00000004", "Sending Hangup to CRM") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/31(*****) – in-00000004", "HANGUP CAUSE: 18") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/31(*****) – in-00000004", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/31(****) – in-00000004", "MASTER CHANNEL: 1551170276.4 = 1551170276.4") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/31(*****) – in-00000004", "0?return") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:6] Set("SIP/31(*****) – in-00000004", "__CRM_HANGUP=1") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:7] AGI("SIP/31(******)– in-00000004", "sangomacrm.agi") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] res_agi.c: <SIP/31(****) – in-00000004>AGI Script sangomacrm.agi completed, returning 0
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] pbx.c: Executing [s@crm-hangup:8] Return("SIP/31(****) – in-00000004", "") in new stack
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] app_stack.c: Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/31(***********) – in-00000004'
[2019-02-26 08:38:28] VERBOSE[3238][C-00000002] app_stack.c: SIP/31(*******) – in-00000004 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

Stewart1 · February 26, 2019, 2:50pm

In Asterisk SIP Settings, NAT Settings, check that External Address and Local Networks are correct. Possibly, your ISP changed your public IP address or some other change occurred on your network.

If that’s not the issue, at the Asterisk command prompt, type
sip set debug on
and make an inbound test call.
The SIP traffic will appear in the log.

Also, post details about your setup (ISP, Modem/router, separate hardware firewall, virtualization, etc.)

nawikre · February 26, 2019, 3:48pm

@Stewart1 t1
thank you for the push…we found it. We enabled ‘sip set debug on’ and looked at what was going wrong. and indeed the ISP public IP adres was changed. We set the correct adres in freepbx ‘Astrix SIP settings’, ‘NAT settings’ then ‘external adress’. Now everything works again…

thanks a lot…

system · March 5, 2019, 3:48pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.