Context Issue

Trunk · January 6, 2019, 12:55am

I’m using FreePBX 14.0.5.23 and Asterisk 15.5.0. I have a Chan_SIP trunk to german Telekom. With incoming calls, Telekom sends the DID in the to header, so the context from-pstn-toheader is necessary and so i specified context=from-pstn-toheader in the User details in incoming sip settings of the trunk. Unfortunately it was completely ignored. For incoming calls the context from-trunk was used and the result was that the displayed DID was always just “s” and no inbound routes matched “s”. As the next step, i also set default context to from-pstn-toheader (in Settings - Asterisk SIP Settings - Chan-SIP-Settings). Since i did that, the behaviour is really strange. After reboot it works fine, the context from-pstn-toheader is used for incoming calls, DID and inbound routing is correct. But some time later, it suddenly does not work anymore, for incoming calls the context from-trunk is used instead of pstn-to-header.until next reboot. This behaviour occurs though no changes are made in the GUI or CLI of freepbx. Sometimes the “context change” occurs after the first incoming call or after a few minutes, sometimes it occurs after about 20 incoming calls or after a few hours. I also don’t see any particular entries In the log when the context changes. There are log entries of the normal Hangup procedure of the preceding call directly followed by the entries of the normal start procedure of the next call.

Any suggestions are appreciated.
Many Thanks

Stewart1 · January 6, 2019, 5:47am

Try adding
context=from-pstn-toheader
to the PEER Details in the Outgoing settings for the trunk.

For better security, also set the default context back to from-sip-external.

If no luck, post the log for a failed call.

Trunk · January 6, 2019, 2:45pm

Thank you much for your help. I added context=from-pstn-toheader to the Peer details in the outgoing settings of the trunk but i had no luck. After reboot, for the first call the context from-pstn-toheader was used and for the second call from-trunk was used.

Here is the log of a failed call. I called the extension +49XXXXXXXX75 from my cellular phone. As you can see, the context from-trunk is used here instead of the configured from-pstn-toheader. As the result, the DID was not extracted correctly and only the inbound route for DID “ANY” matched here. So the call was sent to a ring group for telephonists. Because it’s sunday today everyone except two mobile softphones turned on DND and the two mobile softphones were not connected. A time condition decided that the actual time is outside of business hours of the company and so the call was sendt to the voicemail extension 709.

