Lync 2010 <=> AsteriskNow not working

[rimroot]

Hello. I am new to Asterisk. I have to make sip trunk between lync and trixbox. Lync users can call Asterisk users but call ends after 11 seconds and lync client shows "Call failed due to network issues". Lync and AsteriskNow 1.7.1 servers are behind NAT and clients are outside.

Trunk name: LYNC
PEER Details:

host=lync2010pool.mydomain.lt
type=peer
qualify=yes
transport=tcp, udp
insecure=very
port=5068
canreinvite=yes
fromdomain=mydomain.lt
context=from-lync
dtmfmode=rfc2833

[malcolmd]

So...is is Trixbox, or is it AsteriskNOW?

[rimroot]

So...is is Trixbox, or is it AsteriskNOW?

Sorry it is asteriskNOW. I previously tried Trixbox.

[malcolmd]

What does Asterisk's SIP debug say? Does Lync have some kind of debugging beyond that message?

[rimroot]

What does Asterisk's SIP debug say? Does Lync have some kind of debugging beyond that message?

Here is my Asterisk debug log. For Lync log i will try to find it too.

Lync Server and asteriskNOW server side public IP: 2xx.xxx.1xx.xx1
Client side public ip: 2yy.yyy.1yy.x5
Softphone: 3CX

