* You are viewing Posts Tagged ‘lyncserver’

Asterisk Lync / Call Center Transfer / Refer

Ha! Thanks Vip!

Sorry about not including my version numbers too. On my production box I’m using 1.8.3 (that’s the debug from the original email). On my demo box I just build I’m using 1.8 SVN-trunk-r309404 and that’s what generated these logs. I’m not sure if this is a chan_sip.c problem or if this is a dial plan problem.

So digging in a bit deeper, Asterisk is receving the real REFER message. The “REFER-TO: ” is accurate and in chan_sip.c it knows how to manipulate it. It does grab the “from-tag” and “to-tag” and parses the data. On one of the lines below you can see it says “Looking for Call ID: 655e28eb45e0db7639856ec92ca88909@10.10.10.10:5060 (Checking From) –From tag 15826bef52 –To-tag as41bacc0b”. Then it moves on to bridging the peers/channels together. It’s not until later that I get the final ” SIP/2.0 481 Call leg/transaction does not exist” which doesn’t make sense to me. Also, the Lync client says “Call was not transferred because [Original Extension] cannot be reached and may be offline.”

<------------->
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 0 [ 53]: REFER sip:1820@10.10.10.10:5060;transport=TCP SIP/2.0
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 1 [ 78]: FROM: ;epid=E5790B0758;tag=15826bef52
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 2 [ 41]: TO: ;tag=as41bacc0b
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 3 [ 13]: CSEQ: 2 REFER
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 4 [ 58]: CALL-ID: 655e28eb45e0db7639856ec92ca88909@10.10.10.10:5060
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TCP 20.20.20.20:5068;branch=z9hG4bK70e8a145
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 7 [107]: CONTACT:
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 8 [ 17]: CONTENT-LENGTH: 0
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 9 [200]: REFER-TO:
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Header 10 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer
[Mar 4 12:54:53] VERBOSE[11296] chan_sip.c: — (11 headers 0 lines) —
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: = Looking for Call ID: 655e28eb45e0db7639856ec92ca88909@10.10.10.10:5060 (Checking From) –From tag 15826bef52 –To-tag as41bacc0b
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: **** Received REFER (9) – Command in SIP REFER
[Mar 4 12:54:53] VERBOSE[11296] chan_sip.c: Call 655e28eb45e0db7639856ec92ca88909@10.10.10.10:5060 got a SIP call transfer from caller: (REFER)!
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Attended transfer: Will use Replace-Call-ID : a9b5f241-5e9d-4439-b347-2cac9384a627 F-tag: aa19f11d4f T-tag: 7a9abe27a5
[Mar 4 12:54:53] VERBOSE[11296] chan_sip.c: SIP transfer to extension lyncserver.internal.name:5068@from-internal-xfer by (null)
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: SIP attended transfer: Transferer channel SIP/Lync-00000003, transferee channel SIP/1820-00000002
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Got SIP transfer, applying to bridged peer ‘SIP/1820-00000002′
[Mar 4 12:54:53] VERBOSE[11296] chan_sip.c:
<--- Transmitting (no NAT) to 20.20.20.20:5068 --->
SIP/2.0 202 Accepted
Via: SIP/2.0/TCP 20.20.20.20:5068;branch=z9hG4bK70e8a145;received=20.20.20.20
From: ;epid=E5790B0758;tag=15826bef52
To: ;tag=as41bacc0b
Call-ID: 655e28eb45e0db7639856ec92ca88909@10.10.10.10:5060
CSeq: 2 REFER
Server: FPBX-2.8.1(1.8)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact:
Content-Length: 0

<------------>
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Trying to put ‘SIP/2.0 202′ onto TCP socket destined for 20.20.20.20:5068
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Looking for callid a9b5f241-5e9d-4439-b347-2cac9384a627 (fromtag aa19f11d4f totag 7a9abe27a5)
[Mar 4 12:54:53] DEBUG[11296] chan_sip.c: Strict routing enforced for session 655e28eb45e0db7639856ec92ca88909@10.10.10.10:5060
[Mar 4 12:54:53] VERBOSE[11296] chan_sip.c: set_destination: Parsing for address/port to send to
[Mar 4 12:54:53] DEBUG[11296] netsock2.c: Splitting ‘lyncserver.internal.name:5068′ gives…
[Mar 4 12:54:53] DEBUG[11296] netsock2.c: …host ‘lyncserver.internal.name’ and port ’5068′.
[Mar 4 12:54:53] DEBUG[11293] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/1820-00000002
Variable: SIPREFERRINGCONTEXT
Value: from-internal
Uniqueid: 1299261284.2

