
<--- SIP read from UDP:10.1.29.50:5062 --->
INVITE sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK1113340934;rport
From: <sip:7337@10.1.7.200>;tag=1949110676
To: <sip:7121@10.1.7.200>
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 60 INVITE
Contact: <sip:7337@10.1.29.50:5062>
Max-Forwards: 70
User-Agent: Grandstream GXP1400 1.0.5.32
Privacy: none
P-Preferred-Identity: <sip:7337@10.1.7.200>
Supported: replaces, path, timer
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 398

v=0
o=7337 8001 8000 IN IP4 10.1.29.50
s=SIP Call
c=IN IP4 10.1.29.50
t=0 0
m=audio 5008 RTP/AVP 0 8 4 18 9 97 2 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: --- (16 headers 19 lines) ---
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Using INVITE request as basis request - 1854750743-5062-7@BA.B.CJ.FA
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found peer '7337' for '7337' from 10.1.29.50:5062
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: 
<--- Reliably Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK1113340934;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=1949110676
To: <sip:7121@10.1.7.200>;tag=as1215768b
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 60 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1f74f3d9"
Content-Length: 0


<------------>
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Scheduling destruction of SIP dialog '1854750743-5062-7@BA.B.CJ.FA' in 6400 ms (Method: INVITE)
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
ACK sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK1113340934;rport
From: <sip:7337@10.1.7.200>;tag=1949110676
To: <sip:7121@10.1.7.200>;tag=as1215768b
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 60 ACK
Content-Length: 0

<------------->
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: --- (7 headers 0 lines) ---
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
INVITE sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK900985463;rport
From: <sip:7337@10.1.7.200>;tag=1949110676
To: <sip:7121@10.1.7.200>
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 61 INVITE
Contact: <sip:7337@10.1.29.50:5062>
Authorization: Digest username="7337", realm="asterisk", nonce="1f74f3d9", uri="sip:7121@10.1.7.200", response="69df6edfd42215625c88811082763ecb", algorithm=MD5
Max-Forwards: 70
User-Agent: Grandstream GXP1400 1.0.5.32
Privacy: none
P-Preferred-Identity: <sip:7337@10.1.7.200>
Supported: replaces, path, timer
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 398

v=0
o=7337 8001 8000 IN IP4 10.1.29.50
s=SIP Call
c=IN IP4 10.1.29.50
t=0 0
m=audio 5008 RTP/AVP 0 8 4 18 9 97 2 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: --- (17 headers 19 lines) ---
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Using INVITE request as basis request - 1854750743-5062-7@BA.B.CJ.FA
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found peer '7337' for '7337' from 10.1.29.50:5062
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] netsock2.c: Using SIP VIDEO TOS bits 136
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] netsock2.c: Using SIP VIDEO CoS mark 6
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] netsock2.c: Using SIP RTP TOS bits 184
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] netsock2.c: Using SIP RTP CoS mark 5
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 0
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 8
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 4
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 18
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 9
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 97
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 2
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found RTP audio format 101
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format PCMU for ID 0
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format PCMA for ID 8
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format G723 for ID 4
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format G729 for ID 18
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format G722 for ID 9
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format iLBC for ID 97
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format G726-32 for ID 2
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Found audio description format telephone-event for ID 101
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Capabilities: us - (alaw|g726|gsm|g722|ulaw|g729|h264|mpeg4|vp8), peer - audio=(ulaw|g726|g723|alaw|g722|g729|ilbc)/video=(nothing)/text=(nothing), combined - (alaw|g726|g722|ulaw|g729)
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Peer audio RTP is at port 10.1.29.50:5008
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Peer doesn't provide video
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Looking for 7121 in from-internal (domain 10.1.7.200)
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] sip/route.c: sip_route_dump: route/path hop: <sip:7337@10.1.29.50:5062>
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: 
<--- Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK900985463;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=1949110676
To: <sip:7121@10.1.7.200>
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 61 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: <sip:7121@10.1.7.200:5060>
Content-Length: 0


