Incomming calls disconnect after 16 Seconds

Hi,

I’ve installed asterisk behind a pfsense firewall with the SIPproxy extension.

Outgoing calls work perfectly but incomming calls disconnect after 15-20 seconds.

When using a softphone directly connected to the VOIP provider this problem does not excist.

the softphone that was used to test is on the same internal network as the asterisk server and the only changes that I made between using the two is changing the firewall settings.

I am using NAT.

Extract from my logfile:

Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [asterisk@from-trunk-sip-Tweak:1] Set(“SIP/Tweak-0000004b”, “GROUP()=OUT_2”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [asterisk@from-trunk-sip-Tweak:2] Goto(“SIP/Tweak-0000004b”, “from-trunk,asterisk,1”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (from-trunk,asterisk,1)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [asterisk@from-trunk:1] NoOp(“SIP/Tweak-0000004b”, “Catch-All DID Match - Found asterisk - You probably want a DID for this.”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [asterisk@from-trunk:2] Goto(“SIP/Tweak-0000004b”, “ext-did,s,1”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (ext-did,s,1)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@ext-did:1] Set(“SIP/Tweak-0000004b”, “__FROM_DID=s”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@ext-did:2] Gosub(“SIP/Tweak-0000004b”, “app-blacklist-check,s,1”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/Tweak-0000004b”, “0?blacklisted”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/Tweak-0000004b”, “CALLED_BLACKLIST=1”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/Tweak-0000004b”, “”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@ext-did:3] ExecIf(“SIP/Tweak-0000004b”, “0 ?Set(CALLERID(name)=0611628234)”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@ext-did:4] Set(“SIP/Tweak-0000004b”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@ext-did:5] Set(“SIP/Tweak-0000004b”, “CALLERPRES()=allowed_not_screened”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@ext-did:6] Goto(“SIP/Tweak-0000004b”, “ext-group,400,1”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (ext-group,400,1)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:1] Macro(“SIP/Tweak-0000004b”, “user-callerid,”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/Tweak-0000004b”, “AMPUSER=0611628234”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/Tweak-0000004b”, “0?report”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/Tweak-0000004b”, “1?Set(REALCALLERIDNUM=0611628234)”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/Tweak-0000004b”, “AMPUSER=”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/Tweak-0000004b”, “AMPUSERCIDNAME=”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/Tweak-0000004b”, “1?report”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-user-callerid,s,10)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/Tweak-0000004b”, “0?continue”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/Tweak-0000004b”, “__TTL=64”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/Tweak-0000004b”, “1?continue”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-user-callerid,s,19)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:19] Set(“SIP/Tweak-0000004b”, “CALLERID(number)=0611628234”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:20] Set(“SIP/Tweak-0000004b”, “CALLERID(name)=0611628234”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/Tweak-0000004b”, “Using CallerID “0611628234” <0611628234>”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:2] GotoIf(“SIP/Tweak-0000004b”, “1?skipdb”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (ext-group,400,4)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:4] Set(“SIP/Tweak-0000004b”, “__NODEST=”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:5] Set(“SIP/Tweak-0000004b”, “__BLKVM_OVERRIDE=BLKVM/400/SIP/Tweak-0000004b”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:6] Set(“SIP/Tweak-0000004b”, “__BLKVM_BASE=400”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:7] Set(“SIP/Tweak-0000004b”, “DB(BLKVM/400/SIP/Tweak-0000004b)=TRUE”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:8] Set(“SIP/Tweak-0000004b”, “RRNODEST=”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:9] Set(“SIP/Tweak-0000004b”, “__NODEST=400”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:10] GosubIf(“SIP/Tweak-0000004b”, “0?sub-rgsetcid,s,1”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:11] Set(“SIP/Tweak-0000004b”, “RecordMethod=Group”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:12] Macro(“SIP/Tweak-0000004b”, “record-enable,100-101,Group”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/Tweak-0000004b”, “1?check”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-record-enable,s,4)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/Tweak-0000004b”, “0?MacroExit()”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/Tweak-0000004b”, “1?Group:OUT”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-record-enable,s,6)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:6] Set(“SIP/Tweak-0000004b”, “LOOPCNT=2”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:7] Set(“SIP/Tweak-0000004b”, “ITER=1”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/Tweak-0000004b”, “1?continue”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-record-enable,s,13)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/Tweak-0000004b”, “ITER=2”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/Tweak-0000004b”, “1?begin”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-record-enable,s,8)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/Tweak-0000004b”, “1?continue”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-record-enable,s,13)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/Tweak-0000004b”, “ITER=3”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/Tweak-0000004b”, “0?begin”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/Tweak-0000004b”, “0?IN”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/Tweak-0000004b”, “1?MacroExit()”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:13] Set(“SIP/Tweak-0000004b”, “RingGroupMethod=ringall”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [400@ext-group:14] Macro(“SIP/Tweak-0000004b”, “dial,60,tr,100-101”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/Tweak-0000004b”, “1?dial”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Goto (macro-dial,s,3)
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/Tweak-0000004b”, “dialparties.agi”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: dialparties.agi: Caller ID name is ‘0611628234’ number is ‘0611628234’
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: dialparties.agi: Methodology of ring is ‘ringall’
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: Added extension 100 to extension map
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: Added extension 101 to extension map
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: Extension 100 cf is disabled
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: Extension 101 cf is disabled
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: Extension 100 do not disturb is disabled
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: Extension 101 do not disturb is disabled
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: dbset CALLTRACE/100 to 0611628234
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: dbset CALLTRACE/101 to 0611628234
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – dialparties.agi: Filtered ARG3: 100-101
[Jun 24 12:39:04] VERBOSE[3500] res_agi.c: – <SIP/Tweak-0000004b>AGI Script dialparties.agi completed, returning 0
[Jun 24 12:39:04] VERBOSE[3500] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/Tweak-0000004b”, “SIP/100&SIP/101,60,trM(auto-blkvm)”) in new stack
[Jun 24 12:39:04] VERBOSE[3500] netsock.c: == Using SIP RTP TOS bits 184
[Jun 24 12:39:04] VERBOSE[3500] netsock.c: == Using SIP RTP CoS mark 5
[Jun 24 12:39:04] WARNING[3500] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Unknown)
[Jun 24 12:39:04] VERBOSE[3500] netsock.c: == Using SIP RTP TOS bits 184
[Jun 24 12:39:04] VERBOSE[3500] netsock.c: == Using SIP RTP CoS mark 5
[Jun 24 12:39:04] VERBOSE[3500] app_dial.c: – Called 101
[Jun 24 12:39:04] VERBOSE[3500] app_dial.c: – SIP/101-0000004c is ringing
[Jun 24 12:39:06] VERBOSE[3500] app_dial.c: – SIP/101-0000004c answered SIP/Tweak-0000004b
[Jun 24 12:39:06] VERBOSE[3500] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/101-0000004c”, “__MACRO_RESULT=”) in new stack
[Jun 24 12:39:06] VERBOSE[3500] pbx.c: – Executing [s@macro-auto-blkvm:2] NoOp(“SIP/101-0000004c”, “Deleting: BLKVM/400/SIP/Tweak-0000004b TRUE”) in new stack
[Jun 24 12:39:07] VERBOSE[3500] res_musiconhold.c: – Started music on hold, class ‘default’, on SIP/Tweak-0000004b
[Jun 24 12:39:10] VERBOSE[3502] manager.c: == Manager ‘admin’ logged on from 127.0.0.1
[Jun 24 12:39:10] VERBOSE[3502] manager.c: == Manager ‘admin’ logged off from 127.0.0.1
[Jun 24 12:39:18] NOTICE[3500] rtp.c: Unknown RTP codec 126 received from ‘192.168.2.203’
[Jun 24 12:39:20] VERBOSE[3507] manager.c: == Manager ‘admin’ logged on from 127.0.0.1
[Jun 24 12:39:20] VERBOSE[3507] manager.c: == Manager ‘admin’ logged off from 127.0.0.1
[Jun 24 12:39:24] VERBOSE[3512] manager.c: == Manager ‘admin’ logged on from 127.0.0.1
[Jun 24 12:39:24] VERBOSE[3512] manager.c: == Manager ‘admin’ logged off from 127.0.0.1
[Jun 24 12:39:25] WARNING[3097] chan_sip.c: Maximum retries exceeded on transmission 022bb2f90655f8ed31633ec651d7527c@82.197.223.46 for seqno 102 (Critical Response) – See doc/sip-retransmit.txt.
[Jun 24 12:39:25] WARNING[3097] chan_sip.c: Hanging up call 022bb2f90655f8ed31633ec651d7527c@82.197.223.46 - no reply to our critical packet (see doc/sip-retransmit.txt).
[Jun 24 12:39:25] VERBOSE[3500] res_musiconhold.c: – Stopped music on hold on SIP/Tweak-0000004b
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/Tweak-0000004b”, “hangupcall”) in new stack
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/Tweak-0000004b”, “1?skiprg”) in new stack
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Goto (macro-hangupcall,s,4)
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Executing [s@macro-hangupcall:4] GotoIf(“SIP/Tweak-0000004b”, “0?skipblkvm”) in new stack
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Executing [s@macro-hangupcall:5] NoOp(“SIP/Tweak-0000004b”, “Cleaning Up Block VM Flag: BLKVM/400/SIP/Tweak-0000004b”) in new stack
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Executing [s@macro-hangupcall:6] NoOp(“SIP/Tweak-0000004b”, "Deleting: BLKVM/400/SIP/Tweak-0000004b ") in new stack
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Executing [s@macro-hangupcall:7] GotoIf(“SIP/Tweak-0000004b”, “1?theend”) in new stack
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Goto (macro-hangupcall,s,9)
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: – Executing [s@macro-hangupcall:9] Hangup(“SIP/Tweak-0000004b”, “”) in new stack
[Jun 24 12:39:25] VERBOSE[3500] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/Tweak-0000004b’ in macro ‘hangupcall’
[Jun 24 12:39:25] VERBOSE[3500] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/Tweak-0000004b’ in macro ‘dial’
[Jun 24 12:39:25] VERBOSE[3500] pbx.c: == Spawn extension (ext-group, 400, 14) exited non-zero on ‘SIP/Tweak-0000004b’
[Jun 24 12:39:30] VERBOSE[3517] manager.c: == Manager ‘admin’ logged on from 127.0.0.1

I think the error has something to do with
[Jun 24 12:39:18] NOTICE[3500] rtp.c: Unknown RTP codec 126 received from ‘192.168.2.203’

which is followed by
Jun 24 12:39:25] WARNING[3097] chan_sip.c: Maximum retries exceeded on transmission 022bb2f90655f8ed31633ec651d7527c@82.197.223.46 for seqno 102 (Critical Response) – See doc/sip-retransmit.txt.
[Jun 24 12:39:25] WARNING[3097] chan_sip.c: Hanging up call 022bb2f90655f8ed31633ec651d7527c@82.197.223.46 - no reply to our critical packet (see doc/sip-retransmit.txt).

Anybody any suggestions what’s the problem here ?