Problems with Blind Transfer, PJSIP (Aastra 6869i)

FreePBX
1

Hallo everbody,
i need some help with my PJSIP Aastra Phones (6869i)

i have problems with Blind Transfer.

In my test i called my PJSIP extension from cell phone, then i made blind Transfer to an internal extension.

The Transfer to the extension works, but already in the begining of the transfer my Aastra phone doesnt hagup the call, the lamp on the right top begins to flash blinking and Stucks. After about 30 seconds my phone disconnects the call and works normal as usual.
I also tried the call Internal Extension -> Tranfer internal extension to exclude any possible NAT problems.

I dont know where the problem is. Maybe someone can help.

Calltrace:
[2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:49] Dial("PJSIP/168-00000019", "PJSIP/167/sip:[email protected]:5060;transport=udp,12,TtIb(func-apply-sipheaders^s^1)") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] app_stack.c: PJSIP/167-0000001a Internal Gosub(func-apply-sipheaders,s,1) start [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("PJSIP/167-0000001a", "Applying SIP Headers to channel") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:2] ExecIf("PJSIP/167-0000001a", "1?Set(ZULU_EXT=167):Set(ZULU_EXT=167/sip:[email protected]:5060;transport=udp)") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:3] GotoIf("PJSIP/167-0000001a", "0?endzulu") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:4] Set("PJSIP/167-0000001a", "ZULU_TYPE_FINAL=") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:5] Set("PJSIP/167-0000001a", "ZULU_URL_FINAL=") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:6] ExecIf("PJSIP/167-0000001a", "0?Set(ZULU_TYPE_FINAL=)") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("PJSIP/167-0000001a", "0?Set(ZULU_URL_FINAL=)") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:8] NoOp("PJSIP/167-0000001a", "ZULU EXTENSION: 167") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:9] NoOp("PJSIP/167-0000001a", "ZULU TYPE: ") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:10] NoOp("PJSIP/167-0000001a", "ZULU URL: ") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:11] NoOp("PJSIP/167-0000001a", "ZULU Finished") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:12] Set("PJSIP/167-0000001a", "SIPHEADERKEYS=Alert-Info") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:13] While("PJSIP/167-0000001a", "1") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:14] Set("PJSIP/167-0000001a", "sipheader=info=alert-external") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:15] SIPAddHeader("PJSIP/167-0000001a", "Alert-Info: info=alert-external") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:16] Set("PJSIP/167-0000001a", "PJSIP_HEADER(add,Alert-Info)=info=alert-external") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:17] EndWhile("PJSIP/167-0000001a", "") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:13] While("PJSIP/167-0000001a", "0") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:18] Return("PJSIP/167-0000001a", "") in new stack [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] app_stack.c: Spawn extension (from-internal, 167, 1) exited non-zero on 'PJSIP/167-0000001a' [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] app_stack.c: PJSIP/167-0000001a Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL= [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] app_dial.c: Called PJSIP/167/sip:[email protected]:5060;transport=udp [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] app_dial.c: Connected line update to PJSIP/168-00000019 prevented. [2016-04-14 00:25:50] VERBOSE[19934][C-00000012] app_dial.c: PJSIP/167-0000001a is ringing [2016-04-14 00:25:53] VERBOSE[19934][C-00000012] app_dial.c: PJSIP/167-0000001a answered PJSIP/168-00000019 [2016-04-14 00:25:53] VERBOSE[19949][C-00000012] bridge_channel.c: Channel PJSIP/167-0000001a joined 'simple_bridge' basic-bridge <e811c2e8-5856-4656-9470-1ea534fc1a63> [2016-04-14 00:25:53] VERBOSE[19934][C-00000012] bridge_channel.c: Channel PJSIP/168-00000019 joined 'simple_bridge' basic-bridge <e811c2e8-5856-4656-9470-1ea534fc1a63> [2016-04-14 00:25:53] VERBOSE[19934][C-00000012] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/168-00000019' [2016-04-14 00:25:55] NOTICE[2384] chan_sip.c: Received SIP subscribe for peer without mailbox: 230 [2016-04-14 00:25:57] VERBOSE[19949][C-00000012] bridge_channel.c: Channel PJSIP/167-0000001a left 'simple_bridge' basic-bridge <e811c2e8-5856-4656-9470-1ea534fc1a63> [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] res_musiconhold.c: Stopped music on hold on PJSIP/168-00000019 [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] bridge_channel.c: Channel PJSIP/168-00000019 left 'simple_bridge' basic-bridge <e811c2e8-5856-4656-9470-1ea534fc1a63> [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] app_macro.c: Channel 'PJSIP/168-00000019' jumping out of macro 'dial-one' [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] app_macro.c: Channel 'PJSIP/168-00000019' jumping out of macro 'exten-vm' [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [166@from-internal-xfer:1] GotoIf("PJSIP/168-00000019", "1?ext-local,166,1") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Goto (ext-local,166,1) [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [166@ext-local:1] Set("PJSIP/168-00000019", "__RINGTIMER=15") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [166@ext-local:2] Macro("PJSIP/168-00000019", "exten-vm,novm,166,0,0,0") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:1] Macro("PJSIP/168-00000019", "user-callerid,") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/168-00000019", "TOUCH_MONITOR=1460586350.603") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/168-00000019", "AMPUSER=168") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/168-00000019", "16?report") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Goto (macro-user-callerid,s,15) [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:15] GotoIf("PJSIP/168-00000019", "0?continue") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:16] ExecIf("PJSIP/168-00000019", "0?Set(__CALLEE_ACCOUNCODE=166)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:17] Set("PJSIP/168-00000019", "__TTL=63") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("PJSIP/168-00000019", "1?continue") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Goto (macro-user-callerid,s,29) [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:29] Set("PJSIP/168-00000019", "CALLERID(number)=168") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:30] Set("PJSIP/168-00000019", "CALLERID(name)=Binder Softphone") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:31] Set("PJSIP/168-00000019", "CDR(cnum)=168") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:32] Set("PJSIP/168-00000019", "CDR(cnam)=Binder Softphone") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-user-callerid:33] Set("PJSIP/168-00000019", "CHANNEL(language)=de") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:2] Set("PJSIP/168-00000019", "RingGroupMethod=none") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:3] Set("PJSIP/168-00000019", "__EXTTOCALL=166") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:4] Set("PJSIP/168-00000019", "__PICKUPMARK=166") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:5] Set("PJSIP/168-00000019", "RT=") in new stack [2016-04-14 00:25:57] WARNING[19934][C-00000012] chan_sip.c: This function can only be used on SIP channels. [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:6] ExecIf("PJSIP/168-00000019", "0?Macro(vm,novm,DIRECTDIAL,)") in new stack [2016-04-14 00:25:57] WARNING[19934][C-00000012] chan_sip.c: This function can only be used on SIP channels. [2016-04-14 00:25:57] WARNING[19934][C-00000012] chan_sip.c: This function can only be used on SIP channels. [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:7] ExecIf("PJSIP/168-00000019", "0?MacroExit()") in new stack [2016-04-14 00:25:57] WARNING[19934][C-00000012] chan_sip.c: This function can only be used on SIP channels. [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:8] Gosub("PJSIP/168-00000019", "sub-record-check,s,1(exten,166,dontcare)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/168-00000019", "3?initialized") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Goto (sub-record-check,s,10) [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/168-00000019", "Recordings initialized") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/168-00000019", "0?Set(ARG3=dontcare)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/168-00000019", "REC_POLICY_MODE_SAVE=") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/168-00000019", "1?Set(REC_STATUS=NO)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/168-00000019", "5?checkaction") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Goto (sub-record-check,s,17) [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/168-00000019", "1?sub-record-check,exten,1") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Goto (sub-record-check,exten,1) [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:1] NoOp("PJSIP/168-00000019", "Exten Recording Check between 168 and 166") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:2] Set("PJSIP/168-00000019", "CALLTYPE=internal") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:3] ExecIf("PJSIP/168-00000019", "0?Set(CALLTYPE=)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:4] Set("PJSIP/168-00000019", "CALLEE=dontcare") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:5] ExecIf("PJSIP/168-00000019", "0?Set(CALLEE=dontcare)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:6] GotoIf("PJSIP/168-00000019", "0?callee") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:7] GotoIf("PJSIP/168-00000019", "1?caller") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Goto (sub-record-check,exten,13) [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:13] Set("PJSIP/168-00000019", "RECMODE=dontcare") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:14] ExecIf("PJSIP/168-00000019", "0?Set(RECMODE=dontcare)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:15] ExecIf("PJSIP/168-00000019", "1?Set(RECMODE=dontcare)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:16] Gosub("PJSIP/168-00000019", "recordcheck,1(dontcare,internal,166)") in new stack [2016-04-14 00:25:57] VERBOSE[19934][C-00000012] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/168-00000019", "Starting recording check against dontcare") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/168-00000019", "dontcare") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Goto (sub-record-check,recordcheck,3) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/168-00000019", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [exten@sub-record-check:17] Return("PJSIP/168-00000019", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:9] GotoIf("PJSIP/168-00000019", "1?macrodial") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Goto (macro-exten-vm,s,15) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:15] GosubIf("PJSIP/168-00000019", "0?clrheader,1()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-exten-vm:16] Macro("PJSIP/168-00000019", "dial-one,,Tt,166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:1] Set("PJSIP/168-00000019", "DEXTEN=166") in new stack [2016-04-14 00:25:58] WARNING[19934][C-00000012] func_strings.c: EVAL requires an argument: EVAL(<string>) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:2] ExecIf("PJSIP/168-00000019", "0?Set(__ZULU_URL_166=)") in new stack [2016-04-14 00:25:58] WARNING[19934][C-00000012] func_strings.c: EVAL requires an argument: EVAL(<string>) [2016-04-14 00:25:58] WARNING[19934][C-00000012] func_strings.c: EVAL requires an argument: EVAL(<string>) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:3] ExecIf("PJSIP/168-00000019", "0?Set(__ZULU_TYPE_166=)") in new stack [2016-04-14 00:25:58] WARNING[19934][C-00000012] func_strings.c: EVAL requires an argument: EVAL(<string>) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:4] Set("PJSIP/168-00000019", "DIALSTATUS_CW=") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:5] GosubIf("PJSIP/168-00000019", "0?screen,1()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:6] GosubIf("PJSIP/168-00000019", "0?cf,1()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:7] GotoIf("PJSIP/168-00000019", "1?skip1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Goto (macro-dial-one,s,10) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:10] GotoIf("PJSIP/168-00000019", "0?nodial") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:11] GotoIf("PJSIP/168-00000019", "0?continue") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:12] Set("PJSIP/168-00000019", "EXTHASCW=ENABLED") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:13] GotoIf("PJSIP/168-00000019", "0?next1:cwinusebusy") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Goto (macro-dial-one,s,25) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:25] GotoIf("PJSIP/168-00000019", "0?next3:continue") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Goto (macro-dial-one,s,27) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:27] GotoIf("PJSIP/168-00000019", "0?nodial") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:28] GosubIf("PJSIP/168-00000019", "1?dstring,1():dlocal,1()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:1] Set("PJSIP/168-00000019", "DSTRING=") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:2] Set("PJSIP/168-00000019", "DEVICES=166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("PJSIP/168-00000019", "0?Return()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("PJSIP/168-00000019", "0?Set(DEVICES=66)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:5] Set("PJSIP/168-00000019", "LOOPCNT=1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:6] Set("PJSIP/168-00000019", "ITER=1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:7] Set("PJSIP/168-00000019", "THISDIAL=SIP/166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("PJSIP/168-00000019", "1?zap2dahdi,1()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("PJSIP/168-00000019", "0?Return()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("PJSIP/168-00000019", "NEWDIAL=") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("PJSIP/168-00000019", "LOOPCNT2=1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("PJSIP/168-00000019", "ITER2=1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("PJSIP/168-00000019", "THISPART2=SIP/166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("PJSIP/168-00000019", "0?Set(THISPART2=DAHDI/166)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("PJSIP/168-00000019", "NEWDIAL=SIP/166&") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("PJSIP/168-00000019", "ITER2=2") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("PJSIP/168-00000019", "0?begin2") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("PJSIP/168-00000019", "THISDIAL=SIP/166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("PJSIP/168-00000019", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("PJSIP/168-00000019", "1?docheck") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Goto (macro-dial-one,dstring,12) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:12] GotoIf("PJSIP/168-00000019", "0?skipset") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:13] Set("PJSIP/168-00000019", "DSTRING=SIP/166&") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:14] Set("PJSIP/168-00000019", "ITER=2") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:15] GotoIf("PJSIP/168-00000019", "0?begin") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:16] ExecIf("PJSIP/168-00000019", "0?Return()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:17] Set("PJSIP/168-00000019", "DSTRING=SIP/166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [dstring@macro-dial-one:18] Return("PJSIP/168-00000019", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:29] GotoIf("PJSIP/168-00000019", "0?nodial") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:30] GotoIf("PJSIP/168-00000019", "0?skiptrace") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:31] GosubIf("PJSIP/168-00000019", "1?ctset,1():ctclear,1()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [ctset@macro-dial-one:1] Set("PJSIP/168-00000019", "DB(CALLTRACE/166)=168") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [ctset@macro-dial-one:2] Return("PJSIP/168-00000019", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:32] Set("PJSIP/168-00000019", "D_OPTIONS=Tt") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:33] NoOp("PJSIP/168-00000019", "Blind Transfer: PJSIP/167-0000001a, Attended Transfer: , User: 168, Alert Info: info=alert-external") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:34] ExecIf("PJSIP/168-00000019", "0?Set(ALERT_INFO=info=alert-external)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:35] ExecIf("PJSIP/168-00000019", "1?Set(ALERT_INFO=)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:36] ExecIf("PJSIP/168-00000019", "0?Set(ALERT_INFO=)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:37] GosubIf("PJSIP/168-00000019", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:38] ExecIf("PJSIP/168-00000019", "0?Set(CHANNEL(musicclass)=)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:39] GosubIf("PJSIP/168-00000019", "0?qwait,1()") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:40] Set("PJSIP/168-00000019", "__CWIGNORE=") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:41] Set("PJSIP/168-00000019", "__KEEPCID=TRUE") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:42] GotoIf("PJSIP/168-00000019", "0?usegoto,1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:43] GotoIf("PJSIP/168-00000019", "0?godial") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:44] Gosub("PJSIP/168-00000019", "sub-presencestate-display,s,1(166)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@sub-presencestate-display:1] Goto("PJSIP/168-00000019", "state-dnd,1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Goto (sub-presencestate-display,state-dnd,1) [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [state-dnd@sub-presencestate-display:1] Set("PJSIP/168-00000019", "PRESENCESTATE_DISPLAY=(DND)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [state-dnd@sub-presencestate-display:2] Return("PJSIP/168-00000019", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:45] Set("PJSIP/168-00000019", "CONNECTEDLINE(name,i)=Matthias Binder Mobilteil(DND)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:46] Set("PJSIP/168-00000019", "CONNECTEDLINE(num)=166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:47] Set("PJSIP/168-00000019", "D_OPTIONS=TtI") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:48] Macro("PJSIP/168-00000019", "dialout-one-predial-hook,") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit("PJSIP/168-00000019", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@macro-dial-one:49] Dial("PJSIP/168-00000019", "SIP/166,,TtIb(func-apply-sipheaders^s^1)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] netsock2.c: Using SIP RTP TOS bits 184 [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] netsock2.c: Using SIP RTP CoS mark 5 [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] app_stack.c: SIP/166-0000000a Internal Gosub(func-apply-sipheaders,s,1) start [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/166-0000000a", "Applying SIP Headers to channel") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:2] ExecIf("SIP/166-0000000a", "1?Set(ZULU_EXT=166):Set(ZULU_EXT=166)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:3] GotoIf("SIP/166-0000000a", "0?endzulu") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/166-0000000a", "ZULU_TYPE_FINAL=") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:5] Set("SIP/166-0000000a", "ZULU_URL_FINAL=") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:6] ExecIf("SIP/166-0000000a", "0?Set(ZULU_TYPE_FINAL=)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("SIP/166-0000000a", "0?Set(ZULU_URL_FINAL=)") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:8] NoOp("SIP/166-0000000a", "ZULU EXTENSION: 166") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:9] NoOp("SIP/166-0000000a", "ZULU TYPE: ") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:10] NoOp("SIP/166-0000000a", "ZULU URL: ") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:11] NoOp("SIP/166-0000000a", "ZULU Finished") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:12] Set("SIP/166-0000000a", "SIPHEADERKEYS=Alert-Info") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:13] While("SIP/166-0000000a", "1") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:14] Set("SIP/166-0000000a", "sipheader=info=alert-external") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:15] SIPAddHeader("SIP/166-0000000a", "Alert-Info: info=alert-external") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:16] Set("SIP/166-0000000a", "PJSIP_HEADER(add,Alert-Info)=info=alert-external") in new stack [2016-04-14 00:25:58] ERROR[19934][C-00000012] res_pjsip_header_funcs.c: This function requires a PJSIP channel. [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:17] EndWhile("SIP/166-0000000a", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:13] While("SIP/166-0000000a", "0") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:18] Return("SIP/166-0000000a", "") in new stack [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] app_stack.c: Spawn extension (from-internal, 166, 1) exited non-zero on 'SIP/166-0000000a' [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] app_stack.c: SIP/166-0000000a Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL= [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] app_dial.c: Called SIP/166 [2016-04-14 00:25:58] VERBOSE[19934][C-00000012] app_dial.c: Connected line update to PJSIP/168-00000019 prevented. [2016-04-14 00:25:59] VERBOSE[19934][C-00000012] app_dial.c: SIP/166-0000000a is ringing