[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:2yy.yyy.1yy.x5:5060 --->
REGISTER sip:2xx.xxx.1xx.xx1:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.36.18:5060;branch=z9hG4bK-d8754z-eb06a36727765b64-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
To: <sip:101@2xx.xxx.1xx.xx1:5060>
From: <sip:101@2xx.xxx.1xx.xx1:5060>;tag=4b62eb7e
Call-ID: ZWUxZWJjNTBhMmJlOGMyZDdjNjViZTE4Nzg1ZGY1YTk.
CSeq: 134 REGISTER
Expires: 120
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
Supported: replaces
User-Agent: 3CXPhone 5.0.14900.0
Authorization: Digest username="101",realm="asterisk",nonce="5ce9efbf",uri="sip:2xx.xxx.1xx.xx1:5060",response="cb4e74749e4c0e35ea99e0807e352da5",algorithm=MD5
Content-Length: 0

<------------->
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: --- (14 headers 0 lines) ---
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: Sending to 2yy.yyy.1yy.x5 : 5060 (NAT)
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c:
<--- Transmitting (NAT) to 2yy.yyy.1yy.x5:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.36.18:5060;branch=z9hG4bK-d8754z-eb06a36727765b64-1---d8754z-;received=2yy.yyy.1yy.x5;rport=5060
From: <sip:101@2xx.xxx.1xx.xx1:5060>;tag=4b62eb7e
To: <sip:101@2xx.xxx.1xx.xx1:5060>;tag=as57857641
Call-ID: ZWUxZWJjNTBhMmJlOGMyZDdjNjViZTE4Nzg1ZGY1YTk.
CSeq: 134 REGISTER
Server: FPBX-2.7.0(1.6.2.16.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="3b6a26ac"
Content-Length: 0

<------------>
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: Scheduling destruction of SIP dialog 'ZWUxZWJjNTBhMmJlOGMyZDdjNjViZTE4Nzg1ZGY1YTk.' in 32000 ms (Method: REGISTER)
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:2yy.yyy.1yy.x5:5060 --->
REGISTER sip:2xx.xxx.1xx.xx1:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.36.18:5060;branch=z9hG4bK-d8754z-26379b6e7d297d55-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
To: <sip:101@2xx.xxx.1xx.xx1:5060>
From: <sip:101@2xx.xxx.1xx.xx1:5060>;tag=4b62eb7e
Call-ID: ZWUxZWJjNTBhMmJlOGMyZDdjNjViZTE4Nzg1ZGY1YTk.
CSeq: 135 REGISTER
Expires: 120
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
Supported: replaces
User-Agent: 3CXPhone 5.0.14900.0
Authorization: Digest username="101",realm="asterisk",nonce="3b6a26ac",uri="sip:2xx.xxx.1xx.xx1:5060",response="b5ef97207dc7f1a3d0ad3f697c76af52",algorithm=MD5
Content-Length: 0

<------------->
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: --- (14 headers 0 lines) ---
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: Sending to 2yy.yyy.1yy.x5 : 5060 (NAT)
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: Reliably Transmitting (NAT) to 2yy.yyy.1yy.x5:5060:
OPTIONS sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee SIP/2.0
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK6ff3a36d;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@2xx.xxx.1xx.xx1>;tag=as089178d7
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
Contact: <sip:Unknown@2xx.xxx.1xx.xx1>
Call-ID: 67d11097592ab77840887ff14bf32919@2xx.xxx.1xx.xx1
CSeq: 102 OPTIONS
User-Agent: FPBX-2.7.0(1.6.2.16.1)
Date: Tue, 15 Feb 2011 08:37:45 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

---
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c:
<--- Transmitting (NAT) to 2yy.yyy.1yy.x5:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.36.18:5060;branch=z9hG4bK-d8754z-26379b6e7d297d55-1---d8754z-;received=2yy.yyy.1yy.x5;rport=5060
From: <sip:101@2xx.xxx.1xx.xx1:5060>;tag=4b62eb7e
To: <sip:101@2xx.xxx.1xx.xx1:5060>;tag=as57857641
Call-ID: ZWUxZWJjNTBhMmJlOGMyZDdjNjViZTE4Nzg1ZGY1YTk.
CSeq: 135 REGISTER
Server: FPBX-2.7.0(1.6.2.16.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Expires: 60
Contact: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>;expires=60
Date: Tue, 15 Feb 2011 08:37:45 GMT
Content-Length: 0

<------------>
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: Scheduling destruction of SIP dialog 'ZWUxZWJjNTBhMmJlOGMyZDdjNjViZTE4Nzg1ZGY1YTk.' in 32000 ms (Method: REGISTER)
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:2yy.yyy.1yy.x5:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK6ff3a36d;rport=5060
Contact: <sip:192.168.36.18:5060>
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>;tag=68672505
From: "Unknown"<sip:Unknown@2xx.xxx.1xx.xx1>;tag=as089178d7
Call-ID: 67d11097592ab77840887ff14bf32919@2xx.xxx.1xx.xx1
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Language: en
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
Supported: replaces
Allow-Events: presence, message-summary, tunnel-info
Content-Length: 0

<------------->
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: --- (13 headers 0 lines) ---
[Feb 15 10:37:45] VERBOSE[2484] chan_sip.c: Really destroying SIP dialog '67d11097592ab77840887ff14bf32919@2xx.xxx.1xx.xx1' Method: OPTIONS
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c:
<--- SIP read from TCP:192.168.68.91:60257 --->
INVITE sip:101@asterisknow01.mydomain.lt;user=phone SIP/2.0
FROM: "Artūras Rimonis"<sip:2001@fe01.mydomain.lt;user=phone>;epid=03259E13E5;tag=3bca2e7b83
TO: <sip:101@asterisknow01.mydomain.lt;user=phone>
CSEQ: 23319 INVITE
CALL-ID: 843c3b3a-20a8-425a-9804-2668f9d2a1c9
MAX-FORWARDS: 70
VIA: SIP/2.0/TCP 192.168.68.91:60257;branch=z9hG4bKadf9fb25
CONTACT: <sip:fe01.mydomain.lt:5068;transport=Tcp;maddr=192.168.68.91;ms-opaque=a8e975a9c1cf1341>
CONTENT-LENGTH: 343
SUPPORTED: 100rel
USER-AGENT: RTCC/4.0.0.0 MediationServer
CONTENT-TYPE: application/sdp
ALLOW: ACK
Allow: CANCEL,BYE,INVITE,PRACK,UPDATE

v=0
o=- 148 1 IN IP4 192.168.68.91
s=session
c=IN IP4 192.168.68.91
b=CT:1000
t=0 0
m=audio 57422 RTP/AVP 97 101 13 0 8
c=IN IP4 192.168.68.91
a=rtcp:57423
a=label:Audio
a=sendrecv
a=rtpmap:97 RED/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=ptime:20

<------------->
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: --- (14 headers 18 lines) ---
[Feb 15 10:37:52] VERBOSE[9451] netsock.c: == Using SIP RTP TOS bits 184
[Feb 15 10:37:52] VERBOSE[9451] netsock.c: == Using SIP RTP CoS mark 5
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Sending to 192.168.68.91 : 60257 (NAT)
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Using INVITE request as basis request - 843c3b3a-20a8-425a-9804-2668f9d2a1c9
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found peer 'LYNC' for '2001' from 192.168.68.91:60257
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found RTP audio format 97
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found RTP audio format 101
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found RTP audio format 13
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found RTP audio format 0
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found RTP audio format 8
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found audio description format RED for ID 97
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found audio description format telephone-event for ID 101
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found audio description format CN for ID 13
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found audio description format PCMU for ID 0
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Found audio description format PCMA for ID 8
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x40c (ulaw|alaw|ilbc)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw)
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x3 (telephone-event|CN), combined - 0x1 (telephone-event)
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Peer audio RTP is at port 192.168.68.91:57422
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: Looking for 101 in from-lync (domain asterisknow01.mydomain.lt)
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: list_route: hop: <sip:fe01.mydomain.lt:5068;transport=Tcp;maddr=192.168.68.91;ms-opaque=a8e975a9c1cf1341>
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c:
<--- Transmitting (NAT) to 192.168.68.91:60257 --->
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 192.168.68.91:60257;branch=z9hG4bKadf9fb25;received=192.168.68.91
From: "Artūras Rimonis"<sip:2001@fe01.mydomain.lt;user=phone>;epid=03259E13E5;tag=3bca2e7b83
To: <sip:101@asterisknow01.mydomain.lt;user=phone>
Call-ID: 843c3b3a-20a8-425a-9804-2668f9d2a1c9
CSeq: 23319 INVITE
Server: FPBX-2.7.0(1.6.2.16.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:101@192.168.68.156;transport=TCP>
Content-Length: 0

<------------>
[Feb 15 10:37:52] VERBOSE[9452] pbx.c: -- Executing [101@from-lync:1] Answer("SIP/LYNC-00000012", "") in new stack
[Feb 15 10:37:52] VERBOSE[9452] chan_sip.c: Audio is at 192.168.68.156 port 10084
[Feb 15 10:37:52] VERBOSE[9452] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[Feb 15 10:37:52] VERBOSE[9452] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Feb 15 10:37:52] VERBOSE[9452] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Feb 15 10:37:52] VERBOSE[9452] chan_sip.c:
<--- Reliably Transmitting (NAT) to 192.168.68.91:60257 --->
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.68.91:60257;branch=z9hG4bKadf9fb25;received=192.168.68.91
From: "Artūras Rimonis"<sip:2001@fe01.mydomain.lt;user=phone>;epid=03259E13E5;tag=3bca2e7b83
To: <sip:101@asterisknow01.mydomain.lt;user=phone>;tag=as10e2af07
Call-ID: 843c3b3a-20a8-425a-9804-2668f9d2a1c9
CSeq: 23319 INVITE
Server: FPBX-2.7.0(1.6.2.16.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:101@192.168.68.156;transport=TCP>
Content-Type: application/sdp
Content-Length: 265

v=0
o=root 514945289 514945289 IN IP4 192.168.68.156
s=Asterisk PBX 1.6.2.16.1
c=IN IP4 192.168.68.156
t=0 0
m=audio 10084 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c:
<--- SIP read from TCP:192.168.68.91:60257 --->
ACK sip:101@192.168.68.156;transport=TCP SIP/2.0
FROM: <sip:2001@fe01.mydomain.lt;user=phone>;epid=03259E13E5;tag=3bca2e7b83
TO: <sip:101@asterisknow01.mydomain.lt;user=phone>;tag=as10e2af07
CSEQ: 23319 ACK
CALL-ID: 843c3b3a-20a8-425a-9804-2668f9d2a1c9
MAX-FORWARDS: 70
VIA: SIP/2.0/TCP 192.168.68.91:60257;branch=z9hG4bK9a2162f8
CONTENT-LENGTH: 0
USER-AGENT: RTCC/4.0.0.0 MediationServer

<------------->
[Feb 15 10:37:52] VERBOSE[9451] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 15 10:37:53] VERBOSE[9452] pbx.c: -- Executing [101@from-lync:2] Dial("SIP/LYNC-00000012", "SIP/101,20,tr") in new stack
[Feb 15 10:37:53] VERBOSE[9452] netsock.c: == Using SIP RTP TOS bits 184
[Feb 15 10:37:53] VERBOSE[9452] netsock.c: == Using SIP RTP CoS mark 5
[Feb 15 10:37:53] VERBOSE[9452] chan_sip.c: Audio is at 2xx.xxx.1xx.xx1 port 10056
[Feb 15 10:37:53] VERBOSE[9452] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[Feb 15 10:37:53] VERBOSE[9452] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Feb 15 10:37:53] VERBOSE[9452] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Feb 15 10:37:53] VERBOSE[9452] chan_sip.c: Reliably Transmitting (NAT) to 2yy.yyy.1yy.x5:5060:
INVITE sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee SIP/2.0
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK0e5c6c2e;rport
Max-Forwards: 70
From: "Artūras Rimonis" <sip:2001@2xx.xxx.1xx.xx1>;tag=as34a8831a
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
Contact: <sip:2001@2xx.xxx.1xx.xx1>
Call-ID: 3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1
CSeq: 102 INVITE
User-Agent: FPBX-2.7.0(1.6.2.16.1)
Date: Tue, 15 Feb 2011 08:37:53 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 265

