FreePBX: Непонятная проблема с коммутацией.

[SolarW]

Привет всем.

Есть небольшая проблема с которой сходу не получается разобраться.
Система:
- Asterisk 1.6.2.9
- FreePBX 2.8.0.3
В системник вставлен Huawei 1550 3G модем и собран chan_datacard.
В модеме стоит симка с номером 091XXXXXXX.
Создан Custom Trunk в котором прописано datacard/datacard3/$OUTNUM$
В datacard.conf написано входящие звонки принимать в контекст datacard3-incoming.

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

[datacard3-incoming]
exten => s,1,Set(__FROM_DID=091XXXXXXX)
exten => s,n,Set(CALLERID(num)=${CALLERID(num):1}) ;отрезаю плюсик от номера 
exten => s,n,Set(CALLERID(name)=${CALLERID(num)})
exten => s,n,Goto(from-trunk,091XXXXXXX,1)

В Inbound Routes создаю маршрут, которым звонки с DID 091XXXXXXX и CID 38091YYYYYYY бросаю на DISA.

В результате получаю странный эффект.
Звоню на 091XXXXXXX с номера 38091YYYYYYY

PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER:

[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [s@datacard3-incoming:1] Set("Datacard/datacard3-44fb", "__FROM_DID=091XXXXXXX") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Function result is '+38091YYYYYYY'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [s@datacard3-incoming:2] Set("Datacard/datacard3-44fb", "CALLERID(num)=38091YYYYYYY") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Function result is '38091YYYYYYY'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [s@datacard3-incoming:3] Set("Datacard/datacard3-44fb", "CALLERID(name)=38091YYYYYYY") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Goto'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [s@datacard3-incoming:4] Goto("Datacard/datacard3-44fb", "from-trunk,091XXXXXXX,1") in new stack
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Goto (from-trunk,091XXXXXXX,1)
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [091XXXXXXX@from-trunk:1] Set("Datacard/datacard3-44fb", "__FROM_DID=091XXXXXXX") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Gosub'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [091XXXXXXX@from-trunk:2] Gosub("Datacard/datacard3-44fb", "app-blacklist-check,s,1") in new stack
[Oct 27 16:29:14] DEBUG[20311] app_stack.c: Channel Datacard/datacard3-44fb has no datastore, so we're allocating one.
[Oct 27 16:29:14] DEBUG[20311] db.c: Unable to find key '38091YYYYYYY' in family 'blacklist'
[Oct 27 16:29:14] DEBUG[20311] db.c: Unable to find key '38091YYYYYYY' in family 'blacklist'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Function result is '0'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Expression result is '0'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'GotoIf'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("Datacard/datacard3-44fb", "0?blacklisted") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Not taking any branch
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [s@app-blacklist-check:2] Set("Datacard/datacard3-44fb", "CALLED_BLACKLIST=1") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Return'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [s@app-blacklist-check:3] Return("Datacard/datacard3-44fb", "") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Function result is '38091YYYYYYY'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Expression result is '0'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Function result is '38091YYYYYYY'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'ExecIf'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [091XXXXXXX@from-trunk:3] ExecIf("Datacard/datacard3-44fb", "0 ?Set(CALLERID(name)=38091YYYYYYY)") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Function result is 'allowed_not_screened'
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [091XXXXXXX@from-trunk:4] Set("Datacard/datacard3-44fb", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [091XXXXXXX@from-trunk:5] Set("Datacard/datacard3-44fb", "CALLERPRES()=allowed_not_screened") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Goto'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [091XXXXXXX@from-trunk:6] Goto("Datacard/datacard3-44fb", "disa,1,1") in new stack
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Goto (disa,1,1)
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [1@disa:1] Set("Datacard/datacard3-44fb", "_DISA="disa,1,newcall"") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [1@disa:2] Set("Datacard/datacard3-44fb", "_DISACONTEXT=from-internal") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [1@disa:3] Set("Datacard/datacard3-44fb", "_KEEPCID=TRUE") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [1@disa:4] Set("Datacard/datacard3-44fb", "_HANGUP=") in new stack
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [1@disa:5] Set("Datacard/datacard3-44fb", "TIMEOUT(digit)=5") in new stack
[Oct 27 16:29:14] VERBOSE[20311] func_timeout.c: -- Digit timeout set to 5.000
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'Set'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [1@disa:6] Set("Datacard/datacard3-44fb", "TIMEOUT(response)=10") in new stack
[Oct 27 16:29:14] VERBOSE[20311] func_timeout.c: -- Response timeout set to 10.000
[Oct 27 16:29:14] DEBUG[20311] pbx.c: Launching 'DISA'
[Oct 27 16:29:14] VERBOSE[20311] pbx.c: -- Executing [1@disa:7] DISA("Datacard/datacard3-44fb", "no-password,disa-dial") in new stack
[Oct 27 16:29:14] DEBUG[20311] app_disa.c: Digittimeout: 5000
[Oct 27 16:29:14] DEBUG[20311] app_disa.c: Responsetimeout: 10000
[Oct 27 16:29:14] DEBUG[20311] app_disa.c: Mailbox:
[Oct 27 16:29:14] DEBUG[20311] app_disa.c: Context: disa-dial
[Oct 27 16:29:14] DEBUG[20311] app_disa.c: DISA no-password login success
[Oct 27 16:29:14] DEBUG[20311] channel.c: Set channel Datacard/datacard3-44fb to write format slin
[Oct 27 16:29:14] DEBUG[20311] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Oct 27 16:29:14] DEBUG[20311] channel.c: Prodding channel 'Datacard/datacard3-44fb'
[Oct 27 16:29:24] DEBUG[20311] app_disa.c: DISA extension entry timeout on chan Datacard/datacard3-44fb
[Oct 27 16:29:24] DEBUG[20311] __channel.c: [datacard3] Requested indication 8
[Oct 27 16:29:35] DEBUG[20311] pbx.c: Spawn extension (disa,1,7) exited non-zero on 'Datacard/datacard3-44fb'
[Oct 27 16:29:35] VERBOSE[20311] pbx.c: == Spawn extension (disa, 1, 7) exited non-zero on 'Datacard/datacard3-44fb'
[Oct 27 16:29:35] DEBUG[20311] channel.c: Soft-Hanging up channel 'Datacard/datacard3-44fb'
[Oct 27 16:29:35] DEBUG[20311] channel.c: Hanging up channel 'Datacard/datacard3-44fb'
[Oct 27 16:29:35] DEBUG[20311] __channel.c: [datacard3] Hanging up device
[Oct 27 16:29:35] DEBUG[3437] __channel.c: Checking device state for device datacard3
[Oct 27 16:29:35] DEBUG[3437] devicestate.c: Changing state for Datacard/datacard3 - state 1 (Not in use)
[Oct 27 16:29:35] DEBUG[3437] devicestate.c: device 'Datacard/datacard3' state '1'
[Oct 27 16:29:35] DEBUG[3437] __channel.c: Checking device state for device datacard3
[Oct 27 16:29:35] DEBUG[3437] devicestate.c: Changing state for Datacard/datacard3 - state 1 (Not in use)
[Oct 27 16:29:35] DEBUG[3437] devicestate.c: device 'Datacard/datacard3' state '1'
[Oct 27 16:29:35] DEBUG[3465] app_queue.c: Device 'Datacard/datacard3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct 27 16:29:35] DEBUG[3465] app_queue.c: Device 'Datacard/datacard3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct 27 16:29:35] DEBUG[3471] __at_response.c: [datacard3] CEND: call_index: 1
[Oct 27 16:29:35] DEBUG[3471] __at_response.c: [datacard3] CEND: duration: 0
[Oct 27 16:29:35] DEBUG[3471] __at_response.c: [datacard3] CEND: end_status: 29
[Oct 27 16:29:35] DEBUG[3471] __at_response.c: [datacard3] CEND: cc_cause: 17
[Oct 27 16:29:35] DEBUG[3471] __at_response.c: [datacard3] Line disconnected
[Oct 27 16:29:35] DEBUG[3471] __at_response.c: [datacard3] Successful hangup