<------------>
[2014-12-16 16:40:52] WARNING[29941][C-00000000] pbx.c: PBX requires Asterisk to be fully booted
[2014-12-16 16:40:52] WARNING[29941][C-00000000] chan_sip.c: Failed to start PBX :(
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: 
<--- Reliably Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 503 Unavailable
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK900985463;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=1949110676
To: <sip:7121@10.1.7.200>;tag=as028031ad
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 61 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Length: 0


<------------>
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Scheduling destruction of SIP dialog '1854750743-5062-7@BA.B.CJ.FA' in 6400 ms (Method: INVITE)
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
ACK sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK900985463;rport
From: <sip:7337@10.1.7.200>;tag=1949110676
To: <sip:7121@10.1.7.200>;tag=as028031ad
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 61 ACK
Content-Length: 0

<------------->
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: --- (7 headers 0 lines) ---
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: set_destination: Parsing <sip:7337@10.1.29.50:5062> for address/port to send to
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: set_destination: set destination to 10.1.29.50:5062
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Reliably Transmitting (no NAT) to 10.1.29.50:5062:
BYE sip:7337@10.1.29.50:5062 SIP/2.0
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK6c9ff9e6;rport
Max-Forwards: 70
From: <sip:7121@10.1.7.200>;tag=as028031ad
To: <sip:7337@10.1.7.200>;tag=1949110676
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 102 BYE
User-Agent: FPBX-12.0.18(13.1.0)
Proxy-Authorization: Digest username="7337", realm="asterisk", algorithm=MD5, uri="sip:10.1.7.200", nonce="1f74f3d9", response="1ed4dab8f24fc98efe8365f928915507"
X-Asterisk-HangupCause: Unknown
X-Asterisk-HangupCauseCode: 0
Content-Length: 0


---
[2014-12-16 16:40:52] VERBOSE[29941][C-00000000] chan_sip.c: Scheduling destruction of SIP dialog '1854750743-5062-7@BA.B.CJ.FA' in 6400 ms (Method: ACK)
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
SIP/2.0 481 Call Leg/Transaction Does Not Exist
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK6c9ff9e6;rport=5060
From: <sip:7121@10.1.7.200>;tag=as028031ad
To: <sip:7337@10.1.7.200>;tag=1949110676
Call-ID: 1854750743-5062-7@BA.B.CJ.FA
CSeq: 102 BYE
Supported: replaces, path, timer
User-Agent: Grandstream GXP1400 1.0.5.32
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: --- (10 headers 0 lines) ---
[2014-12-16 16:40:52] VERBOSE[29941] chan_sip.c: Really destroying SIP dialog '1854750743-5062-7@BA.B.CJ.FA' Method: ACK
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
INVITE sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK263168497;rport
From: <sip:7337@10.1.7.200>;tag=1610883898
To: <sip:7121@10.1.7.200>
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 70 INVITE
Contact: <sip:7337@10.1.29.50:5062>
Max-Forwards: 70
User-Agent: Grandstream GXP1400 1.0.5.32
Privacy: none
P-Preferred-Identity: <sip:7337@10.1.7.200>
Supported: replaces, path, timer
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 398

v=0
o=7337 8001 8000 IN IP4 10.1.29.50
s=SIP Call
c=IN IP4 10.1.29.50
t=0 0
m=audio 5008 RTP/AVP 0 8 4 18 9 97 2 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: --- (16 headers 19 lines) ---
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Using INVITE request as basis request - 1484267199-5062-8@BA.B.CJ.FA
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found peer '7337' for '7337' from 10.1.29.50:5062
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: 
<--- Reliably Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK263168497;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=1610883898
To: <sip:7121@10.1.7.200>;tag=as30ebab49
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 70 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="79ee6eea"
Content-Length: 0


<------------>
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Scheduling destruction of SIP dialog '1484267199-5062-8@BA.B.CJ.FA' in 6400 ms (Method: INVITE)
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
ACK sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK263168497;rport
From: <sip:7337@10.1.7.200>;tag=1610883898
To: <sip:7121@10.1.7.200>;tag=as30ebab49
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 70 ACK
Content-Length: 0

<------------->
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: --- (7 headers 0 lines) ---
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
INVITE sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK1085604857;rport
From: <sip:7337@10.1.7.200>;tag=1610883898
To: <sip:7121@10.1.7.200>
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 71 INVITE
Contact: <sip:7337@10.1.29.50:5062>
Authorization: Digest username="7337", realm="asterisk", nonce="79ee6eea", uri="sip:7121@10.1.7.200", response="fb8eb94da5daf55ee6e8d12f7641454d", algorithm=MD5
Max-Forwards: 70
User-Agent: Grandstream GXP1400 1.0.5.32
Privacy: none
P-Preferred-Identity: <sip:7337@10.1.7.200>
Supported: replaces, path, timer
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 398

v=0
o=7337 8001 8000 IN IP4 10.1.29.50
s=SIP Call
c=IN IP4 10.1.29.50
t=0 0
m=audio 5008 RTP/AVP 0 8 4 18 9 97 2 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: --- (17 headers 19 lines) ---
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Using INVITE request as basis request - 1484267199-5062-8@BA.B.CJ.FA
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found peer '7337' for '7337' from 10.1.29.50:5062
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] netsock2.c: Using SIP VIDEO TOS bits 136
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] netsock2.c: Using SIP VIDEO CoS mark 6
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] netsock2.c: Using SIP RTP TOS bits 184
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] netsock2.c: Using SIP RTP CoS mark 5
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 0
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 8
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 4
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 18
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 9
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 97
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 2
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found RTP audio format 101
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format PCMU for ID 0
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format PCMA for ID 8
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format G723 for ID 4
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format G729 for ID 18
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format G722 for ID 9
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format iLBC for ID 97
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format G726-32 for ID 2
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Found audio description format telephone-event for ID 101
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Capabilities: us - (alaw|g726|gsm|g722|ulaw|g729|h264|mpeg4|vp8), peer - audio=(ulaw|g726|g723|alaw|g722|g729|ilbc)/video=(nothing)/text=(nothing), combined - (alaw|g726|g722|ulaw|g729)
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Peer audio RTP is at port 10.1.29.50:5008
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Peer doesn't provide video
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Looking for 7121 in from-internal (domain 10.1.7.200)
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] sip/route.c: sip_route_dump: route/path hop: <sip:7337@10.1.29.50:5062>
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: 
<--- Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK1085604857;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=1610883898
To: <sip:7121@10.1.7.200>
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 71 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: <sip:7121@10.1.7.200:5060>
Content-Length: 0


