Нет голоса(звука) во входящих

Question

Кручу не могу разобраться в чем беда. Чего только не перепробовал, грешу уже на DVG-7111S.

И так имеем: - внутренние между собой хорошо - внутренний на внешний хорошо - входящий на группу плохо, нет голоса

Везде DHCP: Все устройства и Клиенты (10.10.1.0) <-> NAT (DMZ) <-> Сервер (10.10.99.1)

704444 - FXO он же транк (DVG-7111S) 777 - FXS 100 (DPH-400S), 200, 300 - внутренние Extension 600 - группа внутренних

service iptables stop

FreePBX config:

sipgeneraladditional.conf:

faxdetect=yes
vmexten=*97
context=from-sip-external
callerid=Unknown
notifyringing=yes
notifyhold=yes
tos_sip=cs3
tos_audio=ef
tos_video=af41
alwaysauthreject=yes
useragent=FPBX-2.10.0(1.8.9.3)
disallow=all
allow=ulaw
language=ru
callevents=no
jbenable=no
defaultexpiry=120
minexpiry=60
maxexpiry=3600
registertimeout=20
notifyhold=yes
notifyringing=yes
checkmwi=10
srvlookup=no
allowguest=yes
registerattempts=0
g726nonstandard=no
t38pt_udptl=no
videosupport=no
maxcallbitrate=384
canreinvite=no
rtpholdtimeout=300
rtpkeepalive=0
rtptimeout=300
nat=route
externip=128.124.110.134
localnet=10.10.99.0/255.255.255.0
localnet=10.10.1.0/255.255.255.0

sip_additional.conf

[100]
deny=0.0.0.0/0.0.0.0
secret=
dtmfmode=rfc2833
canreinvite=no
context=from-internal
host=dynamic
trustrpid=yes
sendrpid=no
type=friend
nat=route
port=5060
qualify=yes
qualifyfreq=60
transport=udp
encryption=no
callgroup=
pickupgroup=
dial=SIP/100
mailbox=100@device
permit=0.0.0.0/0.0.0.0
callerid=op01 <100>
callcounter=yes
faxdetect=no
cc_monitor_policy=generic

... [200]-[300] то же

[704444]
host=dynamic
type=friend
username=704444
secret=704444
qualify=yes
context=from-trunk
;insecure=invite
;nat=yes

[777]
deny=0.0.0.0/0.0.0.0
secret=
dtmfmode=rfc2833
canreinvite=no
context=from-internal
host=dynamic
trustrpid=yes
sendrpid=no
type=friend
nat=yes
port=5060
qualify=yes
qualifyfreq=60
transport=udp
encryption=no
callgroup=
pickupgroup=
dial=SIP/777
mailbox=777@device
permit=0.0.0.0/0.0.0.0
callerid=777 <777>
callcounter=yes
faxdetect=no
cc_monitor_policy=generic

Остальное выложил на файл-сервер - http://zalil.ru/33614451

