Thursday, 7 December 2017

Spectralink 8400 Edge Issue

I found an interesting issue when testing some Spectralink 8440 handsets the other day and I didn’t see the answer documented anywhere, so I thought I'd change that situation by blogging about it.

Note: The firmware that I was using when I ran into this issue was I also rolled back to a 5.3 and 5.2 version and had the same issue, so this problem may have existed for a while.

The Symptom

Outbound Call
After setting the phones up and logging in using PIN Authentication successfully when making an outbound call, the call would hang after the number was dialled. The screen would sit at the calling screen forever and nothing would happen (i.e. the dialled phone wouldn’t ring).

Outbound Call

Inbound Call
For an inbound call, the calling party (i.e. a Skype for Business client) would receive ringback tone and the call would not get displayed on the Spectralink handset. After the call forwarded timeout was reached, the call forwarded to voicemail and a missed call would appear on the Spectralink screen.
Inbound Call


The symptoms described above were consistent and it was clear that the SIP Signalling was working well enough to allow the device to sign in and receive information from the system. However, both inbound and outbound calls were not setting up correctly. The next port of call was to look into the logs. For an outbound call there wasn’t much information in the logs to dig into. However, for an inbound call I could see the inbound INVITE message arrive and the phone would respond with a TRYING message. At this point I could see that the inbound call was not progressing past the point of parsing the candidates from the inbound INVITE message. From this, I suspected that this was something to do with the Spectralink not being about to process the candidates correctly. I then realised that the lab system I was testing the phone on didn’t actually have an Edge server associated with it. This, of course, meant that the phone would not be getting or receiving any reflexive or relay candidates… Hhhhmmmm, interesting...

