Страница 1 из 2

Unable to acquire target extension for attended transfer!?

Добавлено: 14 янв 2015, 00:29
gaspaarr
Непонятная ситуация с переводом входящего звонка на виртуальный факс freepbx.

Поступает входящий звонок, оператор снимает трубку, делает перевод (в данном случае, как я понимаю не слепой) на факс (у него внутренний 200), видно, что звонящий уходит на удержание, слушает музыку, но после донабора оператором "bridge_basic.c: Unable to acquire target extension for attended transfer." и звонящий отключается (на записи слышу музыку и потом остановка).

По идее, если бы оператор донабирал чушь это было бы видно ввиде "Executing [2000@from-internal-xfer:1]", но ничего такого нет, и более того, при попытке воспроизвести ситуацию своими силами, звонок нормально переводится (через тот же транк, через тот же маршрут)... а при входящих с этого (346613) номера ситуация повторилась 3 или 4 раза.

В чем может быть дело?

Код: Выделить всё

[2015-01-13 14:34:16] VERBOSE[27429][C-00002ee8] netsock2.c: Using SIP RTP TOS bits 184
[2015-01-13 14:34:16] VERBOSE[27429][C-00002ee8] netsock2.c: Using SIP RTP CoS mark 5
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:1] Set("SIP/PROV-00000a91", "__FROM_DID=2220202") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:2] Gosub("SIP/PROV-00000a91", "sub-record-check,s,1(in,2220202,force)") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/PROV-00000a91", "0?initialized") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:2] Set("SIP/PROV-00000a91", "__REC_STATUS=INITIALIZED") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:3] Set("SIP/PROV-00000a91", "NOW=1421148856") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:4] Set("SIP/PROV-00000a91", "__DAY=13") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:5] Set("SIP/PROV-00000a91", "__MONTH=01") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:6] Set("SIP/PROV-00000a91", "__YEAR=2015") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:7] Set("SIP/PROV-00000a91", "__TIMESTR=20150113-143416") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:8] Set("SIP/PROV-00000a91", "__FROMEXTEN=unknown") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:9] Set("SIP/PROV-00000a91", "__MON_FMT=wav") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/PROV-00000a91", "Recordings initialized") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/PROV-00000a91", "0?Set(ARG3=dontcare)") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:12] Set("SIP/PROV-00000a91", "REC_POLICY_MODE_SAVE=") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:13] GotoIf("SIP/PROV-00000a91", "2?checkaction") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,s,16)
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:16] GotoIf("SIP/PROV-00000a91", "1?sub-record-check,in,1") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,in,1)
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [in@sub-record-check:1] NoOp("SIP/PROV-00000a91", "Inbound Recording Check to 2220202") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [in@sub-record-check:2] Set("SIP/PROV-00000a91", "FROMEXTEN=unknown") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [in@sub-record-check:3] ExecIf("SIP/PROV-00000a91", "11?Set(FROMEXTEN=346613)") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [in@sub-record-check:4] Gosub("SIP/PROV-00000a91", "recordcheck,1(force,in,2220202)") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/PROV-00000a91", "Starting recording check against force") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/PROV-00000a91", "force") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,recordcheck,5)
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:5] Set("SIP/PROV-00000a91", "__REC_POLICY_MODE=FORCE") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:6] GotoIf("SIP/PROV-00000a91", "1?startrec") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,recordcheck,16)
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:16] NoOp("SIP/PROV-00000a91", "Starting recording: in, 2220202") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:17] Set("SIP/PROV-00000a91", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:18] Set("SIP/PROV-00000a91", "__CALLFILENAME=in-2220202-346613-20150113-143416-1421148856.136272") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:19] MixMonitor("SIP/PROV-00000a91", "2015/01/13/in-2220202-346613-20150113-143416-1421148856.136272.wav,ai(LOCAL_MIXMON_ID),") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:20] Set("SIP/PROV-00000a91", "__MIXMON_ID=0x7f9838a59190") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:21] Set("SIP/PROV-00000a91", "__RECORD_ID=SIP/PROV-00000a91") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:22] Set("SIP/PROV-00000a91", "__REC_STATUS=RECORDING") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:23] Set("SIP/PROV-00000a91", "CDR(recordingfile)=in-2220202-346613-20150113-143416-1421148856.136272.wav") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:24] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [in@sub-record-check:5] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:3] Gosub("SIP/PROV-00000a91", "app-blacklist-check,s,1()") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("SIP/PROV-00000a91", "0?blacklisted") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@app-blacklist-check:2] Set("SIP/PROV-00000a91", "CALLED_BLACKLIST=1") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@app-blacklist-check:3] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:4] Set("SIP/PROV-00000a91", "CDR(did)=2220202") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:5] ExecIf("SIP/PROV-00000a91", "0 ?Set(CALLERID(name)=346613)") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:6] Set("SIP/PROV-00000a91", "CHANNEL(musicclass)=default") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:7] Set("SIP/PROV-00000a91", "__MOHCLASS=default") in new stack
[2015-01-13 14:34:16] WARNING[29316][C-00002ee8] func_channel.c: Unknown or unavailable item requested: 'reversecharge'
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:8] GotoIf("SIP/PROV-00000a91", "0?macro-hangupcall") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:9] Set("SIP/PROV-00000a91", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:10] Set("SIP/PROV-00000a91", "CALLERPRES()=allowed_not_screened") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2220202@from-trunk:11] Goto("SIP/PROV-00000a91", "ivr-2,s,1") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Goto (ivr-2,s,1)
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:1] Set("SIP/PROV-00000a91", "INVALID_LOOPCOUNT=0") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:2] Set("SIP/PROV-00000a91", "_IVR_CONTEXT_ivr-2=") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:3] Set("SIP/PROV-00000a91", "_IVR_CONTEXT=ivr-2") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:4] Set("SIP/PROV-00000a91", "__IVR_RETVM=") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:5] GotoIf("SIP/PROV-00000a91", "0?skip") in new stack
[2015-01-13 14:34:16] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:6] Answer("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:16] VERBOSE[29320][C-00002ee8] app_mixmonitor.c: Begin MixMonitor Recording SIP/PROV-00000a91
[2015-01-13 14:34:17] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:7] Wait("SIP/PROV-00000a91", "1") in new stack
[2015-01-13 14:34:18] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:8] Set("SIP/PROV-00000a91", "IVR_MSG=custom/IVR-XX") in new stack
[2015-01-13 14:34:18] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:9] Set("SIP/PROV-00000a91", "TIMEOUT(digit)=3") in new stack
[2015-01-13 14:34:18] VERBOSE[29316][C-00002ee8] func_timeout.c: Digit timeout set to 3.000
[2015-01-13 14:34:18] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@ivr-2:10] ExecIf("SIP/PROV-00000a91", "1?Background(custom/IVR-XX)") in new stack
[2015-01-13 14:34:18] VERBOSE[29316][C-00002ee8] file.c: <SIP/PROV-00000a91> Playing 'custom/IVR-XX.slin' (language 'ru')
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [0@ivr-2:1] Goto("SIP/PROV-00000a91", "timeconditions,2,1") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (timeconditions,2,1)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:1] Set("SIP/PROV-00000a91", "DB(TC/2/INUSESTATE)=INUSE") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:2] Set("SIP/PROV-00000a91", "DB(TC/2/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:3] GotoIfTime("SIP/PROV-00000a91", "20:30-07:50,*,*,*?truestate") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:4] GotoIf("SIP/PROV-00000a91", "0?truegoto") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:5] ExecIf("SIP/PROV-00000a91", "0?Set(DB(TC/2)=)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:6] Set("SIP/PROV-00000a91", "DEVICE_STATE(Custom:TC2)=INUSE") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:7] ExecIf("SIP/PROV-00000a91", "0?Set(NOT_INUSE)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [2@timeconditions:8] GotoIf("SIP/PROV-00000a91", "1?from-did-direct,1802,1") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (from-did-direct,1802,1)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [1802@from-did-direct:1] GotoIf("SIP/PROV-00000a91", "1?ext-local,1802,1") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (ext-local,1802,1)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [1802@ext-local:1] Set("SIP/PROV-00000a91", "__RINGTIMER=20") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [1802@ext-local:2] Macro("SIP/PROV-00000a91", "exten-vm,novm,1802,1,0,1") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-exten-vm:1] Macro("SIP/PROV-00000a91", "user-callerid,") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/PROV-00000a91", "TOUCH_MONITOR=1421148856.136272") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/PROV-00000a91", "AMPUSER=346613") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/PROV-00000a91", "0?report") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("SIP/PROV-00000a91", "1?Set(REALCALLERIDNUM=346613)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/PROV-00000a91", "AMPUSER=") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/PROV-00000a91", "0?limit") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/PROV-00000a91", "AMPUSERCIDNAME=") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("SIP/PROV-00000a91", "1?report") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-user-callerid,s,16)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:16] GotoIf("SIP/PROV-00000a91", "0?continue") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:17] ExecIf("SIP/PROV-00000a91", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:18] Set("SIP/PROV-00000a91", "__TTL=64") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("SIP/PROV-00000a91", "1?continue") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-user-callerid,s,30)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:30] Set("SIP/PROV-00000a91", "CALLERID(number)=346613") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:31] Set("SIP/PROV-00000a91", "CALLERID(name)=346613") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:32] Set("SIP/PROV-00000a91", "CDR(cnum)=346613") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:33] Set("SIP/PROV-00000a91", "CDR(cnam)=346613") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-user-callerid:34] Set("SIP/PROV-00000a91", "CHANNEL(language)=ru") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-exten-vm:2] Set("SIP/PROV-00000a91", "RingGroupMethod=none") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-exten-vm:3] Set("SIP/PROV-00000a91", "__EXTTOCALL=1802") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-exten-vm:4] Set("SIP/PROV-00000a91", "__PICKUPMARK=1802") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-exten-vm:5] Set("SIP/PROV-00000a91", "RT=20") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-exten-vm:6] Gosub("SIP/PROV-00000a91", "sub-record-check,s,1(exten,1802,)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/PROV-00000a91", "11?initialized") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,s,10)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/PROV-00000a91", "Recordings initialized") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/PROV-00000a91", "0?Set(ARG3=dontcare)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:12] Set("SIP/PROV-00000a91", "REC_POLICY_MODE_SAVE=FORCE") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:13] GotoIf("SIP/PROV-00000a91", "5?checkaction") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,s,16)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@sub-record-check:16] GotoIf("SIP/PROV-00000a91", "1?sub-record-check,exten,1") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,exten,1)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:1] NoOp("SIP/PROV-00000a91", "Exten Recording Check between 346613 and 1802") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:2] Set("SIP/PROV-00000a91", "CALLTYPE=external") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:3] ExecIf("SIP/PROV-00000a91", "0?Set(CALLTYPE=)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:4] Set("SIP/PROV-00000a91", "CALLEE=dontcare") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:5] ExecIf("SIP/PROV-00000a91", "0?Set(CALLEE=dontcare)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:6] GotoIf("SIP/PROV-00000a91", "1?callee") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,exten,11)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:11] Gosub("SIP/PROV-00000a91", "recordcheck,1(dontcare,external,1802)") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/PROV-00000a91", "Starting recording check against dontcare") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/PROV-00000a91", "dontcare") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Goto (sub-record-check,recordcheck,3)
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [recordcheck@sub-record-check:3] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [exten@sub-record-check:12] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-exten-vm:7] Macro("SIP/PROV-00000a91", "dial-one,20,trL(720000:60000:29501),1802") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:1] Set("SIP/PROV-00000a91", "DEXTEN=1802") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:2] Set("SIP/PROV-00000a91", "DIALSTATUS_CW=") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:3] GosubIf("SIP/PROV-00000a91", "0?screen,1()") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:4] GosubIf("SIP/PROV-00000a91", "0?cf,1()") in new stack
[2015-01-13 14:34:20] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:5] GotoIf("SIP/PROV-00000a91", "1?skip1") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-dial-one,s,8)
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:8] GotoIf("SIP/PROV-00000a91", "0?nodial") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:9] GotoIf("SIP/PROV-00000a91", "0?continue") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:10] Set("SIP/PROV-00000a91", "EXTHASCW=ENABLED") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:11] GotoIf("SIP/PROV-00000a91", "0?next1:cwinusebusy") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-dial-one,s,23)
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:23] GotoIf("SIP/PROV-00000a91", "1?next3:continue") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-dial-one,s,24)
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:24] ExecIf("SIP/PROV-00000a91", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:25] GotoIf("SIP/PROV-00000a91", "0?nodial") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:26] GosubIf("SIP/PROV-00000a91", "1?dstring,1():dlocal,1()") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:1] Set("SIP/PROV-00000a91", "DSTRING=") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:2] Set("SIP/PROV-00000a91", "DEVICES=1802") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("SIP/PROV-00000a91", "0?Return()") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("SIP/PROV-00000a91", "0?Set(DEVICES=802)") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:5] Set("SIP/PROV-00000a91", "LOOPCNT=1") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:6] Set("SIP/PROV-00000a91", "ITER=1") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:7] Set("SIP/PROV-00000a91", "THISDIAL=SIP/1802") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("SIP/PROV-00000a91", "1?zap2dahdi,1()") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/PROV-00000a91", "0?Return()") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("SIP/PROV-00000a91", "NEWDIAL=") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("SIP/PROV-00000a91", "LOOPCNT2=1") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("SIP/PROV-00000a91", "ITER2=1") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("SIP/PROV-00000a91", "THISPART2=SIP/1802") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/PROV-00000a91", "0?Set(THISPART2=DAHDI/1802)") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("SIP/PROV-00000a91", "NEWDIAL=SIP/1802&") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("SIP/PROV-00000a91", "ITER2=2") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/PROV-00000a91", "0?begin2") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("SIP/PROV-00000a91", "THISDIAL=SIP/1802") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("SIP/PROV-00000a91", "1?doset") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-dial-one,dstring,12)
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:12] Set("SIP/PROV-00000a91", "DSTRING=SIP/1802&") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:13] Set("SIP/PROV-00000a91", "ITER=2") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf("SIP/PROV-00000a91", "0?begin") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:15] Set("SIP/PROV-00000a91", "DSTRING=SIP/1802") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [dstring@macro-dial-one:16] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:27] GotoIf("SIP/PROV-00000a91", "0?nodial") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:28] GotoIf("SIP/PROV-00000a91", "0?skiptrace") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:29] GosubIf("SIP/PROV-00000a91", "1?ctset,1():ctclear,1()") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [ctset@macro-dial-one:1] Set("SIP/PROV-00000a91", "DB(CALLTRACE/1802)=346613") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [ctset@macro-dial-one:2] Return("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:30] Set("SIP/PROV-00000a91", "D_OPTIONS=trL(720000:60000:29501)") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:31] ExecIf("SIP/PROV-00000a91", "0?SIPAddHeader(Alert-Info: )") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:32] ExecIf("SIP/PROV-00000a91", "0?SIPAddHeader()") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:33] ExecIf("SIP/PROV-00000a91", "1?Set(CHANNEL(musicclass)=default)") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:34] GosubIf("SIP/PROV-00000a91", "0?qwait,1()") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:35] Set("SIP/PROV-00000a91", "__CWIGNORE=") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:36] Set("SIP/PROV-00000a91", "__KEEPCID=TRUE") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:37] GotoIf("SIP/PROV-00000a91", "0?usegoto,1") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:38] GotoIf("SIP/PROV-00000a91", "1?godial") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-dial-one,s,43)
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:43] Macro("SIP/PROV-00000a91", "dialout-one-predial-hook,") in new stack