[2019-01-06 14:38:48] NOTICE[3277] chan_sip.c: Peer ‘Telekom.de-49XXXXXXXX’ is now UNREACHABLE! Last qualify: 16
[2019-01-06 14:38:58] NOTICE[104813] chan_sip.c: Peer ‘Telekom.de-49XXXXXXXX’ is now Reachable. (15ms / 2000ms)
[2019-01-06 14:44:13] VERBOSE[104813][C-00000007] netsock2.c: Using SIP VIDEO TOS bits 136
[2019-01-06 14:44:13] VERBOSE[104813][C-00000007] netsock2.c: Using SIP VIDEO TOS bits 136 in TCLASS field.
[2019-01-06 14:44:13] VERBOSE[104813][C-00000007] netsock2.c: Using SIP VIDEO CoS mark 6
[2019-01-06 14:44:13] VERBOSE[104813][C-00000007] netsock2.c: Using SIP RTP TOS bits 184
[2019-01-06 14:44:13] VERBOSE[104813][C-00000007] netsock2.c: Using SIP RTP TOS bits 184 in TCLASS field.
[2019-01-06 14:44:13] VERBOSE[104813][C-00000007] netsock2.c: Using SIP RTP CoS mark 5
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:1] Set(“SIP/sip-trunk.telekom.de-00000008”, “__DIRECTION=INBOUND”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:2] Gosub(“SIP/sip-trunk.telekom.de-00000008”, “sub-record-check,s,1(in,s,dontcare)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?initialized”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:2] Set(“SIP/sip-trunk.telekom.de-00000008”, “__REC_STATUS=INITIALIZED”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:3] Set(“SIP/sip-trunk.telekom.de-00000008”, “NOW=1546782253”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:4] Set(“SIP/sip-trunk.telekom.de-00000008”, “__DAY=06”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:5] Set(“SIP/sip-trunk.telekom.de-00000008”, “__MONTH=01”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:6] Set(“SIP/sip-trunk.telekom.de-00000008”, “__YEAR=2019”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:7] Set(“SIP/sip-trunk.telekom.de-00000008”, “__TIMESTR=20190106-144413”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:8] Set(“SIP/sip-trunk.telekom.de-00000008”, “__FROMEXTEN=unknown”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:9] Set(“SIP/sip-trunk.telekom.de-00000008”, “__MON_FMT=wav”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “Recordings initialized”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(ARG3=dontcare)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/sip-trunk.telekom.de-00000008”, “REC_POLICY_MODE_SAVE=”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(REC_STATUS=NO)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “2?checkaction”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “1?sub-record-check,in,1”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (sub-record-check,in,1)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [in@sub-record-check:1] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “Inbound Recording Check to s”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [in@sub-record-check:2] Set(“SIP/sip-trunk.telekom.de-00000008”, “FROMEXTEN=unknown”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [in@sub-record-check:3] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “14?Set(FROMEXTEN=+49YYYYYYYYYYY)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [in@sub-record-check:4] Gosub(“SIP/sip-trunk.telekom.de-00000008”, “recordcheck,1(dontcare,in,s)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “Starting recording check against dontcare”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/sip-trunk.telekom.de-00000008”, “dontcare”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [in@sub-record-check:5] Return(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:3] Set(“SIP/sip-trunk.telekom.de-00000008”, “CHANNEL(tonezone)=de”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:4] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “1?Set(__FROM_DID=s)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:5] Set(“SIP/sip-trunk.telekom.de-00000008”, “returnhere=1”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:6] Gosub(“SIP/sip-trunk.telekom.de-00000008”, “app-blacklist-check,s,1()”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?blacklisted”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@app-blacklist-check:2] Set(“SIP/sip-trunk.telekom.de-00000008”, “CALLED_BLACKLIST=1”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@app-blacklist-check:3] Return(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:7] Set(“SIP/sip-trunk.telekom.de-00000008”, “CDR(did)=s”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:8] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:9] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “1 ?Set(CALLERID(name)=+49YYYYYYYYYYY)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:10] Set(“SIP/sip-trunk.telekom.de-00000008”, “__MOHCLASS=”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:11] Set(“SIP/sip-trunk.telekom.de-00000008”, “__REVERSAL_REJECT=TRUE”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:12] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?post-reverse-charge”) in new stack
[2019-01-06 14:44:13] WARNING[107825][C-00000007] func_channel.c: Unknown or unavailable item requested: ‘reversecharge’
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:13] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?macro-hangupcall”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:14] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:15] Set(“SIP/sip-trunk.telekom.de-00000008”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:16] Set(“SIP/sip-trunk.telekom.de-00000008”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:17] Set(“SIP/sip-trunk.telekom.de-00000008”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:18] Set(“SIP/sip-trunk.telekom.de-00000008”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:19] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “CallerID Entry Point”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:20] Set(“SIP/sip-trunk.telekom.de-00000008”, “__CRM_DIRECTION=INBOUND”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:21] Set(“SIP/sip-trunk.telekom.de-00000008”, “__CRM_SOURCE=+49YYYYYYYYYYY”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:22] Set(“SIP/sip-trunk.telekom.de-00000008”, “__CRM_LINKEDID=1546782253.8”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:23] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@from-trunk:24] Goto(“SIP/sip-trunk.telekom.de-00000008”, “ext-group,0,1”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (ext-group,0,1)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:1] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?cid”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:2] PlayTones(“SIP/sip-trunk.telekom.de-00000008”, “ring”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:3] Progress(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:4] Macro(“SIP/sip-trunk.telekom.de-00000008”, “user-callerid,”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/sip-trunk.telekom.de-00000008”, “TOUCH_MONITOR=1546782253.8”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/sip-trunk.telekom.de-00000008”, “AMPUSER=+49YYYYYYYYYYY”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:3] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?report”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:4] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “1?Set(REALCALLERIDNUM=+49YYYYYYYYYYY)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/sip-trunk.telekom.de-00000008”, “AMPUSER=”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:6] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?limit”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:7] Set(“SIP/sip-trunk.telekom.de-00000008”, “AMPUSERCIDNAME=”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:8] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:9] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “1?report”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (macro-user-callerid,s,16)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:16] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “Macro Depth is 1”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:17] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “1?report2:macroerror”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:18] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?continue”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:19] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:20] Set(“SIP/sip-trunk.telekom.de-00000008”, “__TTL=64”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:21] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “1?continue”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:37] Set(“SIP/sip-trunk.telekom.de-00000008”, “CALLERID(number)=+49YYYYYYYYYYY”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:38] Set(“SIP/sip-trunk.telekom.de-00000008”, “CALLERID(name)=+49YYYYYYYYYYY”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:39] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?cnum”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:40] Set(“SIP/sip-trunk.telekom.de-00000008”, “CDR(cnam)=+49YYYYYYYYYYY”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:41] Set(“SIP/sip-trunk.telekom.de-00000008”, “CDR(cnum)=+49YYYYYYYYYYY”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-user-callerid:42] Set(“SIP/sip-trunk.telekom.de-00000008”, “CHANNEL(language)=en”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:5] Macro(“SIP/sip-trunk.telekom.de-00000008”, “blkvm-setifempty,”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “1?init”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (macro-blkvm-setifempty,s,4)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-blkvm-setifempty:4] Set(“SIP/sip-trunk.telekom.de-00000008”, “__BLKVM_CHANNEL=SIP/sip-trunk.telekom.de-00000008”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-blkvm-setifempty:5] Set(“SIP/sip-trunk.telekom.de-00000008”, “SHARED(BLKVM,SIP/sip-trunk.telekom.de-00000008)=TRUE”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-blkvm-setifempty:6] Set(“SIP/sip-trunk.telekom.de-00000008”, “GOSUB_RETVAL=TRUE”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:6] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “1?skipov”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (ext-group,0,9)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:9] Set(“SIP/sip-trunk.telekom.de-00000008”, “RRNODEST=”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:10] Set(“SIP/sip-trunk.telekom.de-00000008”, “__NODEST=0”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:11] GosubIf(“SIP/sip-trunk.telekom.de-00000008”, “0?sub-rgsetcid,s,1()”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:12] Gosub(“SIP/sip-trunk.telekom.de-00000008”, “sub-record-check,s,1(rg,0,dontcare)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “14?initialized”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (sub-record-check,s,10)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “Recordings initialized”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(ARG3=dontcare)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/sip-trunk.telekom.de-00000008”, “REC_POLICY_MODE_SAVE=”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(REC_STATUS=NO)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “2?checkaction”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?sub-record-check,rg,1”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:18] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “Generic rg Recording Check - +49YYYYYYYYYY 0”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:19] Gosub(“SIP/sip-trunk.telekom.de-00000008”, “recordcheck,1(dontcare,rg,0)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/sip-trunk.telekom.de-00000008”, “Starting recording check against dontcare”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/sip-trunk.telekom.de-00000008”, “dontcare”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@sub-record-check:20] Return(“SIP/sip-trunk.telekom.de-00000008”, “”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:13] Set(“SIP/sip-trunk.telekom.de-00000008”, “RingGroupMethod=memoryhunt”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:14] Set(“SIP/sip-trunk.telekom.de-00000008”, “__ALT_CONFIRM_MSG=”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:15] GotoIf(“SIP/sip-trunk.telekom.de-00000008”, “0?RGVQANNOUNCE:NORGVQANNOUNCE”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx_builtins.c: Goto (ext-group,0,18)
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [0@ext-group:18] Macro(“SIP/sip-trunk.telekom.de-00000008”, “dial,15,HhTtrc,11-23-22-13-17-31-32-36-33-39”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-dial:1] NoOp(“SIP/sip-trunk.telekom.de-00000008”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-dial:2] Set(“SIP/sip-trunk.telekom.de-00000008”, “__CRM_SOURCE=+49YYYYYYYYYYY”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-dial:3] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(ALERT_INFO=)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-dial:4] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(ALERT_INFO=)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-dial:5] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(ALERT_INFO=)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-dial:6] ExecIf(“SIP/sip-trunk.telekom.de-00000008”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2019-01-06 14:44:13] VERBOSE[107825][C-00000007] pbx.c: Executing [s@macro-dial:7] AGI(“SIP/sip-trunk.telekom.de-00000008”, “dialparties.agi”) in new stack
[2019-01-06 14:44:14] VERBOSE[107825][C-00000007] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2019-01-06 14:44:14] VERBOSE[107825][C-00000007] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2019-01-06 14:44:14] VERBOSE[107825][C-00000007] res_agi.c: dialparties.agi: Caller ID name is ‘+49YYYYYYYYYYY’ number is ‘+49YYYYYYYYYYY’
[2019-01-06 14:44:14] VERBOSE[107825][C-00000007] res_agi.c: dialparties.agi: CW Ignore is:
[2019-01-06 14:44:14] VERBOSE[107825][C-00000007] res_agi.c: dialparties.agi: CF Ignore is:
[2019-01-06 14:44:14] VERBOSE[107825][C-00000007] res_agi.c: dialparties.agi: CW IN_USE/BUSY is: 1
[2019-01-06 14:44:14] VERBOSE[107825][C-00000007] res_agi.c: dialparties.agi: Methodology of ring is ‘memoryhunt’