Слушаю в течении 10 сек (тайм-аут DISA) длинные гудки (модем трубку не берет) и происходит обрыв.
Где я забыл сказать модему трубку снимать?

[zlat]

тоже были проблемы с дизой этим летом, на этой же версии * и freepbx2.8 и тоже с модемом е1550
диза вроде через раз давала доступ, вернее 7из10 вызовов заканчивались неудачей. плюнул тогда, написал кастумконтеккст с read, все заработало

[trscod]

А чего за ос, какое ядро?

[SolarW]

2 trscod
Ubuntu 10.04 server
Linux 2.6.34-020634-generic #020634 SMP

2 zlat
Хорошо, попробую обновить до текущих версий asterisk и chan_datacard.
На случай если не поможет - можно привести костяк диалплана с read?
А то моего скила пока не хватает на написание с нуля таких вещей...
В чужом думаю разберусь и смогу откорректировать а вот с нуля вряд ли...

[ded]

exten => _X.,1,Read(DATACARD)
exten => _X.,2,Dial(Datacard/datacard3/${DATACARD})

[zlat]

PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER:

[outgoing]
exten => s,1,Set(samples=0)
exten => s,n(sample),Set(samples=$[${samples}+1])
exten => s,n,GotoIf($[${samples}<4]?:h,1)
exten => s,n,Read(destin,custom/press-number,11,1,20)
exten => s,n,NoOp(${destin})
exten => s,n,Dial(LOCAL/${destin}@from-internal,45,L($[${bal}*1000]))
exten => s,n,NoOp(${DIALSTATUS})
exten => s,n,GotoIf($[$[ "${DIALSTATUS}" = "CHANUNAVAIL" ] ]?:s-${DIALSTATUS},1)
exten => s,n,Playback(all-circuits-busy)
exten => s,n,Goto(h,1)
exten => s-BUSY,1,Playback(number)
exten => s-BUSY,n,Playback(zanjat)
exten => s-BUSY,n,Goto(outgoing,s,sample)
.......
exten => s-ANSWER,1,Goto(h,1)

exten => h,1,Hangup

Как-то так, ответ модема у меня вдругом контексте, где происходит аутентификация и проговаривается баланс