Стал некорректно работать модуль Follow ME когда внутренний номер не зарегистрирован (статус UNKNOWN) (когда номер зарегистрирован но занят - все нормально): вместо переадресации на следующий номер в списке (внешний или внутренний - непринципиально) пытается позвонить на недоступный номер.
PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER: Лог
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (from-internal,401,20)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:20] Set("IAX2/400-14095", "RingGroupMethod=firstavailable") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:21] Set("IAX2/400-14095", "_FMGRP=401") in new stack
[2013-11-02 00:22:32] VERBOSE[3558][C-00000018] app_mixmonitor.c: == Begin MixMonitor Recording IAX2/400-14095
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:22] GotoIf("IAX2/400-14095", "0?doconfirm") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:23] Macro("IAX2/400-14095", "dial,60,TtrI,401-89161234567#") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:1] GotoIf("IAX2/400-14095", "1?dial") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,3)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:3] AGI("IAX2/400-14095", "dialparties.agi") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_request: dialparties.agi
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_channel: IAX2/400-14095
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_language: ru
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_type: IAX2
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_uniqueid: 1383337352.61
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_version: 11.6.0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callerid: 400
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_calleridname: Evgeny
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callingpres: 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callingani2: 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callington: 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callingtns: 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_dnid: 401
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_rdnis: unknown
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_context: macro-dial
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_extension: s
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_priority: 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_enhanced: 0.0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_accountcode:
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_threadid: -1243067536
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >>
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Starting New Dialparties.agi" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE CWINUSEBUSY
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (true)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ASTVERSION
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (11.6.0)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ASTCHANDAHDI
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (1)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE CWIGNORE
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE CFIGNORE
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE HAS_EXTENSION_STATE
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Caller ID name is 'Evgeny' number is '400'" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Caller ID name is 'Evgeny' number is '400'
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE QUEUEWAIT
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE __KEEPCID "TRUE"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE DIALSTATUS_CW ""
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (60)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG2
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (TtrI)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE RingGroupMethod
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (firstavailable)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ALERT_INFO
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE SIPADDHEADER
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE FMGRP
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE PR_DIALSTATUS
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE NODEST
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE RINGGROUP_INDEX
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE USE_CONFIRMATION
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "USE_CONFIRMATION: 'FALSE'" 5
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "RINGGROUP_INDEX: ''" 5
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Methodology of ring is 'firstavailable'" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Methodology of ring is 'firstavailable'
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401-89161234567#)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Added extension 401 to extension map" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Added extension 401 to extension map
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Added extension 89161234567# to extension map" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Added extension 89161234567# to extension map
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE SCREEN
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE FROM_DID
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CF" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 401 cf is disabled" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Extension 401 cf is disabled
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CF" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 89161234567# cf is disabled" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Extension 89161234567# cf is disabled
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "DND" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 401 do not disturb is disabled" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Extension 401 do not disturb is disabled
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CW" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFB" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFU" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "extnum 401 has: cw: 0; hascfb: 0 [] hascfu: 0 []" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE EXTENSION_STATE(401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (UNAVAILABLE)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "EXTENSION_STATE: 4 (UNAVAILABLE)" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: EXTENSION_STATE: 4 (UNAVAILABLE)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 401 has ExtensionState: 4" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Extension 401 has ExtensionState: 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Checking CW and CFB status for extension 401" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Checking CW and CFB status for extension 401
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "AMPUSER" "401/device"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "DEVICE" "401/dial"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (IAX2/401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CW" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFB" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFU" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "extnum 89161234567# has: cw: 0; hascfb: 0 [] hascfu: 0 []" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Built External dialstring component for 89161234567: Local/89161234567@from-internal/n" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE FILTERED_DIAL "401-89161234567"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Filtered ARG3: 401-89161234567" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Filtered ARG3: 401-89161234567
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE CALLTRACE_HUNT "400"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE HuntMember0 "IAX2/401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE HuntMember1 "Local/89161234567@from-internal/n"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "NODEST: 401 adding M(auto-blkvm) to dialopts: TtrIM(auto-blkvm)" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "NODEST: 401 blkvm enabled macro already in dialopts: TtrIM(auto-blkvm)" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE ds ",60,TtrIM(auto-blkvm)"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE HuntMembers "2"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET PRIORITY huntdial
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- <IAX2/400-14095>AGI Script dialparties.agi completed, returning 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:20] NoOp("IAX2/400-14095", "Returned from dialparties with hunt groups to dial ") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:21] Set("IAX2/400-14095", "HuntLoop=0") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:22] GotoIf("IAX2/400-14095", "1?a30") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,26)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:26] Set("IAX2/400-14095", "HuntMember=HuntMember0") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:27] GotoIf("IAX2/400-14095", "1?a32:a35") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,28)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:28] Set("IAX2/400-14095", "CT_EXTEN=401") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:29] Set("IAX2/400-14095", "DB(CALLTRACE/401)=400") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:30] Goto("IAX2/400-14095", "s,a42") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,38)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:38] Dial("IAX2/400-14095", "IAX2/401,60,TtrIM(auto-blkvm)") in new stack
[2013-11-02 00:22:32] WARNING[3557][C-00000018] app_dial.c: Unable to create channel of type 'IAX2' (cause 20 - Subscriber absent)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:20] Set("IAX2/400-14095", "RingGroupMethod=firstavailable") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:21] Set("IAX2/400-14095", "_FMGRP=401") in new stack
[2013-11-02 00:22:32] VERBOSE[3558][C-00000018] app_mixmonitor.c: == Begin MixMonitor Recording IAX2/400-14095
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:22] GotoIf("IAX2/400-14095", "0?doconfirm") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [401@from-internal:23] Macro("IAX2/400-14095", "dial,60,TtrI,401-89161234567#") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:1] GotoIf("IAX2/400-14095", "1?dial") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,3)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:3] AGI("IAX2/400-14095", "dialparties.agi") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_request: dialparties.agi
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_channel: IAX2/400-14095
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_language: ru
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_type: IAX2
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_uniqueid: 1383337352.61
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_version: 11.6.0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callerid: 400
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_calleridname: Evgeny
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callingpres: 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callingani2: 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callington: 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_callingtns: 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_dnid: 401
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_rdnis: unknown
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_context: macro-dial
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_extension: s
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_priority: 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_enhanced: 0.0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_accountcode:
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> agi_threadid: -1243067536
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >>
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Starting New Dialparties.agi" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE CWINUSEBUSY
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (true)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ASTVERSION
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (11.6.0)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ASTCHANDAHDI
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (1)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE CWIGNORE
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE CFIGNORE
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE HAS_EXTENSION_STATE
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Caller ID name is 'Evgeny' number is '400'" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Caller ID name is 'Evgeny' number is '400'
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE QUEUEWAIT
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE __KEEPCID "TRUE"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE DIALSTATUS_CW ""
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (60)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG2
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (TtrI)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE RingGroupMethod
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (firstavailable)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ALERT_INFO
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE SIPADDHEADER
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE FMGRP
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE PR_DIALSTATUS
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE NODEST
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE RINGGROUP_INDEX
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE USE_CONFIRMATION
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "USE_CONFIRMATION: 'FALSE'" 5
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "RINGGROUP_INDEX: ''" 5
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Methodology of ring is 'firstavailable'" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Methodology of ring is 'firstavailable'
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401-89161234567#)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Added extension 401 to extension map" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Added extension 401 to extension map
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Added extension 89161234567# to extension map" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Added extension 89161234567# to extension map
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE ARG4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE SCREEN
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE FROM_DID
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CF" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 401 cf is disabled" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Extension 401 cf is disabled
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CF" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 89161234567# cf is disabled" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Extension 89161234567# cf is disabled
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "DND" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 401 do not disturb is disabled" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Extension 401 do not disturb is disabled
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CW" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFB" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFU" "401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "extnum 401 has: cw: 0; hascfb: 0 [] hascfu: 0 []" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << GET VARIABLE EXTENSION_STATE(401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (UNAVAILABLE)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "EXTENSION_STATE: 4 (UNAVAILABLE)" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: EXTENSION_STATE: 4 (UNAVAILABLE)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Extension 401 has ExtensionState: 4" 1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: dialparties.agi: Extension 401 has ExtensionState: 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Checking CW and CFB status for extension 401" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Checking CW and CFB status for extension 401
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "AMPUSER" "401/device"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "DEVICE" "401/dial"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1 (IAX2/401)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CW" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFB" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << DATABASE GET "CFU" "89161234567#"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "extnum 89161234567# has: cw: 0; hascfb: 0 [] hascfu: 0 []" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Built External dialstring component for 89161234567: Local/89161234567@from-internal/n" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE FILTERED_DIAL "401-89161234567"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "Filtered ARG3: 401-89161234567" 3
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- dialparties.agi: Filtered ARG3: 401-89161234567
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE CALLTRACE_HUNT "400"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE HuntMember0 "IAX2/401"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE HuntMember1 "Local/89161234567@from-internal/n"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "NODEST: 401 adding M(auto-blkvm) to dialopts: TtrIM(auto-blkvm)" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << VERBOSE "NODEST: 401 blkvm enabled macro already in dialopts: TtrIM(auto-blkvm)" 4
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE ds ",60,TtrIM(auto-blkvm)"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET VARIABLE HuntMembers "2"
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=1
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Rx << SET PRIORITY huntdial
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: <IAX2/400-14095>AGI Tx >> 200 result=0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] res_agi.c: -- <IAX2/400-14095>AGI Script dialparties.agi completed, returning 0
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:20] NoOp("IAX2/400-14095", "Returned from dialparties with hunt groups to dial ") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:21] Set("IAX2/400-14095", "HuntLoop=0") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:22] GotoIf("IAX2/400-14095", "1?a30") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,26)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:26] Set("IAX2/400-14095", "HuntMember=HuntMember0") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:27] GotoIf("IAX2/400-14095", "1?a32:a35") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,28)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:28] Set("IAX2/400-14095", "CT_EXTEN=401") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:29] Set("IAX2/400-14095", "DB(CALLTRACE/401)=400") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:30] Goto("IAX2/400-14095", "s,a42") in new stack
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Goto (macro-dial,s,38)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] pbx.c: -- Executing [s@macro-dial:38] Dial("IAX2/400-14095", "IAX2/401,60,TtrIM(auto-blkvm)") in new stack
[2013-11-02 00:22:32] WARNING[3557][C-00000018] app_dial.c: Unable to create channel of type 'IAX2' (cause 20 - Subscriber absent)
[2013-11-02 00:22:32] VERBOSE[3557][C-00000018] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
Если номер занят - переадресация отрабатывает корректно. Проблема присутствуют и на номерах, подключенных по SIP.
Установлен FreePBX 2.11.0.11 и Asterisk 11.6.0. Система - CentOS 6.4. Модуль Follow Me последний 2.11.0.3. Все настраивалось из FreePBX, ручных правок в конфиги не вносил.