Логи:

  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [600@from-trunk:1] NoOp("SIP/704444-0000003d", "Catch-All DID Match - Found 600 - You probably want a DID for this.") in new stack
    -- Executing [600@from-trunk:2] Goto("SIP/704444-0000003d", "ext-did,s,1") in new stack
    -- Goto (ext-did,s,1)
    -- Executing [s@ext-did:1] ExecIf("SIP/704444-0000003d", "1?Set(__FROM_DID=s)") in new stack
    -- Executing [s@ext-did:2] Gosub("SIP/704444-0000003d", "app-blacklist-check,s,1()") in new stack
    -- Executing [s@app-blacklist-check:1] GotoIf("SIP/704444-0000003d", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:2] Set("SIP/704444-0000003d", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:3] Return("SIP/704444-0000003d", "") in new stack
    -- Executing [s@ext-did:3] Gosub("SIP/704444-0000003d", "sub-record-cancel,s,1()") in new stack
    -- Executing [s@sub-record-cancel:1] ExecIf("SIP/704444-0000003d", "1?Return()") in new stack
    -- Executing [s@ext-did:4] Set("SIP/704444-0000003d", "__REC_POLICY_MODE=never") in new stack
    -- Executing [s@ext-did:5] Set("SIP/704444-0000003d", "CHANNEL(language)=ru") in new stack
    -- Executing [s@ext-did:6] Set("SIP/704444-0000003d", "CDR(did)=s") in new stack
    -- Executing [s@ext-did:7] ExecIf("SIP/704444-0000003d", "0 ?Set(CALLERID(name)=704444)") in new stack
    -- Executing [s@ext-did:8] Set("SIP/704444-0000003d", "__CALLINGPRES_SV=allowed_not_screened") in new stack
    -- Executing [s@ext-did:9] Set("SIP/704444-0000003d", "CALLERPRES()=allowed_not_screened") in new stack
    -- Executing [s@ext-did:10] Goto("SIP/704444-0000003d", "ext-group,600,1") in new stack
    -- Goto (ext-group,600,1)
    -- Executing [600@ext-group:1] Macro("SIP/704444-0000003d", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/704444-0000003d", "AMPUSER=704444") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("SIP/704444-0000003d", "0?report") in new stack
    -- Executing [s@macro-user-callerid:3] ExecIf("SIP/704444-0000003d", "1?Set(REALCALLERIDNUM=704444)") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/704444-0000003d", "AMPUSER=704444") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/704444-0000003d", "AMPUSERCIDNAME=704444") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/704444-0000003d", "0?report") in new stack
    -- Executing [s@macro-user-callerid:7] Set("SIP/704444-0000003d", "AMPUSERCID=704444") in new stack
    -- Executing [s@macro-user-callerid:8] Set("SIP/704444-0000003d", "CALLERID(all)="704444" <704444>") in new stack
    -- Executing [s@macro-user-callerid:9] GotoIf("SIP/704444-0000003d", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:10] ExecIf("SIP/704444-0000003d", "0?Set(GROUP(concurrency_limit)=704444)") in new stack
    -- Executing [s@macro-user-callerid:11] GosubIf("SIP/704444-0000003d", "0?sub-ccss,s,1(ext-group,600)") in new stack
    -- Executing [s@macro-user-callerid:12] ExecIf("SIP/704444-0000003d", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@macro-user-callerid:13] GotoIf("SIP/704444-0000003d", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:14] Set("SIP/704444-0000003d", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:15] GotoIf("SIP/704444-0000003d", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,26)
    -- Executing [s@macro-user-callerid:26] Set("SIP/704444-0000003d", "CALLERID(number)=704444") in new stack
    -- Executing [s@macro-user-callerid:27] Set("SIP/704444-0000003d", "CALLERID(name)=704444") in new stack
    -- Executing [s@macro-user-callerid:28] Set("SIP/704444-0000003d", "CHANNEL(language)=ru") in new stack
    -- Executing [600@ext-group:2] Macro("SIP/704444-0000003d", "blkvm-setifempty,") in new stack
    -- Executing [s@macro-blkvm-setifempty:1] GotoIf("SIP/704444-0000003d", "1?init") in new stack
    -- Goto (macro-blkvm-setifempty,s,4)
    -- Executing [s@macro-blkvm-setifempty:4] Set("SIP/704444-0000003d", "__BLKVM_CHANNEL=SIP/704444-0000003d") in new stack
    -- Executing [s@macro-blkvm-setifempty:5] Set("SIP/704444-0000003d", "SHARED(BLKVM,SIP/704444-0000003d)=TRUE") in new stack
    -- Executing [s@macro-blkvm-setifempty:6] Set("SIP/704444-0000003d", "GOSUB_RETVAL=TRUE") in new stack
    -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/704444-0000003d", "") in new stack
    -- Executing [600@ext-group:3] GotoIf("SIP/704444-0000003d", "1?skipov") in new stack
    -- Goto (ext-group,600,6)
    -- Executing [600@ext-group:6] Set("SIP/704444-0000003d", "RRNODEST=") in new stack
    -- Executing [600@ext-group:7] Set("SIP/704444-0000003d", "__NODEST=600") in new stack
    -- Executing [600@ext-group:8] GosubIf("SIP/704444-0000003d", "0?sub-rgsetcid,s,1()") in new stack
    -- Executing [600@ext-group:9] Gosub("SIP/704444-0000003d", "sub-record-check,s,1(rg,600,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("SIP/704444-0000003d", "1?check") in new stack
    -- Goto (sub-record-check,s,6)
    -- Executing [s@sub-record-check:6] Set("SIP/704444-0000003d", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:7] GotoIf("SIP/704444-0000003d", "1?next") in new stack
    -- Goto (sub-record-check,s,10)
    -- Executing [s@sub-record-check:10] ExecIf("SIP/704444-0000003d", "0?Return()") in new stack
    -- Executing [s@sub-record-check:11] GotoIf("SIP/704444-0000003d", "0?rg,1") in new stack
    -- Executing [s@sub-record-check:12] Set("SIP/704444-0000003d", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("SIP/704444-0000003d", "0?Set(__REC_POLICY_MODE=dontcare)") in new stack
    -- Executing [s@sub-record-check:14] Set("SIP/704444-0000003d", "NOW=1343335525") in new stack
    -- Executing [s@sub-record-check:15] Set("SIP/704444-0000003d", "__DAY=26") in new stack
    -- Executing [s@sub-record-check:16] Set("SIP/704444-0000003d", "__MONTH=07") in new stack
    -- Executing [s@sub-record-check:17] Set("SIP/704444-0000003d", "__YEAR=2012") in new stack
    -- Executing [s@sub-record-check:18] Set("SIP/704444-0000003d", "__TIMESTR=20120726-234525") in new stack
    -- Executing [s@sub-record-check:19] Set("SIP/704444-0000003d", "__FROMEXTEN=704444") in new stack
    -- Executing [s@sub-record-check:20] Set("SIP/704444-0000003d", "__CALLFILENAME=rg-600-704444-20120726-234525-1343335525.61") in new stack
    -- Executing [s@sub-record-check:21] Goto("SIP/704444-0000003d", "rg,1") in new stack
    -- Goto (sub-record-check,rg,1)
    -- Executing [rg@sub-record-check:1] GosubIf("SIP/704444-0000003d", "0?record,1(rg,never,704444)") in new stack
    -- Executing [rg@sub-record-check:2] Return("SIP/704444-0000003d", "") in new stack
    -- Executing [600@ext-group:10] Set("SIP/704444-0000003d", "RingGroupMethod=ringall") in new stack
    -- Executing [600@ext-group:11] Macro("SIP/704444-0000003d", "dial,120,tr,100-200-300") in new stack
    -- Executing [s@macro-dial:1] GotoIf("SIP/704444-0000003d", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing [s@macro-dial:3] AGI("SIP/704444-0000003d", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
 dialparties.agi: Starting New Dialparties.agi
 dialparties.agi: Caller ID name is '704444' number is '704444'
 dialparties.agi: Methodology of ring is  'ringall'
    -- dialparties.agi: Added extension 100 to extension map
    -- dialparties.agi: Added extension 200 to extension map
    -- dialparties.agi: Added extension 300 to extension map
    -- dialparties.agi: Extension 100 cf is disabled
    -- dialparties.agi: Extension 200 cf is disabled
    -- dialparties.agi: Extension 300 cf is disabled
    -- dialparties.agi: Extension 100 do not disturb is disabled
    -- dialparties.agi: Extension 200 do not disturb is disabled
    -- dialparties.agi: Extension 300 do not disturb is disabled
    -- dialparties.agi: dbset CALLTRACE/100 to 704444
    -- dialparties.agi: dbset CALLTRACE/200 to 704444
    -- dialparties.agi: dbset CALLTRACE/300 to 704444
    -- dialparties.agi: Filtered ARG3: 100-200-300
    -- <SIP/704444-0000003d>AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] Dial("SIP/704444-0000003d", "SIP/100&SIP/200&SIP/300,120,trM(auto-blkvm)") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Called SIP/100
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Called SIP/200
[2012-07-26 23:45:25] WARNING[7645]: app_dial.c:2218 dial_exec_full: Unable to create channel of type 'SIP' (cause 20 - Unknown)
    -- SIP/100-0000003e connected line has changed. Saving it until answer for SIP/704444-0000003d
    -- SIP/200-0000003f connected line has changed. Saving it until answer for SIP/704444-0000003d
    -- SIP/200-0000003f is ringing
    -- SIP/100-0000003e is ringing
    -- SIP/100-0000003e connected line has changed. Saving it until answer for SIP/704444-0000003d
    -- SIP/100-0000003e answered SIP/704444-0000003d
    -- Executing [s@macro-auto-blkvm:1] Set("SIP/100-0000003e", "__MACRO_RESULT=") in new stack
    -- Executing [s@macro-auto-blkvm:2] Macro("SIP/100-0000003e", "blkvm-clr,") in new stack
    -- Executing [s@macro-blkvm-clr:1] Set("SIP/100-0000003e", "SHARED(BLKVM,SIP/704444-0000003d)=") in new stack
    -- Executing [s@macro-blkvm-clr:2] Set("SIP/100-0000003e", "GOSUB_RETVAL=") in new stack
    -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/100-0000003e", "") in new stack
    -- Executing [s@macro-auto-blkvm:3] ExecIf("SIP/100-0000003e", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=100)") in new stack
    -- Executing [s@macro-auto-blkvm:4] ExecIf("SIP/100-0000003e", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=op01)") in new stack
    -- Executing [h@macro-dial:1] Macro("SIP/704444-0000003d", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("SIP/704444-0000003d", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,3)
    -- Executing [s@macro-hangupcall:3] ExecIf("SIP/704444-0000003d", "0?Set(CDR(recordingfile)=)") in new stack
    -- Executing [s@macro-hangupcall:4] Hangup("SIP/704444-0000003d", "") in new stack
  == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/704444-0000003d' in macro 'hangupcall'
  == Spawn extension (macro-dial, h, 1) exited non-zero on 'SIP/704444-0000003d'
  == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/704444-0000003d' in macro 'dial'
  == Spawn extension (ext-group, 600, 11) exited non-zero on 'SIP/704444-0000003d'

<------------->
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: --- (15 headers 10 lines) ---
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Sending to 10.10.1.185:5060 (NAT)
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Using INVITE request as basis request - 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Found peer '704444' for '704444' from 10.10.1.185:5060
[2012-07-26 23:56:19] VERBOSE[4168] netsock2.c: == Using SIP RTP TOS bits 184
[2012-07-26 23:56:19] VERBOSE[4168] netsock2.c: == Using SIP RTP CoS mark 5
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Found RTP audio format 0
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Found RTP audio format 101
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Found audio description format PCMU for ID 0
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Found audio description format telephone-event for ID 101
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Peer audio RTP is at port 10.10.1.185:10022
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: Looking for 600 in from-trunk (domain 10.10.99.8)
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: list_route: hop: <sip:704444@10.10.1.185:5060>
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c:
<--- Transmitting (NAT) to 10.10.1.185:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bK01094a6712f008e9;received=10.10.1.185;rport=5060
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq: 45 INVITE
Server: FPBX-2.10.0(1.8.9.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:600@10.10.99.8:5060>
Content-Length: 0


<------------>
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@from-trunk:1] NoOp("SIP/704444-00000045", "Catch-All DID Match - Found 600 - You probably want a DID for this.") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@from-trunk:2] Goto("SIP/704444-00000045", "ext-did,s,1") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (ext-did,s,1)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:1] ExecIf("SIP/704444-00000045", "1?Set(__FROM_DID=s)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:2] Gosub("SIP/704444-00000045", "app-blacklist-check,s,1()") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("SIP/704444-00000045", "0?blacklisted") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/704444-00000045", "CALLED_BLACKLIST=1") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/704444-00000045", "") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:3] Gosub("SIP/704444-00000045", "sub-record-cancel,s,1()") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-cancel:1] ExecIf("SIP/704444-00000045", "1?Return()") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:4] Set("SIP/704444-00000045", "__REC_POLICY_MODE=never") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:5] Set("SIP/704444-00000045", "CHANNEL(language)=ru") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:6] Set("SIP/704444-00000045", "CDR(did)=s") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:7] ExecIf("SIP/704444-00000045", "0 ?Set(CALLERID(name)=704444)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:8] Set("SIP/704444-00000045", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:9] Set("SIP/704444-00000045", "CALLERPRES()=allowed_not_screened") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@ext-did:10] Goto("SIP/704444-00000045", "ext-group,600,1") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (ext-group,600,1)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:1] Macro("SIP/704444-00000045", "user-callerid,") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/704444-00000045", "AMPUSER=704444") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/704444-00000045", "0?report") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/704444-00000045", "1?Set(REALCALLERIDNUM=704444)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/704444-00000045", "AMPUSER=704444") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/704444-00000045", "AMPUSERCIDNAME=704444") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/704444-00000045", "0?report") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/704444-00000045", "AMPUSERCID=704444") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:8] Set("SIP/704444-00000045", "CALLERID(all)="704444" <704444>") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:9] GotoIf("SIP/704444-00000045", "0?limit") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:10] ExecIf("SIP/704444-00000045", "0?Set(GROUP(concurrency_limit)=704444)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:11] GosubIf("SIP/704444-00000045", "0?sub-ccss,s,1(ext-group,600)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:12] ExecIf("SIP/704444-00000045", "0?Set(CHANNEL(language)=)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/704444-00000045", "0?continue") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:14] Set("SIP/704444-00000045", "__TTL=64") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:15] GotoIf("SIP/704444-00000045", "1?continue") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (macro-user-callerid,s,26)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:26] Set("SIP/704444-00000045", "CALLERID(number)=704444") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:27] Set("SIP/704444-00000045", "CALLERID(name)=704444") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-user-callerid:28] Set("SIP/704444-00000045", "CHANNEL(language)=ru") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:2] Macro("SIP/704444-00000045", "blkvm-setifempty,") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-setifempty:1] GotoIf("SIP/704444-00000045", "1?init") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (macro-blkvm-setifempty,s,4)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-setifempty:4] Set("SIP/704444-00000045", "__BLKVM_CHANNEL=SIP/704444-00000045") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-setifempty:5] Set("SIP/704444-00000045", "SHARED(BLKVM,SIP/704444-00000045)=TRUE") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-setifempty:6] Set("SIP/704444-00000045", "GOSUB_RETVAL=TRUE") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/704444-00000045", "") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:3] GotoIf("SIP/704444-00000045", "1?skipov") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (ext-group,600,6)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:6] Set("SIP/704444-00000045", "RRNODEST=") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:7] Set("SIP/704444-00000045", "__NODEST=600") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:8] GosubIf("SIP/704444-00000045", "0?sub-rgsetcid,s,1()") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:9] Gosub("SIP/704444-00000045", "sub-record-check,s,1(rg,600,dontcare)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/704444-00000045", "1?check") in new stack
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.185:5060 --->
ACK sip:600@10.10.99.8;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bK42d574f1b86b620e
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>;tag=as4fd42ecf
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq:44 ACK
Max-Forwards:70
Content-Length: 0