Stewart1 · January 6, 2019, 3:33pm

I am guessing that the trunking provider is sending calls from more than one IP address, of which only one matches your trunk. Are you using DNS SRV (which chan_sip handles poorly)? Or, are there multiple A records?

You can use
sip set debug on
at the Asterisk command prompt to see the address from which incoming calls are sent.

If this is your issue, I would recommend a pjsip trunk, though you could add additional chan_sip trunks, one for each source IP address that Telekom is using.

I’m also concerned about the unreachable warning. What is the qualify setting for the trunk?

Please explain the general trunk setup. Does it use registration? If so, post your register string (masking username and password). If IP authentication, Telekom should have supplied you with a list of their source IP addresses.

Trunk · January 6, 2019, 5:16pm

My trunk settings are:

Outgoing SIP settings:

Trunk Name: Telekom.de-49XXXXXXXX
Peer Details:
username=UUUUUUUUUUUU
usereqphone=yes
type=peer
transport=tcp
srvlookup=yes
session-timers=refuse
secret=PPPPPPPP
qualify=yes
insecure=port,invite
host=reg.sip-trunk.telekom .de
fromdomain=sip-trunk.telekom. de
dtmfmode=rfc2833
directmedia=no
defaultuser=UUUUUUUUUUUU
disallow=all
allow=g722,alaw,ulaw,g726,gsm
context=from-pstn-toheader

