Call hang up after less than a minute

lobu · July 31, 2025, 11:41am

I have 2 Grandstream GXP1625 and 2 SNOM 300 phones connected to FreePBX 17/Asterisk 20 installed on Debian 12. Asterisk in turn sets a pjsip trunk. FreePBX has only the opensource modules.

I experience systematic call hang up after less than a minute. This happens for both incoming and outgoing calls.
The following is the log I get from FreePBX of an hung up call (I covered sensitive data), that I personally find very cryptic:

13:48 pbx.c: [nnnnnnnnnnn@from-pstn:1] NoOp("PJSIP/X-0000000a", "Catch-All DID Match - Found nnnnnnnnnnn - You probably want a DID for this.") in new stack
13:48 pbx.c: [nnnnnnnnnnn@from-pstn:2] Set("PJSIP/X-0000000a", "__FROM_DID=nnnnnnnnnnn") in new stack
13:48 pbx.c: [nnnnnnnnnnn@from-pstn:3] Goto("PJSIP/X-0000000a", "ext-did,s,1") in new stack
13:48 pbx_builtins.c: Goto (ext-did,s,1)
13:48 pbx.c: [s@ext-did:1] Set("PJSIP/X-0000000a", "__DIRECTION=INBOUND") in new stack
13:48 pbx.c: [s@ext-did:2] Set("PJSIP/X-0000000a", "CHANNEL(tonezone)=it") in new stack
13:48 pbx.c: [s@ext-did:3] ExecIf("PJSIP/X-0000000a", "0?Set(__FROM_DID=s)") in new stack
13:48 pbx.c: [s@ext-did:4] Set("PJSIP/X-0000000a", "returnhere=1") in new stack
13:48 pbx.c: [s@ext-did:5] Gosub("PJSIP/X-0000000a", "app-blacklist-check,s,1()") in new stack
13:48 pbx.c: [s@app-blacklist-check:1] GotoIf("PJSIP/X-0000000a", "0?blacklisted") in new stack
13:48 pbx.c: [s@app-blacklist-check:2] Set("PJSIP/X-0000000a", "CALLED_BLACKLIST=1") in new stack
13:48 pbx.c: [s@app-blacklist-check:3] Return("PJSIP/X-0000000a", "") in new stack
13:48 pbx.c: [s@ext-did:6] Set("PJSIP/X-0000000a", "CDR(did)=nnnnnnnnnnn") in new stack
13:48 pbx.c: [s@ext-did:7] GotoIf("PJSIP/X-0000000a", "0?") in new stack
13:48 pbx.c: [s@ext-did:8] ExecIf("PJSIP/X-0000000a", "0 ?Set(CALLERID(name)=llllllllll)") in new stack
13:48 pbx.c: [s@ext-did:9] Set("PJSIP/X-0000000a", "__MOHCLASS=") in new stack
13:48 pbx.c: [s@ext-did:10] Set("PJSIP/X-0000000a", "__REVERSAL_REJECT=FALSE") in new stack
13:48 pbx.c: [s@ext-did:11] GotoIf("PJSIP/X-0000000a", "1?post-reverse-charge") in new stack
13:48 pbx_builtins.c: Goto (ext-did,s,13)
13:48 pbx.c: [s@ext-did:13] NoOp("PJSIP/X-0000000a", "") in new stack
13:48 pbx.c: [s@ext-did:14] Set("PJSIP/X-0000000a", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
13:48 pbx.c: [s@ext-did:15] Set("PJSIP/X-0000000a", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
13:48 pbx.c: [s@ext-did:16] Set("PJSIP/X-0000000a", "CALLERID(name-pres)=allowed_not_screened") in new stack
13:48 pbx.c: [s@ext-did:17] Set("PJSIP/X-0000000a", "CALLERID(num-pres)=allowed_not_screened") in new stack
13:48 pbx.c: [s@ext-did:18] NoOp("PJSIP/X-0000000a", "CallerID Entry Point") in new stack
13:48 pbx.c: [s@ext-did:19] Goto("PJSIP/X-0000000a", "ext-group,600,1") in new stack
13:48 pbx_builtins.c: Goto (ext-group,600,1)
13:48 pbx.c: [600@ext-group:1] GotoIf("PJSIP/X-0000000a", "0?cid") in new stack
13:48 pbx.c: [600@ext-group:2] Set("PJSIP/X-0000000a", "__MCGROUP=600") in new stack
13:48 pbx.c: [600@ext-group:3] PlayTones("PJSIP/X-0000000a", "ring") in new stack
13:48 pbx.c: [600@ext-group:4] Progress("PJSIP/X-0000000a", "") in new stack
13:48 pbx.c: [600@ext-group:5] Gosub("PJSIP/X-0000000a", "macro-user-callerid,s,1()") in new stack
13:48 pbx.c: [s@macro-user-callerid:1] Set("PJSIP/X-0000000a", "TOUCH_MONITOR=1753953228.10") in new stack
13:48 pbx.c: [s@macro-user-callerid:2] Set("PJSIP/X-0000000a", "CHANCONTEXT=") in new stack
13:48 pbx.c: [s@macro-user-callerid:3] Set("PJSIP/X-0000000a", "CHANCONTEXT=") in new stack
13:48 pbx.c: [s@macro-user-callerid:4] Set("PJSIP/X-0000000a", "CHANEXTENCONTEXT=X-0000000a") in new stack
13:48 pbx.c: [s@macro-user-callerid:5] Set("PJSIP/X-0000000a", "CHANEXTEN=X-0000000a") in new stack
13:48 pbx.c: [s@macro-user-callerid:6] Set("PJSIP/X-0000000a", "CALLERID(number)=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:7] Set("PJSIP/X-0000000a", "AMPUSER=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:8] Set("PJSIP/X-0000000a", "HOTDESCKCHAN=X-0000000a") in new stack
13:48 pbx.c: [s@macro-user-callerid:9] Set("PJSIP/X-0000000a", "HOTDESKEXTEN=X") in new stack
13:48 pbx.c: [s@macro-user-callerid:10] Set("PJSIP/X-0000000a", "HOTDESKCALL=0") in new stack
13:48 pbx.c: [s@macro-user-callerid:11] ExecIf("PJSIP/X-0000000a", "0?Set(HOTDESKCALL=1)") in new stack
13:48 pbx.c: [s@macro-user-callerid:12] ExecIf("PJSIP/X-0000000a", "0?Set(CALLERID(name)=)") in new stack
13:48 pbx.c: [s@macro-user-callerid:13] GotoIf("PJSIP/X-0000000a", "0?report") in new stack
13:48 pbx.c: [s@macro-user-callerid:14] ExecIf("PJSIP/X-0000000a", "1?Set(REALCALLERIDNUM=llllllllll)") in new stack
13:48 pbx.c: [s@macro-user-callerid:15] Set("PJSIP/X-0000000a", "AMPUSER=") in new stack
13:48 pbx.c: [s@macro-user-callerid:16] GotoIf("PJSIP/X-0000000a", "0?limit") in new stack
13:48 pbx.c: [s@macro-user-callerid:17] Set("PJSIP/X-0000000a", "AMPUSERCIDNAME=") in new stack
13:48 pbx.c: [s@macro-user-callerid:18] ExecIf("PJSIP/X-0000000a", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
13:48 pbx.c: [s@macro-user-callerid:19] GotoIf("PJSIP/X-0000000a", "1?report") in new stack
13:48 pbx_builtins.c: Goto (macro-user-callerid,s,28)
13:48 pbx.c: [s@macro-user-callerid:28] NoOp("PJSIP/X-0000000a", "Macro depricated!! To keep the same line numbers") in new stack
13:48 pbx.c: [s@macro-user-callerid:29] NoOp("PJSIP/X-0000000a", "Macro depricated !!  To keep the same line numbers") in new stack
13:48 pbx.c: [s@macro-user-callerid:30] GotoIf("PJSIP/X-0000000a", "0?continue") in new stack
13:48 pbx.c: [s@macro-user-callerid:31] ExecIf("PJSIP/X-0000000a", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
13:48 pbx.c: [s@macro-user-callerid:32] Set("PJSIP/X-0000000a", "__TTL=64") in new stack
13:48 pbx.c: [s@macro-user-callerid:33] GotoIf("PJSIP/X-0000000a", "1?continue") in new stack
13:48 pbx_builtins.c: Goto (macro-user-callerid,s,49)
13:48 pbx.c: [s@macro-user-callerid:49] Set("PJSIP/X-0000000a", "CALLERID(number)=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:50] Set("PJSIP/X-0000000a", "CALLERID(name)=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:51] GotoIf("PJSIP/X-0000000a", "0?cnum") in new stack
13:48 pbx.c: [s@macro-user-callerid:52] Set("PJSIP/X-0000000a", "__MCNUM=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:53] Set("PJSIP/X-0000000a", "__MCNAME=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:54] Set("PJSIP/X-0000000a", "__MCEXTEN=") in new stack
13:48 pbx.c: [s@macro-user-callerid:55] Set("PJSIP/X-0000000a", "__MCORGCHAN=PJSIP/X-0000000a") in new stack
13:48 pbx.c: [s@macro-user-callerid:56] Set("PJSIP/X-0000000a", "CDR(cnam)=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:57] Set("PJSIP/X-0000000a", "CDR(cnum)=llllllllll") in new stack
13:48 pbx.c: [s@macro-user-callerid:58] Return("PJSIP/X-0000000a", "") in new stack
13:48 pbx.c: [600@ext-group:6] Gosub("PJSIP/X-0000000a", "macro-blkvm-setifempty,s,1()") in new stack
13:48 pbx.c: [s@macro-blkvm-setifempty:1] GotoIf("PJSIP/X-0000000a", "1?init") in new stack
13:48 pbx_builtins.c: Goto (macro-blkvm-setifempty,s,4)
13:48 pbx.c: [s@macro-blkvm-setifempty:4] Set("PJSIP/X-0000000a", "__BLKVM_CHANNEL=PJSIP/X-0000000a") in new stack
13:48 pbx.c: [s@macro-blkvm-setifempty:5] Set("PJSIP/X-0000000a", "SHARED(BLKVM,PJSIP/X-0000000a)=TRUE") in new stack
13:48 pbx.c: [s@macro-blkvm-setifempty:6] Set("PJSIP/X-0000000a", "GOSUB_RETVAL=TRUE") in new stack
13:48 pbx.c: [s@macro-blkvm-setifempty:7] Return("PJSIP/X-0000000a", "TRUE") in new stack
13:48 pbx.c: [600@ext-group:7] GotoIf("PJSIP/X-0000000a", "1?skipov") in new stack
13:48 pbx_builtins.c: Goto (ext-group,600,10)
13:48 pbx.c: [600@ext-group:10] Set("PJSIP/X-0000000a", "RRNODEST=") in new stack
13:48 pbx.c: [600@ext-group:11] Set("PJSIP/X-0000000a", "__NODEST=600") in new stack
13:48 pbx.c: [600@ext-group:12] GosubIf("PJSIP/X-0000000a", "0?sub-rgsetcid,s,1()") in new stack
13:48 pbx.c: [600@ext-group:13] Gosub("PJSIP/X-0000000a", "sub-record-check,s,1(rg,600,dontcare)") in new stack
13:48 pbx.c: [s@sub-record-check:1] GotoIf("PJSIP/X-0000000a", "0?initialized") in new stack
13:48 pbx.c: [s@sub-record-check:2] Set("PJSIP/X-0000000a", "__REC_STATUS=INITIALIZED") in new stack
13:48 pbx.c: [s@sub-record-check:3] Set("PJSIP/X-0000000a", "NOW=1753953228") in new stack
13:48 pbx.c: [s@sub-record-check:4] Set("PJSIP/X-0000000a", "__DAY=31") in new stack
13:48 pbx.c: [s@sub-record-check:5] Set("PJSIP/X-0000000a", "__MONTH=07") in new stack
13:48 pbx.c: [s@sub-record-check:6] Set("PJSIP/X-0000000a", "__YEAR=2025") in new stack
13:48 pbx.c: [s@sub-record-check:7] Set("PJSIP/X-0000000a", "__TIMESTR=20250731-111348") in new stack
13:48 pbx.c: [s@sub-record-check:8] Set("PJSIP/X-0000000a", "__FROMEXTEN=llllllllll") in new stack
13:48 pbx.c: [s@sub-record-check:9] Set("PJSIP/X-0000000a", "__MON_FMT=wav") in new stack
13:48 pbx.c: [s@sub-record-check:10] NoOp("PJSIP/X-0000000a", "Recordings initialized") in new stack
13:48 pbx.c: [s@sub-record-check:11] ExecIf("PJSIP/X-0000000a", "0?Set(ARG3=dontcare)") in new stack
13:48 pbx.c: [s@sub-record-check:12] Set("PJSIP/X-0000000a", "REC_POLICY_MODE_SAVE=") in new stack
13:48 pbx.c: [s@sub-record-check:13] ExecIf("PJSIP/X-0000000a", "0?Set(REC_STATUS=NO)") in new stack
13:48 pbx.c: [s@sub-record-check:14] GotoIf("PJSIP/X-0000000a", "2?checkaction") in new stack
13:48 pbx_builtins.c: Goto (sub-record-check,s,17)
13:48 pbx.c: [s@sub-record-check:17] GotoIf("PJSIP/X-0000000a", "0?sub-record-check,rg,1") in new stack
13:48 pbx.c: [s@sub-record-check:18] NoOp("PJSIP/X-0000000a", "Generic rg Recording Check - llllllllll 600") in new stack
13:48 pbx.c: [s@sub-record-check:19] Gosub("PJSIP/X-0000000a", "recordcheck,1(dontcare,rg,600)") in new stack
13:48 pbx.c: [recordcheck@sub-record-check:1] NoOp("PJSIP/X-0000000a", "Starting recording check against dontcare") in new stack
13:48 pbx.c: [recordcheck@sub-record-check:2] Goto("PJSIP/X-0000000a", "dontcare") in new stack
13:48 pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
13:48 pbx.c: [recordcheck@sub-record-check:3] Return("PJSIP/X-0000000a", "") in new stack
13:48 pbx.c: [s@sub-record-check:20] Return("PJSIP/X-0000000a", "") in new stack
13:48 pbx.c: [600@ext-group:14] Set("PJSIP/X-0000000a", "RingGroupMethod=ringall") in new stack
13:48 pbx.c: [600@ext-group:15] Set("PJSIP/X-0000000a", "__ALT_CONFIRM_MSG=") in new stack
13:48 pbx.c: [600@ext-group:16] GotoIf("PJSIP/X-0000000a", "0?RGVQANNOUNCE:NORGVQANNOUNCE") in new stack
13:48 pbx_builtins.c: Goto (ext-group,600,19)
13:48 pbx.c: [600@ext-group:19] Gosub("PJSIP/X-0000000a", "macro-dial,s,1(20,HhTtrQ(NO_ANSWER),200-201-215-216)") in new stack
13:48 pbx.c: [s@macro-dial:1] NoOp("PJSIP/X-0000000a", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
13:48 pbx.c: [s@macro-dial:2] ExecIf("PJSIP/X-0000000a", "0?Set(ALERT_INFO=)") in new stack
13:48 pbx.c: [s@macro-dial:3] ExecIf("PJSIP/X-0000000a", "0?Set(ALERT_INFO=)") in new stack
13:48 pbx.c: [s@macro-dial:4] ExecIf("PJSIP/X-0000000a", "0?Set(ALERT_INFO=)") in new stack
13:48 pbx.c: [s@macro-dial:5] ExecIf("PJSIP/X-0000000a", "0?Set(CHANNEL(musicclass)=)") in new stack
13:48 pbx.c: [s@macro-dial:6] AGI("PJSIP/X-0000000a", "agi://127.0.0.1/dialparties.agi") in new stack
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Starting New Dialparties.agi
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Caller ID name is 'llllllllll' number is 'llllllllll'
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: CW Ignore is: 
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: CF Ignore is: 
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: CW IN_USE/BUSY is: 1
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Ringgroup confirm is  : 
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Methodology of ring is  'ringall'
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 200 to extension map
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 201 to extension map
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 215 to extension map
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 216 to extension map
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 200 cf is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 201 cf is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 215 cf is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 216 cf is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 200 do not disturb is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 201 do not disturb is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 215 do not disturb is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 216 do not disturb is disabled
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/200
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with real PJSIP Dial string PJSIP/200/sip:[email protected]:5062
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/200 to llllllllll
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/201
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with no PJSIP contacts
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/201 to llllllllll
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/215
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with real PJSIP Dial string PJSIP/215/sip:[email protected]:5062
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/215 to llllllllll
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/216
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with real PJSIP Dial string PJSIP/216/sip:[email protected]:2048
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/216 to llllllllll
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: Filtered ARG3: 200-201-215-216
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: RVOL_MODE '' 
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: RVOL is: 
13:49 res_agi.c: agi://127.0.0.1/dialparties.agi: RVOLPARENT is: 
13:49 res_agi.c: <PJSIP/X-0000000a>AGI Script agi://127.0.0.1/dialparties.agi completed, returning 0
13:49 pbx.c: [s@macro-dial:7] GotoIf("PJSIP/X-0000000a", "1?normdial") in new stack
13:49 pbx_builtins.c: Goto (macro-dial,s,10)
13:49 pbx.c: [s@macro-dial:10] NoOp("PJSIP/X-0000000a", "Returned from dialparties with groups to dial") in new stack
13:49 pbx.c: [s@macro-dial:11] NoOp("PJSIP/X-0000000a", "ringall array  ") in new stack
13:49 pbx.c: [s@macro-dial:12] NoOp("PJSIP/X-0000000a", "ds= PJSIP/200/sip:[email protected]:5062&PJSIP/215/sip:[email protected]:5062&PJSIP/216/sip:[email protected]:2048,20,HhtrQ(NO_ANSWER)U(macro-auto-blkvm) ") in new stack
13:49 pbx.c: [s@macro-dial:13] NoOp("PJSIP/X-0000000a", "dsextra= ") in new stack
13:49 pbx.c: [s@macro-dial:14] Set("PJSIP/X-0000000a", "ds=PJSIP/200/sip:[email protected]:5062&PJSIP/215/sip:[email protected]:5062&PJSIP/216/sip:[email protected]:2048,20,HhtrQ(NO_ANSWER)U(macro-auto-blkvm)") in new stack
13:49 pbx.c: [s@macro-dial:15] NoOp("PJSIP/X-0000000a", "ds= PJSIP/200/sip:[email protected]:5062&PJSIP/215/sip:[email protected]:5062&PJSIP/216/sip:[email protected]:2048,20,HhtrQ(NO_ANSWER)U(macro-auto-blkvm)") in new stack
13:49 pbx.c: [s@macro-dial:16] Set("PJSIP/X-0000000a", "__FMGL_DIAL=") in new stack
13:49 pbx.c: [s@macro-dial:17] Set("PJSIP/X-0000000a", "LOOPCNT=4") in new stack
13:49 pbx.c: [s@macro-dial:18] Set("PJSIP/X-0000000a", "ITER=1") in new stack
13:49 pbx.c: [s@macro-dial:19] Set("PJSIP/X-0000000a", "__EXTTOCALL=200") in new stack
13:49 pbx.c: [s@macro-dial:20] Set("PJSIP/X-0000000a", "__MCEXTTOCALL=200") in new stack
13:49 pbx.c: [s@macro-dial:21] NoOp("PJSIP/X-0000000a", "Working with 200") in new stack
13:49 pbx.c: [s@macro-dial:22] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:23] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:24] Set("PJSIP/X-0000000a", "ITER=2") in new stack
13:49 pbx.c: [s@macro-dial:25] GotoIf("PJSIP/X-0000000a", "1?ndloopbegin") in new stack
13:49 pbx_builtins.c: Goto (macro-dial,s,19)
13:49 pbx.c: [s@macro-dial:19] Set("PJSIP/X-0000000a", "__EXTTOCALL=201") in new stack
13:49 pbx.c: [s@macro-dial:20] Set("PJSIP/X-0000000a", "__MCEXTTOCALL=201") in new stack
13:49 pbx.c: [s@macro-dial:21] NoOp("PJSIP/X-0000000a", "Working with 201") in new stack
13:49 pbx.c: [s@macro-dial:22] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:23] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:24] Set("PJSIP/X-0000000a", "ITER=3") in new stack
13:49 pbx.c: [s@macro-dial:25] GotoIf("PJSIP/X-0000000a", "1?ndloopbegin") in new stack
13:49 pbx_builtins.c: Goto (macro-dial,s,19)
13:49 pbx.c: [s@macro-dial:19] Set("PJSIP/X-0000000a", "__EXTTOCALL=215") in new stack
13:49 pbx.c: [s@macro-dial:20] Set("PJSIP/X-0000000a", "__MCEXTTOCALL=215") in new stack
13:49 pbx.c: [s@macro-dial:21] NoOp("PJSIP/X-0000000a", "Working with 215") in new stack
13:49 pbx.c: [s@macro-dial:22] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:23] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:24] Set("PJSIP/X-0000000a", "ITER=4") in new stack
13:49 pbx.c: [s@macro-dial:25] GotoIf("PJSIP/X-0000000a", "1?ndloopbegin") in new stack
13:49 pbx_builtins.c: Goto (macro-dial,s,19)
13:49 pbx.c: [s@macro-dial:19] Set("PJSIP/X-0000000a", "__EXTTOCALL=216") in new stack
13:49 pbx.c: [s@macro-dial:20] Set("PJSIP/X-0000000a", "__MCEXTTOCALL=216") in new stack
13:49 pbx.c: [s@macro-dial:21] NoOp("PJSIP/X-0000000a", "Working with 216") in new stack
13:49 pbx.c: [s@macro-dial:22] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:23] ExecIf("PJSIP/X-0000000a", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
13:49 pbx.c: [s@macro-dial:24] Set("PJSIP/X-0000000a", "ITER=5") in new stack
13:49 pbx.c: [s@macro-dial:25] GotoIf("PJSIP/X-0000000a", "0?ndloopbegin") in new stack
13:49 pbx.c: [s@macro-dial:26] Gosub("PJSIP/X-0000000a", "macro-dial-ringall-predial-hook,s,1()") in new stack
13:49 pbx.c: [s@macro-dial-ringall-predial-hook:1] Return("PJSIP/X-0000000a", "") in new stack
13:49 pbx.c: [s@macro-dial:27] ExecIf("PJSIP/X-0000000a", "0?Set(CWRING=r(callwaiting)):Set(CWRING=)") in new stack
13:49 pbx.c: [s@macro-dial:28] ExecIf("PJSIP/X-0000000a", "0?Set(RGFMDIAL=216):Set(RGFMDIAL=600)") in new stack
13:49 pbx.c: [s@macro-dial:29] ExecIf("PJSIP/X-0000000a", "0?Set(ds=PJSIP/200/sip:[email protected]:5062&PJSIP/215/sip:[email protected]:5062&PJSIP/216/sip:[email protected]:2048,20,HhtrQ(NO_ANSWER)U(macro-auto-blkvm)g)") in new stack
13:49 pbx.c: [s@macro-dial:30] Gosub("PJSIP/X-0000000a", "dial-with-exten,600,1()") in new stack
13:49 pbx.c: [600@dial-with-exten:1] Dial("PJSIP/X-0000000a", "PJSIP/200/sip:[email protected]:5062&PJSIP/215/sip:[email protected]:5062&PJSIP/216/sip:[email protected]:2048,20,HhtrQ(NO_ANSWER)U(macro-auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
13:49 app_stack.c: PJSIP/200-0000000b Internal Gosub(func-apply-sipheaders,s,1) start
13:49 pbx.c: [s@func-apply-sipheaders:1] NoOp("PJSIP/200-0000000b", "Applying SIP Headers to channel PJSIP/200-0000000b") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:2] Set("PJSIP/200-0000000b", "localchan=200-0000000b") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:3] Set("PJSIP/200-0000000b", "DialMCEXT=200") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:4] Set("PJSIP/200-0000000b", "CHANNEL(hangup_handler_push)=app-missedcall-hangup,200,1") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:5] Set("PJSIP/200-0000000b", "Dchan=200-0000000b") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:6] Set("PJSIP/200-0000000b", "TECH=PJSIP") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:7] Set("PJSIP/200-0000000b", "SIPHEADERKEYS=") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:8] While("PJSIP/200-0000000b", "0") in new stack
13:49 app_while.c: Jumping to priority 14
13:49 pbx.c: [s@func-apply-sipheaders:15] Return("PJSIP/200-0000000b", "") in new stack
13:49 app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on 'PJSIP/200-0000000b'
13:49 app_stack.c: PJSIP/200-0000000b Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
13:49 app_stack.c: PJSIP/215-0000000c Internal Gosub(func-apply-sipheaders,s,1) start
13:49 pbx.c: [s@func-apply-sipheaders:1] NoOp("PJSIP/215-0000000c", "Applying SIP Headers to channel PJSIP/215-0000000c") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:2] Set("PJSIP/215-0000000c", "localchan=215-0000000c") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:3] Set("PJSIP/215-0000000c", "DialMCEXT=215") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:4] Set("PJSIP/215-0000000c", "CHANNEL(hangup_handler_push)=app-missedcall-hangup,215,1") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:5] Set("PJSIP/215-0000000c", "Dchan=215-0000000c") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:6] Set("PJSIP/215-0000000c", "TECH=PJSIP") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:7] Set("PJSIP/215-0000000c", "SIPHEADERKEYS=") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:8] While("PJSIP/215-0000000c", "0") in new stack
13:49 app_while.c: Jumping to priority 14
13:49 pbx.c: [s@func-apply-sipheaders:15] Return("PJSIP/215-0000000c", "") in new stack
13:49 app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on 'PJSIP/215-0000000c'
13:49 app_stack.c: PJSIP/215-0000000c Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
13:49 app_stack.c: PJSIP/216-0000000d Internal Gosub(func-apply-sipheaders,s,1) start
13:49 pbx.c: [s@func-apply-sipheaders:1] NoOp("PJSIP/216-0000000d", "Applying SIP Headers to channel PJSIP/216-0000000d") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:2] Set("PJSIP/216-0000000d", "localchan=216-0000000d") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:3] Set("PJSIP/216-0000000d", "DialMCEXT=216") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:4] Set("PJSIP/216-0000000d", "CHANNEL(hangup_handler_push)=app-missedcall-hangup,216,1") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:5] Set("PJSIP/216-0000000d", "Dchan=216-0000000d") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:6] Set("PJSIP/216-0000000d", "TECH=PJSIP") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:7] Set("PJSIP/216-0000000d", "SIPHEADERKEYS=") in new stack
13:49 pbx.c: [s@func-apply-sipheaders:8] While("PJSIP/216-0000000d", "0") in new stack
13:49 app_while.c: Jumping to priority 14
13:49 pbx.c: [s@func-apply-sipheaders:15] Return("PJSIP/216-0000000d", "") in new stack
13:49 app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on 'PJSIP/216-0000000d'
13:49 app_stack.c: PJSIP/216-0000000d Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
13:49 netsock2.c: Using SIP RTP Audio TOS bits 184
13:49 netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
13:49 netsock2.c: Using SIP RTP Audio CoS mark 5
13:49 app_dial.c: Called PJSIP/200/sip:[email protected]:5062
13:49 netsock2.c: Using SIP RTP Audio TOS bits 184
13:49 netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
13:49 netsock2.c: Using SIP RTP Audio CoS mark 5
13:49 app_dial.c: Called PJSIP/215/sip:[email protected]:5062
13:49 netsock2.c: Using SIP RTP Audio TOS bits 184
13:49 netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
13:49 netsock2.c: Using SIP RTP Audio CoS mark 5
13:49 app_dial.c: Called PJSIP/216/sip:[email protected]:2048
13:49 app_dial.c: PJSIP/215-0000000c connected line has changed. Saving it until answer for PJSIP/X-0000000a
13:49 app_dial.c: PJSIP/215-0000000c is ringing
13:49 app_stack.c: PJSIP/216-0000000d Internal Gosub(app-missedcall-hangup,216,1) start
13:49 pbx.c: [216@app-missedcall-hangup:1] NoOp("PJSIP/216-0000000d", "Dialed: 216") in new stack
13:49 pbx.c: [216@app-missedcall-hangup:2] NoOp("PJSIP/216-0000000d", "Caller: ") in new stack
13:49 pbx.c: [216@app-missedcall-hangup:3] GotoIf("PJSIP/216-0000000d", "0?exit") in new stack
13:49 pbx.c: [216@app-missedcall-hangup:4] Set("PJSIP/216-0000000d", "EXTENNUM=216") in new stack
13:49 pbx.c: [216@app-missedcall-hangup:5] Set("PJSIP/216-0000000d", "FEXTENNUM=216") in new stack
13:49 pbx.c: [216@app-missedcall-hangup:6] GotoIf("PJSIP/216-0000000d", "1?exit") in new stack
13:49 pbx_builtins.c: Goto (app-missedcall-hangup,216,8)
13:49 pbx.c: [216@app-missedcall-hangup:8] Return("PJSIP/216-0000000d", "") in new stack
13:49 app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on 'PJSIP/216-0000000d'
13:49 app_stack.c: PJSIP/216-0000000d Internal Gosub(app-missedcall-hangup,216,1) complete GOSUB_RETVAL=
13:52 app_dial.c: PJSIP/215-0000000c answered PJSIP/X-0000000a
13:52 app_stack.c: PJSIP/200-0000000b Internal Gosub(app-missedcall-hangup,200,1) start
13:52 pbx.c: [200@app-missedcall-hangup:1] NoOp("PJSIP/200-0000000b", "Dialed: 200") in new stack
13:52 pbx.c: [200@app-missedcall-hangup:2] NoOp("PJSIP/200-0000000b", "Caller: ") in new stack
13:52 pbx.c: [200@app-missedcall-hangup:3] GotoIf("PJSIP/200-0000000b", "0?exit") in new stack
13:52 pbx.c: [200@app-missedcall-hangup:4] Set("PJSIP/200-0000000b", "EXTENNUM=200") in new stack
13:52 pbx.c: [200@app-missedcall-hangup:5] Set("PJSIP/200-0000000b", "FEXTENNUM=200") in new stack
13:52 pbx.c: [200@app-missedcall-hangup:6] GotoIf("PJSIP/200-0000000b", "1?exit") in new stack
13:52 pbx_builtins.c: Goto (app-missedcall-hangup,200,8)
13:52 pbx.c: [200@app-missedcall-hangup:8] Return("PJSIP/200-0000000b", "") in new stack
13:52 app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on 'PJSIP/200-0000000b'
13:52 app_stack.c: PJSIP/200-0000000b Internal Gosub(app-missedcall-hangup,200,1) complete GOSUB_RETVAL=
13:52 app_stack.c: PJSIP/215-0000000c Internal Gosub(macro-auto-blkvm,s,1) start
13:52 pbx.c: [s@macro-auto-blkvm:1] Set("PJSIP/215-0000000c", "__GOSUB_RESULT=") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:2] Set("PJSIP/215-0000000c", "CFIGNORE=") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:3] Set("PJSIP/215-0000000c", "MASTER_CHANNEL(CFIGNORE)=") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:4] Set("PJSIP/215-0000000c", "FORWARD_CONTEXT=from-internal") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:5] Set("PJSIP/215-0000000c", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:6] Gosub("PJSIP/215-0000000c", "macro-blkvm-clr,s,1()") in new stack
13:52 pbx.c: [s@macro-blkvm-clr:1] Set("PJSIP/215-0000000c", "SHARED(BLKVM,PJSIP/X-0000000a)=") in new stack
13:52 pbx.c: [s@macro-blkvm-clr:2] Set("PJSIP/215-0000000c", "GOSUB_RETVAL=") in new stack
13:52 pbx.c: [s@macro-blkvm-clr:3] Return("PJSIP/215-0000000c", "") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:7] ExecIf("PJSIP/215-0000000c", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=215/sip:[email protected]:5062)") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:8] ExecIf("PJSIP/215-0000000c", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=)") in new stack
13:52 pbx.c: [s@macro-auto-blkvm:9] Return("PJSIP/215-0000000c", "") in new stack
13:52 app_stack.c: Spawn extension (from-internal, , 1) exited non-zero on 'PJSIP/215-0000000c'
13:52 app_stack.c: PJSIP/215-0000000c Internal Gosub(macro-auto-blkvm,s,1) complete GOSUB_RETVAL=
13:52 bridge_channel.c: Channel PJSIP/215-0000000c joined 'simple_bridge' basic-bridge <2563640a-8d68-47f5-9320-7f0d0e4e83f9>
13:52 bridge_channel.c: Channel PJSIP/X-0000000a joined 'simple_bridge' basic-bridge <2563640a-8d68-47f5-9320-7f0d0e4e83f9>
14:24 bridge_channel.c: Channel PJSIP/X-0000000a left 'simple_bridge' basic-bridge <2563640a-8d68-47f5-9320-7f0d0e4e83f9>
14:24 bridge_channel.c: Channel PJSIP/215-0000000c left 'simple_bridge' basic-bridge <2563640a-8d68-47f5-9320-7f0d0e4e83f9>
14:24 app_stack.c: PJSIP/215-0000000c Internal Gosub(app-missedcall-hangup,215,1) start
14:24 pbx.c: [215@app-missedcall-hangup:1] NoOp("PJSIP/215-0000000c", "Dialed: 215") in new stack
14:24 pbx.c: [215@app-missedcall-hangup:2] NoOp("PJSIP/215-0000000c", "Caller: ") in new stack
14:24 pbx.c: [215@app-missedcall-hangup:3] GotoIf("PJSIP/215-0000000c", "0?exit") in new stack
14:24 pbx.c: [215@app-missedcall-hangup:4] Set("PJSIP/215-0000000c", "EXTENNUM=215") in new stack
14:24 pbx.c: [215@app-missedcall-hangup:5] Set("PJSIP/215-0000000c", "FEXTENNUM=215") in new stack
14:24 pbx.c: [215@app-missedcall-hangup:6] GotoIf("PJSIP/215-0000000c", "1?exit") in new stack
14:24 pbx_builtins.c: Goto (app-missedcall-hangup,215,8)
14:24 pbx.c: [215@app-missedcall-hangup:8] Return("PJSIP/215-0000000c", "") in new stack
14:24 pbx.c: Spawn extension (dial-with-exten, 600, 1) exited non-zero on 'PJSIP/X-0000000a'
14:24 pbx.c: [h@dial-with-exten:1] Gosub("PJSIP/X-0000000a", "macro-hangupcall,s,1()") in new stack
14:24 pbx.c: [s@macro-hangupcall:1] Set("PJSIP/X-0000000a", "__MCVMSTATUS=") in new stack
14:24 pbx.c: [s@macro-hangupcall:2] Gosub("PJSIP/X-0000000a", "app-missedcall-hangup,s,1()") in new stack
14:24 pbx.c: [s@app-missedcall-hangup:1] NoOp("PJSIP/X-0000000a", "Dialed: s") in new stack
14:24 app_stack.c: Spawn extension (from-internal, , 1) exited non-zero on 'PJSIP/215-0000000c'
14:24 app_stack.c: PJSIP/215-0000000c Internal Gosub(app-missedcall-hangup,215,1) complete GOSUB_RETVAL=
14:24 pbx.c: [s@app-missedcall-hangup:2] NoOp("PJSIP/X-0000000a", "Caller: ") in new stack
14:24 pbx.c: [s@app-missedcall-hangup:3] GotoIf("PJSIP/X-0000000a", "0?exit") in new stack
14:24 pbx.c: [s@app-missedcall-hangup:4] Set("PJSIP/X-0000000a", "EXTENNUM=s") in new stack
14:24 pbx.c: [s@app-missedcall-hangup:5] Set("PJSIP/X-0000000a", "FEXTENNUM=s") in new stack
14:24 pbx.c: [s@app-missedcall-hangup:6] GotoIf("PJSIP/X-0000000a", "0?exit") in new stack
14:24 pbx.c: [s@app-missedcall-hangup:7] AGI("PJSIP/X-0000000a", "agi://127.0.0.1/missedcallnotify.php,s,,s,0,,PJSIP/X-0000000a,ANSWER,,600,") in new stack
14:24 res_agi.c: <PJSIP/X-0000000a>AGI Script agi://127.0.0.1/missedcallnotify.php completed, returning 0
14:24 pbx.c: [s@app-missedcall-hangup:8] Return("PJSIP/X-0000000a", "") in new stack
14:24 pbx.c: [s@macro-hangupcall:3] GotoIf("PJSIP/X-0000000a", "1?theend") in new stack
14:24 pbx_builtins.c: Goto (macro-hangupcall,s,5)
14:24 pbx.c: [s@macro-hangupcall:5] ExecIf("PJSIP/X-0000000a", "0?Set(CDR(recordingfile)=)") in new stack
14:24 pbx.c: [s@macro-hangupcall:6] Hangup("PJSIP/X-0000000a", "") in new stack
14:24 pbx.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'PJSIP/X-0000000a'
14:32 WARNING[20209] res_pjsip_pubsub.c: No registered publish handler for event presence from 216