Inbound Call Log
1205143558|sip  |0|00|<<< Data received TLS
1205143558|sip  |0|00|    INVITE sip:Terry.Adams@;transport=tls;ms-received-cid=781300 SIP/2.0
1205143558|sip  |0|00|    Record-Route: <;transport=tls;opaque=state:T:F:Ci.R781300:Ieh.Lvw6TSBMlsUoTJbFhkstQInxeS6wHgXRHMHiO5ioDln-fhNvUO1qLucUD4gO1tXpzhB_8cegAA;lr;ms-route-sig=hkx-TWiKYeik4c0hYMHXqBiJ4op9gbnpuTatBwsuD7moptXpzhB_8cegAA>;tag=B12630CFFCD2C61F74BDE5EB8A4C611A
1205143558|sip  |0|00|    Via: SIP/2.0/TLS;branch=z9hG4bK8BA0D60F.E19C5E6D7DAA886D;branched=TRUE;ms-internal-info="dgFJqKHJ0AXHZY0sy2IaYnenMPK5auGe9rVA0q4_Ro3qxtXpzhVO8OYQAA"
1205143558|sip  |0|00|    Authentication-Info: TLS-DSK qop="auth", opaque="4E02C6ED", srand="4D31E5BD", snum="17", rspauth="420755234a2dbcecd21a249213ceb92d8ba9cfc5", targetname="", realm="SIP Communications Service", version=4
1205143558|sip  |0|00|    Max-Forwards: 69
1205143558|sip  |0|00|    Content-Length: 890
1205143558|sip  |0|00|    Via: SIP/2.0/TLS;branch=z9hG4bK1d5487849DAF07;ms-received-port=42727;ms-received-cid=77D300
1205143558|sip  |0|00|    P-Asserted-Identity: "Terry Adams"<>,<tel:+61266591007;ext=1007>
1205143558|sip  |0|00|    From: "Terry Adams" <>;tag=5C30CCBE-7E228105;epid=64167f23b38c
1205143558|sip  |0|00|    To: <;user=phone>;epid=00907a0f09d8
1205143558|sip  |0|00|    CSeq: 1 INVITE
1205143558|sip  |0|00|    Call-ID: 0888c5534fafd0fc37bc94f7a523b38c
1205143558|sip  |0|00|    Contact: <;opaque=user:epid:F5iF87H531yKmJ1oYYBMjwAA;gruu>
1205143558|sip  |0|00|    User-Agent: Polycom/ PolycomVVX-VVX_311-UA/
1205143558|sip  |0|00|    Accept-Language: en
1205143558|sip  |0|00|    ms-subnet:
1205143558|sip  |0|00|    Allow-Events: conference,talk,hold
1205143558|sip  |0|00|    Supported: replaces
1205143558|sip  |0|00|    Supported: ms-safe-transfer
1205143558|sip  |0|00|    Supported: ms-bypass
1205143558|sip  |0|00|    Supported: ms-dialog-route-set-update
1205143558|sip  |0|00|    Supported: timer
1205143558|sip  |0|00|    Supported: 100rel
1205143558|sip  |0|00|    Supported: gruu-10
1205143558|sip  |0|00|    MS-Conversation-ID: AdNteidtM2YxYWFkN2ZiZjM0ODVhZQ==
1205143558|sip  |0|00|    Content-Type: application/sdp
1205143558|sip  |0|00|    history-info: <>;index=1;ms-target-phone="tel:+61266591007;ext=1007"
1205143558|sip  |0|00|   
1205143558|sip  |0|00|    v=0
1205143558|sip  |0|00|    o=- 1512444953 1512444953 IN IP4
1205143558|sip  |0|00|    s=Polycom IP Phone
1205143558|sip  |0|00|    c=IN IP4
1205143558|sip  |0|00|    t=0 0
1205143558|sip  |0|00|    a=sendrecv
1205143558|sip  |0|00|    m=audio 5350 RTP/S
1205143558|sip  |0|00|<<< Data received TLS
1205143558|sip  |0|00|    AVP 9 112 8 0 18 101
1205143558|sip  |0|00|    a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:/u2wztfJizjOcLml2T1uN/3qiNEZpAiiPqCcyOhn|2^31|1:1
1205143558|sip  |0|00|    a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:gXAfAu4Z6VZ/1ZQYLJe3g4HAGcgwY9w4vDdlLSkJ|2^31
1205143558|sip  |0|00|    a=rtpmap:9 G722/8000
1205143558|sip  |0|00|    a=rtpmap:112 G7221/16000
1205143558|sip  |0|00|    a=fmtp:112 bitrate=24000
1205143558|sip  |0|00|    a=rtpmap:8 PCMA/8000
1205143558|sip  |0|00|    a=rtpmap:0 PCMU/8000
1205143558|sip  |0|00|    a=rtpmap:18 G729/8000
1205143558|sip  |0|00|    a=fmtp:18 annexb=no
1205143558|sip  |0|00|    a=rtpmap:101 telephone-event/8000
1205143558|sip  |0|00|    a=ice-pwd:EK5jmhsUk5xntwoCmEIEAmfT
1205143558|sip  |0|00|    a=ice-ufrag:pbdW
1205143558|sip  |0|00|    a=rtcp:5351
1205143558|sip  |0|00|    a=candidate:1 1 UDP 2130706431 5350 typ host
1205143558|sip  |0|00|    a=candidate:1 2 UDP 2130706430 5351 typ host
1205143558|sip  |0|00|    a=candidate:2 1 TCP-ACT 1684733951 5350 typ srflx raddr rport 5350
1205143558|sip  |0|00|    a=candidate:2 2 TCP-ACT 1684733950 5350 typ srflx raddr rport 5350
1205143558|sip  |1|00|MsgSipTcpPacket
1205143558|sip  |1|00|MsgSipTcpPacket
1205143558|sip  |3|00|CStkDialog::CreateRouteSet: transport set to top route 'TLS'
1205143558|sip  |3|00|CStkDialog::SetAddressLocal localTag set to ''
1205143558|sip  |3|00|CStkDialog::SetAddressLocal new address added of 1
1205143558|sip  |2|00|CStkDialog::CStkDialog SetAddressLocal from pRequest To: 'Terry Adams' <>
1205143558|sip  |2|00|CStkDialog::CStkDialog SetAddressLocal Config 'Terry Adams' <>
1205143558|sip  |2|00|CStkDialog::CStkDialog TAG 'B640E4F5-9C530CE' generated
1205143558|sip  |2|00|CStkDialog::CStkDialog local addr 'Terry Adams' <> Tag 'B640E4F5-9C530CE'
1205143558|sip  |2|00|CStkDialog::CStkDialog exit 0x9d5bf0 local list size 1
1205143558|sip  |2|00|CCallBase::IsChallenged COPIED Dialog Tag to pRequest 'B640E4F5-9C530CE'
1205143558|sip  |2|00|CCallBase::IsChallenged 'INVITE' Dialog Tag 'B640E4F5-9C530CE' pRequest Tag 'B640E4F5-9C530CE' state 'Trying'
1205143558|sip  |2|00|new UA Server INVITE trans state 'proceeding', timeout=0 (0x40d40ea8)
1205143558|sip  |3|00|CStateInviteServer::CStateInviteServer
1205143558|sip  |3|00|CStateInviteServer::CStateInviteServerHandler
1205143558|sip  |3|00|CStateInviteServer::CStateInviteServerHandler - pReplace (0x0)
1205143558|sip  |*|00|CSdp::operator << - setting m_bIsSecured == true
1205143558|sip  |3|00|CStateInviteServer::CStateInviteServerHandler - calling RemoteSdpOffer
1205143558|sip  |3|00|CStkCall::RemoteSdpOffer m_nMediaRTPPort=0
1205143558|sip  |1|00|Dialog 'id9cd7e4d4' State 'Trying'->'Early'
1205143558|sip  |1|00|signatureBuffer: <TLS-DSK><D0E0949F><11><SIP Communications Service><><0888c5534fafd0fc37bc94f7a523b38c><1><INVITE><><5C30CCBE-7E228105><;user=phone><B640E4F5-9C530CE><><tel:+61266591007;ext=1007><><100>
1205143558|sip  |1|00|doDnsListLookup(tls): doDnsSrvLookupForARecordList for '' port 5061 returned 1 results
1205143558|sip  |1|00|doDnsListLookup(tls): result 0 host '' IP '' port 5061 isInBound 0
1205143558|sip  |1|00|CTcp::Send(TLS) entry for address port 5061 can Connect 0 canFailOver 1
1205143558|sip  |0|00|>>> Data Send TLS
1205143558|sip  |0|00|    SIP/2.0 100 Trying
1205143558|sip  |0|00|    Via: SIP/2.0/TLS;branch=z9hG4bK8BA0D60F.E19C5E6D7DAA886D;branched=TRUE;ms-internal-info="dgFJqKHJ0AXHZY0sy2IaYnenMPK5auGe9rVA0q4_Ro3qxtXpzhVO8OYQAA"
1205143558|sip  |0|00|    Via: SIP/2.0/TLS;branch=z9hG4bK1d5487849DAF07;ms-received-port=42727;ms-received-cid=77D300
1205143558|sip  |0|00|    From: "Terry Adams" <>;tag=5C30CCBE-7E228105;epid=64167f23b38c
1205143558|sip  |0|00|    To: "Terry Adams" <;user=phone>;epid=00907a0f09d8;tag=B640E4F5-9C530CE
1205143558|sip  |0|00|    CSeq: 1 INVITE
1205143558|sip  |0|00|    Call-ID: 0888c5534fafd0fc37bc94f7a523b38c
1205143558|sip  |0|00|    Contact: <;opaque=user:epid:x5jsdoUew1a9jiDyam965gAA;gruu>
1205143558|sip  |0|00|    Record-Route: <;transport=tls;opaque=state:T:F:Ci.R781300:Ieh.Lvw6TSBMlsUoTJbFhkstQInxeS6wHgXRHMHiO5ioDln-fhNvUO1qLucUD4gO1tXpzhB_8cegAA;lr;ms-route-sig=hkx-TWiKYeik4c0hYMHXqBiJ4op9gbnpuTatBwsuD7moptXpzhB_8cegAA>;tag=B12630CFFCD2C61F74BDE5EB8A4C611A
1205143558|sip  |0|00|    User-Agent: Spectralink-SL_8440-UA/
1205143558|sip  |0|00|    Accept-Language: en
1205143558|sip  |0|00|    P-Preferred-Identity: "Terry Adams" <>,<tel:+61266591007;ext=1007>
1205143558|sip  |0|00|    Authorization: TLS-DSK qop="auth", realm="SIP Communications Service", opaque="4E02C6ED", crand="D0E0949F", cnum="11", targetname="", response="bf39acaf3c91ff5826574895f209520c0507fe35"
1205143558|sip  |0|00|    Content-Length: 0
1205143558|sip  |0|00|   
1205143558|sip  |1|00|CTcpSocket::SendData TLS queuedTxData = 0 TotalLen 1313 loop count 1 maxQueueDepth 40000
1205143558|sip  |1|00|CTcpSocket::SendData TLS Sent 1313 loop count 1
1205143558|sip  |3|00|CStkCall::NewCallState 'Unknown'->'Offering' (0x9b9b48)
1205143558|sip  |3|00|GetRemotePartyAddress from 'P-Asserted-Identity'
1205143558|sip  |3|00|CStkCall::NewCallState - BEFORE call to SipOnEvNewCall m_nMediaRTPPort=0
1205143558|ice  |0|00|soIceChannelCreate: channelId=-1 category=1 chanType=0 udpPort=2226 portTurn=2726 tcpPort=-1
1205143558|ice  |0|00|soIceRtpChanList.count=1
1205143558|ice  |2|00|soIceChannelCreate: allocated channelId 5
1205143558|ice  |0|00|soIceChannelCreate: channelId=-1 category=1 chanType=1 udpPort=2227 portTurn=2727 tcpPort=-1
1205143558|ice  |0|00|soIceRtpChanList.count=2
1205143558|ice  |2|00|soIceChannelCreate: allocated channelId 6
1205143558|ice  |0|00|soIceSessionCreate start
1205143558|ice  |0|00|    channelIdAudioRtp=5
1205143558|ice  |0|00|    enableBWManagement=0
1205143558|ice  |0|00|    bwAudioMin=64
1205143558|ice  |0|00|    bwAudioMax=64
1205143558|ice  |0|00|soIceSessionCreate - full functionality so set gatheringStunReqMaxRetransmit = 4
1205143558|ice  |0|00|soIceSessionListRemove: soIceSessionList.count=0
1205143558|ice  |0|00|soIceSessionCreate: sessEntryP (0x426d0f60) - set bInitialInvite true
1205143558|ice  |0|00|soIceSessionList.count=1
1205143558|ice  |1|00|soIceSessionCreate: linked channel (5) with session (3)
1205143558|ice  |1|00|soIceSessionCreate: linked channel (6) with session (3)
1205143558|ice  |2|00|soIceSessionCreate: allocated hSpiSession 0xb1f9d8 sessionId 3 for audio 5 6
1205143558|ice  |0|00|soIceSessionSdpGetCallAnswer
1205143558|ice  |0|00|soIceSessionSdpGetCallAnswer: len=890 pSdpInvite=
1205143558|ice  |0|00|v=0
1205143558|ice  |0|00|o=- 1512444953 1512444953 IN IP4
1205143558|ice  |0|00|s=Polycom IP Phone
1205143558|ice  |0|00|c=IN IP4
1205143558|ice  |0|00|t=0 0
1205143558|ice  |0|00|a=sendrecv
1205143558|ice  |0|00|m=audio 5350 RTP/SAVP 9 112 8 0 18 101
1205143558|ice  |0|00|a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:/u2wztfJizjOcLml2T1uN/3qiNEZpAiiPqCcyOhn|2^31|1:1
1205143558|ice  |0|00|a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:gXAfAu4Z6VZ/1ZQYLJe3g4HAGcgwY9w4vDdlLSkJ|2^31
1205143558|ice  |0|00|a=rtpmap:9 G722/8000
1205143558|ice  |0|00|a=rtpmap:112 G7221/16000
1205143558|ice  |0|00|a=fmtp:112 bitrate=24000
1205143558|ice  |0|00|a=rtpmap:8 PCMA/8000
1205143558|ice  |0|00|a=rtpmap:0 PCMU/8000
1205143558|ice  |0|00|a=rtpmap:18 G729/8000
1205143558|ice  |0|00|a=fmtp:18 annexb=no
1205143558|ice  |0|00|a=rtpmap:101 telephone-event/8000
1205143558|ice  |0|00|a=ice-pwd:EK5jmhsUk5xntwoCmEIEAmfT
1205143558|ice  |0|00|a=ice-ufrag:pbdW
1205143558|ice  |0|00|a=rtcp:5351
1205143558|ice  |0|00|a=candidate:1 1 UDP 2130706431 5350 typ host
1205143558|ice  |0|00|a=candidate:1 2 UDP 2130706430 5351 typ host
1205143558|ice  |0|00|a=candidate:2 1 TCP-ACT 1684733951 5350 typ srflx raddr rport 5350
1205143558|ice  |0|00|a=candidate:2 2 TCP-ACT 1684733950 5350 typ srflx raddr rport 5350
1205143558|ice  |0|00|soIceSessionSdpGetCallAnswer: RvIceSessionSDPIn returned 0
1205143558|ice  |0|00|*** sdpInpRes.eIceSupport 0
1205143558|ice  |0|00|soIceSessionSdpGetCallAnswer: entryP (0x426d0f60) bInitialInvite=1
1205143558|ice  |0|00|soIceSetLocalHostCandidates - local rtp port 2226
1205143558|ice  |0|00|soIceSetLocalHostCandidates: RvIceSessionSetLocalRtpCandidatesToAllMediaStreams returned 0
1205143558|ice  |0|00|soIceSessionSdpGetCallAnswer: RvIceSessionGatherReflexiveCandidatesEx returned=-1
1205143558|sip  |2|00|SipOnEvNewCall new call appearnce 1 SRTP key È Ô@¨ Ô@
1205143558|sip  |3|00|CStkCall::NewCallState - after call to SipOnEvNewCall m_nMediaRTPPort=2226
1205143558|sip  |2|00|SipOnEvCallNewState 9b9b48,bdb4a0 1,(null)
1205143558|sip  |3|00|CStkCall::NewCallState update held and hold flags, state 1
1205143558|sip  |3|00|CStkCall::NewCallState held 0 hold 0