<------------>
[2014-12-16 16:41:08] WARNING[29941][C-00000001] pbx.c: PBX requires Asterisk to be fully booted
[2014-12-16 16:41:08] WARNING[29941][C-00000001] chan_sip.c: Failed to start PBX :(
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: 
<--- Reliably Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 503 Unavailable
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK1085604857;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=1610883898
To: <sip:7121@10.1.7.200>;tag=as55b3a053
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 71 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Length: 0


<------------>
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Scheduling destruction of SIP dialog '1484267199-5062-8@BA.B.CJ.FA' in 6400 ms (Method: INVITE)
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
ACK sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK1085604857;rport
From: <sip:7337@10.1.7.200>;tag=1610883898
To: <sip:7121@10.1.7.200>;tag=as55b3a053
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 71 ACK
Content-Length: 0

<------------->
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: --- (7 headers 0 lines) ---
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: set_destination: Parsing <sip:7337@10.1.29.50:5062> for address/port to send to
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: set_destination: set destination to 10.1.29.50:5062
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Reliably Transmitting (no NAT) to 10.1.29.50:5062:
BYE sip:7337@10.1.29.50:5062 SIP/2.0
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK15a1cfa6;rport
Max-Forwards: 70
From: <sip:7121@10.1.7.200>;tag=as55b3a053
To: <sip:7337@10.1.7.200>;tag=1610883898
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 102 BYE
User-Agent: FPBX-12.0.18(13.1.0)
Proxy-Authorization: Digest username="7337", realm="asterisk", algorithm=MD5, uri="sip:10.1.7.200", nonce="79ee6eea", response="a275105ccb561f6600a09c8cd47799d7"
X-Asterisk-HangupCause: Unknown
X-Asterisk-HangupCauseCode: 0
Content-Length: 0


---
[2014-12-16 16:41:08] VERBOSE[29941][C-00000001] chan_sip.c: Scheduling destruction of SIP dialog '1484267199-5062-8@BA.B.CJ.FA' in 6400 ms (Method: ACK)
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: Retransmitting #1 (no NAT) to 10.1.29.50:5062:
BYE sip:7337@10.1.29.50:5062 SIP/2.0
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK15a1cfa6;rport
Max-Forwards: 70
From: <sip:7121@10.1.7.200>;tag=as55b3a053
To: <sip:7337@10.1.7.200>;tag=1610883898
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 102 BYE
User-Agent: FPBX-12.0.18(13.1.0)
Proxy-Authorization: Digest username="7337", realm="asterisk", algorithm=MD5, uri="sip:10.1.7.200", nonce="79ee6eea", response="a275105ccb561f6600a09c8cd47799d7"
X-Asterisk-HangupCause: Unknown
X-Asterisk-HangupCauseCode: 0
Content-Length: 0


---
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
SIP/2.0 481 Call Leg/Transaction Does Not Exist
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK15a1cfa6;rport=5060
From: <sip:7121@10.1.7.200>;tag=as55b3a053
To: <sip:7337@10.1.7.200>;tag=1610883898
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 102 BYE
Supported: replaces, path, timer
User-Agent: Grandstream GXP1400 1.0.5.32
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: --- (10 headers 0 lines) ---
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: Really destroying SIP dialog '1484267199-5062-8@BA.B.CJ.FA' Method: ACK
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
SIP/2.0 481 Call Leg/Transaction Does Not Exist
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK15a1cfa6;rport=5060
From: <sip:7121@10.1.7.200>;tag=as55b3a053
To: <sip:7337@10.1.7.200>;tag=1610883898
Call-ID: 1484267199-5062-8@BA.B.CJ.FA
CSeq: 102 BYE
Supported: replaces, path, timer
User-Agent: Grandstream GXP1400 1.0.5.32
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
[2014-12-16 16:41:08] VERBOSE[29941] chan_sip.c: --- (10 headers 0 lines) ---
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: Reliably Transmitting (no NAT) to 10.1.29.59:53856:
OPTIONS sip:7121@10.1.29.59:53856 SIP/2.0
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK066d2cee
Max-Forwards: 70
From: "Unknown" <sip:Unknown@10.1.7.200>;tag=as28f061aa
To: <sip:7121@10.1.29.59:53856>
Contact: <sip:Unknown@10.1.7.200:5060>
Call-ID: 58ac5d214bc27dae122a2eba292eee27@10.1.7.200:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-12.0.18(13.1.0)
Date: Tue, 16 Dec 2014 14:41:16 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.59:53856 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK066d2cee
From: "Unknown" <sip:Unknown@10.1.7.200>;tag=as28f061aa
To: <sip:7121@10.1.29.59:53856>;tag=1566331346
Call-ID: 58ac5d214bc27dae122a2eba292eee27@10.1.7.200:5060
CSeq: 102 OPTIONS
Supported: replaces, path, timer, eventlist
User-Agent: Grandstream GXV3140 1.0.7.60
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: --- (10 headers 0 lines) ---
[2014-12-16 16:40:18] VERBOSE[29895] loader.c: app_mp3.so => (Silly MP3 Application)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_env.so.
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: Really destroying SIP dialog '58ac5d214bc27dae122a2eba292eee27@10.1.7.200:5060' Method: OPTIONS
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'ENV'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'STAT'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'FILE'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'FILE_COUNT_LINE'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'FILE_FORMAT'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_env.so => (Environment/filesystem dialplan functions)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading res_ari_applications.so.
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: res_ari_applications.so => (RESTful API module - Stasis application resources)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_minivm.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MinivmRecord'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MinivmGreet'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MinivmNotify'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MinivmDelete'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MinivmAccMess'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MinivmMWI'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'MINIVMACCOUNT'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'MINIVMCOUNTER'
[2014-12-16 16:41:16] WARNING[29895] app_minivm.c: Failed to load configuration file. Module activated with default settings.
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_minivm.so => (Mini VoiceMail (A minimal Voicemail e-mail System))
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading res_convert.so.
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: res_convert.so => (File format conversion CLI command)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_extstate.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'EXTENSION_STATE'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_extstate.so => (Gets an extension's state in the dialplan)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_macro.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MacroExit'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MacroIf'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'MacroExclusive'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'Macro'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_macro.so => (Extension Macros)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_logic.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'ISNULL'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'SET'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'EXISTS'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'IF'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'IFTIME'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'IMPORT'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_logic.so => (Logical dialplan functions)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading bridge_builtin_interval_features.so.
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: bridge_builtin_interval_features.so => (Built in bridging interval features)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_verbose.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'Log'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'Verbose'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_verbose.so => (Send verbose output)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_timeout.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'TIMEOUT'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_timeout.so => (Channel timeout dialplan functions)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_talkdetect.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'TALK_DETECT'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_talkdetect.so => (Talk detection dialplan function)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading res_ari_sounds.so.
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: res_ari_sounds.so => (RESTful API module - Sound resources)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading codec_g726.so.
[2014-12-16 16:41:16] VERBOSE[29895] translate.c: Registered translator 'g726tolin' from codec g726 to slin, table cost, 900000, computational cost 4000
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: Reliably Transmitting (no NAT) to 10.1.29.50:5062:
OPTIONS sip:7337@10.1.29.50:5062 SIP/2.0
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK30451017
Max-Forwards: 70
From: "Unknown" <sip:Unknown@10.1.7.200>;tag=as2809ead9
To: <sip:7337@10.1.29.50:5062>
Contact: <sip:Unknown@10.1.7.200:5060>
Call-ID: 4a089df856e6fdb43baf92106328e376@10.1.7.200:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-12.0.18(13.1.0)
Date: Tue, 16 Dec 2014 14:41:16 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2014-12-16 16:41:16] VERBOSE[29895] translate.c: Registered translator 'lintog726' from codec slin to g726, table cost, 600000, computational cost 8998
[2014-12-16 16:41:16] VERBOSE[29895] translate.c: Registered translator 'g726aal2tolin' from codec g726aal2 to slin, table cost, 900000, computational cost 3999
[2014-12-16 16:41:16] VERBOSE[29895] translate.c: Registered translator 'lintog726aal2' from codec slin to g726aal2, table cost, 600000, computational cost 6999
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: codec_g726.so => (ITU G.726-32kbps G726 Transcoder)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_dumpchan.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'DumpChan'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_dumpchan.so => (Dump Info About The Calling Channel)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_disa.so.
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK30451017
From: "Unknown" <sip:Unknown@10.1.7.200>;tag=as2809ead9
To: <sip:7337@10.1.29.50:5062>;tag=72755430
Call-ID: 4a089df856e6fdb43baf92106328e376@10.1.7.200:5060
CSeq: 102 OPTIONS
Supported: replaces, path, timer
User-Agent: Grandstream GXP1400 1.0.5.32
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: --- (10 headers 0 lines) ---
[2014-12-16 16:41:16] VERBOSE[29941] chan_sip.c: Really destroying SIP dialog '4a089df856e6fdb43baf92106328e376@10.1.7.200:5060' Method: OPTIONS
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'DISA'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_disa.so => (DISA (Direct Inward System Access) Application)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading pbx_loopback.so.
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: pbx_loopback.so => (Loopback Switch)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_page.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'Page'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_page.so => (Page Multiple Phones)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_sprintf.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'SPRINTF'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_sprintf.so => (SPRINTF dialplan function)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading res_realtime.so.
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: res_realtime.so => (Realtime Data Lookup/Rewrite)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_module.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'IFMODULE'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_module.so => (Checks if Asterisk module is loaded in memory)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_db.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'DBdel'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'DBdeltree'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_db.so => (Database Access Functions)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_speex.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'AGC'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'DENOISE'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_speex.so => (Noise reduction and Automatic Gain Control (AGC))
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_privacy.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'PrivacyManager'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_privacy.so => (Require phone number to be entered, if no CallerID sent)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_sayunixtime.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'SayUnixTime'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'DateTime'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_sayunixtime.so => (Say time)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_dial.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'Dial'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'RetryDial'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_dial.so => (Dialing Application)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading chan_unistim.so.
[2014-12-16 16:41:16] ERROR[29895] chan_unistim.c: Unable to load config unistim.conf
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_srv.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'SRVQUERY'
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'SRVRESULT'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_srv.so => (SRV related dialplan functions)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading func_rand.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered custom function 'RAND'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: func_rand.so => (Random number dialplan function)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading app_chanisavail.so.
[2014-12-16 16:41:16] VERBOSE[29895] pbx.c: Registered application 'ChanIsAvail'
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: app_chanisavail.so => (Check channel availability)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading res_manager_presencestate.so.
[2014-12-16 16:41:16] VERBOSE[29895] manager.c: Manager registered action PresenceStateList
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: res_manager_presencestate.so => (Manager Presence State Topic Forwarder)
[2014-12-16 16:41:16] VERBOSE[29895] loader.c: Loading res_manager_devicestate.so.
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action DeviceStateList
[2014-12-16 16:41:17] VERBOSE[29895] loader.c: res_manager_devicestate.so => (Manager Device State Topic Forwarder)
[2014-12-16 16:41:17] VERBOSE[29895] loader.c: Loading app_queue.so.
[2014-12-16 16:41:17] NOTICE[29895] app_queue.c: No queuerules.conf file found, queues will not follow penalty rules
[2014-12-16 16:41:17] VERBOSE[29895] config.c: Parsing '/etc/asterisk/queues.conf': Found
[2014-12-16 16:41:17] VERBOSE[29895] config.c: Parsing '/etc/asterisk/queues_general_additional.conf': Found
[2014-12-16 16:41:17] VERBOSE[29895] config.c: Parsing '/etc/asterisk/queues_custom_general.conf': Found
[2014-12-16 16:41:17] VERBOSE[29895] config.c: Parsing '/etc/asterisk/queues_custom.conf': Found
[2014-12-16 16:41:17] VERBOSE[29895] config.c: Parsing '/etc/asterisk/queues_additional.conf': Found
[2014-12-16 16:41:17] VERBOSE[29895] config.c: Parsing '/etc/asterisk/queues_post_custom.conf': Found
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered application 'Queue'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered application 'AddQueueMember'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered application 'RemoveQueueMember'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered application 'PauseQueueMember'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered application 'UnpauseQueueMember'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered application 'QueueLog'
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action Queues
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueStatus
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueSummary
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueAdd
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueRemove
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueuePause
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueLog
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueuePenalty
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueMemberRingInUse
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueRule
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueReload
[2014-12-16 16:41:17] VERBOSE[29895] manager.c: Manager registered action QueueReset
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered custom function 'QUEUE_VARIABLES'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered custom function 'QUEUE_EXISTS'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered custom function 'QUEUE_MEMBER'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered custom function 'QUEUE_MEMBER_COUNT'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered custom function 'QUEUE_MEMBER_LIST'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered custom function 'QUEUE_WAITING_COUNT'
[2014-12-16 16:41:17] VERBOSE[29895] pbx.c: Registered custom function 'QUEUE_MEMBER_PENALTY'
[2014-12-16 16:41:17] VERBOSE[29895] loader.c: app_queue.so => (True Call Queueing)
[2014-12-16 16:41:17] VERBOSE[29895] asterisk.c: Asterisk Ready.
[2014-12-16 16:41:26] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
INVITE sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK303263610;rport
From: <sip:7337@10.1.7.200>;tag=911294988
To: <sip:7121@10.1.7.200>
Call-ID: 2141766105-5062-9@BA.B.CJ.FA
CSeq: 80 INVITE
Contact: <sip:7337@10.1.29.50:5062>
Max-Forwards: 70
User-Agent: Grandstream GXP1400 1.0.5.32
Privacy: none
P-Preferred-Identity: <sip:7337@10.1.7.200>
Supported: replaces, path, timer
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 398

v=0
o=7337 8001 8000 IN IP4 10.1.29.50
s=SIP Call
c=IN IP4 10.1.29.50
t=0 0
m=audio 5008 RTP/AVP 0 8 4 18 9 97 2 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
[2014-12-16 16:41:26] VERBOSE[29941] chan_sip.c: --- (16 headers 19 lines) ---
[2014-12-16 16:41:26] VERBOSE[29941] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Using INVITE request as basis request - 2141766105-5062-9@BA.B.CJ.FA
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found peer '7337' for '7337' from 10.1.29.50:5062
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: 
<--- Reliably Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK303263610;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=911294988
To: <sip:7121@10.1.7.200>;tag=as7342c150
Call-ID: 2141766105-5062-9@BA.B.CJ.FA
CSeq: 80 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0389420f"
Content-Length: 0


<------------>
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Scheduling destruction of SIP dialog '2141766105-5062-9@BA.B.CJ.FA' in 6400 ms (Method: INVITE)
[2014-12-16 16:41:26] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
ACK sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK303263610;rport
From: <sip:7337@10.1.7.200>;tag=911294988
To: <sip:7121@10.1.7.200>;tag=as7342c150
Call-ID: 2141766105-5062-9@BA.B.CJ.FA
CSeq: 80 ACK
Content-Length: 0

<------------->
[2014-12-16 16:41:26] VERBOSE[29941] chan_sip.c: --- (7 headers 0 lines) ---
[2014-12-16 16:41:26] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.50:5062 --->
INVITE sip:7121@10.1.7.200 SIP/2.0
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK922388165;rport
From: <sip:7337@10.1.7.200>;tag=911294988
To: <sip:7121@10.1.7.200>
Call-ID: 2141766105-5062-9@BA.B.CJ.FA
CSeq: 81 INVITE
Contact: <sip:7337@10.1.29.50:5062>
Authorization: Digest username="7337", realm="asterisk", nonce="0389420f", uri="sip:7121@10.1.7.200", response="fce28c63b131d497d9b8054c6b0f277f", algorithm=MD5
Max-Forwards: 70
User-Agent: Grandstream GXP1400 1.0.5.32
Privacy: none
P-Preferred-Identity: <sip:7337@10.1.7.200>
Supported: replaces, path, timer
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 398

v=0
o=7337 8001 8000 IN IP4 10.1.29.50
s=SIP Call
c=IN IP4 10.1.29.50
t=0 0
m=audio 5008 RTP/AVP 0 8 4 18 9 97 2 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
[2014-12-16 16:41:26] VERBOSE[29941] chan_sip.c: --- (17 headers 19 lines) ---
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Sending to 10.1.29.50:5062 (no NAT)
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Using INVITE request as basis request - 2141766105-5062-9@BA.B.CJ.FA
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found peer '7337' for '7337' from 10.1.29.50:5062
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] netsock2.c: Using SIP VIDEO TOS bits 136
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] netsock2.c: Using SIP VIDEO CoS mark 6
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] netsock2.c: Using SIP RTP TOS bits 184
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] netsock2.c: Using SIP RTP CoS mark 5
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 0
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 8
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 4
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 18
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 9
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 97
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 2
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 101
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format PCMU for ID 0
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format PCMA for ID 8
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format G723 for ID 4
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format G729 for ID 18
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format G722 for ID 9
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format iLBC for ID 97
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format G726-32 for ID 2
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format telephone-event for ID 101
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Capabilities: us - (alaw|g726|gsm|g722|ulaw|g729|h264|mpeg4|vp8), peer - audio=(ulaw|g726|g723|alaw|g722|g729|ilbc)/video=(nothing)/text=(nothing), combined - (alaw|g726|g722|ulaw|g729)
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Peer audio RTP is at port 10.1.29.50:5008
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Peer doesn't provide video
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: Looking for 7121 in from-internal (domain 10.1.7.200)
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] sip/route.c: sip_route_dump: route/path hop: <sip:7337@10.1.29.50:5062>
[2014-12-16 16:41:26] VERBOSE[29941][C-00000002] chan_sip.c: 
<--- Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK922388165;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=911294988
To: <sip:7121@10.1.7.200>
Call-ID: 2141766105-5062-9@BA.B.CJ.FA
CSeq: 81 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: <sip:7121@10.1.7.200:5060>
Content-Length: 0


