Thursday, 1 March 2018

Building an Edge Server Port Monitor with Azure Function Apps – Part 1

For this blog series I thought I would branch out a bit and take my Powershell scripting to the next level using Azure Function Apps. What on earth is an Azure Function App, I hear you asking? Well, come in closer around the camp fire and I’ll explain. An Azure Function App is a Serverless application platform. I know that sounds like an oxymoron… An application platform that is serverless! Well, yes, you are correct, there are in fact servers that are running these Function Apps in a nameless data centre somewhere. However, the reason that they are referred to as being “serverless” is that you never have to administer any part of the server hardware or software yourself. You simply write your code and paste it into the Azure Portal and then click the run button….  aannnndd bam! You end up with a very useful application that runs all day, every day, on hardware in a distant land that you never have think about. You just kick back and once a month pay the very reasonable rates offered by Azure. Brilliant!

As a means to teach myself about the Azure Functions platform I decided to give myself a challenge to design a useful application that could run using only Powershell as the programming language. The application I decided to design was an Skype for Business Edge Server port monitoring service. The idea of this application is that it would monitor all the important ports on any number of remote Edge servers and report to me if any of them went down. Due to the number of steps involved in doing this I will be breaking this into 3 separate blog posts.

For part 1 the requirements of the application are as follows:
  • Allow for multiple far end server ports to be monitored.
  • Allow for multiple far end servers to be monitored.
  • Allow for tests to be run on an ongoing basis at configurable intervals.
  • If a port is found to be inaccessible, then the application must email me with details of what is down.
In part 2 of the series I will expand on the application to do the following:
  • Allow for coalescing of emails so that multiple errors result in only one email being sent instead of many emails.
  • Allow for the application to have a memory so it can only send me an email after seeing a configurable number of errors. This is to guard against flapping type scenarios and only to update in the case of a fair dinkum outage.
  • In addition to sending an email when ports are down, it will also send an email to inform me that the ports have come back up - so I can rest easy in the knowledge that the server recovered without logging in to check. 
  • Use Azure Storage Tables to store state about the Edge servers current status.
In part 3 (Coming Soon) of the series I will expand the application to do even more:
  • Save all port test results to Azure Storage tables for later analysis.
  • Use Power Bi to connect to Azure Storage Tables and create nice graphs showing information about the Edge servers over a period of time.

By the end of the series there will be a feature-rich service that allows for the monitoring of remote servers and analyses results in a relatively comprehensive way. This should highlight how powerful Azure Function Apps can be!

Limitations of Powershell Functions


Upfront I should say that Azure Function Apps using Powershell is still considered an “Experimental” language. Whilst I was writing this application I found there are some limitations when coding in Powershell using Function Apps. This list is by no means complete - it’s just some interesting things I noticed:
  • I couldn’t call any commands that requested access to the networking stack. By this I mean commands to query the IP Address of the machine or ports in use, etc. This seems fair given that Function Apps run on shared machines and there is some level of abstraction between the code and the machine it’s running on.
  • I noticed that Invoke-WebRequest would give a warning that requested the use of Basic Parsing due to “The response content cannot be parsed because the Internet Explorer engine is not available, or Internet Explorer's first-launch configuration is not complete. Specify the UseBasicParsing parameter and try again.” This is not a limitation for the functionality in this application but may be something to keep in mind for your future apps.
  • I had a weird issue where function (ie. “function ConnectTCP”) returns would include all of the text from Write-Output commands that executed in the function. I’m not sure if this was a bug or a limitation... Something to look out for though.
  • You need to manually upload additional external powershell modules into the Azure backend. There is no basic “Install-Module” command that can grab code from the Powershell Gallery yet. This can also be problematic if the module attempts to access something that’s not supported by Azure Functions (for example access the networking stack like mentioned earlier).
  • “Write-Host” is not a supported output method like it is in server based Powershell. In order to get output from your script you need to use “Write-Output” which will be written to the Function App log.
  • When sending out port queries I tried to also specify the source port being used, however, it appears that the source port gets NATed on the way out of Azure. So the source port will be random in this case.

Creating the Function App


 Step 1
Open up the Azure Portal and Select “App Services” from the left menu. Then select the “Add” button:



Step 2
Select “Function App” as the type of service app that you would like to create:



Step 3
Click the create button:




Step 4
Fill in the details of the function application. The important parts here are to give your app a unique name, select Windows as the OS and select a Location nearest the servers you would like to be testing.




Step 5
You will need to wait a few minutes for the Function App to be provisioned for you. During this time you will see a “Deploying Function App” icon on the dashboard:



Step 6
Once the Function App has finished deploying, open the app to the Overview tab. Then select “Application settings”:



Step 7
In order for your application to output the correct time information in emails, you need to set the timezone within the “Application settings” to your local timezone. To do this add a row in the “Application settings” called “WEBSITE_TIME_ZONE” and then enter the name of the timezone (eg. “AUS Eastern Standard Time”). You can get a full list of timezones from here: https://msdn.microsoft.com/en-us/library/gg154758.aspx



Don’t forget to click the save button on the Application settings page after making the change:



Step 8
In the main page of the Function App select the “Functions” tab on the left-hand tree. Then click the “New function” button:



Step 9
You will now be presented with a screen that allows you to select the type of Function App that you would like to create. In order to be able to create a Powershell based Function App you need to click the “Experimental Language Support” switch in the top right corner of the screen:



Step 10
Once “Experimental Language Support” has been selected you can choose to create a “Timer trigger” app using Powershell as the language:



Step 11
The timer trigger type of application uses a CRON type format for representing when the application will execute. You will be presented with a dialog that allows you to enter the “Name” and “Schedule” for your application to run. The schedule expression is a CRON expression that includes 6 fields. These are:

{second} {minute} {hour} {day} {month} {day of the week}

Note: This is slightly different to CRON that is used on Linux that doesn’t have the seconds value. You need to be careful when borrowing CRON syntax off the Internet. For more information on the CRON format refer to this page: https://docs.microsoft.com/en-us/azure/azure-functions/functions-bindings-timer



Note: The important thing to know about this CRON Schedule is that the “*/5” means to run once every 5 minutes.

Step 12
Now that you have created your Trigger Timer, it will appear under the Functions tree in the left side of the Function App. When you select the trigger timer it will open up a code window that is pre-filled with a single “Write-Output” statement. This is the window in which you will be pasting in the Powershell code. You will also see on the right hand side the actual Powershell file called “run.ps1” and a function.json manifest file. At the bottom of the screen there is a Logs window where all the “Write-Output” logging will be sent to. Note that Function Apps use Write-Output instead of Write-Host like you see in most Powershell script running on servers.




Step 13 - Sign up for Mailjet
The script uses a web service called Mailjet in order to send emails. In order for the Function Application to send the email it needs to send a REST call out to Mailjet with the correct Account Keys in it. The free level of Mailjet lets you send up to 6000 emails per month, which is plenty for this kind of scenario.

After signing up for the Mailjet web site go to the following location to get your API username and password:

My Account > REST API > Master API Key & Sub API key management

In your Mailjet account you will also need to set up the mail account that you wish to be allowed to send emails: 

Accounts > Sender Addresses



Step 14
Insert the following Powershell script into your Function App code window (run.ps1) and make the edits required in Step 15:




Like this:




Step 15
Edit the script as necessary for your Mailjet account and Edge servers.

Enter your Mailjet API Key (Username) and Secret Key (Password) and paste them into the following section of the script. Also update the sender email address to your email account that is configured in the "Sender Addresses" in Mailjet and the recipent email address you want to send to:


#MAIL JET USERNAME/PASSWORD#######
$emailUsername = "kjh3k23h4kjhkj37573f8f020879dff7"     
$emailPassword = "9898f98fhdjkkdjh46cd418100075a3b"
#EMAIL ADDRESS TO SEND ERRORS FROM
$SENDEREMAIL = "YourRealEmailAddress@domain.com"
#EMAIL ADDRESS TO SEND ERRORS TO
$RECIPIENTEMAIL = "YourRealEmailAddress@domamin.com"
################################## 

Edit the Skype for Business Edge server details as required. These are entered as an array of hash tables. The sections highlighted in yellow can be changed. In this case the application is monitoring 2 Edge servers, one in Melbourne and one in Sydney.

Location
ServerName
ServerRole
DestinationPort
Protocol
Melbourne
147.70.50.10
Federation
5061
TCP
Melbourne
147.70.50.10
Access Edge
443
TCP
Melbourne
147.70.50.11
Web Conferencing
443
TCP
Melbourne
147.70.50.12
AV Edge
443
TCP
Sydney
147.70.60.20
Federation
5061
TCP
Sydney
147.70.60.20
Access Edge
443
TCP
Sydney
147.70.60.21
Web Conferencing
443
TCP
Sydney
147.70.60.22
AV Edge
443
TCP
Note: The script only supports testing TCP ports at this time.

$Records = @(@{"Location" = "Melbourne"; "ServerName" = "147.70.50.10"; "ServerRole" = "Federation"; "DestinationPort" = "5061"; "Protocol" = "TCP"})
$Records += @(@{"Location" = "Melbourne"; "ServerName" = "147.70.50.10"; "ServerRole" = "Access Edge"; "DestinationPort" = "443"; "Protocol" = "TCP"})
$Records += @(@{"Location" = "Melbourne"; "ServerName" = "147.70.50.11"; "ServerRole" = "Web Conferencing"; "DestinationPort" = "443"; "Protocol" = "TCP"})
$Records += @(@{"Location" = "Melbourne"; "ServerName" = "147.70.50.12"; "ServerRole" = "AV Edge"; "DestinationPort" = "443"; "Protocol" = "TCP"})

$Records += @(@{"Location" = "Sydney"; "ServerName" = "147.70.60.20"; "ServerRole" = "Federation"; "DestinationPort" = "5061"; "Protocol" = "TCP"})
$Records += @(@{"Location" = "Sydney"; "ServerName" = "147.70.60.20"; "ServerRole" = "Access Edge"; "DestinationPort" = "443"; "Protocol" = "TCP"})
$Records += @(@{"Location" = "Sydney"; "ServerName" = "147.70.60.21"; "ServerRole" = "Web Conferencing"; "DestinationPort" = "443"; "Protocol" = "TCP"})
$Records += @(@{"Location" = "Sydney"; "ServerName" = "147.70.60.22"; "ServerRole" = "AV Edge"; "DestinationPort" = "443"; "Protocol" = "TCP"})



Step 16
By default your Function App will be running at the CRON trigger interval. However, you can stop your Function App from running by switching off the trigger function in under the “Functions” tree item on the left hand side:



Step 17
Start receiving emails when your Edge servers are offline!




The Wrap Up


Well, this has been fun! Hasn’t it?! I hope that in addition to helping you monitor your edge servers, this has been informative and taught you some new skills that might help in the future when making your own Function Apps. Enjoy!




Read more →

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 5.4.4.1156. 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

Troubleshooting


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@10.22.2.11:33207;transport=tls;ms-received-cid=781300 SIP/2.0
1205143558|sip  |0|00|    Record-Route: <sip:SFB001.sfbdomain.com:5061;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 10.20.1.223:5061;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="SFB001.sfbdomain.com", 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 10.22.0.22:42727;branch=z9hG4bK1d5487849DAF07;ms-received-port=42727;ms-received-cid=77D300
1205143558|sip  |0|00|    P-Asserted-Identity: "Terry Adams"<sip:Terry.Adams@sfbdomain.com>,<tel:+61266591007;ext=1007>
1205143558|sip  |0|00|    From: "Terry Adams" <sip:Terry.Adams@sfbdomain.com>;tag=5C30CCBE-7E228105;epid=64167f23b38c
1205143558|sip  |0|00|    To: <sip:+61266591007@sfbdomain.com;user=phone>;epid=00907a0f09d8
1205143558|sip  |0|00|    CSeq: 1 INVITE
1205143558|sip  |0|00|    Call-ID: 0888c5534fafd0fc37bc94f7a523b38c
1205143558|sip  |0|00|    Contact: <sip:Terry.Adams@sfbdomain.com;opaque=user:epid:F5iF87H531yKmJ1oYYBMjwAA;gruu>
1205143558|sip  |0|00|    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
1205143558|sip  |0|00|    User-Agent: Polycom/5.6.0.17325 PolycomVVX-VVX_311-UA/5.6.0.17325_64167f23b38c
1205143558|sip  |0|00|    Accept-Language: en
1205143558|sip  |0|00|    ms-subnet: 10.22.0.0
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: <sip:Terry.Adams@sfbdomain.com>;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 10.22.0.22
1205143558|sip  |0|00|    s=Polycom IP Phone
1205143558|sip  |0|00|    c=IN IP4 10.22.0.22
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 10.22.0.22 5350 typ host
1205143558|sip  |0|00|    a=candidate:1 2 UDP 2130706430 10.22.0.22 5351 typ host
1205143558|sip  |0|00|    a=candidate:2 1 TCP-ACT 1684733951 10.22.0.22 5350 typ srflx raddr 10.22.0.22 rport 5350
1205143558|sip  |0|00|    a=candidate:2 2 TCP-ACT 1684733950 10.22.0.22 5350 typ srflx raddr 10.22.0.22 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' <+61266591007@sfbdomain.com:0>
1205143558|sip  |2|00|CStkDialog::CStkDialog SetAddressLocal Config 'Terry Adams' <Terry.Adams@sfbdomain.com:0>
1205143558|sip  |2|00|CStkDialog::CStkDialog TAG 'B640E4F5-9C530CE' generated
1205143558|sip  |2|00|CStkDialog::CStkDialog local addr 'Terry Adams' <+61266591007@sfbdomain.com:0> 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><SFB001.sfbdomain.com><0888c5534fafd0fc37bc94f7a523b38c><1><INVITE><sip:Terry.Adams@sfbdomain.com><5C30CCBE-7E228105><sip:+61266591007@sfbdomain.com;user=phone><B640E4F5-9C530CE><sip:Terry.Adams@sfbdomain.com><tel:+61266591007;ext=1007><><100>
1205143558|sip  |1|00|doDnsListLookup(tls): doDnsSrvLookupForARecordList for '10.20.1.223' port 5061 returned 1 results
1205143558|sip  |1|00|doDnsListLookup(tls): result 0 host '' IP '10.20.1.223' port 5061 isInBound 0
1205143558|sip  |1|00|CTcp::Send(TLS) entry for address 10.20.1.223 port 5061 can Connect 0 canFailOver 1
1205143558|sip  |0|00|>>> Data Send TLS 10.20.1.223:5061
1205143558|sip  |0|00|    SIP/2.0 100 Trying
1205143558|sip  |0|00|    Via: SIP/2.0/TLS 10.20.1.223:5061;branch=z9hG4bK8BA0D60F.E19C5E6D7DAA886D;branched=TRUE;ms-internal-info="dgFJqKHJ0AXHZY0sy2IaYnenMPK5auGe9rVA0q4_Ro3qxtXpzhVO8OYQAA"
1205143558|sip  |0|00|    Via: SIP/2.0/TLS 10.22.0.22:42727;branch=z9hG4bK1d5487849DAF07;ms-received-port=42727;ms-received-cid=77D300
1205143558|sip  |0|00|    From: "Terry Adams" <sip:Terry.Adams@sfbdomain.com>;tag=5C30CCBE-7E228105;epid=64167f23b38c
1205143558|sip  |0|00|    To: "Terry Adams" <sip:+61266591007@sfbdomain.com;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: <sip:Terry.Adams@sfbdomain.com;opaque=user:epid:x5jsdoUew1a9jiDyam965gAA;gruu>
1205143558|sip  |0|00|    Record-Route: <sip:SFB001.sfbdomain.com:5061;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/5.4.4.1156
1205143558|sip  |0|00|    Accept-Language: en
1205143558|sip  |0|00|    P-Preferred-Identity: "Terry Adams" <sip:Terry.Adams@sfbdomain.com>,<tel:+61266591007;ext=1007>
1205143558|sip  |0|00|    Authorization: TLS-DSK qop="auth", realm="SIP Communications Service", opaque="4E02C6ED", crand="D0E0949F", cnum="11", targetname="SFB001.sfbdomain.com", 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 10.22.0.22
1205143558|ice  |0|00|s=Polycom IP Phone
1205143558|ice  |0|00|c=IN IP4 10.22.0.22
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 10.22.0.22 5350 typ host
1205143558|ice  |0|00|a=candidate:1 2 UDP 2130706430 10.22.0.22 5351 typ host
1205143558|ice  |0|00|a=candidate:2 1 TCP-ACT 1684733951 10.22.0.22 5350 typ srflx raddr 10.22.0.22 rport 5350
1205143558|ice  |0|00|a=candidate:2 2 TCP-ACT 1684733950 10.22.0.22 5350 typ srflx raddr 10.22.0.22 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 software forked from the same original base code) is to configure the baseProfile setting to make it run in "Lync" mode. Lync mode 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, to try and make a comparison I used a Polycom VVX running 5.6 firmware (because it was easier to get access to the settings than Spectralink) as a comparison point to see what settings the Lync profile changed in the config:

Lync Base Profile settings (in comparison to Generic mode):
call.defaultTransferType="Blind"
call.enableOnNotRegistered="0"
callLists.collapseDuplicates="0"
callLists.logConsultationCalls="1"
device.baseProfile="Lync"
dialplan.1.applyToCallListDial="0"
dialplan.1.applyToDirectoryDial="1"
dialplan.1.applyToForward="1"
dialplan.1.conflictMatchHandling="1"
dialplan.1.digitmap="x.T"
dialplan.1.digitmap.timeOut="4"
dialplan.1.impossibleMatchHandling="3"
dialplan.1.lyncDigitmap.timeOut="4"
dialplan.applyToDirectoryDial="1"
dialplan.applyToForward="1"
dialplan.applyToPstnDialing="1"
dialplan.applyToRemoteDialing="1"
dialplan.conflictMatchHandling="1"
dialplan.digitmap=""
dialplan.impossibleMatchHandling="3"
dialplan.routing.emergency.1.description=""
dialplan.routing.emergency.1.value=""
dialplan.TranslationInAutoComp="1"
dialplan.userDial.timeOut="4"
feature.btoe.enabled="1"
feature.deviceLock.enable="1"
feature.EWSAutodiscover.enabled="1"
feature.exchangeCalendar.enabled="1"
feature.exchangeCallLog.enabled="1"
feature.exchangeContacts.enabled="1"
feature.exchangeVoiceMail.enabled="1"
feature.logUpload.enabled="1"
feature.lync.abs.enabled="1"
feature.LyncCCCP2010AudioWorkaround.enabled="1"
feature.lyncSafeTransfer.enabled="1"
feature.messaging.enabled="1"
feature.moh.enabled="1"
feature.presence.enabled="1"
locInfo.source="MS_E911_LIS"
reg.1.applyServerDigitMapLocally="1"
reg.1.auth.useLoginCredentials="1"
reg.1.auth.usePinCredentials="1"
reg.1.offerFullCodecListUponResume="0"
reg.1.server.1.registerRetry.baseTimeOut="10"
reg.1.server.1.registerRetry.maxTimeOut="180"
reg.1.server.1.specialInterop="lync2010"
reg.1.server.1.transport="TLS"
reg.1.serverFeatureControl.signalingMethod="serviceMsForwardContact"
reg.1.useTelUriAsLineLabel="0"
roaming_buddies.reg="1"
sec.srtp.holdWithNewKey="0"
sec.srtp.key.lifetime="2^31"
sec.srtp.mki.enabled="1"
sec.srtp.mki.length="1"
sec.srtp.mki.startSessionAtOne="1"
sec.srtp.resumeWithNewKey="0"
sec.TLS.profileSelection.SIP="ApplicationProfile1"
server.log.setting.enabled="1"
softkey.feature.MeetNow="1"
softkey.feature.simplifiedSignIn="1"
tcpIpApp.ice.mode="MSOCS"
tcpIpApp.keepalive.tcp.sip.tls.enable="1"
tcpIpApp.port.rtp.videoPortRange.enable="1"
tcpIpApp.sntp.address="time.windows.com"
tone.dtmf.rfc2833Payload="101"
up.numOfDisplayColumns="2"
up.oneTouchDirectory="1"
up.oneTouchVoiceMail="1"
video.iFrame.delay="2"
video.iFrame.onPacketLoss="1"
voice.codecPref.G7221.24kbps="5"
voice.codecPref.G7221.32kbps="0"
voice.qualityMonitoring.rtcpxr.enable="1"
voIpProt.SIP.allowTransferOnProceeding="0"
voIpProt.SIP.considerTlsDnsEntriesOnly="1"
voIpProt.SIP.failoverOn503Response="0"
voIpProt.SIP.header.diversion.enable="1"
voIpProt.SIP.IM.autoAnswerDelay="40"
voIpProt.SIP.mtls.enable="0"
voIpProt.SIP.serverFeatureControl.cf="1"
voIpProt.SIP.serverFeatureControl.dnd="1"
voIpProt.SIP.serverFeatureControl.localProcessing.cf="0"
voIpProt.SIP.serverFeatureControl.localProcessing.dnd="0"

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 tcpIpApp.ice.mode="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 tcpIpApp.ice.mode setting to “disabled”. In a config file this might look something like this:

<!-- If there is an Edge then tcpIpApp.ice.mode="MSOCS" if there is no Edge then tcpIpApp.ice.mode="disabled" -->
<LyncBaseProfile
device.baseProfile.set="1"
device.baseProfile="Lync"
tcpIpApp.ice.mode="disabled"             
> 
</LyncBaseProfile>


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 →

Popular Posts