[2015-01-13 14:34:21] WARNING[29316][C-00002ee8] app_macro.c: No such context 'macro-dialout-one-predial-hook' for macro 'dialout-one-predial-hook'. Was called by s@macro-dial-one

[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-dial-one:44] Dial("SIP/PROV-00000a91", "SIP/1802,20,trL(720000:60000:29501)") in new stack
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] netsock2.c: Using SIP RTP TOS bits 184
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] netsock2.c: Using SIP RTP CoS mark 5
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] app_dial.c: Called SIP/1802
[2015-01-13 14:34:21] VERBOSE[29316][C-00002ee8] app_dial.c: SIP/1802-00000a92 is ringing
[2015-01-13 14:34:34] VERBOSE[29316][C-00002ee8] app_dial.c: SIP/1802-00000a92 answered SIP/PROV-00000a91
[2015-01-13 14:34:34] VERBOSE[29316][C-00002ee8] bridge_channel.c: Channel SIP/PROV-00000a91 joined 'simple_bridge' basic-bridge <7c8a66bb-78f2-4e26-b141-da3c4e4f7367>
[2015-01-13 14:34:34] VERBOSE[29370][C-00002ee8] bridge_channel.c: Channel SIP/1802-00000a92 joined 'simple_bridge' basic-bridge <7c8a66bb-78f2-4e26-b141-da3c4e4f7367>
[2015-01-13 14:34:54] VERBOSE[29370][C-00002ee8] file.c: <SIP/1802-00000a92> Playing 'pbx-transfer.slin' (language 'ru')
[2015-01-13 14:34:54] VERBOSE[29316][C-00002ee8] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/PROV-00000a91'