[Mar 4 12:54:53] DEBUG[11293] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/1820-00000002
Variable: SIPREFERREDBYHDR
Value:
Uniqueid: 1299261284.2

[Mar 4 12:54:53] DEBUG[11296] netsock2.c: Splitting ’20.20.20.20′ gives…
[Mar 4 12:54:53] DEBUG[11296] netsock2.c: …host ’20.20.20.20′ and port ‘(null)’.
[Mar 4 12:54:53] VERBOSE[11296] chan_sip.c: set_destination: set destination to 20.20.20.20:5068
[Mar 4 12:54:53] VERBOSE[11296] chan_sip.c: Reliably Transmitting (no NAT) to 20.20.20.20:5068:
NOTIFY sip:lyncserver.internal.name:5068;transport=Tcp;maddr=20.20.20.20 SIP/2.0
Via: SIP/2.0/TCP 10.10.10.10:5060;branch=z9hG4bK3f177f10
Max-Forwards: 70
From: ;tag=as41bacc0b
To: ;epid=E5790B0758;tag=15826bef52
Contact:
Call-ID: 655e28eb45e0db7639856ec92ca88909@10.10.10.10:5060
CSeq: 103 NOTIFY
User-Agent: FPBX-2.8.1(1.8)
Event: refer;id=2
Subscription-state: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 49

SIP/2.0 481 Call leg/transaction does not exist

Asterisk Lync / Call Center Transfer / Refer

Hey all,

Alright. So we decided to not go with Avaya for our next PBX and we are now full on into an Asterisk/Lync 2010 implementation. Asterisk/FreePBX is our SIP gateway and call center and Lync is our internal UC and IP-PBX server. I’ve already got Asterisk tied with our Nortel/Merridian Option 11 with QSig and all is beautiful (except for the Opt11 not receiving names from * but that’s another topic). So, my problem now is with the call center.

This setup may be a bit convoluted at first but it’ll make sense I hope. I’ve created the queues in Asterisk via FreePBX. I then created a ring group for each Lync extension so we get the “Confirm Calls” option and dodge the voice mail problem. The agents the login via their Lync phone with the Ring Group extension as their Agent ID. It kind of looks like this:

Queue 2001
Agent 4001
Agent 4002
Agent 4003

Ring Group 4001 -> Lync Extention 5001
Ring Group 4002 -> Lync Extention 5002
Ring Group 4003 -> Lync Extention 5003

This all works beautifuly! The problem I have is on transfers. If Lync extension 5001 trasnfers to Lync extension 5010, Asterisk is unaware of the transfer and shows that 5001 is still active with the call. We’re using OrderlyStats to monitor the queue so I watch the “Talking” counter just keep counting instead of being aware the transfer took place. Now to me, that says to me that the transfer took place within Lync so Asterisk is unaware of the transfer. So my next step was to enable Refer support in Lync so Lync sends the refer message back to Asterisk to transfer the call so Asterisk is fully aware of what’s going on. It seems like the refer message is trying to work and Lync is sending it and Asterisk is receiving it but the “Refer-To” is changing between the two so I’m at a loss.

(Logs are below signature)
Lync says it’s sending the following message with a “Refer-to:

Asterisk is seeing the following and the refer-to changed, it’s now “REFER-TO: “.

At first it seems like Lync is sending a true SIP URI so I need to get Asterisk to know how to handle that SIP URI and then secondly, it seems like Asterisk doesn’t even receive the same REFER-TO message that Lync sent. Is this because Asterisk doesn’t know how to handle the SIP URI?

So I guess I’m left with wondering if fixing the REFER message stuff is going to fix my problem even? The end goal is for Asterisk to be aware that a call was transferred to another extension in Lync.

Thanks in advance everyone!
Louis