Incoming SIP settings:
User context: UUUUUUUUUUUU
User Details:
usereqphone=yes
type=peer
transport=tcp
srvlookup=yes
session-timers=refuse
secret=PPPPPPPP
qualify=yes
insecure=port,invite
host=reg . sip-trunk . telekom . de
fromdomain=sip-trunk . telekom . de
dtmfmode=rfc2833
directmedia=no
defaultuser=UUUUUUUUUUUU
disallow=all
allow=g722,alaw,ulaw,g726,gsm
context=from-pstn-toheader
Register String: tcp://+49XXXXXXXX@sip-trunk . telekom . de:PPPPPPPP:[email protected] . telekom . de:5060~300

In Settings - Asterisk-SIP-Settings - Chan-SIP-settings
Registration Timeout: 20
Registration Minimum Expiry: 60
Registration Maximum Expiry: 3600
Registration Default Expiry = 120
Enable SRV Lookup: yes
activate TCP: yes

“sip show settings” in asterisk CLI reports Qualify Freq = 60000ms

Telekom didn’t supply any list of their IP-addresses. They only supplied:
Username: UUUUUUUUUUUU
Password: PPPPPPPP
Outbound-Proxy: reg . sip-trunk.telekom . de
Registrar: sip-trunk . telekom . de

I’m sorry, i had to write space dot space because i’m not allowed to post links. These additional spaces are not in the configurations.

Stewart1 · January 6, 2019, 5:42pm

OK, so it appears that there are three servers:

> set type=SRV
> _sip._tcp.reg.sip-trunk.telekom.de
Server:  google-public-dns-a.google.com
Address:  8.8.8.8

Non-authoritative answer:
_sip._tcp.reg.sip-trunk.telekom.de      SRV service location:
          priority       = 10
          weight         = 5
          port           = 5060
          svr hostname   = d-ipr-a01.sip-trunk.telekom.de
_sip._tcp.reg.sip-trunk.telekom.de      SRV service location:
          priority       = 0
          weight         = 5
          port           = 5060
          svr hostname   = n-ipr-a01.sip-trunk.telekom.de
_sip._tcp.reg.sip-trunk.telekom.de      SRV service location:
          priority       = 1
          weight         = 5
          port           = 5060
          svr hostname   = n-ipr-a02.sip-trunk.telekom.de
>

chan_sip will only recognize one (at a time) and if an INVITE comes in from a different one, it won’t match your trunk and will be treated as an anonymous caller.

Assuming that your testing shows that you are indeed getting calls from multiple addresses, you can either switch to a pjsip trunk, or set up three dummy chan_sip trunks, using
host=d-ipr-a01.sip-trunk.telekom.de
host=n-ipr-a01.sip-trunk.telekom.de
and
host=n-ipr-a02.sip-trunk.telekom.de

Each should have
context=from-pstn-toheader
insecure=port,invite
codec settings, etc. but no registration and don’t route any outbound calls to them.

Or, find out why changing the default context isn’t working properly (using a more verbose log).

Trunk · January 7, 2019, 4:42pm

You are right. I set sip debug on, did some test calls and investigated the log. Indeed I found two different IP addresses. I resolved the IP addresses of the three Telekom Servers above and one of them matched one of the Two addresses in the log. The other address in the log did not match any of these servers but it also belongs to the network 217.0.0.0/13 which is owned by Telekom.

I deactivated the Chan_SIP-Trunk and added a PJSIP-Trunk to Telekom yesterday evening and it worked. Today in the business hours there were many incoming and outgoing calls and no more issues were observed. I think this problem is solved.

Thank you very much for your help.

system · January 14, 2019, 4:42pm

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