2
1 Like
3

This sounds like a phone problem, but I have tested with a 57iCT and 6865i and can’t reproduce this. Years ago I ran into some Aastra bugs that were fixed by enabling/disabling the “live dialpad” feature, you might also try disabling RPID if you are using it. Does the same problem appear if the call is an internal extension to extension call? Is there anything odd about the Caller ID Number or Caller ID name (and by odd I am thinking special characters in name or non-digits in number)?

4

Thank you for answer.
I tried enabling/disabling live dial pad
I tried disabling rpid

The problem also appears by internal Transfers from extension to extension (like ext 105 to ext 110)
We have some caller id names which contain ä,ö,ü
I tried transfer also with cids that dont contain letters like this.

We have more than 40 Aastra 6869i running. We have the problem with all phones, not only with one.

We give the numbers out with pai beginning with +43xxxx

5

Hi there,

i recorded the syslogs of the phone today.

Maybe someone can find the issue?
Im realy confused

Wireshark Syslog:
https://cloud.mitterhuemer.at/index.php/s/CcOEcX6IYyadLRk/download

6

TCPDUMP of Asterisk Directly
https://cloud.mitterhuemer.at/index.php/s/JLEuL6iuHA5aRou/download

7

What happens when you force all codecs to g711?

8

I will try tonight and post another syslog and tcpdump :slight_smile:
Thanks