================================= Begin Lync SIP message ============================================
TL_INFO(TF_PROTOCOL) [0]0B10.1E88::03/04/2011-13:21:17.501.0004fcd9 (SIPStack,SIPAdminLog::TraceProtocolRecord:SIPAdminLog.cpp(125))$$begin_record
Trace-Correlation-Id: 215606761
Instance-Id: 00011F02
Direction: outgoing
Peer: lyncserver.internal.domain:5070
Message-Type: request
Start-Line: REFER sip:lyncserver.internal.domain:5070;grid=ed392a6bc0344a30b0841cd69be137ed SIP/2.0
From: “” ;epid=e9688aa93e;tag=8be38bb187
To: ;epid=B3E26C1E76;tag=9227b8a39d
CSeq: 2 REFER
Call-ID: aa6f8871-4151-4149-ad5a-29ab941bf4d0
Via: SIP/2.0/TLS 20.20.20.20:54166;branch=z9hG4bKEB39D72C.F05E7E34CF9EF4FD;branched=FALSE
Max-Forwards: 69
Via: SIP/2.0/TLS 172.16.2.29:53851;ms-received-port=53851;ms-received-cid=400
User-Agent: CPE/4.0.7577.107 OCPhone/4.0.7577.107 (Microsoft Lync 2010 Phone Edition)
Supported: ms-dialog-route-set-update
Refer-to:
Referred-By: ;ms-referee-uri=”sip:500;phone-context=enterprise@domainname.com;user=phone”;ms-identity=”MIIBxwYJKoZIhvcNAQcCoIIBuDCCAbQCAQExDzANBgkqhkiG9w0BAQUFADALBgkqhkiG9w0BBwExggGPMIIBiwIBATBkMFYxFDASBgoJkiaJk/IsZAEZFgRSb290MRcwFQYKCZImiZPyLGQBGRYHTmV0d29yazElMCMGA1UEAxMcUGluY2ggQSBQZW5ueSBSb290IEF1dGhvcml0eQIKH1RMewAAAAAABjANBgkqhkiG9w0BAQUFADANBgkqhkiG9w0BAQEFAASCAQDCqFfl86RgR0gyLlbf6kEtUbFIWu2zCaFlqOoBWH/1ftxR80WwlsM142hImIGJhugOnXGIpCPMwC5OsPlD5Zk5+J371SSiz0dLhTjC1EzQzTMiIf9xbAd+ohi+e46TfXrJSN+esDNAafFKau0sj4hqPuuMh4EsabcNPrZwmroF5FX7zzEmRiavIKdGjyFgtwrwTIVkWjOnKdJdZN7T9jUj7Eb5HJGvOuG29LeJajTbogLugzsRA85RGQ7s+HMhU8F/RTJwQEvDhM4HQNeRFqUENi4jkYFUjuQaL3A2+Zqoml6LeZQNKU/afq8L9vck9+5qL1tc7c3+BtT+RxwlE92C:Fri, 04 Mar 2011 13:21:17 GMT”;ms-identity-info=”sip:Lyncserver.internal.domain:5061;transport=tls”;ms-identity-alg=rsa-sha1
Content-Length: 0
P-Asserted-Identity:
Privacy: id
Message-Body: -
$$end_record
================================= End Lync SIP message ============================================