[2015-01-13 14:34:59] WARNING[29370][C-00002ee8] bridge_basic.c: Unable to acquire target extension for attended transfer.

[2015-01-13 14:34:59] VERBOSE[29370][C-00002ee8] bridge_channel.c: Channel SIP/1802-00000a92 left 'simple_bridge' basic-bridge <7c8a66bb-78f2-4e26-b141-da3c4e4f7367>
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] bridge_channel.c: Channel SIP/PROV-00000a91 left 'simple_bridge' basic-bridge <7c8a66bb-78f2-4e26-b141-da3c4e4f7367>
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] res_musiconhold.c: Stopped music on hold on SIP/PROV-00000a91
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] app_macro.c: Spawn extension (macro-dial-one, s, 44) exited non-zero on 'SIP/PROV-00000a91' in macro 'dial-one'
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] app_macro.c: Spawn extension (macro-exten-vm, s, 7) exited non-zero on 'SIP/PROV-00000a91' in macro 'exten-vm'
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] pbx.c: Spawn extension (ext-local, 1802, 2) exited non-zero on 'SIP/PROV-00000a91'
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] pbx.c: Executing [h@ext-local:1] Macro("SIP/PROV-00000a91", "hangupcall,") in new stack
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/PROV-00000a91", "1?theend") in new stack
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] pbx.c: Goto (macro-hangupcall,s,3)
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/PROV-00000a91", "0?Set(CDR(recordingfile)=)") in new stack
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] pbx.c: Executing [s@macro-hangupcall:4] Hangup("SIP/PROV-00000a91", "") in new stack
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/PROV-00000a91' in macro 'hangupcall'
[2015-01-13 14:34:59] VERBOSE[29316][C-00002ee8] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/PROV-00000a91'
[2015-01-13 14:34:59] VERBOSE[29320][C-00002ee8] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2015-01-13 14:34:59] VERBOSE[29320][C-00002ee8] app_mixmonitor.c: End MixMonitor Recording SIP/PROV-00000a91

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 02:36
ded
При при входящих с этого (346613) номера какой кодек на входящем плече?
А при попытке воспроизвести ситуацию своими силами?

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 10:08
gaspaarr
Для транка разрешены только alaw и ulaw, соответственно один их них, скорее всего alaw. Но логов пира в этот момент не велось.

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 13:19
ded
Проверяйте.

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 16:38
gaspaarr
Проверить с тем же номером не могу, т.к. не знаком с ними лично. При собственных тестах всегда был ALAW.
Есть какая-то встроенная функция, которая бы регулярно логила Chan_Sip Channel(s), чтобы можно было с большей выборкой сделать анализ по кодекам?