The Fix!

After realising that this probably had something to do with not having an Edge server deployed on the lab system I was using, I moved the Spectralink over to another system that did have an Edge… and what do you know, the phone started working perfectly. Not having an Edge was in fact the issue. The next question was, is there any configuration that could be done on the Spectralink to make it work without an Edge? (Spoiler: Yes)

As you may or may not know, one of the main configuration items on a Spectralink (or Polycom phones which have basically the same software) is to configure the baseProfile setting to make it run in "Lync" mode. This makes a whole raft of settings in the background on your behalf, to make your life easier. What are these settings that get made when the base profile is set to Lync mode? Well, I did a comparison on the Polycom VVX running 5.6 firmware to find out exactly what the Lync profile settings were:

Lync Base Profile settings (in comparison to Generic mode):

Based on my earlier assumption that the issue has something to do with the Edge reflexive and relay candidates, the fault was likely caused by something to do with the Microsoft specific ICE interaction. There was one setting this this sizable list that stood out to me - the"MSOCS" setting. This setting was made specifically to handle the candidate negotiations required by Microsoft Lync/Skype for Business. After disabling this setting, guess what happened? Inbound and outbound calls started working…

TLDR Answer

When you have no Edge server deployed within your Lync/Skype for Business environment and you are deploying Spectralink phones, set the setting to “disabled”. In a config file this might look something like this:

<!-- If there is an Edge then"MSOCS" if there is no Edge then"disabled" -->

The Wrap Up

Well, another day another crazy config setting. There always seems to be an endless supply of gotchas in this business and this is another one to add to your list. Till next time!

Read more →

Wednesday, 15 November 2017

Deploying Powershell Scripts with Group Policy

I have written quite a few Powershell tools for Skype for Business and some of these might be tools that people want to use on a regular basis across their Front End servers. People may want to deploy so that others within the administrative team can also use them in a simple and centrally managed way. So I thought I would write a blog post that explains a simple way to centrally deploy scripts out to multiple servers so they are easily accessible to yourself and other team members.
The method described below uses Active Directory Group Policy to control the deployment Powershell scripts across a number of Skype for Business Front End servers.

Step 1: Create a central file share where you will be storing the script files that you would like to have available on your Front End servers. In this case I created a folder named Scripts where I placed a Powershell script.

Step 2: Share the folder (Right Click on Folder-> Properties -> Sharing Tab -> Sharing…). In this case I have given Read access to everyone.

Step 3: In Active Directory Users and Computers create an OU for your Skype for Business servers. In this case I have created an OU called SfBServers and have moved all of the Skype for Business Front Ends Computer Objects to this OU.

Step 4: Open Active Directory Group Policy Management (gpmc.msc) and Right Click the SfBServers OU and “Create a GPO in this domain, and Link it here…”.