The full log (including the startup) is too long to be pasted here and, as new user, I cannot upload files.

Can anyone help me to understand where the issue is?

Thanks

AaronM1 · July 31, 2025, 7:25pm

Very often, this happens when either side of the call doesn’t get ACKs or responses to signaling packets after media is set up, and suspect #1 is ALG on a firewall/router.

First thing I’d check is a wire shark capture, being sure that both sides of your trunk are communicating properly after the INVITE.

airsay · July 31, 2025, 10:35pm

Is this often exactly after 32 seconds? Like previous comment, I suspect the 200 OK isn’t getting an ACK resulting in the call being torn down per SIP spec. Log in to the CLI, run sngrep, make a call, open up the INVITE and arrow down to the 200 OK. What IP address is in the Contact: header? Is it reachable from the phone calling?

david55 · August 1, 2025, 7:49am

Are these logs with standard FreePBX settings? Normal Asterisk logs give times down to the second, and, as has been pointed out, knowing whether the call drops at exactly 32 seconds is a significant piece of information. (Actually I preferred to set the logs to record to the millisecond, but I seem to remember there is some reason that one isn’t allowed to do that in FreePBX. I’m wondering if they have made an even worse decision about the time resolution.)

lobu · August 1, 2025, 7:51am

Since I am a “new user” I stripped out some information from the log to stay in the constraint of max 32000 chars per message.
In any case the resolution of the original messages was limited to seconds, as you can see in these few sample lines:

[2025-07-31 11:14:24] VERBOSE[94680][C-00000004] pbx.c: Executing [215@app-missedcall-hangup:1] NoOp("PJSIP/215-0000000c", "Dialed: 215") in new stack
[2025-07-31 11:14:24] VERBOSE[94680][C-00000004] pbx.c: Executing [215@app-missedcall-hangup:2] NoOp("PJSIP/215-0000000c", "Caller: ") in new stack
[2025-07-31 11:14:24] VERBOSE[94680][C-00000004] pbx.c: Executing [215@app-missedcall-hangup:3] GotoIf("PJSIP/215-0000000c", "0?exit") in new stack
[2025-07-31 11:14:24] VERBOSE[94680][C-00000004] pbx.c: Executing [215@app-missedcall-hangup:4] Set("PJSIP/215-0000000c", "EXTENNUM=215") in new stack
[2025-07-31 11:14:24] VERBOSE[94680][C-00000004] pbx.c: Executing [215@app-missedcall-hangup:5] Set("PJSIP/215-0000000c", "FEXTENNUM=215") in new stack
[2025-07-31 11:14:24] VERBOSE[94680][C-00000004] pbx.c: Executing [215@app-missedcall-hangup:6] GotoIf("PJSIP/215-0000000c", "1?exit") in new stack

lobu · August 1, 2025, 8:43am

Hi @airsay,
I really appreciate your help (sngrep is awesome).
I’m attaching a screenshot of the first ‘200 OK’ (I should have covered only the strictly necessary sensitive information).

In the meantime, I’ll save the sngrep log and try to figure something out myself.
Thank you so much.

david55 · August 1, 2025, 11:06am

Your SDP contains the wrong address, which is odd, as I thought that FreePBX didn’t given individual access to media and signalling addresses.

You are not receiving an ACK, which probably means the signalling address is also wrong; you have 93.189.186.198.

The media address error may get mitigated if they apply symmetric RTP.