v=0
o=root 31703178 31703178 IN IP4 2xx.xxx.1xx.xx1
s=Asterisk PBX 1.6.2.16.1
c=IN IP4 2xx.xxx.1xx.xx1
t=0 0
m=audio 10056 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
[Feb 15 10:37:53] VERBOSE[9452] app_dial.c: -- Called 101
[Feb 15 10:37:53] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:2yy.yyy.1yy.x5:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK0e5c6c2e;rport=5060
Contact: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>;tag=7f79e84a
From: "Artūras Rimonis"<sip:2001@2xx.xxx.1xx.xx1>;tag=as34a8831a
Call-ID: 3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1
CSeq: 102 INVITE
User-Agent: 3CXPhone 5.0.14900.0
Content-Length: 0

<------------->
[Feb 15 10:37:53] VERBOSE[2484] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 15 10:37:53] VERBOSE[9452] app_dial.c: -- SIP/101-00000013 is ringing
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:2yy.yyy.1yy.x5:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK0e5c6c2e;rport=5060
Contact: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>;tag=7f79e84a
From: "Artūras Rimonis"<sip:2001@2xx.xxx.1xx.xx1>;tag=as34a8831a
Call-ID: 3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1
CSeq: 102 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
Content-Type: application/sdp
Supported: replaces
User-Agent: 3CXPhone 5.0.14900.0
Content-Length: 237