================================= Begin Asterisk Debug ============================================
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 0 [ 53]: REFER sip:500@10.10.10.10:5067;transport=TLS SIP/2.0
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 1 [ 78]: FROM: ;epid=431D53633D;tag=42b6d8c72b
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 2 [ 46]: TO: ;tag=as0d823373
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 3 [ 13]: CSEQ: 2 REFER
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 4 [ 59]: CALL-ID: 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TLS 20.20.20.20:5067;branch=z9hG4bK4614ad68
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 7 [ 86]: CONTACT:
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 8 [ 17]: CONTENT-LENGTH: 0
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 9 [179]: REFER-TO:
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 10 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 11 [ 0]:
[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c:
<--- SIP read from TLS:20.20.20.20:5067 --->
REFER sip:500@10.10.10.10:5067;transport=TLS SIP/2.0
FROM: ;epid=431D53633D;tag=42b6d8c72b
TO: ;tag=as0d823373
CSEQ: 2 REFER
CALL-ID: 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067
MAX-FORWARDS: 70
VIA: SIP/2.0/TLS 20.20.20.20:5067;branch=z9hG4bK4614ad68
CONTACT:
CONTENT-LENGTH: 0
REFER-TO:
USER-AGENT: RTCC/4.0.0.0 MediationServer

<------------->
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 0 [ 53]: REFER sip:500@10.10.10.10:5067;transport=TLS SIP/2.0
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 1 [ 78]: FROM: ;epid=431D53633D;tag=42b6d8c72b
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 2 [ 46]: TO: ;tag=as0d823373
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 3 [ 13]: CSEQ: 2 REFER
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 4 [ 59]: CALL-ID: 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TLS 20.20.20.20:5067;branch=z9hG4bK4614ad68
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 7 [ 86]: CONTACT:
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 8 [ 17]: CONTENT-LENGTH: 0
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 9 [179]: REFER-TO:
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Header 10 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer
[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c: — (11 headers 0 lines) —
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: = Looking for Call ID: 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067 (Checking From) –From tag 42b6d8c72b –To-tag as0d823373
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: **** Received REFER (9) – Command in SIP REFER
[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c: Call 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067 got a SIP call transfer from caller: (REFER)!
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Attended transfer: Will use Replace-Call-ID : aa6f8871-4151-4149-ad5a-29ab941bf4d0 F-tag: 9227b8a39d T-tag: 8be38bb187
[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c: SIP transfer to extension Lyncserver.internal.domain:5067@from-internal-xfer by (null)
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: SIP attended transfer: Transferer channel SIP/Lync-00000003, transferee channel DAHDI/i1/500-2
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Got SIP transfer, applying to bridged peer ‘DAHDI/i1/500-2′
[Mar 4 08:21:05] DEBUG[18502] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/i1/500-2
Variable: SIPREFERRINGCONTEXT
Value: from-internal
Uniqueid: 1299244801.4

[Mar 4 08:21:05] DEBUG[18502] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/i1/500-2
Variable: SIPREFERREDBYHDR
Value:
Uniqueid: 1299244801.4

[Mar 4 08:21:05] DEBUG[18497] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/i1/500-2
Variable: SIPREFERRINGCONTEXT
Value: from-internal
Uniqueid: 1299244801.4

[Mar 4 08:21:05] DEBUG[18497] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/i1/500-2
Variable: SIPREFERREDBYHDR
Value:
Uniqueid: 1299244801.4

[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c:
<--- Transmitting (no NAT) to 20.20.20.20:5067 --->
SIP/2.0 202 Accepted
Via: SIP/2.0/TLS 20.20.20.20:5067;branch=z9hG4bK4614ad68;received=20.20.20.20
From: ;epid=431D53633D;tag=42b6d8c72b
To: ;tag=as0d823373
Call-ID: 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067
CSeq: 2 REFER
Server: FPBX-2.8.1(1.8.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact:
Content-Length: 0

<------------>
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Trying to put ‘SIP/2.0 202′ onto TLS socket destined for 20.20.20.20:5067
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Looking for callid aa6f8871-4151-4149-ad5a-29ab941bf4d0 (fromtag 9227b8a39d totag 8be38bb187)
[Mar 4 08:21:05] DEBUG[18506] chan_sip.c: Strict routing enforced for session 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067
[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c: set_destination: Parsing for address/port to send to
[Mar 4 08:21:05] DEBUG[18506] netsock2.c: Splitting ‘Lyncserver.internal.domain:5067′ gives…
[Mar 4 08:21:05] DEBUG[18506] netsock2.c: …host ‘Lyncserver.internal.domain’ and port ’5067′.
[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c: set_destination: set destination to 20.20.20.20:5067
[Mar 4 08:21:05] VERBOSE[18506] chan_sip.c: Reliably Transmitting (no NAT) to 20.20.20.20:5067:
NOTIFY sip:Lyncserver.internal.domain:5067;transport=Tls SIP/2.0
Via: SIP/2.0/TLS 10.10.10.10:5067;branch=z9hG4bK05f81334
Max-Forwards: 70
From: ;tag=as0d823373
To: ;epid=431D53633D;tag=42b6d8c72b
Contact:
Call-ID: 4ad0626f79c7c8de66b668b13d624129@10.10.10.10:5067
CSeq: 103 NOTIFY
User-Agent: FPBX-2.8.1(1.8.3)
Event: refer;id=2
Subscription-state: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 49

SIP/2.0 481 Call leg/transaction does not exist