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

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

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

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

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

ответил Jul 26 '12

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()

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

ответил Jul 27 '12

awsswa

685 ● 5 ● 2 ● 9

обновил Jul 28 '12

Comments

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

okt (Jul 27 '12)edit

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

awsswa (Jul 27 '12)edit

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

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

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

okt (Jul 27 '12)edit

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

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

okt (Jul 28 '12)edit

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

okt (Jul 28 '12)edit

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

awsswa (Jul 29 '12)edit

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

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

okt (Jul 30 '12)edit

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

awsswa (Jul 30 '12)edit

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

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

okt (Jul 30 '12)edit

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

awsswa (Jul 31 '12)edit

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

2 Ответа

Comments

Ваш ответ

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

Статистика

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