v=0
o=3cxVCE 151176870 205173900 IN IP4 2yy.yyy.1yy.x5
s=3cxVCE Audio Call
c=IN IP4 2yy.yyy.1yy.x5
t=0 0
m=audio 10030 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

<------------->
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: --- (12 headers 10 lines) ---
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Found RTP audio format 0
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Found RTP audio format 8
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Found RTP audio format 101
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Found audio description format PCMU for ID 0
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Found audio description format PCMA for ID 8
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Found audio description format telephone-event for ID 101
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw)
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Peer audio RTP is at port 2yy.yyy.1yy.x5:10030
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: list_route: hop: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: set_destination: Parsing <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee> for address/port to send to
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: set_destination: set destination to 2yy.yyy.1yy.x5, port 5060
[Feb 15 10:37:57] VERBOSE[2484] chan_sip.c: Transmitting (NAT) to 2yy.yyy.1yy.x5:5060:
ACK sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee SIP/2.0
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK2870a1ca;rport
Max-Forwards: 70
From: "Artūras Rimonis" <sip:2001@2xx.xxx.1xx.xx1>;tag=as34a8831a
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>;tag=7f79e84a
Contact: <sip:2001@2xx.xxx.1xx.xx1>
Call-ID: 3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1
CSeq: 102 ACK
User-Agent: FPBX-2.7.0(1.6.2.16.1)
Content-Length: 0

---
[Feb 15 10:37:57] VERBOSE[9452] app_dial.c: -- SIP/101-00000013 answered SIP/LYNC-00000012
[Feb 15 10:38:00] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:192.168.68.152:49890 --->