<------------->
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: --- (8 headers 0 lines) ---
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (sub-record-check,s,6)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/704444-00000045", "__MON_FMT=wav") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:7] GotoIf("SIP/704444-00000045", "1?next") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (sub-record-check,s,10)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:10] ExecIf("SIP/704444-00000045", "0?Return()") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:11] GotoIf("SIP/704444-00000045", "0?rg,1") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/704444-00000045", "__REC_STATUS=INITIALIZED") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/704444-00000045", "0?Set(__REC_POLICY_MODE=dontcare)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:14] Set("SIP/704444-00000045", "NOW=1343336179") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:15] Set("SIP/704444-00000045", "__DAY=26") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:16] Set("SIP/704444-00000045", "__MONTH=07") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:17] Set("SIP/704444-00000045", "__YEAR=2012") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:18] Set("SIP/704444-00000045", "__TIMESTR=20120726-235619") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:19] Set("SIP/704444-00000045", "__FROMEXTEN=704444") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:20] Set("SIP/704444-00000045", "__CALLFILENAME=rg-600-704444-20120726-235619-1343336179.69") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@sub-record-check:21] Goto("SIP/704444-00000045", "rg,1") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (sub-record-check,rg,1)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [rg@sub-record-check:1] GosubIf("SIP/704444-00000045", "0?record,1(rg,never,704444)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [rg@sub-record-check:2] Return("SIP/704444-00000045", "") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:10] Set("SIP/704444-00000045", "RingGroupMethod=ringall") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [600@ext-group:11] Macro("SIP/704444-00000045", "dial,120,tr,100-200-300") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-dial:1] GotoIf("SIP/704444-00000045", "1?dial") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Goto (macro-dial,s,3)
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-dial:3] AGI("SIP/704444-00000045", "dialparties.agi") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: dialparties.agi: Caller ID name is '704444' number is '704444'
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: dialparties.agi: Methodology of ring is 'ringall'
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Added extension 100 to extension map
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Added extension 200 to extension map
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Added extension 300 to extension map
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Extension 100 cf is disabled
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Extension 200 cf is disabled
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Extension 300 cf is disabled
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Extension 100 do not disturb is disabled
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Extension 200 do not disturb is disabled
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Extension 300 do not disturb is disabled
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: dbset CALLTRACE/100 to 704444
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: dbset CALLTRACE/200 to 704444
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: dbset CALLTRACE/300 to 704444
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- dialparties.agi: Filtered ARG3: 100-200-300
[2012-07-26 23:56:19] VERBOSE[7824] res_agi.c: -- <SIP/704444-00000045>AGI Script dialparties.agi completed, returning 0
[2012-07-26 23:56:19] VERBOSE[7824] pbx.c: -- Executing [s@macro-dial:7] Dial("SIP/704444-00000045", "SIP/100&SIP/200&SIP/300,120,trM(auto-blkvm)") in new stack
[2012-07-26 23:56:19] VERBOSE[7824] netsock2.c: == Using SIP RTP TOS bits 184
[2012-07-26 23:56:19] VERBOSE[7824] netsock2.c: == Using SIP RTP CoS mark 5
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Audio is at 10496
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Reliably Transmitting (NAT) to 10.10.1.156:5060:
INVITE sip:100@10.10.1.156:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.99.8:5060;branch=z9hG4bK65309a1f;rport
Max-Forwards: 70
From: "704444" <sip:704444@10.10.99.8>;tag=as29a75a71
To: <sip:100@10.10.1.156:5060>
Contact: <sip:704444@10.10.99.8:5060>
Call-ID: 611c1270398f5dc81f3b0fe3469282f1@10.10.99.8:5060
CSeq: 102 INVITE
User-Agent: FPBX-2.10.0(1.8.9.3)
Date: Thu, 26 Jul 2012 20:56:19 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 230

