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.

Tuesday, October 6, 2015

AudioCodes Webinar about Fax and Modem Transmission over TDM and IP Networks

AudioCodes did a webinar on Fax and Modem transmission over TDM and IP networks that is very informative. If you have ever implemented Fax and Modems in an AudioCodes environment, then you'll know how valuable this presentation is. I had to learn all this the hard way and they have served it up on a nice platter for you to enjoy...

Recording

Presentation (requires AudioCodes website login)

Monday, September 28, 2015

Time2Market's Cloud Complete Unified Communications as a Service (UCaaS)

First off... this blog post is going to come across as a sales pitch and that is because it is. I'm not going to insult your intelligence... but there is a lot of confusion out there as to what is offered with various different Unified Communications as a Service (UCaaS) solutions and where they can fit into an organizations plan to further their communications. I'm not going to go into detail about all the other offerings out there, but what I'm going to do is offer you detail about Time2Market's Cloud Complete offering. We also offer a Cloud Custom option, that adds some additional functionality, but this blog post will focus on the Cloud Complete offering.

Anyone who knows me... knows that I'm not a fan of the "cloud". The reason is because I think it is one of those terms that gets thrown around and decisions made without really understanding the implications of turning over control to the cloud. I'm not saying that it doesn't make sense 100 percent of the time... because it actually does in a lot of scenarios.  I just don't like the blind run toward the cloud that I see a lot of people doing just because all the cool kids are doing it.

Having said that, Time2Market's Cloud Complete offering is a hosted UCaaS that is a Multi-tenant... Enterprise Voice... Skype for Business environment.

Yup.. you read that right... Skype for Business.

Time2Market's cloud is not based on the now defunct Lync Hosting Pack that was limited to the same feature set and Lync Online.

The is a Skype for Business hosted environment with feature sets that to my knowledge are currently not offered anywhere else. Those feature sets even include the new Broadcast Meeting offering that depends on a hybrid implementation with Office365. We even leverage Exchange Unified Messaging in Office365.



Now why would an organization want to do this. It is simple... instead of investing in all the equipment, server licenses and professional services to implement an on-premises solution that has costs as a capital expenditure. This allows an organization to move these costs to the operational expenditure column. The Cloud Complete offering scales and shrinks as you do and is a totally managed service from deployment to support. In short, you focus on your business, not running a Unified Communications infrastructure.

So what are some of the things that Time2Market offers in its Cloud Complete that make it unique...
  • E-Faxing Services
  • Advanced Call Routing Options
  • DID Parking
  • Common Area Phones
  • Standalone Fax Services
  • Unlimited Calling Plans
  • Auto Attendant
  • Dedicated Conference Bridge
  • Room Systems and Video Integration
  • Conference Room Audio Devices
  • 800# Support
  • Paging Applications
  • Contact Center (Clarity)

But here is the really big key to Time2Market's offering, we have a whole organization that will help you every step along the way with a White Glove Service. Cloud Complete isn't a self service type of offering, instead it is an offering where you have a whole team of people who have been in the business of helping organizations communicate for decades. Here are some of the things we can help you with...
  • Office365 Tenant Setup/Mail Migration
  • Unified Messaging Setup
  • IP Phone Setup
  • On-Premises Active Directory Integration
  • Auto Attendant Configuration
  • Room System Installation
  • Device Consultation

But wait.... there's more!! Sorry couldn't resist saying that.

But really there is more... Time2Market has created a Self Service web based portal that gives easy access to the following tasks...
  • Password Reset
  • Add New Users
  • Assign DIDs
  • Modify/Update Conferencing and Global Dialing Policies
  • Update Federation Policies
  • Get Support
  • Access to Usage Reports and Billing Info
  • Access to training, tips and tricks





What are you waiting for? Interested in Time2Market's Cloud Complete offering or have further questions? You can contact me by SIP or email using jonathan at t2mdev dot com or by calling 303 997 2100.

Tuesday, September 15, 2015