<------------->
[Feb 15 10:38:00] VERBOSE[2484] chan_sip.c: Really destroying SIP dialog 'N2I1MjI1ZmQxZTViY2ViNGFiOTMwNmU1Yzc5MTI2MWI.' Method: REGISTER
[Feb 15 10:38:04] VERBOSE[9451] chan_sip.c:
<--- SIP read from TCP:192.168.68.91:60257 --->
BYE sip:101@192.168.68.156;transport=TCP SIP/2.0
FROM: <sip:2001@fe01.mydomain.lt;user=phone>;epid=03259E13E5;tag=3bca2e7b83
TO: <sip:101@asterisknow01.mydomain.lt;user=phone>;tag=as10e2af07
CSEQ: 23320 BYE
CALL-ID: 843c3b3a-20a8-425a-9804-2668f9d2a1c9
MAX-FORWARDS: 70
VIA: SIP/2.0/TCP 192.168.68.91:60257;branch=z9hG4bK305b846a
CONTACT: <sip:fe01.mydomain.lt:5068;transport=Tcp;maddr=192.168.68.91>
CONTENT-LENGTH: 0
USER-AGENT: RTCC/4.0.0.0 MediationServer

<------------->
[Feb 15 10:38:04] VERBOSE[9451] chan_sip.c: --- (10 headers 0 lines) ---
[Feb 15 10:38:04] VERBOSE[9451] chan_sip.c: Sending to 192.168.68.91 : 60257 (NAT)
[Feb 15 10:38:04] VERBOSE[9451] chan_sip.c:
<--- Transmitting (NAT) to 192.168.68.91:60257 --->
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.68.91:60257;branch=z9hG4bK305b846a;received=192.168.68.91
From: <sip:2001@fe01.mydomain.lt;user=phone>;epid=03259E13E5;tag=3bca2e7b83
To: <sip:101@asterisknow01.mydomain.lt;user=phone>;tag=as10e2af07
Call-ID: 843c3b3a-20a8-425a-9804-2668f9d2a1c9
CSeq: 23320 BYE
Server: FPBX-2.7.0(1.6.2.16.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
[Feb 15 10:38:04] VERBOSE[9452] chan_sip.c: Scheduling destruction of SIP dialog '3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1' in 8576 ms (Method: INVITE)
[Feb 15 10:38:04] VERBOSE[9452] chan_sip.c: set_destination: Parsing <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee> for address/port to send to
[Feb 15 10:38:04] VERBOSE[9452] chan_sip.c: set_destination: set destination to 2yy.yyy.1yy.x5, port 5060
[Feb 15 10:38:04] VERBOSE[9452] chan_sip.c: Reliably Transmitting (NAT) to 2yy.yyy.1yy.x5:5060:
BYE sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee SIP/2.0
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK78a3367e;rport
Max-Forwards: 70
From: "Artūras Rimonis" <sip:2001@2xx.xxx.1xx.xx1>;tag=as34a8831a
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>;tag=7f79e84a
Call-ID: 3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1
CSeq: 103 BYE
User-Agent: FPBX-2.7.0(1.6.2.16.1)
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

---
[Feb 15 10:38:04] VERBOSE[9452] pbx.c: == Spawn extension (from-lync, 101, 2) exited non-zero on 'SIP/LYNC-00000012'
[Feb 15 10:38:04] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:2yy.yyy.1yy.x5:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 2xx.xxx.1xx.xx1:5060;branch=z9hG4bK78a3367e;rport=5060
Contact: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>
To: <sip:101@2yy.yyy.1yy.x5:5060;rinstance=d7d50749ac51fbee>;tag=7f79e84a
From: "Artūras Rimonis"<sip:2001@2xx.xxx.1xx.xx1>;tag=as34a8831a
Call-ID: 3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1
CSeq: 103 BYE
User-Agent: 3CXPhone 5.0.14900.0
Content-Length: 0

<------------->
[Feb 15 10:38:04] VERBOSE[2484] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 15 10:38:04] VERBOSE[2484] chan_sip.c: Really destroying SIP dialog '843c3b3a-20a8-425a-9804-2668f9d2a1c9' Method: BYE
[Feb 15 10:38:04] VERBOSE[2484] chan_sip.c: Really destroying SIP dialog '3e411fd70af178cd24db2bc348ac7db1@2xx.xxx.1xx.xx1' Method: INVITE
[Feb 15 10:38:04] VERBOSE[2484] chan_sip.c:
<--- SIP read from UDP:2yy.yyy.1yy.x5:5060 --->

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

[malcolmd]

Okay, so Lync is sending BYE. Does it report why it does that?

[rimroot]