<------------>
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [7121@from-internal:1] Set("SIP/7337-00000002", "__RINGTIMER=60") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [7121@from-internal:2] Macro("SIP/7337-00000002", "exten-vm,novm,7121,0,0,0") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:1] Macro("SIP/7337-00000002", "user-callerid,") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/7337-00000002", "TOUCH_MONITOR=1418740886.10") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/7337-00000002", "AMPUSER=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/7337-00000002", "0?report") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("SIP/7337-00000002", "1?Set(REALCALLERIDNUM=7337)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/7337-00000002", "AMPUSER=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/7337-00000002", "0?limit") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/7337-00000002", "AMPUSERCIDNAME=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("SIP/7337-00000002", "0?report") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:9] Set("SIP/7337-00000002", "AMPUSERCID=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:10] Set("SIP/7337-00000002", "__DIAL_OPTIONS=Ttr") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:11] Set("SIP/7337-00000002", "CALLERID(all)="7337" <7337>") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:12] GotoIf("SIP/7337-00000002", "0?limit") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("SIP/7337-00000002", "0?Set(GROUP(concurrency_limit)=7337)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:14] GosubIf("SIP/7337-00000002", "7?sub-ccss,s,1(macro-exten-vm,7121)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-ccss:1] ExecIf("SIP/7337-00000002", "0?Return()") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-ccss:2] Set("SIP/7337-00000002", "CCSS_SETUP=TRUE") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-ccss:3] GosubIf("SIP/7337-00000002", "7?monitor_config,1(macro-exten-vm,7121):monitor_default,1(macro-exten-vm,7121)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [monitor_config@sub-ccss:1] Set("SIP/7337-00000002", "CALLCOMPLETION(cc_monitor_policy)=generic") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [monitor_config@sub-ccss:2] GotoIf("SIP/7337-00000002", "1?set_monitor") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Goto (sub-ccss,monitor_config,5)
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [monitor_config@sub-ccss:5] Set("SIP/7337-00000002", "CALLCOMPLETION(cc_max_monitors)=") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [monitor_config@sub-ccss:6] Return("SIP/7337-00000002", "TRUE") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-ccss:4] GosubIf("SIP/7337-00000002", "7?agent_config,1():agent_default,1()") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:1] Set("SIP/7337-00000002", "CALLCOMPLETION(cc_agent_policy)=generic") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:2] Set("SIP/7337-00000002", "CALLCOMPLETION(cc_offer_timer)=30") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:3] Set("SIP/7337-00000002", "CALLCOMPLETION(ccbs_available_timer)=") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:4] Set("SIP/7337-00000002", "CALLCOMPLETION(ccnr_available_timer)=") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:5] Set("SIP/7337-00000002", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2014-12-16 16:41:26] WARNING[29994][C-00000002] ccss.c: Usage of cc_callback_macro is deprecated.  Please use cc_callback_sub instead.
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:6] ExecIf("SIP/7337-00000002", "1?Set(CALLCOMPLETION(cc_recall_timer)=)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:7] ExecIf("SIP/7337-00000002", "1?Set(CALLCOMPLETION(cc_max_agents)=)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:8] ExecIf("SIP/7337-00000002", "0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/7337_7121@from-ccss-)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:9] Set("SIP/7337-00000002", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2014-12-16 16:41:26] WARNING[29994][C-00000002] ccss.c: Usage of cc_callback_macro is deprecated.  Please use cc_callback_sub instead.
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [agent_config@sub-ccss:10] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-ccss:5] Set("SIP/7337-00000002", "DB(AMPUSER/7337/ccss/last_number)=7121") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-ccss:6] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("SIP/7337-00000002", "0?Set(CHANNEL(language)=)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:16] GotoIf("SIP/7337-00000002", "0?continue") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:17] ExecIf("SIP/7337-00000002", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:18] Set("SIP/7337-00000002", "__TTL=64") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("SIP/7337-00000002", "1?continue") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Goto (macro-user-callerid,s,30)
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:30] Set("SIP/7337-00000002", "CALLERID(number)=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:31] Set("SIP/7337-00000002", "CALLERID(name)=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:32] Set("SIP/7337-00000002", "CDR(cnum)=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:33] Set("SIP/7337-00000002", "CDR(cnam)=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:34] Set("SIP/7337-00000002", "CHANNEL(language)=ru") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:35] Set("SIP/7337-00000002", "TRUNKCALLERIDNUM=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-user-callerid:36] Set("SIP/7337-00000002", "TRUNKCALLERIDNAME=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:2] Set("SIP/7337-00000002", "RingGroupMethod=none") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:3] Set("SIP/7337-00000002", "__EXTTOCALL=7121") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:4] Set("SIP/7337-00000002", "__PICKUPMARK=7121") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:5] Set("SIP/7337-00000002", "RT=") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:6] ExecIf("SIP/7337-00000002", "0?Macro(vm,novm,DIRECTDIAL,)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:7] ExecIf("SIP/7337-00000002", "0?MacroExit()") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:8] Gosub("SIP/7337-00000002", "sub-record-check,s,1(exten,7121,)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/7337-00000002", "0?initialized") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:2] Set("SIP/7337-00000002", "__REC_STATUS=INITIALIZED") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:3] Set("SIP/7337-00000002", "NOW=1418740886") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:4] Set("SIP/7337-00000002", "__DAY=16") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:5] Set("SIP/7337-00000002", "__MONTH=12") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:6] Set("SIP/7337-00000002", "__YEAR=2014") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:7] Set("SIP/7337-00000002", "__TIMESTR=20141216-164126") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:8] Set("SIP/7337-00000002", "__FROMEXTEN=7337") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:9] Set("SIP/7337-00000002", "__MON_FMT=wav") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/7337-00000002", "Recordings initialized") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/7337-00000002", "0?Set(ARG3=dontcare)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:12] Set("SIP/7337-00000002", "REC_POLICY_MODE_SAVE=") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:13] GotoIf("SIP/7337-00000002", "5?checkaction") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Goto (sub-record-check,s,16)
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-record-check:16] GotoIf("SIP/7337-00000002", "1?sub-record-check,exten,1") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Goto (sub-record-check,exten,1)
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:1] NoOp("SIP/7337-00000002", "Exten Recording Check between 7337 and 7121") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:2] Set("SIP/7337-00000002", "CALLTYPE=internal") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:3] ExecIf("SIP/7337-00000002", "0?Set(CALLTYPE=)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:4] Set("SIP/7337-00000002", "CALLEE=dontcare") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:5] ExecIf("SIP/7337-00000002", "0?Set(CALLEE=dontcare)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:6] GotoIf("SIP/7337-00000002", "0?callee") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:7] GotoIf("SIP/7337-00000002", "1?caller") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Goto (sub-record-check,exten,13)
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:13] Set("SIP/7337-00000002", "RECMODE=dontcare") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:14] ExecIf("SIP/7337-00000002", "0?Set(RECMODE=dontcare)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:15] ExecIf("SIP/7337-00000002", "1?Set(RECMODE=dontcare)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:16] Gosub("SIP/7337-00000002", "recordcheck,1(dontcare,internal,7121)") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/7337-00000002", "Starting recording check against dontcare") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/7337-00000002", "dontcare") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Goto (sub-record-check,recordcheck,3)
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [recordcheck@sub-record-check:3] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [exten@sub-record-check:17] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:9] GotoIf("SIP/7337-00000002", "1?macrodial") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Goto (macro-exten-vm,s,15)
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:15] GosubIf("SIP/7337-00000002", "0?clrheader,1()") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-exten-vm:16] Macro("SIP/7337-00000002", "dial-one,,Ttr,7121") in new stack
[2014-12-16 16:41:26] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:1] Set("SIP/7337-00000002", "DEXTEN=7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:2] Set("SIP/7337-00000002", "DIALSTATUS_CW=") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:3] GosubIf("SIP/7337-00000002", "0?screen,1()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:4] GosubIf("SIP/7337-00000002", "0?cf,1()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:5] GotoIf("SIP/7337-00000002", "1?skip1") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Goto (macro-dial-one,s,8)
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:8] GotoIf("SIP/7337-00000002", "0?nodial") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:9] GotoIf("SIP/7337-00000002", "0?continue") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:10] Set("SIP/7337-00000002", "EXTHASCW=ENABLED") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:11] GotoIf("SIP/7337-00000002", "0?next1:cwinusebusy") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Goto (macro-dial-one,s,23)
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:23] GotoIf("SIP/7337-00000002", "1?next3:continue") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Goto (macro-dial-one,s,24)
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:24] ExecIf("SIP/7337-00000002", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:25] GotoIf("SIP/7337-00000002", "0?nodial") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:26] GosubIf("SIP/7337-00000002", "1?dstring,1():dlocal,1()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:1] Set("SIP/7337-00000002", "DSTRING=") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:2] Set("SIP/7337-00000002", "DEVICES=7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("SIP/7337-00000002", "0?Return()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("SIP/7337-00000002", "0?Set(DEVICES=121)") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:5] Set("SIP/7337-00000002", "LOOPCNT=1") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:6] Set("SIP/7337-00000002", "ITER=1") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:7] Set("SIP/7337-00000002", "THISDIAL=SIP/7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("SIP/7337-00000002", "1?zap2dahdi,1()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/7337-00000002", "0?Return()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("SIP/7337-00000002", "NEWDIAL=") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("SIP/7337-00000002", "LOOPCNT2=1") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("SIP/7337-00000002", "ITER2=1") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("SIP/7337-00000002", "THISPART2=SIP/7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/7337-00000002", "0?Set(THISPART2=DAHDI/7121)") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("SIP/7337-00000002", "NEWDIAL=SIP/7121&") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("SIP/7337-00000002", "ITER2=2") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/7337-00000002", "0?begin2") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("SIP/7337-00000002", "THISDIAL=SIP/7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("SIP/7337-00000002", "1?doset") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Goto (macro-dial-one,dstring,12)
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:12] Set("SIP/7337-00000002", "DSTRING=SIP/7121&") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:13] Set("SIP/7337-00000002", "ITER=2") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf("SIP/7337-00000002", "0?begin") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:15] Set("SIP/7337-00000002", "DSTRING=SIP/7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [dstring@macro-dial-one:16] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:27] GotoIf("SIP/7337-00000002", "0?nodial") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:28] GotoIf("SIP/7337-00000002", "0?skiptrace") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:29] GosubIf("SIP/7337-00000002", "1?ctset,1():ctclear,1()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [ctset@macro-dial-one:1] Set("SIP/7337-00000002", "DB(CALLTRACE/7121)=7337") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [ctset@macro-dial-one:2] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:30] Set("SIP/7337-00000002", "D_OPTIONS=Ttr") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:31] ExecIf("SIP/7337-00000002", "0?SIPAddHeader(Alert-Info: )") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:32] ExecIf("SIP/7337-00000002", "0?SIPAddHeader()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:33] ExecIf("SIP/7337-00000002", "0?Set(CHANNEL(musicclass)=)") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:34] GosubIf("SIP/7337-00000002", "0?qwait,1()") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:35] Set("SIP/7337-00000002", "__CWIGNORE=") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:36] Set("SIP/7337-00000002", "__KEEPCID=TRUE") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:37] GotoIf("SIP/7337-00000002", "0?usegoto,1") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:38] GotoIf("SIP/7337-00000002", "0?godial") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:39] Gosub("SIP/7337-00000002", "sub-presencestate-display,s,1(7121)") in new stack
[2014-12-16 16:41:27] WARNING[29994][C-00000002] func_presencestate.c: PRESENCE_STATE unknown 
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@sub-presencestate-display:1] Goto("SIP/7337-00000002", "state-,1") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Goto (sub-presencestate-display,state-,1)
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [state-@sub-presencestate-display:1] Set("SIP/7337-00000002", "PRESENCESTATE_DISPLAY=") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [state-@sub-presencestate-display:2] Return("SIP/7337-00000002", "") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:40] Set("SIP/7337-00000002", "CONNECTEDLINE(name,i)=7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:41] Set("SIP/7337-00000002", "CONNECTEDLINE(num)=7121") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:42] Set("SIP/7337-00000002", "D_OPTIONS=TtrI") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:43] Macro("SIP/7337-00000002", "dialout-one-predial-hook,") in new stack
[2014-12-16 16:41:27] WARNING[29994][C-00000002] app_macro.c: No such context 'macro-dialout-one-predial-hook' for macro 'dialout-one-predial-hook'. Was called by s@macro-dial-one
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] pbx.c: Executing [s@macro-dial-one:44] Dial("SIP/7337-00000002", "SIP/7121,,TtrI") in new stack
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] netsock2.c: Using SIP VIDEO TOS bits 136
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] netsock2.c: Using SIP VIDEO CoS mark 6
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] netsock2.c: Using SIP RTP TOS bits 184
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] netsock2.c: Using SIP RTP CoS mark 5
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Audio is at 12066
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Video is at 10.1.7.200:18588
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding codec alaw to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding codec g726 to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding codec gsm to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding codec g722 to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding codec ulaw to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding codec g729 to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding video codec h264 to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding video codec mpeg4 to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding video codec vp8 to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: Reliably Transmitting (no NAT) to 10.1.29.59:53856:
INVITE sip:7121@10.1.29.59:53856 SIP/2.0
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK7a0737ba
Max-Forwards: 70
From: "7337" <sip:7337@10.1.7.200>;tag=as4c8e91a5
To: <sip:7121@10.1.29.59:53856>
Contact: <sip:7337@10.1.7.200:5060>
Call-ID: 2f7176773d764d3c19ecf49e61c4c7fb@10.1.7.200:5060
CSeq: 102 INVITE
User-Agent: FPBX-12.0.18(13.1.0)
Date: Tue, 16 Dec 2014 14:41:27 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 533