Step 5: Give the New GPO a name. In this case I have called the GPO “PowershellScripts”.

Step 6: Right Click the PowershellScripts GPO and select “Edit…”.

Step 7: Open Computer Configuration -> Preferences -> Windows Settings, Right Click Shortcuts and select New -> Shortcut.

Step 8: Fill in the shortcut properties as described below.

Action: Update
Name: VVX Manager
Target type: File System Object
Location: All Users Desktop
Target path: C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe
Arguments: -WindowStyle Hidden -nologo -executionpolicy bypass -command "& \\ServerHostName\Scripts\Skype4B-Lync-PolycomVVXManager2.21.ps1"
Icon file path: %SystemRoot%\system32\SHELL32.dll
Icon index: 24

Powershell Arguments Breakdown:
-WindowStyle: This argument is being used to supress the Powershell window from being displayed when the script is run. I am using this deliberately because the script I am using this for has its own Windows Forms GUI that will be displayed and the Powershell window is not required. This will give the script the feeling of being more like an application.
-NoLogo: Tells the Powershell window to not show the Copyright banner - to make it that little bit quicker (or maybe not… but you never know…).
-ExecutionpPolicy: This is set to “bypass” in order to avoid the Windows server execution policy defaults that may block the script from running on the server.
-Command: Specifies the command text to execute as though it were typed at the PowerShell command prompt. In this case we are selecting to open the script file from the share that we created in Steps 1-2. You can also include any arguments for the script here if they are required.

For the Icon selection, when you click the ellipse you will get an Icon picker with  many icons to choose from. Choose the one that makes most sense for the script you are using.

Step 9: Now on the Front End server run “gpupdate /force” to get the new Group Policy pushed down to the server:

You should now get a new shortcut on the Desktop of the server that matches the one that you made in Group Policy. When you double click it you will see a command window for a second (if you chose the Window Style as Hidden like in this example) and then the Powershell GUI will be displayed:

It’s that easy! Now you can package your favourite scripts and centrally manage the version used by all users across all your servers.

The Wrap Up

I hope you found this post useful and that it allows you a better experience in using and managing your favourite Powershell scripts on your servers. Enjoy!

Read more →

Popular Posts