Okay, so Lync is sending BYE. Does it report why it does that?

I'm not sure where to look. There is "Lync Server Logging Tool" but i don't know which information is relevant.

here is some information from Lync Server:

TL_INFO(TF_PROTOCOL) [0]0A60.0BFC::02/17/2011-13:22:40.661.000ac1c1 (SIPStack,SIPAdminLog::TraceProtocolRecord:SIPAdminLog.cpp(125))$$begin_record
Trace-Correlation-Id: 248475806
Instance-Id: 0008CEBF
Direction: outgoing
Peer: edge01.mydomain.lt:57398
Message-Type: request
Start-Line: BYE sip:2yy.yyy.1yy.x5:23824;transport=tls;ms-opaque=28d20d250e;ms-received-cid=23A600;grid SIP/2.0
From: <sip:101;phone-context=DefaultProfile@mydomain.lt;user=phone>;epid=B37A35025C;tag=8c3ea1ace1
To: <sip:2001;phone-context=DefaultProfile@mydomain.lt;user=phone>;epid=3c07f5d2ab;tag=4c69b3fc72
CSeq: 14072 BYE
Call-ID: a74d3538-591a-4685-ac1f-4a3dbbd09c93
Via: SIP/2.0/TLS 192.168.68.91:5061;branch=z9hG4bK106D6EE1.A4A1B9E592F64550;branched=FALSE
Authentication-Info: TLS-DSK qop="auth", opaque="EC10C3F3", srand="56FA71D7", snum="123", rspauth="008e74f819e69a40a9a592e238293b6711ec4a0f", targetname="fe01.mydomain.lt", realm="SIP Communications Service", version=4
Max-Forwards: 69
Via: SIP/2.0/TLS 192.168.68.91:57447;branch=z9hG4bKdcc09f32;ms-received-port=57447;ms-received-cid=1648B00
CONTACT: <sip:fe01.mydomain.lt@mydomain.lt;gruu;opaque=srvr:MediationServer:eb1vQskkbF2HSn2QbEhv8wAA;grid=ebfd9ad6c1b6492692b62e3fc0dcd689>;isGateway
CONTENT-LENGTH: 0
SUPPORTED: ms-dialog-route-set-update
SUPPORTED: gruu-10
USER-AGENT: RTCC/4.0.0.0 MediationServer
P-ASSERTED-IDENTITY: "Pirmas vartotojas"<sip:101;phone-context=DefaultProfile@mydomain.lt;user=phone>
ms-diagnostics: 23;source="fe01.mydomain.lt";reason="Call failed to establish due to a media connectivity failure when one endpoint is internal and the other is remote";component="MediationServer";Exception="Proxy side ICE connectivity check failed.";ICEWarningFlags="ICEWarn=0x1120,LocalSite=192.168.68.91:55784,LocalMR=192.168.68.91:448,RemoteSite=2yy.yyy.1yy.x5:3643,RemoteMR=2zz.zzz.1zz.zz5:54567,PortRange=49152:57500,RemoteMRTCPPort=54567,LocalLocation=2,RemoteLocation=0,FederationType=0"
ms-diagnostics-public: 23;reason="Call failed to establish due to a media connectivity failure when one endpoint is internal and the other is remote";component="MediationServer";Exception="Proxy side ICE connectivity check failed."
ms-endpoint-location-data: NetworkScope;ms-media-location-type=intranet
Route: <sip:lync2010edgepool.mydomain.lt:57398;transport=tls;maddr=192.168.68.101;opaque=state:Ee.blxfvGSaV1nWQsMj9ilf8LpwAA;lr;ms-received-cid=162F200>
Message-Body: –
$$end_record

[malcolmd]

"Call failed to establish due to a media connectivity failure when one endpoint is internal and the other is remote";

Different networks?

[rimroot]

"Call failed to establish due to a media connectivity failure when one endpoint is internal and the other is remote";

Different networks?

http://www.part.lt/img/9d69e53cd283999f21dddf31653c4bbb373.jpg

[rimroot]

I did some more testing. So basically calls between Lync clients and Asterisk clients are working. Only thing that is not working is calls between External Lync clients and interneal/external Asterisk clients.
Here is updated diagram:

https://picasaweb.google.com/lh/photo/2 ... directlink

[briankeating]

I too have been using Microsoft Lync 2010 and have never come across this error.