ERROR[15042] pjproject: sip_inv.c ....Error parsing/validating SDP body: Invalid SDP origin line (PJMEDIA_SDP_EINORIGIN)

I’m having an issue with a softphone.

Channel Driver is PJSIP

Calling outbound everything works perfectly.

Inbound calling, phone rings, but immediately disconnects on answer. Received the following error in the log:

ERROR[15042] pjproject: sip_inv.c …Error parsing/validating SDP body: Invalid SDP origin line (PJMEDIA_SDP_EINORIGIN)

Using FreePBX 16.0.19

Softphone is 3CXPhone for Windows v. 6.0.26523.0

It failed to parse/validate so could be invalid, you’d need to actually provide the SIP trace using “pjsip set logger on” to see what it actually is.

Is there a way to generate the log that doesn’t have all of the gobbledygook from the other 100+ extensions on the system?

What I’m generating now is essentially unreadable because of all of the extra junk from other extensions in the mix.

You can limit it based on IP address using "pjsip set logger host ".

If the signaling is unencrypted, sngrep is a very friendly option. Virtuous Signalling

Log (1/3)

399810[2022-04-11 08:53:49] VERBOSE[32511][C-000000a9] sig_pri.c: Accepting call from ‘xxxxxxxxxx’ to ‘3966’ on channel 0/1, span 1
399811[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__DIRECTION=INBOUND”) in new stack
399812[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CHANNEL(tonezone)=us”) in new stack
399813[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:3] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__FROM_DID=3966”) in new stack
399814[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:4] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “returnhere=1”) in new stack
399815[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:5] Gosub(“DAHDI/i1/xxxxxxxxxx-6c”, “app-blacklist-check,s,1()”) in new stack
399816[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?blacklisted”) in new stack
399817[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@app-blacklist-check:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLED_BLACKLIST=1”) in new stack
399818[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@app-blacklist-check:3] Return(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
399819[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:6] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CDR(did)=3966”) in new stack
399820[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:7] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?”) in new stack
399821[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:8] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0 ?Set(CALLERID(name)=xxxxxxxxxx)”) in new stack
399822[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:9] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__MOHCLASS=”) in new stack
399823[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:10] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__REVERSAL_REJECT=FALSE”) in new stack
399824[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:11] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?post-reverse-charge”) in new stack
399825[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (from-digital,3966,13)
399826[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:13] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
399827[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:14] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
399828[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:15] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
399829[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:16] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
399830[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:17] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
399831[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:18] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “CallerID Entry Point”) in new stack
399832[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:19] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CRM_DIRECTION=INBOUND”) in new stack
399833[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:20] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CRM_SOURCE=xxxxxxxxxx”) in new stack
399834[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:21] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CRM_LINKEDID=1649688829.424”) in new stack
399835[2022-04-11 08:53:49] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:22] AGI(“DAHDI/i1/xxxxxxxxxx-6c”, “agi://127.0.0.1/sangomacrm.agi,true”) in new stack
399836[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] res_agi.c: <DAHDI/i1/xxxxxxxxxx-6c>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
399837[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:23] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
399838[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [3966@from-digital:24] Goto(“DAHDI/i1/xxxxxxxxxx-6c”, “timeconditions,4,1”) in new stack
399839[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (timeconditions,4,1)
399840[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [4@timeconditions:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DB(TC/4/INUSESTATE)=INUSE”) in new stack
399841[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [4@timeconditions:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DB(TC/4/NOT_INUSESTATE)=NOT_INUSE”) in new stack
399842[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [4@timeconditions:3] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?truegoto”) in new stack
399843[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [4@timeconditions:4] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(DB(TC/4)=)”) in new stack
399844[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [4@timeconditions:5] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DEVICE_STATE(Custom:TC4)=INUSE”) in new stack
399845[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [4@timeconditions:6] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)”) in new stack
399846[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [4@timeconditions:7] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?timeconditions,1,1”) in new stack
399847[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (timeconditions,1,1)
399848[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DB(TC/1/INUSESTATE)=INUSE”) in new stack
399849[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DB(TC/1/NOT_INUSESTATE)=NOT_INUSE”) in new stack
399850[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:3] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “TIMENOW: 08:53,Mon,11,Apr”) in new stack
399851[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:4] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “TIMEMATCHED: TRUE”) in new stack
399852[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:5] GotoIfTime(“DAHDI/i1/xxxxxxxxxx-6c”, “07:30-16:00,mon-fri,1-31,jan-dec?truestate”) in new stack
399853[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (timeconditions,1,14)
399854[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:14] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?falsegoto”) in new stack
399855[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:15] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(DB(TC/1)=)”) in new stack
399856[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:16] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DEVICE_STATE(Custom:TC1)=NOT_INUSE”) in new stack
399857[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:17] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)”) in new stack
399858[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [1@timeconditions:18] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?ivr-1,s,1”) in new stack
399859[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (ivr-1,s,1)
399860[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “INVALID_LOOPCOUNT=0”) in new stack
399861[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “_IVR_CONTEXT_ivr-1=”) in new stack
399862[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:3] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “_IVR_CONTEXT=ivr-1”) in new stack
399863[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:4] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__IVR_RETVM=”) in new stack
399864[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:5] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?skip”) in new stack
399865[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:6] Answer(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
399866[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:7] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “IVR_MSG=custom/MS_MainDay”) in new stack
399867[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:8] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “TIMEOUT(digit)=10”) in new stack
399868[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] func_timeout.c: Digit timeout set to 10.000
399869[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:9] Read(“DAHDI/i1/xxxxxxxxxx-6c”, “IVREXT,custom/MS_MainDay,0,10”) in new stack
399870[2022-04-11 08:53:50] VERBOSE[23314][C-000000a9] file.c: <DAHDI/i1/xxxxxxxxxx-6c> Playing ‘custom/MS_MainDay.slin’ (language ‘en’)
399871[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF begin ‘1’ received on DAHDI/i1/xxxxxxxxxx-6c
399872[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF begin ignored ‘1’ on DAHDI/i1/xxxxxxxxxx-6c
399873[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF end ‘1’ received on DAHDI/i1/xxxxxxxxxx-6c, duration 267 ms
399874[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF end passthrough ‘1’ on DAHDI/i1/xxxxxxxxxx-6c
399875[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF begin ‘4’ received on DAHDI/i1/xxxxxxxxxx-6c
399876[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF begin ignored ‘4’ on DAHDI/i1/xxxxxxxxxx-6c
399877[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF end ‘4’ received on DAHDI/i1/xxxxxxxxxx-6c, duration 267 ms
399878[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF end passthrough ‘4’ on DAHDI/i1/xxxxxxxxxx-6c
399879[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF begin ‘6’ received on DAHDI/i1/xxxxxxxxxx-6c
399880[2022-04-11 08:53:56] DTMF[23314][C-000000a9] channel.c: DTMF begin ignored ‘6’ on DAHDI/i1/xxxxxxxxxx-6c
399881[2022-04-11 08:53:57] DTMF[23314][C-000000a9] channel.c: DTMF end ‘6’ received on DAHDI/i1/xxxxxxxxxx-6c, duration 280 ms
399882[2022-04-11 08:53:57] DTMF[23314][C-000000a9] channel.c: DTMF end passthrough ‘6’ on DAHDI/i1/xxxxxxxxxx-6c
399883[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_read.c: User entered ‘146’
399884[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:10] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?#,1”) in new stack
399885[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:11] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?t,1”) in new stack
399886[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:12] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?Set(LOCALEXT=1)”) in new stack
399887[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:13] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?i,1”) in new stack
399888[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@ivr-1:14] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?from-did-direct-ivr,146,1”) in new stack
399889[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (from-did-direct-ivr,146,1)
399890[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@from-did-direct-ivr:1] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?i,1”) in new stack
399891[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@from-did-direct-ivr:2] Macro(“DAHDI/i1/xxxxxxxxxx-6c”, “blkvm-clr,”) in new stack
399892[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-blkvm-clr:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “SHARED(BLKVM,)=”) in new stack
399893[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-blkvm-clr:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “GOSUB_RETVAL=”) in new stack
399894[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
399895[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@from-did-direct-ivr:3] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__NODEST=”) in new stack
399896[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@from-did-direct-ivr:4] Goto(“DAHDI/i1/xxxxxxxxxx-6c”, “from-did-direct,146,1”) in new stack
399897[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (from-did-direct,146,1)
399898[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@from-did-direct:1] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?ext-local,*146,1”) in new stack
399899[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@from-did-direct:2] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?ext-local,146,1:followme-check,146,1”) in new stack
399900[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (ext-local,146,1)
399901[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@ext-local:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__RINGTIMER=30”) in new stack
399902[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@ext-local:2] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(__CWIGNORE=)”) in new stack
399903[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [146@ext-local:3] Macro(“DAHDI/i1/xxxxxxxxxx-6c”, “exten-vm,146,146,0,0,0”) in new stack
399904[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:1] Macro(“DAHDI/i1/xxxxxxxxxx-6c”, “user-callerid,”) in new stack
399905[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “TOUCH_MONITOR=1649688829.424”) in new stack
399906[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CHANCONTEXT=”) in new stack
399907[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:3] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CHANCONTEXT=”) in new stack
399908[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:4] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CHANEXTENCONTEXT=i1”) in new stack
399909[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:5] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CHANEXTEN=i1”) in new stack
399910[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:6] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLERID(number)=xxxxxxxxxx”) in new stack
399911[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:7] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “AMPUSER=xxxxxxxxxx”) in new stack
399912[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:8] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “HOTDESCKCHAN=i1”) in new stack
399913[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:9] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “HOTDESKEXTEN=i1”) in new stack
399914[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:10] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “HOTDESKCALL=0”) in new stack
399915[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:11] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(HOTDESKCALL=1)”) in new stack
399916[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:12] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(CALLERID(name)=)”) in new stack
399917[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:13] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?report”) in new stack
399918[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:14] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?Set(REALCALLERIDNUM=xxxxxxxxxx)”) in new stack
399919[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:15] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “AMPUSER=”) in new stack
399920[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:16] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?limit”) in new stack
399921[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:17] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “AMPUSERCIDNAME=”) in new stack
399922[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:18] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
399923[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:19] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?report”) in new stack
399924[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-user-callerid,s,28)
399925[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:28] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Macro Depth is 2”) in new stack
399926[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:29] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?report2:macroerror”) in new stack
399927[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-user-callerid,s,30)
399928[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:30] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?continue”) in new stack
399929[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:31] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
399930[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:32] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__TTL=64”) in new stack
399931[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:33] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?continue”) in new stack
399932[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-user-callerid,s,49)
399933[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:49] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLERID(number)=xxxxxxxxxx”) in new stack
399934[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:50] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLERID(name)=USER”) in new stack
399935[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:51] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?cnum”) in new stack
399936[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:52] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CDR(cnam)=USER”) in new stack
399937[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:53] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CDR(cnum)=xxxxxxxxxx”) in new stack
399938[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-user-callerid:54] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CHANNEL(language)=en”) in new stack
399939[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “RingGroupMethod=none”) in new stack
399940[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:3] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__EXTTOCALL=146”) in new stack
399941[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:4] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__PICKUPMARK=146”) in new stack
399942[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:5] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “RT=30”) in new stack
399943[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399944[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:6] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Macro(vm,146,DIRECTDIAL,)”) in new stack
399945[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399946[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399947[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:7] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?MacroExit()”) in new stack
399948[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399949[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399950[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:8] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Macro(vm,146,DIRECTDIAL,)”) in new stack
399951[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399952[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399953[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:9] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?MacroExit()”) in new stack
399954[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399955[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399956[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:10] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?ChanSpy(PJSIP/146,q)”) in new stack
399957[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399958[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399959[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:11] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?MacroExit()”) in new stack
399960[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399961[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399962[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:12] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?ChanSpy(PJSIP/146,q)”) in new stack
399963[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399964[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399965[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:13] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?MacroExit()”) in new stack
399966[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399967[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399968[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:14] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Gosub(ext-intercom,nointercom146,1())”) in new stack
399969[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399970[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399971[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:15] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?MacroExit()”) in new stack
399972[2022-04-11 08:54:07] ERROR[23314][C-000000a9] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
399973[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399974[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:16] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Gosub(ext-intercom,nointercom146,1())”) in new stack
399975[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399976[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399977[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:17] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?MacroExit()”) in new stack
399978[2022-04-11 08:54:07] WARNING[23314][C-000000a9] chan_sip.c: This function can only be used on SIP channels.
399979[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:18] Gosub(“DAHDI/i1/xxxxxxxxxx-6c”, “sub-record-check,s,1(exten,146,dontcare)”) in new stack
399980[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:1] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?initialized”) in new stack
399981[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__REC_STATUS=INITIALIZED”) in new stack
399982[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:3] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “NOW=1649688847”) in new stack
399983[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:4] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__DAY=11”) in new stack
399984[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:5] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__MONTH=04”) in new stack
399985[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:6] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__YEAR=2022”) in new stack
399986[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:7] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__TIMESTR=20220411-085407”) in new stack
399987[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:8] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__FROMEXTEN=xxxxxxxxxx”) in new stack
399988[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:9] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__MON_FMT=wav”) in new stack
399989[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:10] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Recordings initialized”) in new stack
399990[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:11] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(ARG3=dontcare)”) in new stack
399991[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:12] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “REC_POLICY_MODE_SAVE=”) in new stack
399992[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:13] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(REC_STATUS=NO)”) in new stack
399993[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:14] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “5?checkaction”) in new stack
399994[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (sub-record-check,s,17)
399995[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@sub-record-check:17] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?sub-record-check,exten,1”) in new stack
399996[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (sub-record-check,exten,1)
399997[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:1] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Exten Recording Check between xxxxxxxxxx and 146”) in new stack
399998[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLTYPE=external”) in new stack
399999[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:3] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(CALLTYPE=)”) in new stack
400000[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:4] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “CALLEE=dontcare”) in new stack
400001[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:5] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(CALLEE=dontcare)”) in new stack
400002[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:6] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?callee”) in new stack
400003[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (sub-record-check,exten,11)
400004[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:11] Gosub(“DAHDI/i1/xxxxxxxxxx-6c”, “recordcheck,1(dontcare,external,146)”) in new stack
400005[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Starting recording check against dontcare”) in new stack
400006[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“DAHDI/i1/xxxxxxxxxx-6c”, “dontcare”) in new stack
400007[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
400008[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400009[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [exten@sub-record-check:12] Return(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400010[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-exten-vm:19] Macro(“DAHDI/i1/xxxxxxxxxx-6c”, “dial-one,30,Ttr,146”) in new stack
400011[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DEXTEN=146”) in new stack

400012[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CRM_SOURCE=xxxxxxxxxx”) in new stack
400013[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:3] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(__EXTTOCALL=146)”) in new stack
400014[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:4] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DIALSTATUS_CW=”) in new stack
400015[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:5] GosubIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?screen,1()”) in new stack
400016[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:6] GosubIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?cf,1()”) in new stack
400017[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:7] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?skip1”) in new stack
400018[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-dial-one,s,10)
400019[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:10] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?nodial”) in new stack
400020[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:11] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?continue”) in new stack
400021[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:12] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “EXTHASCW=ENABLED”) in new stack
400022[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:13] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?next1:cwinusebusy”) in new stack
400023[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-dial-one,s,25)
400024[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:25] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?next3:continue”) in new stack
400025[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-dial-one,s,27)
400026[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:27] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?nodial”) in new stack
400027[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:28] GosubIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?dstring,1():dlocal,1()”) in new stack
400028[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DSTRING=”) in new stack
400029[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:2] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DEVICES=99146&146”) in new stack
400030[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Return()”) in new stack
400031[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(DEVICES=9146&146)”) in new stack
400032[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:5] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “LOOPCNT=2”) in new stack
400033[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:6] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “ITER=1”) in new stack
400034[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:7] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “THISDIAL=PJSIP/99146”) in new stack
400035[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:8] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?docheck”) in new stack
400036[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:9] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Debug: Found PJSIP Destination PJSIP/99146”) in new stack
400037[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:10] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?doset”) in new stack
400038[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:11] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
400039[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:12] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “THISDIAL=”) in new stack
400040[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:13] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
400041[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?skipset”) in new stack
400042[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-dial-one,dstring,16)
400043[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:16] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “ITER=2”) in new stack
400044[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?begin”) in new stack
400045[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-dial-one,dstring,7)
400046[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:7] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “THISDIAL=PJSIP/146”) in new stack
400047[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:8] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?docheck”) in new stack
400048[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:9] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Debug: Found PJSIP Destination PJSIP/146”) in new stack
400049[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:10] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?doset”) in new stack
400050[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:11] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
400051[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:12] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “THISDIAL=PJSIP/146/sip:[email protected]:63721;rinstance=73836fb16eda4c6c;x-ast-orig-host=50.238.89.26:63721”) in new stack
400052[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:13] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
400053[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?skipset”) in new stack
400054[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:15] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DSTRING=PJSIP/146/sip:[email protected]:63721;rinstance=73836fb16eda4c6c;x-ast-orig-host=50.238.89.26:63721&”) in new stack
400055[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:16] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “ITER=3”) in new stack
400056[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?begin”) in new stack
400057[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Return()”) in new stack
400058[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:19] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DSTRING=PJSIP/146/sip:[email protected]:63721;rinstance=73836fb16eda4c6c;x-ast-orig-host=50.238.89.26:63721”) in new stack
400059[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [dstring@macro-dial-one:20] Return(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400060[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:29] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?nodial”) in new stack
400061[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:30] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?skiptrace”) in new stack
400062[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:31] GosubIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?ctset,1():ctclear,1()”) in new stack
400063[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [ctset@macro-dial-one:1] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “DB(CALLTRACE/146)=xxxxxxxxxx”) in new stack
400064[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [ctset@macro-dial-one:2] Return(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400065[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:32] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “D_OPTIONS=Ttr”) in new stack
400066[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:33] GosubIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
400067[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:34] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
400068[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:35] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(ALERT_INFO=)”) in new stack
400069[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:36] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(ALERT_INFO=)”) in new stack
400070[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:37] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(ALERT_INFO=)”) in new stack
400071[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:38] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
400072[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:39] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
400073[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:40] GosubIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
400074[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:41] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(CHANNEL(musicclass)=)”) in new stack
400075[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:42] GosubIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?qwait,1()”) in new stack
400076[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:43] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CWIGNORE=”) in new stack
400077[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:44] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__KEEPCID=TRUE”) in new stack
400078[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:45] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?usegoto,1”) in new stack
400079[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:46] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?godial”) in new stack
400080[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-dial-one,s,51)
400081[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:51] Macro(“DAHDI/i1/xxxxxxxxxx-6c”, “dialout-one-predial-hook,”) in new stack
400082[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400083[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:52] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?Set(D_OPTIONS=trI)”) in new stack
400084[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:53] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(CWRING=r(callwaiting)):Set(CWRING=)”) in new stack
400085[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:54] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400086[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:55] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(D_OPTIONS=trIg)”) in new stack
400087[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-dial-one:56] Dial(“DAHDI/i1/xxxxxxxxxx-6c”, “PJSIP/146/sip:[email protected]:63721;rinstance=73836fb16eda4c6c;x-ast-orig-host=50.238.89.26:63721,30,trIb(func-apply-sipheaders^s^1)”) in new stack
400088[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_stack.c: PJSIP/146-000000f6 Internal Gosub(func-apply-sipheaders,s,1) start
400089[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“PJSIP/146-000000f6”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
400090[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“PJSIP/146-000000f6”, “Applying SIP Headers to channel PJSIP/146-000000f6”) in new stack
400091[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“PJSIP/146-000000f6”, “TECH=PJSIP”) in new stack
400092[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“PJSIP/146-000000f6”, “SIPHEADERKEYS=”) in new stack
400093[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/146-000000f6”, “0”) in new stack
400094[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_while.c: Jumping to priority 11
400095[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@func-apply-sipheaders:12] Return(“PJSIP/146-000000f6”, “”) in new stack
400096[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_stack.c: Spawn extension (from-internal, 146, 1) exited non-zero on ‘PJSIP/146-000000f6’
400097[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_stack.c: PJSIP/146-000000f6 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
400098[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_dial.c: Called PJSIP/146/sip:[email protected]:63721;rinstance=73836fb16eda4c6c;x-ast-orig-host=50.238.89.26:63721
400099[2022-04-11 08:54:07] VERBOSE[12594] netsock2.c: Using SIP RTP Audio TOS bits 184
400100[2022-04-11 08:54:07] VERBOSE[12594] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
400101[2022-04-11 08:54:07] VERBOSE[12594] netsock2.c: Using SIP RTP Audio CoS mark 5
400102[2022-04-11 08:54:07] VERBOSE[12594] res_rtp_asterisk.c: DTLS ECDH initialized (automatic), faster PFS enabled
400103[2022-04-11 08:54:07] VERBOSE[12594] res_pjsip_logger.c: <— Transmitting SIP request (1939 bytes) to UDP:192.168.88.105:63721 —>
400104INVITE sip:[email protected]:63721;rinstance=73836fb16eda4c6c SIP/2.0
400105Via: SIP/2.0/UDP 10.13.37.230:5061;rport;branch=z9hG4bKPj2d88acb5-134a-4b13-80c6-8990b4dbd679
400106From: “USER” sip:[email protected];tag=054c89b3-d569-49db-9da7-6481d7c4168f
400107To: sip:[email protected];rinstance=73836fb16eda4c6c
400108Contact: sip:[email protected]:5061
400109Call-ID: d3335089-0976-46c0-ba3d-245b94ca91e6
400110CSeq: 28364 INVITE
400111Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
400112Supported: 100rel, timer, replaces, norefersub, histinfo
400113Session-Expires: 1800
400114Min-SE: 90
400115Remote-Party-ID: “USER” sip:[email protected];party=calling;privacy=off;screen=no
400116Max-Forwards: 70
400117User-Agent: FPBX-16.0.19(16.25.0)
400118Content-Type: application/sdp
400119Content-Length: 1094
400120
400121v=0
400122o=- 101202136 101202136 IN IP4 10.13.37.230
400123s=Asterisk
400124c=IN IP4 10.13.37.230
400125t=0 0
400126m=audio 12134 UDP/TLS/RTP/SAVPF 0 8 3 97 9 111 4 18 116 101
400127a=connection:new
400128a=setup:actpass
400129a=fingerprint:SHA-256 EB:E0:F4:F7:D0:4B:4E:11:3C:19:6D:30:04:91:28:C0:92:90:EF:65:11:AA:24:3A:46:63:AB:7D:73:8B:CB:EC
400130a=ice-ufrag:4e0e34f34c58acc85dd2ce90439f07e5
400131a=ice-pwd:60e6edb1553d61dd1f039bed16b5a483
400132a=candidate:Ha0d25e6 1 UDP 2130706431 10.13.37.230 12134 typ host
400133a=candidate:Hf439462e 1 UDP 2130706431 fe80::76d4:35ff:fe4c:1870 12134 typ host
400134a=candidate:S32ee591a 1 UDP 1694498815 50.238.89.26 12134 typ srflx raddr 10.13.37.230 rport 12134
400135a=candidate:Rd827fc0e 1 UDP 16777215 216.39.252.14 37811 typ relay raddr 50.238.89.26 rport 58084
400136a=rtpmap:0 PCMU/8000
400137a=rtpmap:8 PCMA/8000
400138a=rtpmap:3 GSM/8000
400139a=rtpmap:97 iLBC/8000
400140a=fmtp:97 mode=20
400141a=rtpmap:9 G722/8000
400142a=rtpmap:111 G726-32/8000
400143a=rtpmap:4 G723/8000
400144a=rtpmap:18 G729/8000
400145a=fmtp:18 annexb=no
400146a=rtpmap:116 G719/48000
400147a=rtpmap:101 telephone-event/8000
400148a=fmtp:101 0-16
400149a=ptime:20
400150a=maxptime:80
400151a=sendrecv
400152a=rtcp-mux
400153
400154[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_dial.c: Connected line update to DAHDI/i1/xxxxxxxxxx-6c prevented.
400155[2022-04-11 08:54:07] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP response (690 bytes) from UDP:192.168.88.105:63721 —>
400156SIP/2.0 180 Ringing
400157Via: SIP/2.0/UDP 10.13.37.230:5061;rport=5061;branch=z9hG4bKPj2d88acb5-134a-4b13-80c6-8990b4dbd679
400158Contact: sip:[email protected]:63721;rinstance=73836fb16eda4c6c
400159To: sip:[email protected];rinstance=73836fb16eda4c6c;tag=071e9159
400160From: "USER"sip:[email protected];tag=054c89b3-d569-49db-9da7-6481d7c4168f
400161Call-ID: d3335089-0976-46c0-ba3d-245b94ca91e6
400162CSeq: 28364 INVITE
400163User-Agent: 3CXPhone 6.0.26523.0
400164Content-Length: 0
400165X-Dc: PHNpcDoxNDZANTAuMjM4Ljg5LjI2OjYzNzIxO3JpbnN0YW5jZT03MzgzNmZiMTZlZGE0YzZjPg==
400166X-Dv: U0lQLzIuMC9VRFAgMTAuMTMuMzcuMjMwOjUwNjE7cnBvcnQ9NTA2MTticmFuY2g9ejloRzRiS1BqMmQ4OGFjYjUtMTM0YS00YjEzLTgwYzYtODk5MGI0ZGJkNjc5
400167
400168
400169[2022-04-11 08:54:07] VERBOSE[23314][C-000000a9] app_dial.c: PJSIP/146-000000f6 is ringing
400170[2022-04-11 08:54:09] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP response (1916 bytes) from UDP:192.168.88.105:63721 —>
400171SIP/2.0 200 OK
400172Via: SIP/2.0/UDP 10.13.37.230:5061;rport=5061;branch=z9hG4bKPj2d88acb5-134a-4b13-80c6-8990b4dbd679
400173Contact: sip:[email protected]:63721;rinstance=73836fb16eda4c6c
400174To: sip:[email protected];rinstance=73836fb16eda4c6c;tag=071e9159
400175From: "USER"sip:[email protected];tag=054c89b3-d569-49db-9da7-6481d7c4168f
400176Call-ID: d3335089-0976-46c0-ba3d-245b94ca91e6
400177CSeq: 28364 INVITE
400178Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
400179Content-Type: application/sdp
400180Supported: replaces
400181User-Agent: 3CXPhone 6.0.26523.0
400182Content-Length: 1069
400183X-Dc: PHNpcDoxNDZANTAuMjM4Ljg5LjI2OjYzNzIxO3JpbnN0YW5jZT03MzgzNmZiMTZlZGE0YzZjPg==
400184X-Dv: U0lQLzIuMC9VRFAgMTAuMTMuMzcuMjMwOjUwNjE7cnBvcnQ9NTA2MTticmFuY2g9ejloRzRiS1BqMmQ4OGFjYjUtMTM0YS00YjEzLTgwYzYtODk5MGI0ZGJkNjc5
400185X-Damp: MA==
400186
400187v=0
400188o=3cxVCE 181743090 213864780 IN IP4
400189s=3cxVCE Audio Call
400190t=0 0
400191m=audio 0 UDP/TLS/RTP/SAVPF 0 8 3 97 9 111 4 18 116 101
400192a=connection:new
400193a=setup:actpass
400194a=fingerprint:SHA-256 EB:E0:F4:F7:D0:4B:4E:11:3C:19:6D:30:04:91:28:C0:92:90:EF:65:11:AA:24:3A:46:63:AB:7D:73:8B:CB:EC
400195a=ice-ufrag:4e0e34f34c58acc85dd2ce90439f07e5
400196a=ice-pwd:60e6edb1553d61dd1f039bed16b5a483
400197a=candidate:Ha0d25e6 1 UDP 2130706431 10.13.37.230 12134 typ host
400198a=candidate:Hf439462e 1 UDP 2130706431 fe80::76d4:35ff:fe4c:1870 12134 typ host
400199a=candidate:S32ee591a 1 UDP 1694498815 50.238.89.26 12134 typ srflx raddr 10.13.37.230 rport 12134
400200a=candidate:Rd827fc0e 1 UDP 16777215 216.39.252.14 37811 typ relay raddr 50.238.89.26 rport 58084
400201a=rtpmap:0 PCMU/8000
400202a=rtpmap:8 PCMA/8000
400203a=rtpmap:3 GSM/8000
400204a=rtpmap:97 iLBC/8000
400205a=fmtp:97 mode=20
400206a=rtpmap:9 G722/8000
400207a=rtpmap:111 G726-32/8000
400208a=rtpmap:4 G723/8000
400209a=rtpmap:18 G729/8000
400210a=fmtp:18 annexb=no
400211a=rtpmap:116 G719/48000
400212a=rtpmap:101 telephone-event/8000
400213a=fmtp:101 0-16
400214a=ptime:20
400215a=maxptime:80
400216a=sendrecv
400217a=rtcp-mux
400218
400219[2022-04-11 08:54:09] ERROR[20860] pjproject: sip_inv.c …Error parsing/validating SDP body: Invalid SDP origin line (PJMEDIA_SDP_EINORIGIN)
400220[2022-04-11 08:54:09] VERBOSE[20860] res_pjsip_logger.c: <— Transmitting SIP request (469 bytes) to UDP:192.168.88.105:63721 —>
400221ACK sip:[email protected]:63721;rinstance=73836fb16eda4c6c SIP/2.0
400222Via: SIP/2.0/UDP 10.13.37.230:5061;rport;branch=z9hG4bKPj8576bcc5-b136-44be-b8df-4d24a78eecb6
400223From: “USER” sip:[email protected];tag=054c89b3-d569-49db-9da7-6481d7c4168f
400224To: sip:[email protected];rinstance=73836fb16eda4c6c;tag=071e9159
400225Call-ID: d3335089-0976-46c0-ba3d-245b94ca91e6
400226CSeq: 28364 ACK
400227Max-Forwards: 70
400228User-Agent: FPBX-16.0.19(16.25.0)
400229Content-Length: 0
400230
400231
400232[2022-04-11 08:54:09] VERBOSE[20860] res_pjsip_logger.c: <— Transmitting SIP request (469 bytes) to UDP:192.168.88.105:63721 —>
400233BYE sip:[email protected]:63721;rinstance=73836fb16eda4c6c SIP/2.0
400234Via: SIP/2.0/UDP 10.13.37.230:5061;rport;branch=z9hG4bKPjd095bc15-6553-44aa-9100-5621abc0af45
400235From: “USER” sip:[email protected];tag=054c89b3-d569-49db-9da7-6481d7c4168f
400236To: sip:[email protected];rinstance=73836fb16eda4c6c;tag=071e9159
400237Call-ID: d3335089-0976-46c0-ba3d-245b94ca91e6
400238CSeq: 28365 BYE
400239Max-Forwards: 70
400240User-Agent: FPBX-16.0.19(16.25.0)
400241Content-Length: 0
400242
400243
400244[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] app_dial.c: PJSIP/146-000000f6 answered DAHDI/i1/xxxxxxxxxx-6c
400245[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] bridge_channel.c: Channel PJSIP/146-000000f6 joined ‘simple_bridge’ basic-bridge <5285941d-a05b-4fee-80c8-fe521e0b1a62>
400246[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] bridge_channel.c: Channel DAHDI/i1/xxxxxxxxxx-6c joined ‘simple_bridge’ basic-bridge <5285941d-a05b-4fee-80c8-fe521e0b1a62>
400247[2022-04-11 08:54:09] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP response (682 bytes) from UDP:192.168.88.105:63721 —>
400248SIP/2.0 200 OK
400249Via: SIP/2.0/UDP 10.13.37.230:5061;rport=5061;branch=z9hG4bKPjd095bc15-6553-44aa-9100-5621abc0af45
400250Contact: sip:[email protected]:63721;rinstance=73836fb16eda4c6c
400251To: sip:[email protected];rinstance=73836fb16eda4c6c;tag=071e9159
400252From: "USER"sip:[email protected];tag=054c89b3-d569-49db-9da7-6481d7c4168f
400253Call-ID: d3335089-0976-46c0-ba3d-245b94ca91e6
400254CSeq: 28365 BYE
400255User-Agent: 3CXPhone 6.0.26523.0
400256Content-Length: 0
400257X-Dc: PHNpcDoxNDZANTAuMjM4Ljg5LjI2OjYzNzIxO3JpbnN0YW5jZT03MzgzNmZiMTZlZGE0YzZjPg==
400258X-Dv: U0lQLzIuMC9VRFAgMTAuMTMuMzcuMjMwOjUwNjE7cnBvcnQ9NTA2MTticmFuY2g9ejloRzRiS1BqZDA5NWJjMTUtNjU1My00NGFhLTkxMDAtNTYyMWFiYzBhZjQ1
400259
400260
400261[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] bridge_channel.c: Channel PJSIP/146-000000f6 left ‘simple_bridge’ basic-bridge <5285941d-a05b-4fee-80c8-fe521e0b1a62>
400262[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] app_stack.c: PJSIP/146-000000f6 Internal Gosub(crm-hangup,s,1) start
400263[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] pbx.c: Executing [s@crm-hangup:1] NoOp(“PJSIP/146-000000f6”, “Sending Hangup to CRM”) in new stack
400264[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] pbx.c: Executing [s@crm-hangup:2] NoOp(“PJSIP/146-000000f6”, “HANGUP CAUSE: 16”) in new stack
400265[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] pbx.c: Executing [s@crm-hangup:3] ExecIf(“PJSIP/146-000000f6”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
400266[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] pbx.c: Executing [s@crm-hangup:4] NoOp(“PJSIP/146-000000f6”, “MASTER CHANNEL: 1649688847.425 = 1649688829.424”) in new stack
400267[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] pbx.c: Executing [s@crm-hangup:5] GotoIf(“PJSIP/146-000000f6”, “1?return”) in new stack
400268[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] pbx_builtins.c: Goto (crm-hangup,s,8)
400269[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] pbx.c: Executing [s@crm-hangup:8] Return(“PJSIP/146-000000f6”, “”) in new stack
400270[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] app_stack.c: Spawn extension (from-internal, , 1) exited non-zero on ‘PJSIP/146-000000f6’
400271[2022-04-11 08:54:09] VERBOSE[23546][C-000000a9] app_stack.c: PJSIP/146-000000f6 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
400272[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] bridge_channel.c: Channel DAHDI/i1/xxxxxxxxxx-6c left ‘simple_bridge’ basic-bridge <5285941d-a05b-4fee-80c8-fe521e0b1a62>
400273[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] app_macro.c: Spawn extension (macro-dial-one, s, 56) exited non-zero on ‘DAHDI/i1/xxxxxxxxxx-6c’ in macro ‘dial-one’
400274[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] app_macro.c: Spawn extension (macro-exten-vm, s, 19) exited non-zero on ‘DAHDI/i1/xxxxxxxxxx-6c’ in macro ‘exten-vm’
400275[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Spawn extension (ext-local, 146, 3) exited non-zero on ‘DAHDI/i1/xxxxxxxxxx-6c’
400276[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [h@ext-local:1] Macro(“DAHDI/i1/xxxxxxxxxx-6c”, “hangupcall,”) in new stack
400277[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “1?theend”) in new stack
400278[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx_builtins.c: Goto (macro-hangupcall,s,3)
400279[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(CDR(recordingfile)=)”) in new stack
400280[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@macro-hangupcall:4] Hangup(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400281[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘DAHDI/i1/xxxxxxxxxx-6c’ in macro ‘hangupcall’
400282[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘DAHDI/i1/xxxxxxxxxx-6c’
400283[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] app_stack.c: DAHDI/i1/xxxxxxxxxx-6c Internal Gosub(crm-hangup,s,1) start
400284[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:1] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “Sending Hangup to CRM”) in new stack
400285[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:2] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “HANGUP CAUSE: 16”) in new stack
400286[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:3] ExecIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
400287[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:4] NoOp(“DAHDI/i1/xxxxxxxxxx-6c”, “MASTER CHANNEL: 1649688829.424 = 1649688829.424”) in new stack
400288[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:5] GotoIf(“DAHDI/i1/xxxxxxxxxx-6c”, “0?return”) in new stack
400289[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:6] Set(“DAHDI/i1/xxxxxxxxxx-6c”, “__CRM_HANGUP=1”) in new stack
400290[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:7] AGI(“DAHDI/i1/xxxxxxxxxx-6c”, “agi://127.0.0.1/sangomacrm.agi”) in new stack
400291[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] res_agi.c: <DAHDI/i1/xxxxxxxxxx-6c>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
400292[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] pbx.c: Executing [s@crm-hangup:8] Return(“DAHDI/i1/xxxxxxxxxx-6c”, “”) in new stack
400293[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘DAHDI/i1/xxxxxxxxxx-6c’
400294[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] app_stack.c: DAHDI/i1/xxxxxxxxxx-6c Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
400295[2022-04-11 08:54:09] VERBOSE[23314][C-000000a9] chan_dahdi.c: Hungup ‘DAHDI/i1/xxxxxxxxxx-6c’
400296[2022-04-11 08:54:16] VERBOSE[20860] res_pjsip_logger.c: <— Transmitting SIP request (476 bytes) to UDP:192.168.88.105:63721 —>
400297OPTIONS sip:[email protected]:63721;rinstance=73836fb16eda4c6c SIP/2.0
400298Via: SIP/2.0/UDP 10.13.37.230:5061;rport;branch=z9hG4bKPj1bc574a7-a5fc-416f-9ea3-5ce4acfd65ff
400299From: sip:[email protected];tag=0ce0bfa7-3dca-4e4b-b1dd-ff00eca2a87f
400300To: sip:[email protected];rinstance=73836fb16eda4c6c
400301Contact: sip:[email protected]:5061
400302Call-ID: 80045680-8aaa-4b02-a88b-54b80d93d1b9
400303CSeq: 5111 OPTIONS
400304Max-Forwards: 70
400305User-Agent: FPBX-16.0.19(16.25.0)
400306Content-Length: 0
400307
400308
400309[2022-04-11 08:54:16] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP response (596 bytes) from UDP:192.168.88.105:63721 —>
400310SIP/2.0 200 OK
400311Via: SIP/2.0/UDP 10.13.37.230:5061;rport=5061;branch=z9hG4bKPj1bc574a7-a5fc-416f-9ea3-5ce4acfd65ff
400312Contact: sip:192.168.88.105:63721
400313To: sip:[email protected];rinstance=73836fb16eda4c6c;tag=6a37f219
400314From: sip:[email protected];tag=0ce0bfa7-3dca-4e4b-b1dd-ff00eca2a87f
400315Call-ID: 80045680-8aaa-4b02-a88b-54b80d93d1b9
400316CSeq: 5111 OPTIONS
400317Accept: application/sdp
400318Accept-Language: en
400319Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
400320Supported: replaces
400321Allow-Events: presence, message-summary, tunnel-info
400322Content-Length: 0
400323
400324
400325[2022-04-11 08:54:25] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP request (1033 bytes) from UDP:192.168.88.105:63721 —>
400326SUBSCRIBE sip:10.13.37.230:5061 SIP/2.0
400327Via: SIP/2.0/UDP 192.168.88.105:63721;branch=z9hG4bK-d8754z-21793a381f73be78-1—d8754z-;rport
400328Max-Forwards: 70
400329Contact: sip:[email protected]:63721;rinstance=73836fb16eda4c6c
400330To: "USER"sip:[email protected];tag=bf991b87-4985-4ca8-ab18-dca6944efb2f
400331From: "USER"sip:[email protected];tag=850f0122
400332Call-ID: MjM3NmU2ZTE0NDcwYzc2ZTkwZDAzNDk4NDgyODg5YTk.
400333CSeq: 27 SUBSCRIBE
400334Expires: 119
400335User-Agent: 3CXPhone 6.0.26523.0
400336Authorization: Digest username=“146”,realm=“asterisk”,nonce=“1649686306/bf18bc56ead94caa53ceaa321353ce46”,uri=“sip:10.13.37.230:5061”,response=“e0c8c2d3da3c5b152ad6b28e6f3107f9”,cnonce=“e096209a1bd0f3c1afc72c75f0c8836b”,nc=00000019,qop=auth,algorithm=md5,opaque=“2a4b0ff5458b78f9”
400337Event: message-summary
400338Content-Length: 0
400339X-Dc: PHNpcDoxNDZANTAuMjM4Ljg5LjI2OjYzNzIxO3JpbnN0YW5jZT03MzgzNmZiMTZlZGE0YzZjPg==
400340X-Dv: U0lQLzIuMC9VRFAgMTkyLjE2OC44OC4xMDU6NjM3MjE7YnJhbmNoPXo5aEc0YkstZDg3NTR6LTIxNzkzYTM4MWY3M2JlNzgtMS0tLWQ4NzU0ei07cnBvcnQ=
400341
400342
400343[2022-04-11 08:54:25] VERBOSE[6289] res_pjsip_logger.c: <— Transmitting SIP response (629 bytes) to UDP:192.168.88.105:63721 —>
400344SIP/2.0 200 OK
400345Via: SIP/2.0/UDP 192.168.88.105:63721;rport=63721;received=192.168.88.105;branch=z9hG4bK-d8754z-21793a381f73be78-1—d8754z-
400346Call-ID: MjM3NmU2ZTE0NDcwYzc2ZTkwZDAzNDk4NDgyODg5YTk.
400347From: “USER” sip:[email protected];tag=850f0122
400348To: “USER” sip:[email protected];tag=bf991b87-4985-4ca8-ab18-dca6944efb2f
400349CSeq: 27 SUBSCRIBE
400350Expires: 119
400351Contact: sip:10.13.37.230:5061
400352Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
400353Supported: 100rel, timer, replaces, norefersub
400354Server: FPBX-16.0.19(16.25.0)
400355Content-Length: 0
400356

Log (3/3)

400357
400358[2022-04-11 08:54:25] VERBOSE[6289] res_pjsip_logger.c: <— Transmitting SIP request (724 bytes) to UDP:192.168.88.105:63721 —>
400359NOTIFY sip:[email protected]:63721;rinstance=73836fb16eda4c6c SIP/2.0
400360Via: SIP/2.0/UDP 10.13.37.230:5061;rport;branch=z9hG4bKPj68e24bc6-4137-4126-9923-ca0a95fde33c
400361From: “USER” sip:[email protected];tag=bf991b87-4985-4ca8-ab18-dca6944efb2f
400362To: “USER” sip:[email protected];tag=850f0122
400363Contact: sip:10.13.37.230:5061
400364Call-ID: MjM3NmU2ZTE0NDcwYzc2ZTkwZDAzNDk4NDgyODg5YTk.
400365CSeq: 27450 NOTIFY
400366Event: message-summary
400367Subscription-State: active;expires=119
400368Allow-Events: presence, dialog, message-summary, refer
400369Max-Forwards: 70
400370User-Agent: FPBX-16.0.19(16.25.0)
400371Content-Type: application/simple-message-summary
400372Content-Length: 48
400373
400374Messages-Waiting: no
400375Voice-Message: 0/0 (0/0)
400376
400377[2022-04-11 08:54:25] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP response (462 bytes) from UDP:192.168.88.105:63721 —>
400378SIP/2.0 200 OK
400379Via: SIP/2.0/UDP 10.13.37.230:5061;rport=5061;branch=z9hG4bKPj68e24bc6-4137-4126-9923-ca0a95fde33c
400380Contact: sip:[email protected]:63721;rinstance=73836fb16eda4c6c
400381To: "USER"sip:[email protected];tag=850f0122
400382From: "USER"sip:[email protected];tag=bf991b87-4985-4ca8-ab18-dca6944efb2f
400383Call-ID: MjM3NmU2ZTE0NDcwYzc2ZTkwZDAzNDk4NDgyODg5YTk.
400384CSeq: 27450 NOTIFY
400385User-Agent: 3CXPhone 6.0.26523.0
400386Content-Length: 0
400387
400388
400389[2022-04-11 08:54:42] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP request (1136 bytes) from UDP:192.168.88.105:63721 —>
400390REGISTER sip:phone.system.ext.url:5061 SIP/2.0
400391Via: SIP/2.0/UDP 192.168.88.105:63721;branch=z9hG4bK-d8754z-3d30c117660b924e-1—d8754z-;rport
400392Max-Forwards: 70
400393Contact: sip:[email protected]:63721;transport=UDP;rinstance=73836fb16eda4c6c
400394To: "USER"sip:[email protected]:5061
400395From: "USER"sip:[email protected]:5061;tag=d3413e2c
400396Call-ID: ZGYxM2ZiZjFlOGVkNzdjOWI2MGEyNWUyOThlZDA5YTk.
400397CSeq: 49 REGISTER
400398Expires: 120
400399Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
400400Supported: replaces
400401User-Agent: 3CXPhone 6.0.26523.0
400402Authorization: Digest username=“146”,realm=“asterisk”,nonce=“1649688775/3bf25a4d33a5f062eb8c5d305b68985b”,uri=“sip:phone.system.ext.url:5061”,response=“a2d037697deb09bf5a51fb02a1aa0cc2”,cnonce=“ae5ff9ef28b25f6b0dfe10657f4f449e”,nc=00000002,qop=auth,algorithm=md5,opaque=“65700d900a759236”
400403Content-Length: 0
400404X-Dc: PHNpcDoxNDZANTAuMjM4Ljg5LjI2OjYzNzIxO3RyYW5zcG9ydD1VRFA7cmluc3RhbmNlPTczODM2ZmIxNmVkYTRjNmM+
400405X-Dv: U0lQLzIuMC9VRFAgMTkyLjE2OC44OC4xMDU6NjM3MjE7YnJhbmNoPXo5aEc0YkstZDg3NTR6LTNkMzBjMTE3NjYwYjkyNGUtMS0tLWQ4NzU0ei07cnBvcnQ=
400406
400407
400408[2022-04-11 08:54:42] VERBOSE[15042] res_pjsip_logger.c: <— Transmitting SIP response (595 bytes) to UDP:192.168.88.105:63721 —>
400409SIP/2.0 401 Unauthorized
400410Via: SIP/2.0/UDP 192.168.88.105:63721;rport=63721;received=192.168.88.105;branch=z9hG4bK-d8754z-3d30c117660b924e-1—d8754z-
400411Call-ID: ZGYxM2ZiZjFlOGVkNzdjOWI2MGEyNWUyOThlZDA5YTk.
400412From: “USER” sip:[email protected];tag=d3413e2c
400413To: “USER” sip:[email protected];tag=z9hG4bK-d8754z-3d30c117660b924e-1—d8754z-
400414CSeq: 49 REGISTER
400415WWW-Authenticate: Digest realm=“asterisk”,nonce=“1649688882/c0f39e27b19077b61cbb45777d840cb1”,opaque=“4e2e0df258f12390”,stale=true,algorithm=md5,qop=“auth”
400416Server: FPBX-16.0.19(16.25.0)
400417Content-Length: 0
400418
400419
400420[2022-04-11 08:54:42] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP request (1136 bytes) from UDP:192.168.88.105:63721 —>
400421REGISTER sip:phone.system.ext.url:5061 SIP/2.0
400422Via: SIP/2.0/UDP 192.168.88.105:63721;branch=z9hG4bK-d8754z-280ae55f876c0c7a-1—d8754z-;rport
400423Max-Forwards: 70
400424Contact: sip:[email protected]:63721;transport=UDP;rinstance=73836fb16eda4c6c
400425To: "USER"sip:[email protected]:5061
400426From: "USER"sip:[email protected]:5061;tag=d3413e2c
400427Call-ID: ZGYxM2ZiZjFlOGVkNzdjOWI2MGEyNWUyOThlZDA5YTk.
400428CSeq: 50 REGISTER
400429Expires: 120
400430Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
400431Supported: replaces
400432User-Agent: 3CXPhone 6.0.26523.0
400433Authorization: Digest username=“146”,realm=“asterisk”,nonce=“1649688882/c0f39e27b19077b61cbb45777d840cb1”,uri=“sip:phone.system.ext.url:5061”,response=“aeb83b8002067a353f45830db25d108f”,cnonce=“7cad854f5dcc91e33c5f6a3e540fe22b”,nc=00000001,qop=auth,algorithm=md5,opaque=“4e2e0df258f12390”
400434Content-Length: 0
400435X-Dc: PHNpcDoxNDZANTAuMjM4Ljg5LjI2OjYzNzIxO3RyYW5zcG9ydD1VRFA7cmluc3RhbmNlPTczODM2ZmIxNmVkYTRjNmM+
400436X-Dv: U0lQLzIuMC9VRFAgMTkyLjE2OC44OC4xMDU6NjM3MjE7YnJhbmNoPXo5aEc0YkstZDg3NTR6LTI4MGFlNTVmODc2YzBjN2EtMS0tLWQ4NzU0ei07cnBvcnQ=
400437
400438
400439[2022-04-11 08:54:42] VERBOSE[26177] res_pjsip_logger.c: <— Transmitting SIP response (557 bytes) to UDP:192.168.88.105:63721 —>
400440SIP/2.0 200 OK
400441Via: SIP/2.0/UDP 192.168.88.105:63721;rport=63721;received=192.168.88.105;branch=z9hG4bK-d8754z-280ae55f876c0c7a-1—d8754z-
400442Call-ID: ZGYxM2ZiZjFlOGVkNzdjOWI2MGEyNWUyOThlZDA5YTk.
400443From: “USER” sip:[email protected];tag=d3413e2c
400444To: “USER” sip:[email protected];tag=z9hG4bK-d8754z-280ae55f876c0c7a-1—d8754z-
400445CSeq: 50 REGISTER
400446Date: Mon, 11 Apr 2022 14:54:42 GMT
400447Contact: sip:[email protected]:63721;rinstance=73836fb16eda4c6c;expires=119
400448Expires: 120
400449Server: FPBX-16.0.19(16.25.0)
400450Content-Length: 0
400451
400452
400453[2022-04-11 08:55:16] VERBOSE[26177] res_pjsip_logger.c: <— Transmitting SIP request (477 bytes) to UDP:192.168.88.105:63721 —>
400454OPTIONS sip:[email protected]:63721;rinstance=73836fb16eda4c6c SIP/2.0
400455Via: SIP/2.0/UDP 10.13.37.230:5061;rport;branch=z9hG4bKPj82bda77a-2d5c-4fb0-9984-b82de74451b2
400456From: sip:[email protected];tag=19fe41d4-2f36-42a4-9880-85c61da18673
400457To: sip:[email protected];rinstance=73836fb16eda4c6c
400458Contact: sip:[email protected]:5061
400459Call-ID: 4efb3cc2-7d30-4d7e-bec7-301b1dee6a30
400460CSeq: 16771 OPTIONS
400461Max-Forwards: 70
400462User-Agent: FPBX-16.0.19(16.25.0)
400463Content-Length: 0
400464
400465
400466[2022-04-11 08:55:16] VERBOSE[3705] res_pjsip_logger.c: <— Received SIP response (597 bytes) from UDP:192.168.88.105:63721 —>
400467SIP/2.0 200 OK
400468Via: SIP/2.0/UDP 10.13.37.230:5061;rport=5061;branch=z9hG4bKPj82bda77a-2d5c-4fb0-9984-b82de74451b2
400469Contact: sip:192.168.88.105:63721
400470To: sip:[email protected];rinstance=73836fb16eda4c6c;tag=ee48a70b
400471From: sip:[email protected];tag=19fe41d4-2f36-42a4-9880-85c61da18673
400472Call-ID: 4efb3cc2-7d30-4d7e-bec7-301b1dee6a30
400473CSeq: 16771 OPTIONS
400474Accept: application/sdp
400475Accept-Language: en
400476Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
400477Supported: replaces
400478Allow-Events: presence, message-summary, tunnel-info
400479Content-Length: 0
400480

You’d might also need to turn the verbosity down., depending on what FreePBX uses as default.

The offending line is this: “o=3cxVCE 181743090 213864780 IN IP4”.

The PJSIP SDP parser/validator is expecting an IPv4 address or hostname to be present, and there is not. As a result it considers it invalid. According to the RFC[1] it is required.

[1] RFC 8866: SDP: Session Description Protocol

1 Like

@jcolp is right. I’m guessing that this is somehow related to ICE.
By default, Enable ICE Support for an extension is No.
If you enabled it but don’t need it, try turning it off.
If it is off, do you know what may be causing the ICE negotiation?
There may also be a setting in the softphone related to ICE.
Please don’t post lengthy logs directly in the forum. Paste them at pastebin.freepbx.org and post the link here. That also avoids some garbling of the format.

1 Like

I turned off ICE support for the extension I’m testing on.

No dice.

I don’t see anything in my General SIP settings defining ICE candidates or blacklist. Nothing in the Softphone app for ICE.

So, I’m not sure where the ICE negotiation is coming from.

Does the INVITE sent to the softphone still have ICE? If so, we need to find out what is forcing it. If not, please paste a new log.

https://pastebin.freepbx.org/view/52a38704

It’s essentially doing what it was doing before I changed it.

I only applied the settings, did I need to restart Asterisk?

Wait, I see. No, There are no ICE candidates being established in the second log dump.

The IP address is supposed to be after the IP4, correct?

Is that IP address the callee?

Any idea what would cause the IP address to not be there?

Yes, that is where it is supposed to be. It’s a hostname or IP address of the endpoint. The endpoint is responsible for putting it there, so I can’t comment on its behavior.

The latest log also has no “c=” line which contains the IP address for media. Without that things would also likely fall apart. Oh, and no port assigned for the media so it would have seemingly rejected the media too.

This is purely in the land of the endpoint.

Thanks,

My focus is shifting to the soft phone.

My next guess is SIP ALG. The 192.168.88.105 address of the softphone sounds suspiciously like MikroTik, notorious for buggy SIP ALG. There is apparently no NAT involved, so I would think that any ALG would be inactive. But they’re so close to Russia; perhaps illogical thinking is contagious :slight_smile:

Anyhow, try turning off any SIP ALG in the router between the softphone and PBX (MikroTik or not).

If that’s not your issue, please describe the networking involved, including any VoIP-related settings.

Of course, you can capture traffic at the 3CX machine to see whether any network gear is butchering it.