v=0
o=root 762505793 762505793 IN IP4 10.10.99.8
s=Asterisk PBX 1.8.9.3
c=IN IP4 10.10.99.8
t=0 0
m=audio 10496 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
[2012-07-26 23:56:19] VERBOSE[7824] app_dial.c: -- Called SIP/100
[2012-07-26 23:56:19] VERBOSE[7824] netsock2.c: == Using SIP RTP TOS bits 184
[2012-07-26 23:56:19] VERBOSE[7824] netsock2.c: == Using SIP RTP CoS mark 5
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Audio is at 14650
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Reliably Transmitting (NAT) to 10.10.1.2:5060:
INVITE sip:200@10.10.1.2:5060;ob SIP/2.0
Via: SIP/2.0/UDP 10.10.99.8:5060;branch=z9hG4bK2e4e8704;rport
Max-Forwards: 70
From: "704444" <sip:704444@10.10.99.8>;tag=as427db69e
To: <sip:200@10.10.1.2:5060;ob>
Contact: <sip:704444@10.10.99.8:5060>
Call-ID: 55775e4f06181237088c747d0fca4d76@10.10.99.8:5060
CSeq: 102 INVITE
User-Agent: FPBX-2.10.0(1.8.9.3)
Date: Thu, 26 Jul 2012 20:56:19 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 232

