Thursday, August 3, 2017

Tips and Tricks / Unofficial Party and Sweepstakes list for Microsoft Ignite 2017

Registration

Every year there has been a Microsoft Ignite, it has sold out. Don't delay registration. The Microsoft Ignite 2017 website already indicates there are limited passes available.

At the time of writing this blog, there are only a couple of conference discounted hotels with rooms available. If you find that those hotels don't work for you, you might take a look at Airbnb, there are still a number of options around the Orange County Convention Center available.

Taking Notes and Recording during Sessions

Microsoft does provide a video with the slide deck for most of the sessions that can then be later referenced, if you can't quite remember that one little detail.

If you are really bent on recording sessions, I'd suggest using a Jabra Speak 410/510 (or similar devce) with OneNote. If you have the Bluetooth version you might even get permission to put it up near where the speaker is speaking. Using OneNote in this manner, you can take notes and they will be tied to the audio so you can go back and listen to the audio at that moment you made the entry in OneNote. I cover this technique in my Lync Masters report.

Clothing

I'm no style expert... so don't expect any style tips from me. The expected temp in Orlando for September is around 90 Fahrenheit (32C). To me... being from Colorado that is rather hot. Some people from further down south will likely disagree. My point is you know yourself better than I do. Bring appropriate clothes and be prepared for rain.

Shoes are really, really, really important. Did I mention REALLY important? Even if you have a car, you will do an enormous amount of walking just in the convention center. If you plan to visit any theme parks like Disney/Universal while you are there (Microsoft Attendee party is at Universal) they can be quite large as well. Please bring your best walking shoes... you'll thank me later. If you want to really be prepared, take a look at what some die hard Disney fans prepare for.

Dress code... In all the searches I did, the only places you'll encounter a dress code are Night Clubs and upscale restaurants. Once I know party venues, I'll try to dig that up and post here if I find something.

Networking

Not the wired kind of networking... but the people kind of networking. You know... like LinkedIn... but in person. For me, networking with others is by far the most important part of going to a conference. There always seems to be a way to get the "information" shared at a conference before or after, but you can't replace that face to face interaction, especially with people that understand your tech language.

Use the time wisely to meet people and make connections. Many of the connections I made at conferences like this have come in handy when I have questions I can't answer on my own.

If you are looking for me... just ping me on Twitter @ucomsgeek . Feel free to follow me too, because I'll be trying to feverishly be more social than Matt Landis (which is impossible) ;-)

It's always a good idea to bring your Business Cards to hand out and there are usually a number of drawings that you'll probably want to enter (some right on the spot during a session). If I come across any really good ones, I'll post them here.

Sweepstakes / Awards

Cloud Burst Sweepstakes by Turbonomic - Do you want to attend Microsoft Ignite® in Orlando, Florida but your company won’t pay for the conference passes? Enter the Turbonomic® Cloud Burst Sweepstakes to earn your chance to win a full conference pass and unlock access to other monthly cloud prizes – including our grand prize worth $4,950.00! Microsoft Ignite drawing takes place on September 1st!       

$300 DINNER AT FOGO DE CHÃO! by Nigel Frank International -
Microsoft Ignite Orlando 2017 is fast approaching, and to celebrate Nigel Frank are offering attendees the chance to win a $300 voucher for Fogo de Chão. Nigel Frank are thrilled to be Silver Sponsors at Ignite 2017, and we can’t wait to see you there. To make one lucky attendee’s Ignite experience even more incredible, we’re giving away $300 to spend at fine dining, full service Brazilian steakhouse Fogo de Chão.

2017 Microsoft Ignite Pass Giveaway by Adaptiva - Participants enter the Microsoft Ignite 2017 free pass contest by completing the Adaptiva online entry form in addition to liking or following us on one of the following networks: Facebook, Twitter or LinkedIn. By completing the Adaptiva online entry form and following at least one of our social sites, participants will automatically be entered into the contest drawing.

SAPIEN Technologies, Inc., developer of PowerShell Studio and PrimalScript, will award a full conference pass for Microsoft Ignite 2017 to a woman in the Windows PowerShell community, or any individual who is new to IT or devops within the last two years, and works with Windows PowerShell in some capacity.  SAPIEN encourages other Ignite vendors to match this award and support the attendance of technical women and new talent at IT and devop conferences. See details on the link!

GSX Super Hero Giveaway - Got complaints with Office 365 performance? Be a Super Hero, Fight Against Poor End-User Experience Today! GSX is the Office 365 End-User Experience Monitoring Company. Measuring and improving service delivery within complex hybrid and cloud scenarios
will make you a super hero. With SuperPower, Come SuperPrizes! Enter to win prizes totalling $2,000!

Metalogix Microsoft Ignite 2017 Conference Pass Giveaway - We're giving away two free passes to Microsoft Ignite 2017! For a chance to win a Microsoft Ignite Full Conference Pass, simply fill out the entry form by Wednesday, August 23, 2017 to be automatically placed in the raffle. Winners will be selected on Thursday, August 24, 2017.


Parties

There are a always a number of parties being thrown during Microsoft Ignite. Some by Microsoft you can find easily in the agenda on the Microsoft Ignite 2017 site. There are other extra-curricular parties that are put on by different vendors and groups. At the time of writing this blog, it is still a bit early for vendor announced parties. When they are announced I will only list the ones I know are public so far. If you are a vendor and would like to be listed on this blog, please reach out to me via @ucomsgeek

Saturday

None yet.

Sunday

None yet.

Monday

Microsoft Ignite Welcome Reception

Tuesday

Azure Stack Customer Meetup - If you are familiar with hybrid clouds and are interested in shaping the future of Microsoft Azure Stack by interfacing with the Azure Stack engineering team - this meetup is for you! The event will take place on Tuesday 26th September in the evening at a hotel location near the event center. An email invite detailing the exact details will be sent closer to the event. To receive an invite it is a pre-requisite that you have successfully deployed the Azure Stack Development Kit . By Ignite will you have completed a successful deployment? (There will be a test!!)

Veeam's Annual Ignite Party 2017 - by Veeam - Join us Tuesday night at Dewey’s Indoor Golf & Sports Grill for Veeam's Annual Microsoft Ignite Party! Enjoy a night of music, interactive entertainment and drinks on Veeam! A Microsoft Ignite 2017 badge is required for entrance. If you are bringing a guest, please mark that on your registration and EventBrite will send you two separate tickets. Register & bring your Eventbrite ticket to show at the door for entry in a FASTER line!*Occupancy is limited, so admittance will be granted on a first come, first serve basis.

SolarWinds Microsoft Ignite 2017 Meetup - by SolarWinds - Both residents in the Orlando area and Microsoft Ignite attendees are encouraged to register and attend this SolarWinds User Group. See details below! Beer, wine and non-alcoholic refreshments (along with a Buffet it looks like) will be served throughout the evening along with talks and demos!

Wednesday

eNow has done some pretty epic parties in the past and the Microsoft Ignite "//scheduledMaintenance"... is likely to be something you won't want to miss. Tired of your servers receiving all the attention? Need your own Scheduled Maintenance? This might be the place for you... space is limited and like the other parties... spots might go quickly.

MetaFest 2017 by Metalogix - Join us for our annual MetaFest on Wednesday, September 27, at Mango’s Tropical Café! MetaFest will feature an amazing lineup of live bands, dance performances, and an abundance of food and drinks. It’s one party you definitely won’t want to miss! Passes are limited, so register now to reserve your spot! It’s guaranteed to be a great time.

Thursday

Microsoft Ignite Attendee Celebration - Get ready for one of the biggest parties Microsoft has ever thrown—we’ve reserved both Universal Orlando Resort™ theme parks for Microsoft Ignite attendees only. From 7:30pm to 12:00am on Thursday, 9/28, you’ll have unlimited access to immersive, award-winning rides and attractions.


Transportation

Most people will be flying in, and I'm sure a great number will be new to Orlando. If you plan to just stick to the Agenda and not do anything extra, you can likely get away with not having a rental car. But if you plan on exploring Orlando, or going to any Vendor parties, you might want to have one available or at least be prepared to do a Taxi/Uber. To use Uber, you'll want to download their app to your device.

Getting from the Airport to the Hotel without a rental car is as simple as getting a Taxi, Super Shuttle, or use Uber.

Super Shuttle will cost about $18 each way (I used the Orange County Convention Center as reference). I've used Super Shuttle in many cities and they are very efficient and professional. You can usually find them close to the rental car counters... but I highly recommend having a reservation ahead of time with so many people traveling to Orlando the same time you are.

The Uber method from the Airport to your Hotel, you should be aware that there are specific instructions you need to follow in order to find your ride successfully. Cost will probably be in the $23-28 range but you won't be sharing with others (I used the Orange County Convention Center as reference).

The Taxi method from the Airport is the most common. There should be signs for Ground Transportation at the airport that takes you to the Taxi area. Cost will be in the $40-65 range depending on traffic (I used the Orange County Convention Center as reference).


Keep checking back... this blog post will be updated as more information comes out!



Wednesday, July 5, 2017

PowerShell Script to Backup AudioCodes Gateways (updated for 7.0 and 7.2)

A few years ago I created a PowerShell script that would backup AudioCodes gateways. It's gone through several iterations as AudioCodes has changed how they do authentication. Now with 7.0 and 7.2 out in the wild, I again found that I needed to update this script again to support the changes to the user interface.

Fortunately I've got great friends and Mitch Steiner had been messing with AudioCodes new API to pull some interesting metrics for our T2M Cloud and he let me know that he stumbled upon a way to pull the .ini configuration using the REST API. The new REST API reduced the amount of code to do a backup down to literally one line. Now obviously it would be cool to have a script that detected which AudioCodes version it was connected to, so it is more than just one line in the script below. I also found a way to "Burn" the configuration on 7.0 and 7.2 using the API. So that is part of the script and executes just before backup.

Couple of key items before you run the script below.
  • If you are running on a Windows 7 or other workstation you'll need to set your PowerShell Execution Policy.
  • Next you will need to install a package called cURL that is a command line tool for interacting with web pages. It is required to work with the Forms Based Auth that audiocodes uses. I used a new tool to install it called Chocolatey, which is the equivalent of RPM packages for Windows. Here is the page for cURL (http://chocolatey.org/packages/curl) and here is the main page for Chocolatey (http://chocolatey.org/)
  • PowerShell has an alias for curl that you'll need to remove. The command is Remove-Item alias:curl 
Without further adieu... I give you the AudioCodes backup script that will backup any 6.4, 6.6, 6.8, 7.0, or 7.2 AudioCodes Gateway/SBC. 

# Script to Backup AudioCodes Gateways# Created By Jonathan McKinney (blog.ucomsgeek.com)# Disclaimer: You running this script means you won't blame Jonathan McKinney or his employer if this breaks your stuff. This script is provided AS IS without warranty of any kind.

# User Modifiable Variables
$username = "Admin"
$password = "Admin"
$address = "m4000.ucomsgeek.com"
$backuppath = "c:\scripts\backups\"


# Variable Initialization
$filename = $null
$statuscodeeval = $null


#Function to detect if Forms Auth is present
function DetectAuthType ($ad)
{
    $loginurl = $null
    
    $loginurl = "http://" + $ad + "/api"
    $statuscode = curl -o null.txt $loginurl -w '%{http_code}'
    If ($statuscode -eq "404")
    {
        $loginurl = "http://" + $ad + "/"
        $statuscode = curl -o null.txt $loginurl -w '%{http_code}'
        Write-host `r`n "Status Code " $statuscode
        If ($statuscode -eq "401")
        {
            $statuscodeeval = "basic"
        }
        ElseIf ($statuscode -eq "203")
        {
            $statuscodeeval = "forms"
        }
        Else
        {
            $statuscodeeval = "neither"
        }
    }
    ElseIf ($statuscode -eq "401")
        {
            $statuscodeeval = "api"
        }
    Return $statuscodeeval
    Remove-Item null.txt
}


 # Function to Authenticate with Forms Auth
function AuthenticateForms ($un, $pw, $ad)
{
     $login1sregex = "\<s\>(\d*)\<\/s\>"
     $login1rregex = "\<r\>(.*)\<\/r\>"
     $a1 = $null
     $loginusername = $null
     $loginurl = $null
     $login1webpage = $null
     $login1spattern = $null
     $login1rpattern = $null
     $hashByteArray1 = $null
     $hashByteArray2 = $null
     $passwordhash = $null
     $resultwebpage = $null
     $formsbasedauth = $null
     
     Write-Host `r`n 'Forms Authentication' `r`n
     $login1username = "c1=" + $un
     $loginurl = "http://" + $ad + "/UE/Login"
     $login1webpage = curl $loginurl --data-urlencode "t=1" `
                                     --data-urlencode "c0=0" `
                                     --data-urlencode $login1username `
                                     --header "X-Requested-With: XMLHttpRequest" `
                                     -c cookiejar.txt `
                                     --header "Cookie: aclogname=; C2=ct" `
                                     --user-agent "Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0) like Gecko"

      $login1spattern = $login1webpage -split "`n" | Select-String -pattern $login1sregex -Allmatches | % { $_.Matches | % { $_.groups[1].Value } }

      $login1spattern = "s=" + $login1spattern
     $login1rpattern = $login1webpage -split "`n" | Select-String -pattern $login1rregex -Allmatches | % { $_.Matches | % { $_.groups[1].Value } }

      $cryptoServiceProvider = [System.Security.Cryptography.SHA256CryptoServiceProvider]
     $hashAlgorithm = New-Object $cryptoServiceProvider
     $hashByteArray1 = $hashAlgorithm.ComputeHash($([Char[]]$password))
     foreach ($byte in $hashByteArray1)
     {
          $a1 += "{0:x2}" -f $byte
     }
     
     $a2 = $username + ":" + $login1rpattern + ":" + $a1
     $hashByteArray2 = $hashAlgorithm.ComputeHash($([Char[]]$a2))

      foreach ($byte in $hashByteArray2)
     {
          $passwordhash += "{0:x2}" -f $byte
     }
     
     $passwordhash = "c1=" + $passwordhash
     $resultwebpage = curl $loginurl --data-urlencode "t=1" `
                                     --data-urlencode $login1spattern `
                                     --data-urlencode "c0=1" `
                                     --data-urlencode $passwordhash `
                                     --header "X-Requested-With: XMLHttpRequest" `
                                     -c cookiejar.txt `
                                     --header "Cookie: aclogname=; C2=ct" `
                                     --user-agent "Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0) like Gecko"
}


# Function to Backup Gateway WITHOUT Forms Auth
function BackupBasic ($un, $pw, $ad, $path)
{
     $regex = "BOARD.*\.ini"
     $webclient = $null
     $configurl = $null
     $backupurl = $null
     $webpage = $null
     $pattern = $null
     $backupfilename = $null

     $webclient = new-object System.Net.WebClient
     $webclient.Credentials = New-Object System.Net.NetworkCredential($un, $pw)

     Write-Host `r`n 'Detecting .ini name' `r`n
     $configurl = "http://" + $ad + "/ConfigurationFile"
     $webpage = $webclient.DownloadString($configurl)
     $pattern = $webpage -split "`n" | Select-String -pattern $regex -Allmatches | % { $_.Matches | % { $_.Value } }
     Write-Host `r`n 'Detected Board Filename ' $pattern

      Write-Host `r`n 'Backing up ' $ad `r`n
     $backupurl = "http://" + $ad + "/FS/" + $pattern
     $backupfilename = $path + $pattern
     $webclient.DownloadFile($backupurl,$backupfilename)
     Write-Host `r
}


# Function to Detect the Backup Filename with Forms Auth for the Audiocodes Configuration File
function DetectFilenameForms ($ad)
{
     $fnregex = "BOARD.*\.ini"
     $configurl = $null
     $fnpat = $null
     $configwebpage = $null

     Write-Host `r`n 'Detecting .ini name' `r`n
     $configurl = "http://" + $ad + "/ConfigurationFile"
     $configwebpage = curl $configurl -b cookiejar.txt
     $fnpat = $configwebpage -split "`n" | Select-String -pattern $fnregex -Allmatches | % { $_.Matches | % { $_.Value } }

     Write-Host `r`n 'Detected Board Filename ' $fnpat
     return $fnpat
}


# Function to Backup Gateway with Forms Auth
function BackupGatewayForms ($ad, $path, $fn)
{
     $backupurl = $null
     $backupfilename = $null
     
     Write-Host `r`n 'Backing up ' $ad `r`n
     $backupurl = "http://" + $ad + "/FS/" + $fn
     $backupfilename = $path + $fn
     curl -o $backupfilename $backupurl -b cookiejar.txt
     Write-Host `r
}

function BackupGatewayAPI ($un, $pw, $ad, $path)
{
    $backupurlsc = $null
    $backupurlini = $null
    $backupfilename = $null
    $securepw = $null
    $cred = $null

    $backupurlsc = "http://" + $ad + "/api/v1/actions/saveConfiguration"
    $backupurlini = "http://" + $ad + "/api/v1/files/ini"
    $addressfilename = $ad.Replace(“.”,”-”)
    $backupfilename = $path + "BOARD.ini"
    Write-Host $backupfilename
    $securepw = ConvertTo-SecureString -String $pw -AsPlainText -Force
    $cred = new-object System.Management.Automation.PSCredential ($un, $securepw)
    Invoke-RestMethod $backupurlsc -Method post -Credential $cred
    Invoke-RestMethod $backupurlini -Method get -Credential $cred -OutFile $backupfilename -verbose
    
    Write-Host  `r
}


# Function to Logoff Audiocodes with Forms Auth after finishing work
function LogoffForms ($ad)
{
     $logoffurl = $null
     $logoffwebpage = $null
     
     $logoffurl = "http://" + $ad + "/PressLogOff"
     $logoffwebpage = curl $logoffurl -b cookiejar.txt
     Remove-Item cookiejar.txt
}


# Main Script

 $formsbasedauth = DetectAuthType $address

 if ($formsbasedauth -eq "forms")
{
     AuthenticateForms $username $password $address
     $filename = DetectFilenameForms $address
     BackupGatewayForms $address $backuppath $filename
     LogoffForms $address
}
ElseIf ($formsbasedauth -eq "basic")
{
     BackupBasic $username $password $address $backuppath
}
ElseIf ($formsbasedauth -eq "api")
{
     BackupGatewayAPI $username $password $address $backuppath
}
Else
{
     Write-Host "Something went really wrong... couldn't detect Authentication type... Might I suggest Wireshark"
}

Friday, June 30, 2017

Polycom VVX 5.5.2 QoE Reports

It's no secret that I've been hard on Polycom VVX phones in the past (especially with the lack of local Normalization rules processing). But I will say with the version 5.5 release they have come a long way on addressing some key issues and making the phone a decent replacement for the old Aries sets (Polycom CX Series).

Today, I'm excited to share that I've verified that Polycom VVX 5.5.2 now produces QoE reports just like the SfB/Lync PC Client. This means if you have Lync, Skype for Business on-premises or Skype for Business CloudPBX, they all will start showing reports for VVX phones.

If you look at the release notes, QoE Reporting actually was in 5.5.1 but at least for my customer there was a problem with that release that prevented deployment. My guess is there are a lot of people out there that haven't updated to 5.5 because what they have just works.

I am super excited about QoE reporting for VVX because it was a huge hole that was missing in the story. It's really hard to explain to customers that they have these great phones, but there is no way to see how they are performing on a call-by-call basis with what SfB provides out of the box (Polycom has some solutions of course). 

This also means that other tools like EventZero, IR Prognosis, Nectar, etc can now have more complete reporting on these devices.

Here are a couple of screen shots of how the information looks in Monitoring Server for VVX phones. The VVX was the Calee side of the call in these examples.


One of the things I noticed right off the bat is that the Codec report is G711Mu instead of the typical PCMU for G.711 Mulaw. It's minor... but it is a diff. 

On the device metrics, it seems on par with other devices providing good information on how the audio performance of the device is doing.

Anyway... I hope you are already downloading the firmware so you can go see for yourself what you've been missing... Later


Wednesday, November 2, 2016

How to enable Microsoft Teams Preview

So you are all revved up and ready to use Microsoft Teams... but you can't find it in your Admin Portal on Office365. Well I got you covered and its real simple.

All you need to do is go into your Admin Portal and navigate to "Services". Under there click "Services & add-in"



Then click "Microsoft Teams" and flip the on switch. Additionally you can get more granular about the features you want your users to have access to.



To start... Navigate to https://teams.microsoft.com/ and create your first team.

Enjoy!

Tuesday, June 28, 2016

Decrypting HTTPS web traffic without private key

So anyone who knows me... knows that I love Wireshark. Recently while preparing for a presentation at the Colorado UC User Group, I found out that my old reliable technique of decrypting HTTPS traffic using a private key, actually no longer works anymore since many of the modern servers and devices I work with use some form of Diffie Hellman cipher to setup the Encrypted connection. Why is this so... because Diffie Hellman type ciphers never actually transmit the "secret" on the wire like the old RSA based ciphers did. Here is a pretty good explanation of what happens in English.

So I went searching for alternatives and much like one of my favorite podcast from RadioLab revealed about magic tricks... The only secret in magic is that the secret must be ugly (said by Penn Jillette).

I present to you the fantastic and ugly secret of the SSLKEYLOGFILE environment variable.

So... what I stumbled upon and have been debating for over a month is a way in which you can decrypt HTTPS traffic without a man in the middle technique (Fiddler) or having the private key (old Wireshark method that is useless now). Instead, the browser does all the hard work and logs yours session key to a log file that is then easily referenced by Wireshark.

Say what?!

Let me repeat... your browser tells all your secrets and makes decrypting HTTPS traffic something that even sniveling grade school kid could do.

Before I go on... I truly hope that you will use this information for good and not evil. Because someone that is a bit creative could really wreak havoc on someone else's life without much effort. I'm telling you this, because I finally came to the conclusion that knowing this will make you able to defend yourself better.

The Ugly Secret


First off, this only works with Chrome and Firefox. Edge and Internet Explorer do not use this technique. My guess is that won't be a problem since most people seem to use Chrome these days. Start off by navigating to the "System" Control Panel applet. Select "Advanced system settings" from the links on the left.


A "System Properties" dialog box appears. Next select "Environment Variables"

When the "Environment Variables" dialog appears, Select "New" under "System variables".

 Yet another dialog box appears. The "Variable name" is "SSLKEYLOGFILE" and the value is a directory and filename of your desire. Please make note of this directory and filename for future use in the configuration of Wireshark. Click OK

View that the "SSLKEYLOGFILE" variable now appears in the "System variables" list with the correct path to the filename you specified.


Start up Chrome or Firefox and browse to a website with HTTPS capability. After doing so, you should see the log file you specified. Feel free to open it in Notepad if you want to see what is there. You'll be surprised as to how many entries appear in a short time.




Next start Wireshark (Download here if you don't have it). I'm using the Legacy UI in case you are wondering why yours might be different. Navigate to the Edit -> Preferences Menu.



Navigate to the "SSL" Protocol and enter the directory path and filename for the log file you specified in the Envrionment Variable under "(Pre)-Master-Secret log filename". Click OK


Capturing HTTPS Traffic


So now all this is setup, what does it all look like when you do a capture? Start your Wireshark capture and browse to a website that uses HTTPS. If you want to make it easier to view the traffic you can set your Display filter to "http" and hit Apply.


You know that decryption is happening by viewing the Decypted SSL portion at the bottom of the screen. If this is not there, then decryption is not happening and you either have a packet that is not encrypted or the reference to the log file is incorrect.



So there you have it. The ugly secret your browser has. I hope you didn't read this just before bedtime.




Wednesday, May 25, 2016

InboundRouting and tmx file madness... AGAIN

Oh hey! It's been awhile... okay... it's been WAAAAAY too long since I've posted a blog. I've had many blogs that I thought I should write, but having 5 kids, all with various activities in the spring, just kills the mood of blog writing in the evening.

So many moons ago I wrote about how the default.tmx file was corrupt and didn't produce any output and that it could be fixed by copying the default.tmx file from a directory under "Common Files".

Well same song... second verse. I recently found InboundRouting debug produces some output... just not all the goey goodness you'd expect when you are trying to see how calls are routing and all the decisions that are being made.

The Problem

The Lync Server 2013 Debugging Tools that are installed separately have sparse output for debug logs for after you click "View Log Files" for InboundRouting.

The easiest way you can verify this is by starting OCSLogger.exe and set a debug session for InboundRouting and set the "Level" to All and "Flags" to All Flags.


Start Logging and make a call from the PSTN in to your Lync Server 2013 system. When the call is completed hang up and click Stop Logging.

Click "View Log Files" and make sure "InboundRouting" is the only Log File selected. If you get output similar to this... Congratulations... you have reproduced the problem I saw.

TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecb (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=flags:clientflags(block)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecc (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=flags:clientflags(e911active)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecd (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=class:Secondary>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deece (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=privateLine>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecf (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed0 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=member:breakthrough>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed1 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=referred:breakthrough>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed2 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=member:add_voice>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed3 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=flags:clientflags(work_hours)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed4 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed5 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=flags:clientflags(team_ring)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed6 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=flags:clientflags(delegate_ring)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed7 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=dnd>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed8 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed9 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=flags:clientflags(forward_immediate)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deeda (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deedb (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[484752463]<group class='Registered' action='Replace' wait='0'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee9 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[484752463]<group class='StaticRegistered' action='Extend' wait='0'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deeed (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[484752463]<group class='Secondary' action='Extend' wait='0' criteria='registered'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef3 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[484752463]<group class='Secondary' action='NoRing' wait='0'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef7 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[484752463]<group class='Secondary' action='Extend' waitref='total' wait='15' criteria='flags:clientflags(simultaneous_ring)'>
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def20 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[484752463]<group class='Primary' action='Replace' wait='60' criteria='flags:clientflags(enablecf)'>
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def23 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[484752463]<group class='Primary' action='Replace' wait='60' criteria='umenabled'>
TL_VERBOSE(TF_COMPONENT) [1]11BC.0CA8::05/25/2016-16:32:17.647.001def5e (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[2153832770]<filter criteria=flags:clientflags(block)>=false
TL_VERBOSE(TF_COMPONENT) [1]11BC.0CA8::05/25/2016-16:32:17.647.001def5f (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[2153832770]<filter criteria=routingAppInvite>=false
TL_VERBOSE(TF_COMPONENT) [1]11BC.0CA8::05/25/2016-16:32:17.647.001def60 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[2153832770]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [1]11BC.0CA8::05/25/2016-16:32:17.647.001def61 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[2153832770]<group class='Registered' action='Replace' wait='0'>
TL_VERBOSE(TF_COMPONENT) [1]11BC.0CA8::05/25/2016-16:32:17.647.001def6b (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[2153832770]<group class='StaticRegistered' action='Extend'>
TL_VERBOSE(TF_COMPONENT) [1]11BC.19D4::05/25/2016-16:32:20.840.001def96 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3011151961]<filter criteria=umenabled>=false
TL_VERBOSE(TF_COMPONENT) [1]11BC.19D4::05/25/2016-16:32:20.840.001def97 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3011151961]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [1]11BC.19D4::05/25/2016-16:32:20.840.001def98 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[3011151961]<group class='Registered' action='Replace'>
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.762.001defb8 (InboundRouting,RoutingPresenceState.Parse:routingpresencestate.cs(35))[3994464144]XML that should contain user's dnd state is empty.
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defc6 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=routingAppInvite>=false
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defc7 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=flags:clientflags(block)>=false
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defc8 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=class:Secondary>=false
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defc9 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=privateLine>=false
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defca (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=flags:clientflags(work_hours)>=false
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defcb (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defcc (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=dnd>=false
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defcd (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=flags:clientflags(forward_immediate)>=false
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defce (InboundRouting,RoutingFilter.Execute:routingmodel.cs(145))[3994464144]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defcf (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[3994464144]<group class='Registered' action='Replace' wait='0'>
TL_VERBOSE(TF_COMPONENT) [0]11BC.182C::05/25/2016-16:32:35.763.001defd9 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(966))[3994464144]<group class='Secondary' action='Extend' waitref='total' wait='15' criteria='flags:clientflags(simultaneous_ring)'>




The correct output should look something like this... with a lot more details about what the routing is actually doing (note this is output from the same .etl file with numbers, names, and IPs to protect the innocent).

TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:31:46.395.001deeb6 (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(521))[484752463]OnInboundRequest() for someuser@ucomsgeek.com
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:31:46.395.001deeb7 (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(532))[484752463]routing instance=<routing xmlns="http://schemas.microsoft.com/02/2006/sip/routing" name="rtcdefault" version="2" minSupportedClientVersion="4.0.0.0"><preamble><flags name="clientflags" value=""></flags><wait name="total" seconds="20"></wait></preamble></routing>
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:31:46.395.001deeb8 (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(537))[484752463]dndStateXml=<state xmlns:xsi="
http://www.w3.org/2001/XMLSchema-instance" xmlns="http://schemas.microsoft.com/2006/09/sip/state" xsi:type="userState" manual="true"></state>
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:31:46.395.001deeb9 (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(538))[484752463]userPropertiesXml=<userProperties xmlns="
http://schemas.microsoft.com/2006/09/sip/categories">
<lines>
<line lineType="Uc">
tel:+13039973064;ext=89973064</line>
</lines>
<telephonyMode>
Uc</telephonyMode>
<l>
Roseville</l>
<st>
Mn</st>
<exumEnabled>
1</exumEnabled>
<exumURL>
EUM:someuser@ucomsgeek.com;voicemail-destination=default</exumURL>
</userProperties>
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:31:46.395.001deeba (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(539))[484752463]calendarDataXml=<calendarData xmlns="
http://schemas.microsoft.com/2006/09/sip/calendarData" mailboxID="someuser@ucomsgeek.com"><WorkingHours xmlns="http://schemas.microsoft.com/exchange/services/2006/types"><TimeZone><Bias>360</Bias><StandardTime><Bias>0</Bias><Time>02:00:00</Time><DayOrder>1</DayOrder><Month>11</Month><DayOfWeek>Sunday</DayOfWeek></StandardTime><DaylightTime><Bias>-60</Bias><Time>02:00:00</Time><DayOrder>2</DayOrder><Month>3</Month><DayOfWeek>Sunday</DayOfWeek></DaylightTime></TimeZone><WorkingPeriodArray><WorkingPeriod><DayOfWeek>Monday Tuesday Wednesday Thursday Friday</DayOfWeek><StartTimeInMinutes>480</StartTimeInMinutes><EndTimeInMinutes>1020</EndTimeInMinutes></WorkingPeriod></WorkingPeriodArray></WorkingHours></calendarData>
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:31:46.395.001deebb (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(540))[484752463]registeredEndpointCount=2
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:31:46.395.001deebc (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(541))[484752463]userIsDualMode=False
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deebd (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(616))[484752463]Not checking for LBR
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deebe (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(630))[484752463]Presence State is 0
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deebf (InboundRouting,UserProperties.Parse:exumuserproperties.cs(281))[484752463]ExumEnabled=1 ExumAddress='EUM:someuser@ucomsgeek.com;voicemail-destination=default'
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec0 (InboundRouting,InboundRouting.OnInboundInvite:inboundrouting.cs(697))[484752463]Preamble matched a known script name=rtcdefault version=2 for user
someuser@ucomsgeek.com
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec1 (InboundRouting,InboundRoutingContext.InitializeAttributesFromRequest:inboundroutingcontext.cs(1496))[484752463]Found 'max-forwards' header with value 70.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec2 (InboundRouting,InboundRoutingContext.InitializeAttributesFromRequest:inboundroutingcontext.cs(1593))[484752463]Found Multipart content-type: multipart/alternative; boundary=s704xhVieLenjcRabw4IMHITzZm6d4Lk
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec3 (InboundRouting,InboundRoutingContext.InitializeAttributesFromRequest:inboundroutingcontext.cs(1644))[484752463]Request Sensitivity: Normal
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec4 (InboundRouting,InboundRoutingContext.InitializeAttributesFromRequest:inboundroutingcontext.cs(1646))[484752463]Request Target Class: Primary
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec5 (InboundRouting,InboundRoutingContext.CheckForPrivateLine:inboundroutingcontext.cs(1740))[484752463]UserProperties empty or no private line for this user. Nothing to do further.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec6 (InboundRouting,InboundRoutingContext.InitializeAttributesFromRequest:inboundroutingcontext.cs(1726))[484752463]Phone Invite: [Public] Line
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec7 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: NotReady->Active
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec8 (InboundRouting,RoutingContext.AddTargetToAttemptedList:routingcontext.cs(15))[484752463]Added to attempt list:
+13039973064@ucomsgeek.com;user=phone
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deec9 (InboundRouting,RoutingContext.AddTargetToAttemptedList:routingcontext.cs(15))[484752463]Added to attempt list: 7203398001;phone-context=PstnGateway_192.168.67.198@ucomsgeek.com;user=phone
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deeca (InboundRouting,RoutingContext.AddTargetToAttemptedList:routingcontext.cs(15))[484752463]Added to attempt list: 89973064;phone-context=PstnGateway_192.168.67.198@ucomsgeek.com;user=phone
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecb (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=flags:clientflags(block)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecc (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=flags:clientflags(e911active)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecd (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=class:Secondary>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deece (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=privateLine>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deecf (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed0 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=member:breakthrough>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed1 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=referred:breakthrough>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed2 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=member:add_voice>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed3 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=flags:clientflags(work_hours)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed4 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed5 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=flags:clientflags(team_ring)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed6 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=flags:clientflags(delegate_ring)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed7 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=dnd>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed8 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deed9 (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=flags:clientflags(forward_immediate)>=false
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deeda (InboundRouting,RoutingFilter.Execute:routingmodel.cs(14))[484752463]<filter criteria=default>=true
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deedb (InboundRouting,RoutingGroup.Execute:routingmodel.cs(96))[484752463]<group class='Registered' action='Replace' wait='0'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deedc (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(45))[484752463]Cancelling existing transactions since group criteria result is true.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deedd (InboundRouting,RoutingContext.SendRequestsForGroup:routingcontext.cs(96))[484752463]Sending request to 2 registered endpoints.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deede (InboundRouting,InboundRoutingContext.CreateClientTransactionForRequest:inboundroutingcontext.cs(573))[484752463]Creating Client Transaction to: sip:192.168.66.56:65346;transport=tls;ms-opaque=4cfd005019;ms-received-cid=1FDF200
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deedf (InboundRouting,InboundRoutingContext.CreateClientTransactionForRequest:inboundroutingcontext.cs(744))[484752463]Adding Max-Forwards header: 69
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.397.001deee0 (InboundRouting,InboundRoutingClientTransaction.constructor:inboundroutingcontext.cs(1910))[484752463]Addressing request using ContactInfo.
TL_INFO(TF_PROTOCOL) [2]11BC.06EC::05/25/2016-16:31:46.397.001deee1 (InboundRouting,InboundRoutingClientTransaction.SendImpl:inboundroutingcontext.cs(2315))[484752463]SendImpl() to sip:192.168.66.56:65346;transport=tls;ms-opaque=4cfd005019;ms-received-cid=1FDF200
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee2 (InboundRouting,InboundRoutingContext.CreateClientTransactionForRequest:inboundroutingcontext.cs(573))[484752463]Creating Client Transaction to: sip:someuser@192.168.67.41:35542;transport=tls;ms-received-cid=1612E00
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee3 (InboundRouting,InboundRoutingContext.CreateClientTransactionForRequest:inboundroutingcontext.cs(744))[484752463]Adding Max-Forwards header: 69
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee4 (InboundRouting,InboundRoutingClientTransaction.constructor:inboundroutingcontext.cs(1910))[484752463]Addressing request using ContactInfo.
TL_INFO(TF_PROTOCOL) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee5 (InboundRouting,InboundRoutingClientTransaction.SendImpl:inboundroutingcontext.cs(2315))[484752463]SendImpl() to sip:someuser@192.168.67.41:35542;transport=tls;ms-received-cid=1612E00
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee6 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(65))[484752463]There were 2 new requests sent by this group.
TL_INFO(TF_PROTOCOL) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee7 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(904))[484752463]Sending internally generated response 101
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee8 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(941))[484752463]Response 101 generated and sent
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deee9 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(96))[484752463]<group class='StaticRegistered' action='Extend' wait='0'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deeea (InboundRouting,RoutingContext.CheckAndRequestContactGroupResoltion:routingcontext.cs(28))[484752463]Referenced <list> named 'StaticRegistration' does not exist in preamble.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deeeb (InboundRouting,RoutingContext.SendRequestsForGroup:routingcontext.cs(98))[484752463]Referenced <list> named 'StaticRegistration' does not exist in preamble.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deeec (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(73))[484752463]There were no new requests sent by this group.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deeed (InboundRouting,RoutingGroup.Execute:routingmodel.cs(96))[484752463]<group class='Secondary' action='Extend' wait='0' criteria='registered'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deeee (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(44))[484752463]Group criteria registered=True
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deeef (InboundRouting,RoutingContext.CheckAndRequestContactGroupResoltion:routingcontext.cs(28))[484752463]Referenced <list> named 'GroupPickupList' does not exist in preamble.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef0 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(63))[484752463]Setting Routing Scenario to forwarding.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef1 (InboundRouting,RoutingContext.SendRequestsForGroup:routingcontext.cs(98))[484752463]Referenced <list> named 'GroupPickupList' does not exist in preamble.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef2 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(73))[484752463]There were no new requests sent by this group.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef3 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(96))[484752463]<group class='Secondary' action='NoRing' wait='0'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef4 (InboundRouting,RoutingContext.CheckAndRequestContactGroupResoltion:routingcontext.cs(28))[484752463]Referenced <list> named 'ControlledDevice' does not exist in preamble.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef5 (InboundRouting,RoutingContext.SendRequestsForGroup:routingcontext.cs(98))[484752463]Referenced <list> named 'ControlledDevice' does not exist in preamble.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef6 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(73))[484752463]There were no new requests sent by this group.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef7 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(96))[484752463]<group class='Secondary' action='Extend' waitref='total' wait='15' criteria='flags:clientflags(simultaneous_ring)'>
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef8 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(44))[484752463]Group criteria flags:clientflags(simultaneous_ring)=False
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deef9 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(73))[484752463]There were no new requests sent by this group.
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deefa (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [2]11BC.06EC::05/25/2016-16:31:46.398.001deefb (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(77))[484752463]Started group wait for 20000 milliseconds.
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.403.001deefc (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 100 from sip:192.168.66.56:65346;transport=tls;ms-opaque=4cfd005019;ms-received-cid=1FDF200
TL_VERBOSE(TF_COMPONENT) [1]11BC.01A8::05/25/2016-16:31:46.446.001deefd (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 100 from sip:someuser@192.168.67.41:35542;transport=tls;ms-received-cid=1612E00
TL_VERBOSE(TF_COMPONENT) [1]11BC.171C::05/25/2016-16:31:46.604.001deefe (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 180 from sip:192.168.66.56:65346;transport=tls;ms-opaque=4cfd005019;ms-received-cid=1FDF200
TL_VERBOSE(TF_COMPONENT) [1]11BC.171C::05/25/2016-16:31:46.604.001deeff (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [1]11BC.171C::05/25/2016-16:31:46.604.001def00 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 180
TL_VERBOSE(TF_COMPONENT) [1]11BC.171C::05/25/2016-16:31:46.604.001def01 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.802.001def02 (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 183 from sip:192.168.66.56:65346;transport=tls;ms-opaque=4cfd005019;ms-received-cid=1FDF200
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.802.001def03 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.802.001def04 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 183
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.802.001def05 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.992.001def06 (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 183 from sip:someuser@192.168.67.41:35542;transport=tls;ms-received-cid=1612E00
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.992.001def07 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.992.001def08 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 183
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:31:46.992.001def09 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [1]11BC.01A8::05/25/2016-16:31:47.033.001def0a (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 180 from sip:someuser@192.168.67.41:35542;transport=tls;ms-received-cid=1612E00
TL_VERBOSE(TF_COMPONENT) [1]11BC.01A8::05/25/2016-16:31:47.033.001def0b (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [1]11BC.01A8::05/25/2016-16:31:47.033.001def0c (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 180
TL_VERBOSE(TF_COMPONENT) [1]11BC.01A8::05/25/2016-16:31:47.033.001def0d (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def1e (InboundRouting,RoutingContext.OnWaitTimerElapsed:routingcontext.cs(17))[484752463]Group wait timer elapsed
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def1f (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def20 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(96))[484752463]<group class='Primary' action='Replace' wait='60' criteria='flags:clientflags(enablecf)'>
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def21 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(44))[484752463]Group criteria flags:clientflags(enablecf)=False
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def22 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(73))[484752463]There were no new requests sent by this group.
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def23 (InboundRouting,RoutingGroup.Execute:routingmodel.cs(96))[484752463]<group class='Primary' action='Replace' wait='60' criteria='umenabled'>
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def24 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(44))[484752463]Group criteria umenabled=True
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def25 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(45))[484752463]Cancelling existing transactions since group criteria result is true.
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def26 (InboundRouting,InboundRoutingClientTransaction.CancelImpl:inboundroutingcontext.cs(2234))[484752463]Canceling sip:192.168.66.56:65346;transport=tls;ms-opaque=4cfd005019;ms-received-cid=1FDF200
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def27 (InboundRouting,InboundRoutingClientTransaction.ClientTransactionCanceled:inboundroutingcontext.cs(2047))[484752463]ClientTransactionCanceled: sip:192.168.66.56:65346;transport=tls;ms-opaque=4cfd005019;ms-received-cid=1FDF200
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def28 (InboundRouting,InboundRoutingClientTransaction.CancelImpl:inboundroutingcontext.cs(2234))[484752463]Canceling sip:someuser@192.168.67.41:35542;transport=tls;ms-received-cid=1612E00
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def29 (InboundRouting,InboundRoutingClientTransaction.ClientTransactionCanceled:inboundroutingcontext.cs(2047))[484752463]ClientTransactionCanceled: sip:someuser@192.168.67.41:35542;transport=tls;ms-received-cid=1612E00
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def2a (InboundRouting,RoutingContext.SendRequestsForGroup:routingcontext.cs(10))[484752463]This group has 1 targets
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def2b (InboundRouting,RoutingContext.AddTargetToAttemptedList:routingcontext.cs(15))[484752463]Added to attempt list:
+13039973064@ucomsgeek.com;user=phone/voicemail
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def2c (InboundRouting,InboundRoutingContext.CreateClientTransactionForRequest:inboundroutingcontext.cs(573))[484752463]Creating Client Transaction to: sip:someuser@ucomsgeek.com;opaque=app:voicemail
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def2d (InboundRouting,InboundRoutingContext.CreateClientTransactionForRequest:inboundroutingcontext.cs(744))[484752463]Adding Max-Forwards header: 16
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def2e (InboundRouting,InboundRoutingClientTransaction.constructor:inboundroutingcontext.cs(1933))[484752463]Addressing request with Retarget(sip:someuser@ucomsgeek.com;opaque=app:voicemail)
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def2f (InboundRouting,InboundRoutingClientTransaction.InitializeDiagnosticsReporter:inboundroutingcontext.cs(2285))[484752463]Initializing diagnostics error reporter for transaction.
TL_INFO(TF_PROTOCOL) [3]11BC.0E18::05/25/2016-16:32:06.389.001def30 (InboundRouting,InboundRoutingClientTransaction.SendImpl:inboundroutingcontext.cs(2315))[484752463]SendImpl() to sip:someuser@ucomsgeek.com;opaque=app:voicemail
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def31 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(65))[484752463]There were 1 new requests sent by this group.
TL_INFO(TF_PROTOCOL) [3]11BC.0E18::05/25/2016-16:32:06.389.001def32 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(904))[484752463]Sending internally generated response 181
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def33 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(941))[484752463]Response 181 generated and sent
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def34 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [3]11BC.0E18::05/25/2016-16:32:06.389.001def35 (InboundRouting,RoutingContext.ProcessGroup:routingcontext.cs(77))[484752463]Started group wait for 60000 milliseconds.
TL_VERBOSE(TF_COMPONENT) [0]11BC.13B0::05/25/2016-16:32:06.397.001def36 (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 101 from sip:someuser@ucomsgeek.com;opaque=app:voicemail
TL_VERBOSE(TF_COMPONENT) [0]11BC.13B0::05/25/2016-16:32:06.397.001def37 (InboundRouting,InboundRoutingResponse.constructor:inboundroutingcontext.cs(2392))[484752463]Response has ms-diagnostic header with value: 15010
TL_VERBOSE(TF_COMPONENT) [0]11BC.13B0::05/25/2016-16:32:06.397.001def38 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [0]11BC.13B0::05/25/2016-16:32:06.397.001def39 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 101
TL_VERBOSE(TF_COMPONENT) [0]11BC.13B0::05/25/2016-16:32:06.397.001def3a (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:32:07.232.001def3b (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 101 from sip:someuser@ucomsgeek.com;opaque=app:voicemail
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:32:07.232.001def3c (InboundRouting,InboundRoutingResponse.constructor:inboundroutingcontext.cs(2392))[484752463]Response has ms-diagnostic header with value: 15023
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:32:07.232.001def3d (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:32:07.232.001def3e (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 101
TL_VERBOSE(TF_COMPONENT) [1]11BC.06EC::05/25/2016-16:32:07.232.001def3f (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [0]11BC.171C::05/25/2016-16:32:07.902.001def40 (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 101 from sip:someuser@ucomsgeek.com;opaque=app:voicemail
TL_VERBOSE(TF_COMPONENT) [0]11BC.171C::05/25/2016-16:32:07.902.001def41 (InboundRouting,InboundRoutingResponse.constructor:inboundroutingcontext.cs(2392))[484752463]Response has ms-diagnostic header with value: 15023
TL_VERBOSE(TF_COMPONENT) [0]11BC.171C::05/25/2016-16:32:07.902.001def42 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [0]11BC.171C::05/25/2016-16:32:07.902.001def43 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 101
TL_VERBOSE(TF_COMPONENT) [0]11BC.171C::05/25/2016-16:32:07.902.001def44 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:32:09.893.001def45 (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 180 from sip:someuser@ucomsgeek.com;opaque=app:voicemail
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:32:09.893.001def46 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:32:09.893.001def47 (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 180
TL_VERBOSE(TF_COMPONENT) [0]11BC.19D4::05/25/2016-16:32:09.893.001def48 (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Waiting
TL_VERBOSE(TF_COMPONENT) [0]11BC.06EC::05/25/2016-16:32:10.164.001def49 (InboundRouting,InboundRoutingClientTransaction.ResponseReceived:inboundroutingcontext.cs(2150))[484752463]ResponseReceived 200 from sip:someuser@ucomsgeek.com;opaque=app:voicemail
TL_VERBOSE(TF_COMPONENT) [0]11BC.06EC::05/25/2016-16:32:10.164.001def4a (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Waiting->Active
TL_VERBOSE(TF_COMPONENT) [0]11BC.06EC::05/25/2016-16:32:10.164.001def4b (InboundRouting,InboundRoutingResponse.get_ProxyAssertedIdentity:inboundroutingcontext.cs(2526))[484752463]value=<sip:someuser@ucomsgeek.com> scheme=sip
TL_VERBOSE(TF_COMPONENT) [0]11BC.06EC::05/25/2016-16:32:10.164.001def4c (InboundRouting,RoutingContext.CancelAllOutstandingRequests:routingcontext.cs(16))[484752463]Nothing to cancel.
TL_VERBOSE(TF_COMPONENT) [0]11BC.06EC::05/25/2016-16:32:10.164.001def4d (InboundRouting,InboundRoutingContext.ProxyResponseImpl:inboundroutingcontext.cs(860))[484752463]Proxying response 200
TL_VERBOSE(TF_COMPONENT) [0]11BC.06EC::05/25/2016-16:32:10.164.001def4e (InboundRouting,RoutingContext.SetState:routingcontext.cs(91))[484752463]Context State: Active->Terminated
TL_VERBOSE(TF_COMPONENT) [0]11BC.06EC::05/25/2016-16:32:10.164.001def4f (InboundRouting,InboundRoutingContext.OnSessionTerminated:inboundroutingcontext.cs(1146))[484752463]Session terminated.


The Fix!

The fix that was shared with me by those smarter than me a long time ago and I was reminded of by @jeffcsp while troubleshooting this :-) ... In my defense the original problem was a really small file of like 5.5MB and the one that is installed with the 5.0.8308.577 Debugging tools is 22MB. But still I should have caught it and he gets props for catching it.

In troubleshooting this problem, I found that the file located in the Common Files directory mentioned below is updated by the Cumulative Updates. I think it comes in during the Core Components update, but I'm not 100% sure. So I'd recommend until Microsoft figures out how to fix this the right way, you check the Common Files directory for any updated files and copy them over and of course TEST after you do so. I also recommend making a backup of any default.tmx files you replace, just in case you need to go back to the original.

Here are the steps...

Rename the default.tmx in the C:\Program Files\Microsoft Lync Server 2013\Debugging Tools directory

You need to copy default.tmx from
c:\Program Files\Common Files\Microsoft Lync Server 2013\Tracing
To
C:\Program Files\Microsoft Lync Server 2013\Debugging Tools

The file size of the default.tmx from the Tracing folder is approximately 26MB (December Update) vs 22MB of the default.tmx that came with the debugging tools (January 18, 2014).

Start up OCSLogger.exe (or CLS) again after the procedure above and run the InboundRouting debug again. This time you should have output in the log file.

So far I have confirmed this impacts at least InboundRouting on this go around. But in the past this has impacted other debug areas... so don't be surprised if there is something you've been missing when troubleshooting.