Change in route selection behavior in Lync Server 2013 from Lync Server 2010

I was recently working on a rather complicated dial plan and ran into a situation where the route I expected to be followed wasn't being followed. What I was trying to do was create a single Voice Usage that would route for specific numbers and then have a catch all route that would be the route as a last resort.

After doing numerous tests and doing an Outbound Routing debug it was clear that the route wasn't being skipped and it wasn't being marked down. The catch all route was being tried first even though the order of the routes in the Voice Usage had it at the bottom.

Interestingly, if I simplified the regular expression of the route that matched a range of specific numbers to just be one of those numbers, it magically started to work correctly. As soon as I modified it back to the larger range, it would fail.

Knowing that I have done this many times before, I was convinced somehow I hit some sort of bug. So a case with Microsoft was opened. After some lengthy testing, the Microsoft support engineer was just as baffled as I was and was coming to the same conclusion I did.

As a work around, until the Microsoft engineer decided how to proceed, we created two different Voice Usages. The first one was for ranges of numbers and the second usage contained the catch all route all by itself. The routing worked as expected, but this was not ideal, because this would increase the number of Voice Usages across the hundreds of sites in this deployment. I was aiming for the simplest dial plan possible since it was already complex.

Anyway, after a few days the Microsoft engineer got back to us and dropped a huge bomb.

Believe it or not, this was working as designed. He informed me that there was a change in Lync Server 2013 in how it processes routes in a Voice Usage. Lync Server 2013 now chooses the least complex regular expression before it processes the other routes. The reason for this change I don't agree with, but apparently there were some customers that had really large dial plans, where processing a large list of routes in a Voice Usage was taking too long and this change was decided to speed up processing the list.

So... if you have similarly complex in the same usage, the order of the routes matters. But if you mix complex and simple rules in the same Voice Usage, then the more simple rules will always be followed first.

I hate this because now everyone else is forced to create more Voice Usages, sometimes with a single route in them, to have the routing work as desired. The other item that bugs me is that there is next to no documentation of this change and this was not communicated to the technical community in any other way that I'm aware of. This is a big change for a product that a lot of people depend on to be consistent.

I think a better alternative would have been to give the engineer an option to process the routes within a Voice Usage using the Lync Server 2010 method or to switch to the new Lync Server 2013 method. I can see merits to both methods, but ideally I would like a choice.

Now... If you are like I am, you want to know what exactly constitutes a simple rule vs complex rule. Unfortunately I can't tell you exactly. All I can share with you is a somewhat vague answer that I got back.
The algorithm has quite a bit of complexity – in simple terms, the route that has simpler “prefix” will be preferred over more complex ones. The “prefix” is a combination of characters, character escapes, alterations and substitutions (as defined in regular expressions).
So if anyone has more detail on this algorithm, I'd like to have it. But in the mean time it doesn't really matter because the permanent fix is to have similarly complex rules in the same Voice Usage and then make sure you test to verify the route order is being followed as desired.

Tuesday, April 28, 2015

Active Noise Cancelling Smackdown: Plantronics Blackwire C725 vs Jabra Evolve 80

So I recently obtained two different Active Noise Cancelling headsets that are Lync/Skype for Business optimized devices. I've been using both the Jabra Evolve 80 (E80) and the Plantronics Blackwire C725 (C725) quite a bit and one thing I've noticed is that even though they are both Active Noise Cancelling, they are Apples and Oranges when you go to compare them. So I thought it would be interesting to highlight their Pros and Cons and really help those that want to find the right headset for their situation.

It is important to note that both of these headsets were given to me directly by each vendor and my assumption is that they hoped I would review them. There was no guidance as to how that was done from either vendor. These views can be considered my own opinion.


Let's start off with a opening statement of each product from each vendors own marketing material...

Plantronics Blackwire C725