v=0
o=root 2089674538 2089674538 IN IP4 10.10.99.8
s=Asterisk PBX 1.8.9.3
c=IN IP4 10.10.99.8
t=0 0
m=audio 14650 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
[2012-07-26 23:56:19] VERBOSE[7824] app_dial.c: -- Called SIP/200
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c: Really destroying SIP dialog '3d66e4795764ac9212928d9c549a58c6@127.0.0.1:0' Method: INVITE
[2012-07-26 23:56:19] WARNING[7824] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Unknown)
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c:
<--- Transmitting (NAT) to 10.10.1.185:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bK01094a6712f008e9;received=10.10.1.185;rport=5060
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>;tag=as3207e092
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq: 45 INVITE
Server: FPBX-2.10.0(1.8.9.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:600@10.10.99.8:5060>
Content-Length: 0


<------------>
[2012-07-26 23:56:19] VERBOSE[7824] app_dial.c: -- SIP/100-00000046 connected line has changed. Saving it until answer for SIP/704444-00000045
[2012-07-26 23:56:19] VERBOSE[7824] app_dial.c: -- SIP/200-00000047 connected line has changed. Saving it until answer for SIP/704444-00000045
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.2:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.10.99.8:5060;rport=5060;received=10.10.99.8;branch=z9hG4bK2e4e8704
Call-ID: 55775e4f06181237088c747d0fca4d76@10.10.99.8:5060
From: "704444" <sip:704444@10.10.99.8>;tag=as427db69e
To: <sip:200@10.10.1.2;ob>
CSeq: 102 INVITE
Content-Length: 0

<------------->
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: --- (7 headers 0 lines) ---
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.2:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.10.99.8:5060;rport=5060;received=10.10.99.8;branch=z9hG4bK2e4e8704
Call-ID: 55775e4f06181237088c747d0fca4d76@10.10.99.8:5060
From: "704444" <sip:704444@10.10.99.8>;tag=as427db69e
To: <sip:200@10.10.1.2;ob>;tag=f7360326cda5480e9b151653d7a20c20
CSeq: 102 INVITE
Contact: <sip:10.10.1.2:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length: 0

<------------->
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: --- (9 headers 0 lines) ---
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: list_route: hop: <sip:10.10.1.2:5060>
[2012-07-26 23:56:19] VERBOSE[7824] app_dial.c: -- SIP/200-00000047 is ringing
[2012-07-26 23:56:19] VERBOSE[7824] chan_sip.c:
<--- Transmitting (NAT) to 10.10.1.185:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bK01094a6712f008e9;received=10.10.1.185;rport=5060
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>;tag=as3207e092
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq: 45 INVITE
Server: FPBX-2.10.0(1.8.9.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:600@10.10.99.8:5060>
Content-Length: 0


<------------>
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.156:5060 --->
SIP/2.0 180 Ringing
From: "704444"<sip:704444@10.10.99.8>;tag=as29a75a71
To: <sip:100@10.10.1.156:5060>;tag=a0a019c-13c45011d922
Call-ID: 611c1270398f5dc81f3b0fe3469282f1@10.10.99.8:5060
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.10.99.8:5060;rport=5060;branch=z9hG4bK65309a1f
Supported: 100rel,replaces
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
User-Agent: DPH-400S/SE-1.01
Contact: <sip:100@10.10.1.156:5060>
Content-Length: 0

<------------->
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: --- (11 headers 0 lines) ---
[2012-07-26 23:56:19] VERBOSE[4168] chan_sip.c: list_route: hop: <sip:100@10.10.1.156:5060>
[2012-07-26 23:56:19] VERBOSE[7824] app_dial.c: -- SIP/100-00000046 is ringing
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.156:5060 --->
SIP/2.0 200 OK
From: "704444"<sip:704444@10.10.99.8>;tag=as29a75a71
To: <sip:100@10.10.1.156:5060>;tag=a0a019c-13c45011d922
Call-ID: 611c1270398f5dc81f3b0fe3469282f1@10.10.99.8:5060
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.10.99.8:5060;rport=5060;branch=z9hG4bK65309a1f
Supported: 100rel,replaces
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
User-Agent: DPH-400S/SE-1.01
Contact: <sip:100@10.10.1.156:5060>
Content-Type: application/sdp
Content-Length: 146

v=0
o=100 1343346978 1343346978 IN IP4 10.10.1.156
s=_
c=IN IP4 10.10.1.156
t=0 0
m=audio 10002 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=sendrecv
<------------->
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: --- (12 headers 8 lines) ---
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Found RTP audio format 0
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Found audio description format PCMU for ID 0
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x0 (nothing), combined - 0x0 (nothing)
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Peer audio RTP is at port 10.10.1.156:10002
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: list_route: hop: <sip:100@10.10.1.156:5060>
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: set_destination: Parsing <sip:100@10.10.1.156:5060> for address/port to send to
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: set_destination: set destination to 10.10.1.156:5060
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Transmitting (NAT) to 10.10.1.156:5060:
ACK sip:100@10.10.1.156:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.99.8:5060;branch=z9hG4bK717ba49f;rport
Max-Forwards: 70
From: "704444" <sip:704444@10.10.99.8>;tag=as29a75a71
To: <sip:100@10.10.1.156:5060>;tag=a0a019c-13c45011d922
Contact: <sip:704444@10.10.99.8:5060>
Call-ID: 611c1270398f5dc81f3b0fe3469282f1@10.10.99.8:5060
CSeq: 102 ACK
User-Agent: FPBX-2.10.0(1.8.9.3)
Content-Length: 0


---
[2012-07-26 23:56:21] VERBOSE[7824] app_dial.c: -- SIP/100-00000046 connected line has changed. Saving it until answer for SIP/704444-00000045
[2012-07-26 23:56:21] VERBOSE[7824] app_dial.c: -- SIP/100-00000046 answered SIP/704444-00000045
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: Scheduling destruction of SIP dialog '55775e4f06181237088c747d0fca4d76@10.10.99.8:5060' in 6400 ms (Method: INVITE)
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: set_destination: Parsing <sip:200@10.10.1.2:5060;ob> for address/port to send to
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: set_destination: set destination to 10.10.1.2:5060
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: Reliably Transmitting (NAT) to 10.10.1.2:5060:
CANCEL sip:200@10.10.1.2:5060;ob SIP/2.0
Via: SIP/2.0/UDP 10.10.99.8:5060;branch=z9hG4bK2e4e8704;rport
Max-Forwards: 70
From: "704444" <sip:704444@10.10.99.8>;tag=as427db69e
To: <sip:200@10.10.1.2:5060;ob>
Call-ID: 55775e4f06181237088c747d0fca4d76@10.10.99.8:5060
CSeq: 102 CANCEL
User-Agent: FPBX-2.10.0(1.8.9.3)
Reason: SIP;cause=200;text="Call completed elsewhere"
Content-Length: 0


---
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: Scheduling destruction of SIP dialog '55775e4f06181237088c747d0fca4d76@10.10.99.8:5060' in 6400 ms (Method: INVITE)
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.2:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.99.8:5060;rport=5060;received=10.10.99.8;branch=z9hG4bK2e4e8704
Call-ID: 55775e4f06181237088c747d0fca4d76@10.10.99.8:5060
From: "704444" <sip:704444@10.10.99.8>;tag=as427db69e
To: <sip:200@10.10.1.2;ob>;tag=f7360326cda5480e9b151653d7a20c20
CSeq: 102 CANCEL
Content-Length: 0

<------------->
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: --- (7 headers 0 lines) ---
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.2:5060 --->
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 10.10.99.8:5060;rport=5060;received=10.10.99.8;branch=z9hG4bK2e4e8704
Call-ID: 55775e4f06181237088c747d0fca4d76@10.10.99.8:5060
From: "704444" <sip:704444@10.10.99.8>;tag=as427db69e
To: <sip:200@10.10.1.2;ob>;tag=f7360326cda5480e9b151653d7a20c20
CSeq: 102 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length: 0

<------------->
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: --- (8 headers 0 lines) ---
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: set_destination: Parsing <sip:200@10.10.1.2:5060;ob> for address/port to send to
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: set_destination: set destination to 10.10.1.2:5060
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Transmitting (NAT) to 10.10.1.2:5060:
ACK sip:10.10.1.2:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.99.8:5060;branch=z9hG4bK2e4e8704;rport
Max-Forwards: 70
From: "704444" <sip:704444@10.10.99.8>;tag=as427db69e
To: <sip:200@10.10.1.2:5060;ob>;tag=f7360326cda5480e9b151653d7a20c20
Contact: <sip:704444@10.10.99.8:5060>
Call-ID: 55775e4f06181237088c747d0fca4d76@10.10.99.8:5060
CSeq: 102 ACK
User-Agent: FPBX-2.10.0(1.8.9.3)
Content-Length: 0


---
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Really destroying SIP dialog '55775e4f06181237088c747d0fca4d76@10.10.99.8:5060' Method: INVITE
[2012-07-26 23:56:21] VERBOSE[7824] pbx.c: -- Executing [s@macro-auto-blkvm:1] Set("SIP/100-00000046", "__MACRO_RESULT=") in new stack
[2012-07-26 23:56:21] VERBOSE[7824] pbx.c: -- Executing [s@macro-auto-blkvm:2] Macro("SIP/100-00000046", "blkvm-clr,") in new stack
[2012-07-26 23:56:21] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-clr:1] Set("SIP/100-00000046", "SHARED(BLKVM,SIP/704444-00000045)=") in new stack
[2012-07-26 23:56:21] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-clr:2] Set("SIP/100-00000046", "GOSUB_RETVAL=") in new stack
[2012-07-26 23:56:21] VERBOSE[7824] pbx.c: -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/100-00000046", "") in new stack
[2012-07-26 23:56:21] VERBOSE[7824] pbx.c: -- Executing [s@macro-auto-blkvm:3] ExecIf("SIP/100-00000046", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=100)") in new stack
[2012-07-26 23:56:21] VERBOSE[7824] pbx.c: -- Executing [s@macro-auto-blkvm:4] ExecIf("SIP/100-00000046", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=op01)") in new stack
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: Audio is at 18964
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2012-07-26 23:56:21] VERBOSE[7824] chan_sip.c:
<--- Reliably Transmitting (NAT) to 10.10.1.185:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bK01094a6712f008e9;received=10.10.1.185;rport=5060
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>;tag=as3207e092
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq: 45 INVITE
Server: FPBX-2.10.0(1.8.9.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:600@10.10.99.8:5060>
Content-Type: application/sdp
Content-Length: 232

v=0
o=root 2016952313 2016952313 IN IP4 10.10.99.8
s=Asterisk PBX 1.8.9.3
c=IN IP4 10.10.99.8
t=0 0
m=audio 18964 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: Retransmitting #1 (NAT) to 10.10.1.185:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bK01094a6712f008e9;received=10.10.1.185;rport=5060
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>;tag=as3207e092
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq: 45 INVITE
Server: FPBX-2.10.0(1.8.9.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:600@10.10.99.8:5060>
Content-Type: application/sdp
Content-Length: 232

v=0
o=root 2016952313 2016952313 IN IP4 10.10.99.8
s=Asterisk PBX 1.8.9.3
c=IN IP4 10.10.99.8
t=0 0
m=audio 18964 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.185:5060 --->
ACK sip:600@10.10.99.8:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bKac5f552f388bd70c
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>;tag=as3207e092
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq:45 ACK
Max-Forwards:70
Authorization:Digest username="704444",realm="asterisk",nonce="1a73ae50",uri="sip:600@10.10.99.8;user=phone",response="e5e5ff94a814d4a1557b790a628b08a5",algorithm=MD5
User-Agent:dlink 12-3854-2846-0.10.47.1-TSO
Content-Length: 0

<------------->
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: --- (10 headers 0 lines) ---
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.185:5060 --->
ACK sip:600@10.10.99.8:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.1.185:5060;branch=z9hG4bK796ab34b551ba02e
From: "Anonymous" <sip:704444@10.10.99.8;user=phone>;tag=5b6155b0-690494
To: <sip:600@10.10.99.8;user=phone>;tag=as3207e092
Call-ID: 1B1B-12CA-46690494C945BE79E6C3-017@SipHost
CSeq:45 ACK
Max-Forwards:70
Authorization:Digest username="704444",realm="asterisk",nonce="1a73ae50",uri="sip:600@10.10.99.8;user=phone",response="e5e5ff94a814d4a1557b790a628b08a5",algorithm=MD5
User-Agent:dlink 12-3854-2846-0.10.47.1-TSO
Content-Length: 0

<------------->
[2012-07-26 23:56:21] VERBOSE[4168] chan_sip.c: --- (10 headers 0 lines) ---
[2012-07-26 23:56:23] VERBOSE[4168] chan_sip.c:
<--- SIP read from UDP:10.10.1.2:5060 --->

<------------->

Комманды:

call*CLI> sip show peers
Name/username              Host                                    Dyn Forcerport ACL Port     Status     
100/100                    10.10.1.156                              D   N   A  5060     OK (17 ms) 
200/200                    10.10.1.2                                D   N   A  5060     OK (1 ms)  
300/300                    (Unspecified)                            D   N   A  0        UNKNOWN    
704444/704444              10.10.1.185                              D   N      5060     OK (58 ms) 
777/777                    10.10.1.185                              D   N   A  5060     OK (55 ms) 
5 sip peers [Monitored: 4 online, 1 offline Unmonitored: 0 online, 0 offline]

Answer 1

0

Фигасе вопросик.

Извините за флуд ))