Но, даже если допустить, что был транскодинг, это как-то могло повлиять на перевод звонка? Вообще о чем говорит указанная ошибка?

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 17:25
ded
Вот как раз нельзя допустить, чтобы был транскодинг, ибо при транскодинге факс не пойдёт.
Указаная ошибка - надо разбираться в логике бриджинга:
http://doxygen.asterisk.org/trunk/de/dc ... ic_8c.html

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 20:06
gaspaarr
Попробовал с телефона с G722 позвонить на системный (виртуальный) факс, в соединениях используемый кодек был G722 (поддерживает ли системный факс этот кодек или был транскодинг?), так же пробовал с G722 звонить на аппаратный факс в ULAW, тоже был транскодинг. Прохождение факса не проверял, но факт отсутствия обрыва соединения зафиксировал.

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 21:15
ded
Не "чистый" эксперимент. У вас не соединяет через attended transfer входящий из мира, от провайдера, насколько я понял. И там G722 быть не может.
Проверьте свой виртуальный факс - экстен, на который переводите. Если это физический пир, то чтно указано в Transfer mode при выводе sip show peer XXX ?
Ну а если это виртуальный номер, то как стыкуется он с внутренним диал-планом from-internal?

Re: Unable to acquire target extension for attended transfer

Добавлено: 14 янв 2015, 22:14
gaspaarr
Делаю исходящий в мир через один транк, из-за тупости * получаю транскодинг между G722 и ALAW.
Он приходит как входящий на другой транк, соединяется с внутренним абонентом (уже на ALAW) оттуда перекидываю на факс.

Факс виртуальный:
[ext-featurecodes]
exten => 666,1,Goto(from-internal,200,1)

Re: Unable to acquire target extension for attended transfer

Добавлено: 15 янв 2015, 05:27
ded
1) Не надо использовать диавольское число 666
2) Ну а что такое 200?
dialplan show 200@from-internal ?
3) В таком варианте Вам надо делать трансфер не на 666, а на 200