9

Tried it actually with complete g711 forced on all extensions and also at the trunk.
I have the same Issue as with g722. Doesnt matter which codec i use.
In this capture i used g711a but i also tried it with g711u before.

Captured with Wireshark.

Asterisk TCPDUMP
https://cloud.mitterhuemer.at/index.php/s/KczAcI2nJznGuRo/download

Mitel 6869i Syslog Level 65535
https://cloud.mitterhuemer.at/index.php/s/a2EyziT3GryaVDc/download

10

This is the good case with chan sip for comparison which works fine:

Asterisk TCPDUMP ChanSIP
https://cloud.mitterhuemer.at/index.php/s/A6orcpikza4bEHb/download

Aastra 6869i Syslog 65535 ChanSIP
https://cloud.mitterhuemer.at/index.php/s/0CTohHleruP6UZk/download

11

Sounds like you need to open a issue with Mitel on this as the transfer on the phone is all handled by Mitel in the software stack of the phone.

12

Mitel Germany and Austria already told me they do not offer support for end consumers. Only for distributors and developers of PBX Systems.
So im confused and dont know how to get help for this :frowning:

Edit
If i had known about the bad support from Mitel before buying them i never would choose this Brand anymore.

My favourite phone for the next system will be the Sangoma S500
It looks very similar to my aastra
But we have over 40 peaces of them so we need a solution for our Aastra Phones.