ссылка удалить спам редактировать

ответил 2012-07-27 01:45:09 +0400

freeneutron
11 ● 7 ● 3 ● 5

Answer 2

0

image description Догодались наверно уже сами что проблема в NAT ? я для экспериментов с натом завожу отдельный тестовый номер примерно так и всё сразу становится видно. Позвонили на 592, пикнуло, сказали в трубку "Чё за фигня с натом", нажали # , и услышили ( не услышили ) свой голос.

exten => 592,1,Set(TIME="${STRFTIME(${EPOCH},,%Y-%m-%d_%H-%M-%S)}")

exten => 592,n,Playback(beep)

exten => 592,n,Record(/var/lib/asterisk/sounds/custom/record_${TIME}:gsm)

exten => 592,n,Playback(beep)

exten => 592,n,Playback(/var/lib/asterisk/sounds/custom/record_${TIME})

exten => 592,n,Hangup()

ссылка удалить спам редактировать

ответил 2012-07-27 10:07:56 +0400

awsswa

685 ● 5 ● 2 ● 9

обновил 2012-07-28 20:08:40 +0400

Comments

Исходящие то есть. =) Nat везде включен, где это было возможно. Логи и конфиги привел.

okt ( 2012-07-27 13:22:21 +0400 )редактировать

Включение Nat не говорит о том что он работает. Пример который я дал попробовали ? Лог внешнего звонка ?