v=0
o=root 1505364180 1505364180 IN IP4 10.1.7.200
s=Asterisk PBX 13.1.0
c=IN IP4 10.1.7.200
b=CT:384
t=0 0
m=audio 12066 RTP/AVP 8 2 3 9 0 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:3 GSM/8000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=sendrecv
m=video 18588 RTP/AVP 99 104 100
a=rtpmap:99 H264/90000
a=rtpmap:104 MP4V-ES/90000
a=rtpmap:100 VP8/90000
a=rtcp-fb:* ccm fir
a=sendrecv

---
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] app_dial.c: Called SIP/7121
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: 
<--- Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK922388165;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=911294988
To: <sip:7121@10.1.7.200>;tag=as3a2d77bc
Call-ID: 2141766105-5062-9@BA.B.CJ.FA
CSeq: 81 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: <sip:7121@10.1.7.200:5060>
Content-Length: 0


<------------>
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] app_dial.c: Connected line update to SIP/7337-00000002 prevented.
[2014-12-16 16:41:27] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.59:53856 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK7a0737ba
From: "7337" <sip:7337@10.1.7.200>;tag=as4c8e91a5
To: <sip:7121@10.1.29.59:53856>
Call-ID: 2f7176773d764d3c19ecf49e61c4c7fb@10.1.7.200:5060
CSeq: 102 INVITE
Supported: replaces, path, timer, eventlist
User-Agent: Grandstream GXV3140 1.0.7.60
Warning: 399 10.1.29.59 "Detected NAT type is UDP Blocked"
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
[2014-12-16 16:41:27] VERBOSE[29941] chan_sip.c: --- (11 headers 0 lines) ---
[2014-12-16 16:41:27] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.59:53856 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK7a0737ba
From: "7337" <sip:7337@10.1.7.200>;tag=as4c8e91a5
To: <sip:7121@10.1.29.59:53856>;tag=347607070
Call-ID: 2f7176773d764d3c19ecf49e61c4c7fb@10.1.7.200:5060
CSeq: 102 INVITE
Contact: <sip:7121@10.1.29.59:53856>
Supported: replaces, path, timer, eventlist
User-Agent: Grandstream GXV3140 1.0.7.60
Allow-Events: talk, hold
Warning: 399 10.1.29.59 "Detected NAT type is UDP Blocked"
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
[2014-12-16 16:41:27] VERBOSE[29941] chan_sip.c: --- (13 headers 0 lines) ---
[2014-12-16 16:41:27] VERBOSE[29941][C-00000002] sip/route.c: sip_route_dump: route/path hop: <sip:7121@10.1.29.59:53856>
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] app_dial.c: SIP/7121-00000003 is ringing
[2014-12-16 16:41:27] VERBOSE[29994][C-00000002] chan_sip.c: 
<--- Transmitting (no NAT) to 10.1.29.50:5062 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.1.29.50:5062;branch=z9hG4bK922388165;received=10.1.29.50;rport=5062
From: <sip:7337@10.1.7.200>;tag=911294988
To: <sip:7121@10.1.7.200>;tag=as3a2d77bc
Call-ID: 2141766105-5062-9@BA.B.CJ.FA
CSeq: 81 INVITE
Server: FPBX-12.0.18(13.1.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: <sip:7121@10.1.7.200:5060>
Content-Length: 0


<------------>
[2014-12-16 16:41:32] VERBOSE[29941] chan_sip.c: 
<--- SIP read from UDP:10.1.29.59:53856 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.7.200:5060;branch=z9hG4bK7a0737ba
From: "7337" <sip:7337@10.1.7.200>;tag=as4c8e91a5
To: <sip:7121@10.1.29.59:53856>;tag=347607070
Call-ID: 2f7176773d764d3c19ecf49e61c4c7fb@10.1.7.200:5060
CSeq: 102 INVITE
Contact: <sip:7121@10.1.29.59:53856>
Supported: replaces, path, timer, eventlist
User-Agent: Grandstream GXV3140 1.0.7.60
Warning: 399 10.1.29.59 "Detected NAT type is UDP Blocked"
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Content-Length: 427

v=0
o=7121 8000 8000 IN IP4 10.1.29.59
s=SIP Call
c=IN IP4 10.1.29.59
t=0 0
m=audio 30180 RTP/AVP 8 3 0 18 101
a=sendrecv
a=rtpmap:8 PCMA/8000
a=ptime:20
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 20130 RTP/AVP 99
b=AS:64
a=sendrecv
a=rtpmap:99 H264/90000
a=fmtp:99 sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecg==
<------------->
[2014-12-16 16:41:32] VERBOSE[29941] chan_sip.c: --- (13 headers 20 lines) ---
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 8
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 3
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 0
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 18
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP audio format 101
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format PCMA for ID 8
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format GSM for ID 3
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format PCMU for ID 0
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format G729 for ID 18
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found audio description format telephone-event for ID 101
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found RTP video format 99
[2014-12-16 16:41:32] VERBOSE[29941][C-00000002] chan_sip.c: Found video description format H264 for ID 99
[2014-12-16 16:41:38] Asterisk 13.1.0 built by root @ aster_test.xxxx.xx on a i686 running Linux on 2014-12-16 13:32:41 UTC