13

I spent a few minutes reviewing the pcaps of a good and a bad transfer, and apart from confirming exactly what you report, I can’t see much. It will take someone very familiar with SIP to understand what’s at play here.

14

Ya unfortunately Mitel is not a certified partners of ours so we have no ability to assist here as a PBX Developer.

15

This is in german, but a technical support employee of Mitel is reviewing this maybe in the next few days.
http://forum.aastra.de/viewtopic.php?f=4&t=1842&start=10

16

Mitel Released a new Firmware which handles my bug a little bit.
The phone does not stuck anymore but i get an error (500 Server error) shown on the phones display when making a blind transfer. After this moment i can send a “goodbye” key and the phones disconnects the call.

Maybe someone can now help and tell me what causes the issue.

6800 Series Release Notes (V4.2.0 SP2, 07/2016, pdf) (English, 134.91 KB)

“ENH42545 In previous releases, a “UI Enhancements for Failed Call-on-Hold Retrieval
Scenarios” feature was implemented whereby the phones would display an
error message when an attempt to retrieve a call on hold failed. Moreover,
users were then able to drop the call on hold by pressing the Goodbye key.
In Release 4.2.0 SP2, this functionality has been extended to failed blind
transfer retrieval scenarios. As some platforms do not send NOTIFY messages
regarding call transfer progress details during blind transfer scenarios, issues
can arise if the transfer target does not answer the transfered call. In Release
4.2.0 SP2, when using the phones with these platforms, retrieving a call that
has been blind transferred will now result in an error message being displayed.
Users are then able to press the Goodbye key to drop the blind transferred call
after the failed retrieval attempt.”

17

Hallo Again,
i made some new Paket Captures from FreePBX and from the 6869i. (The german Mitel Support is analysing this also now)

With the latest firmware i get a defined error on the Phone now.

500 - Internal Server error (shown in the phone’s display)

This error appears when i make the Transfer…the phone stucks on hold…and after pressing “L1” (Line 1), the error 500 appears and the call gets unatented transfered.

6869i Syslogs (level 65535) Download and Asterisk Paket Capture
(tcpdump -w - -p -n -s 0 udp > /tmp/capture-asterisk.pcap)
https://cloud.mitterhuemer.at/index.php/s/giWvWEMeM5JrKYe/download

18

This would not a problem with mitel and pjsip and can only be resolved by Mitel or Digium. I suggest you open a bug also with Digium on this.

19

HI there,

After having a look at the sip traces I have come to the following conclusion:

The Problem:

The channel drivers CHAN_SIP and CHAN_PJSIP seem to implement the REFER method differently.

– CHAN_SIP responds the REFER with an “202 Accepted” followed by a “200 OK” in NOTIFY sip/frag body as soon as Asterisk knows that the user can be reached.

chan_sip.JPG1361Ă—617 149 KB

– On the other hand CHAN_PJSIP notifies all the progress details of the C user e.g. Trying, Ringing etc. It sends a “200 OK” ONLY if the called user answers the call.

chan_pjsip1.JPG1419Ă—649 153 KB

chan_pjsip2.JPG1421Ă—667 163 KB

This leads to the stated issue because in case of Blind Transfer, Mitel Phones expect a “200 OK” after REFER has been accepted. Otherwise the line is kept busy. This is by-design with no intension to change it at the moment.

The Solution or Workaround:

This issue can be avoided by using Semi-Attended Call Transfer instead of Blind Transfer. This is just an additional pressing of the “Dial” Key after the first “Xfer Press”. That is: Press Xfer → Enter the number → Press Dial → Press Xfer Key again.

However this will only work if following parameter is set in the configuration file (startup.cfg or aastra.cfg):

sip refer-to with replaces:1

Please confirm the parameter setting by downloading the server.cfg file on the Troubleshooting page of the Phone’s Web Page.

I hope this helps.

Thanks,

Mazhar

1 Like
20

FreePBX Community :slight_smile:

Are there any solutions to modify pjsip that this works without workaround?