awsswa ( 2012-07-27 14:39:44 +0400 )редактировать

Нет пример не пробовал, завтра только смогу попробовать, может быть заскачу на пол часика на офис сегодня но не факт. Лог внешнего звонка в самом топике. набирал с другого телефона. Звонок идет голоса нет, причем в оба конца. Почему тогда если проблема в NAT в 2х из 3х случаях все гуд? Я вообще хочу загнать все в одну сеть напрямую минуя всякие маршрутизаторы.

Пакеты rtp ходят.

Вы наверное знаете, если что-то руками добавлять в конфиг под FreePBX - то они потом перезаписываются старыми данными, при старте/рестарте астера. По этому вопрос, куда писать конфиг или даже скорее как, создавать транк новый?

okt ( 2012-07-27 17:30:31 +0400 )редактировать

Нет пример не пробовал, завтра только смогу попробовать, может быть заскачу на пол часика на офис сегодня но не факт. Лог внешнего звонка в самом топике. набирал с другого телефона. Звонок идет голоса нет, причем в оба конца. Почему тогда если проблема в NAT в 2х из 3х случаях все гуд? Я вообще хочу загнать все в одну сеть напрямую минуя всякие маршрутизаторы. Пакеты rtp ходят. Вы наверное знаете, если что-то руками добавлять в конфиг под FreePBX - то они потом перезаписываются старыми данными, при старте/рестарте астера. По этому вопрос, куда писать конфиг или даже скорее как, создавать транк новый?