The Blackwire 725 USB Headset is great for keeping you focused in noisy office environments. Featuring Active Noise Canceling technology, a nose-cancelling mic, and hi-fi stereo performance, the Blackwire 725 minimizes external noises while ensuring that PC-based calls and multimedia come through crystal clear. With the Blackwire 725, distractions go down and productivity goes up.


Jabra Evolve 80

Jabra Evolve series is a professional range of head-sets designed to improve concentration and conversations. Premium noise cancellation technology gives you peace to work in a noisy environment, open office, effectively creating a concentration zone around you so you can stay focused.


Round 1: Fit and Comfort

Right away you will notice the biggest difference between the two. The C725 is an ON THE EAR muff, where the E80 is an OVER THE EAR muff. Using both for very long calls I've noticed a few things.

E80 Fit and Comfort Negatives
  • Can start to become itchy where the muffs touch your skin
  • People have complained that it is too tight on their head (squeezing their noggin)
  • The mic is ONLY on the right
  • They are pretty bulky

C725 Fit and Comfort Negatives
  • None that I can think of

E80 Fit and Comfort Positives
  • Muffs have lots of padding
  • Band against head is padded

C725 Fit and Comfort Positives
  • Very comfortable with lots of adjustments
  • Mic can be on either side of head
  • Not bulky
  • Band against head is padded
  • Muffs are padded well


Route 2: Sound Quality

This one I realize is fairly subjective. So this is one that you'll definitely have to take with a grain of salt. But it really comes down to what do you do with your headset. Do you like to listen to music AND use it for Lync? or is this strictly a business headset only used for communication? Depending on how you answer those two questions, I could probably guess which one you would choose.

C725 Sound Quality Negatives
  • Great sound quality, but for music won't blow you mind.
  • Ear muffs allow for extra noise to creep in

E80 Sound Quality Negatives
  • Certain voices can seem deeper than normal
  • Needed to adjust side tone audio out of the box (hear yourself)

C725 Sound Quality Positives
  • I think I could literally hear a pin drop on a conference call
  • Voices sound very natural
  • Sidetone audio was perfect out of the box (hear yourself)

E80 Sound Quality Positives
  • Very rich bass
  • Music is phenomenal


Round 3: Noise Cancellation

You would think that two products that highlight Active Noise Cancellation as a major feature would actually be very similar. But I'm here to tell you that they are very different.

E80 Noise Cancellation Negatives
  • Noise Cancellation is only for the person wearing... ambient noises can be heard on Mic!
  • Needs battery charged to work

C725 Noise Cancelling Negatives
  • Ambient Noise can come in around ear muffs
  • Doesn't work unless you are in a call or using audio from PC
  • Can't be used with smart phone or other audio device (iPod)

E80 Noise Cancellation Positives
  • Amazingly effective at cutting out ambient noise
  • Can be used with smart phone (if battery is charged)
  • Has "Listen in" button on side to let you hear ambient noise... 

C725 Noise Cancellation Positives
  • Amazingly effective at cutting out ambient noise on the MIC
  • Pretty good at cutting out ambient noise on the muffs
  • Don't need to worry about charging a battery


Conclusion

The point of this blog post was not to find a winner, but to point out that these two headsets meet very different needs.

If you are in the office (especially cubes or call center) and on the phone all day long, then the C725 would probably be the better choice.

If you travel a lot and need a headset that you can use on the road and on the plane, then the E80 is probably a better choice.

Quite honestly, I plan to use both of these headsets depending on what I'm doing. Who knows... maybe Plantronics or Jabra will create a Active Noise Cancelling headset to rule them all.

Extras

E80 Extras you need to know
  • Listen In button is nice, but not obvious (push the jabra on the side with the mic)
  • When microphone is in the up position it is automatically muted
  • You will want to adjust sidetone audio, because otherwise you may not hear yourself at all
  • Headset can disconnect from call controls and be used with smart phone
  • Extra audio adjustments in the Jabra app on the PC.
  • You will stand out in a crowd when you use these
C725 Extras you need to know
  • The microphone boom can be used on left or right side of head
  • The headset automatically answers a call when you put it on