Видел смотрел по схемам ползал. ЧТО МЕНЯТЬ УЖЕ НЕ ЗНАЮ!!!!

okt ( 2012-07-28 21:13:38 +0400 )редактировать

У МЕНЯ ПРОБЛЕМА С ВХОДЯЩИМИ!!!

okt ( 2012-07-28 21:14:19 +0400 )редактировать

Голос только в одну сторону ? Сервер или клиент за NAT ? = (равно!!!) = Проблемы с NAT

awsswa ( 2012-07-29 09:41:53 +0400 )редактировать

Так, а что еще в настройках копать - вроде бы уже все проверил, нат везде включен - пробовал разные варианты единственное для Транка нат не включается!

А вообще хоть на мысль натолкните, не просто так же я запостил конфиги всего.

okt ( 2012-07-30 18:35:05 +0400 )редактировать

Чтоб на мысль толкать надо сначала узнать что у вас роутером стоит и с какими настройками. Вообще только freepbx выставляет nat=route у чистого астериск настройка совсем другая.

awsswa ( 2012-07-30 21:22:58 +0400 )редактировать

На роутере pfSense - "админ" роутера, утверждает что полностью все разрешил. Опять же RTP пакеты идут, сначала была ошибка с ними поставил интервал больше, ошибка пропала... покопавшись на форумах.

Да с настройками, это я руками выставлял когда игрался.

okt ( 2012-07-31 03:48:23 +0400 )редактировать

FreeBSD в девичистве. Вот чем хорош D-Link - тем что там всего одна галочка - сделать мне хорошо. А вот чем плох роутер на FreeBSD что там галочеч ну очень много - DNAT, SNAT, VLAN, и т.д. и покрутить много как можно чего. У правильного NATа клиет uTorrent горит зеленым :) - Вечерком смените на D-Link роутер и попробуйте на нем - заработает, значит знаете где искать проблему.

awsswa ( 2012-07-31 08:00:28 +0400 )редактировать

Нет голоса(звука) во входящих

2 Ответа

Comments

Ваш ответ

Закладки и информация

Статистика

Похожие вопросы: