Busy on Busy (BoB) Intern

Diese Seite beschreibt die internen Funktionen und Details von Busy on Busy (BOB) in Skype for Business Server CU3).

Die BoB Application

Die Einrichtung mit "New-CSServerApplication" hat natürlich meine Neugierde geweckt und wie nicht anders zu erwarten, gibt es eine entsprechende AM-Datei, die ein MSPL-Skript enthält, welches die SIP-Pakete inspiziert.

Das AM-File können Sie mit jedem Texteditor anschauen und mit etwas Übung auch sehen, was hier passiert. Das MSPL-Skript protokolliert Ausgaben zum APILogger. (Siehe auch MSPL)

Wenn ich es richtig gesehen habe, dann verbindet sich die Powershell per LDAP mit dem AD und per 1433 auf den SQL-Server. Die Einstellungen zu "Busy On Busy" liegen zumindest nicht beim Active Directory Objekt des Benutzers und werden daher auch nicht über den UserReplicator erst in die SQL-Datenbank übertragen. Allerdings sind die Daten natürlich verschlüsselt.

Bei der Analyse ist mit auch noch eine Besonderheit aufgefallen. Ich habe die Skype for Business Powershell auf einem eigenen PC installiert um per Netmon die Verbindungen besser analysieren zu können. Und hier bin ich auf einen Fehler gelaufen:

Set-CsBusyOptions : The operation failed due to issues with Tls. See the exception for more information.
 

PS C:\> $Error[0].Exception.StackTrace
   at Microsoft.Rtc.Signaling.RealTimeServerTlsConnectionManager.SetDefaultTlsTuple()
   at Microsoft.Rtc.Signaling.RealTimeServerTlsConnectionManager.SetLocalCertificate(
         String certificateIssuerName, Byte[] certificateSerialNumber)
   at Microsoft.Rtc.Collaboration.CollaborationPlatform.CreateConnectionManager(
         ITraceFilterConfiguration traceFilterConfiguration, PoolConfiguration poolConfiguration)
   at Microsoft.Rtc.Collaboration.CollaborationPlatform.Initialize(
         CollaborationPlatformSettings platformSettings)
   at Microsoft.Rtc.Collaboration.CollaborationPlatform.Initialize(
         CommonApplicationPlatformSettings platformSettings)
   at Microsoft.Rtc.Collaboration.CollaborationPlatform..ctor(
         ServerPlatformSettings platformSettings)
   at Microsoft.Rtc.SyntheticTransactions.SyntheticTransactionCollaborationPlatform.
         CreateAndInitializeServerPlatform()
   at Microsoft.Rtc.SyntheticTransactions.SyntheticTransactionCollaborationPlatform.
         get_ServerCollaborationPlatform()
   at Microsoft.Rtc.Management.Internal.PreambleBaseCmdlet`1.GetCollaborationPlatform()
   at Microsoft.Rtc.Management.Internal.PreambleBaseCmdlet`1.InitializePlatform()
   at Microsoft.Rtc.Management.Internal.PreambleBaseCmdlet`1.InternalProcessRecord()
   at Microsoft.Rtc.Management.AD.ADTask`1.CmdletProcessRecord()
   at Microsoft.Rtc.Management.OcsCmdlet.ProcessRecord()
   at System.Management.Automation.CommandProcessor.ProcessRecord()

Sie man sieht, ist es zuerst einmal ein TLS-Fehler, der sich aber durch den Start der PowerShell als "Administrator" lösen lässt. Anscheinend kommt mein normaler Anwender (UAC ist aktiv) nicht an den privaten Schlüssel des Zertifikats, um sich damit gegenüber dem Server auszuweisen. Das Problem besteht nicht, wenn Sie gleich eine "Remote Powershell" aufmachen.

BoB Entscheidungsbaum

Einen vollständigen Baum, wie die Skype for Business Application entscheidet, ob der Anruf beim Ziel signalisiert wird oder nicht, habe ich noch nicht gefunden. Aber aus den Logs, die ich weiter unten beschreibe, lässt sich in etwas auslesen, dass zuerst die Policies und aktuellen Einstellungen des Anwenders ausgewertet werden, um dann verschiedene Fälle zu evaluieren. Anscheinend werden alle Fälle bewertet, selbst wenn ein Zwischenergebnis schon das Endergebnis festlegt. Ich denke damit behält Microsoft mehr Flexibilität für spätere Änderungen.

TL_VERBOSE(TF_STACKTRACE) [poolname\servername]3104.A928::12/05/2016-12:34:55.673.000026BF
(BusyOptions,PolicyReaderWrapper.ReadPolicy:policyreaderwrapper.cs(48)) (00000000012F87AC)[Exit] 
   Returning new BobVoicePolicy with policyName: [Global], vPolicy.EnableBusyOptions: [True]

BusyOptions,UserAttributeReader.GetUserAttributes:Userattributereader.cs(111)) (00000000028D34C3) User voice policy enabled: [True]

(BusyOptions,UserAttributeReader.GetUserAttributes:Userattributereader.cs(126)) (00000000028D34C3)[Exit] 
   Returning UserDetails with UserDetails.BusyOption: [BusyOnBusy], UserDetails.ClientFlags [simultaneous_ring]

(BusyOptions,CallInfo.GetIsTeamCall:callinfo.cs
   Querying history info header and callee clientflags to determine whether it is a team call.
(BusyOptions,CallInfo.GetIsRgsCall:callinfo.cs
   Querying History-Info and MS-Application-Aor headers to determine if this is an RGS related call.
BusyOptions,CallInfo.GetIsCpsCall:callinfo.cs
   Querying the Contact header for the [isCps] parameter to determine if this is a CPS call.
BusyOptions,CallInfo.GetIsReferredByHeaderPresent:callinfo.cs
   Checking if the Referred-By header is present.
BusyOptions,CallInfo.GetIsDelegateCall:callinfo.cs
   Check clientflags to determine whether this is a Delegate related call.
BusyOptions,CallInfo.GetIsConferenceInvite:callinfo.cs
   Querying TO header to determine if this is a conference invite.
BusyOptions,CallInfo.GetIsCallForwardingEnabled:callinfo.cs
   Check clientflags to determine whether call forwarding is enabled.
BusyOptions,CallInfo.GetIsSimultaneousRingEnabled:callinfo.cs
   Check clientflags to determine whether simultaneous ring is enabled
BusyOptions,CallInfo.GetIsReInvite:callinfo.cs
   Querying TO header to determine if this is a re-invite
   Querying history info header and callee routing preamble to determine whether should prioritize call.

BusyOptions,CallRecordStore.Count:callrecordstore.cs
   Call record for User [sip:User1@msxfaq.de] -
    CallId: [065b86cf-a213-48de-97ba-96649a28d59c], 
    Caller: [NULL], 
    Callee: [sip:User1@msxfaq.de], LastHeartBeatTime: [12/5/2016 1:34:51 PM], HeartbeatIntervalInSeconds: [720]

Entsprechend ergibt sich folgender Baum:

Wenn Sie Erkenntnisse beisteuern können, nehme ich diese gerne mit auf.

Performance Counter

Bei der Untersuchung nach neuen Dateien ist mir natürlich auch die Datei "BusyOptionsPerf.dll" aufgefallen. Ein Blick in Perfmon zeigt, dass auch diese neue Option ein paar Counter mitbringt, die Sie auswerten können:

Mehr als ein paar Zahlen ist hier aber nicht zu holen.

Eventlog

Leider gibt es weder von dem MSPL-Skript noch von dem EXE weitergehende Meldungen im Eventlog. Das habe ich aber auch gar nicht erwartet, dass jede Aktivität mir das Eventlog füllt. Das hier ist also der falsche Platz. Allerdings finde sich hier zumindest der Event 30253 im Lync Server Eventlog, der beim Start des Frontend Servers anzeigt, welche Applications geladen werden. Die BOB Application selbst schreibt aber schon den ein oder anderen Eventlog, speziell bei Fehlerfällen.

Sie können ja man auf die Quelle "LS Busy Options" filtern.

OCSLogger

Leider installiert das CU3 kein eigenes Szenario für den CLS-Logger. Aber Microsoft hat in seiner Anleitung ein entsprechendes PowerShell-Script veröffentlicht, welches ich hier übernommen habe.

$p1 = New-CsClsProvider `
   -Name S4 `
   -Type WPP `
   -Level Info `
   -Flags All
$p2 = New-CsClsProvider `
   -Name Sipstack `
   -Type WPP `
   -Level Info `
   -Flags "TF_PROTOCOL,TF_CONNECTION,TF_SECURITY,TF_DIAG,TF_SHOW_CONFERENCE,TF_SHOW_ALLREQUESTS,TF_SHOW_ALLSIPHEADERS" `
   -Role Registrar
$p3 = New-CsClsProvider `
   -Name BusyOptions `
   -Type WPP `
   -Level Verbose `
   -Flags All
New-CsClsScenario `
   -Parent Global `
   -Name BusyOptions `
   -Provider @{Add=$p1,$p2,$p3}

# Ausgabe
Identity : Global/BusyOptions
Provider : {Name=S4;Type=WPP;Level=Info;Flags=All;Guid=;Role=, Name=Sipstack;Ty
pe=WPP;Level=Info;Flags=TF_PROTOCOL,TF_CONNECTION,TF_SECURITY,TF_DIA
G,TF_SHOW_CONFERENCE,TF_SHOW_ALLREQUESTS,TF_SHOW_ALLSIPHEADERS;Guid=
;Role=Registrar,
Name=BusyOptions;Type=WPP;Level=Verbose;Flags=All;Guid=;Role=}
Name : BusyOptions

Es legt quasi drei CLSProvider-Einstellungen an, die für die Aufzeichnung der relevanten Quellen erforderlich sind und generiert dann im vierten Schritt ein Scenario. Das können Sie dann im CLSLogger einfach auswählen.

 

Mit diesem Szenario zeichnen die Skype for Business Server dann nur die Events auf, die für die Fehlersuche relevant sind. Die Anzeige erfolgt dann natürlich wieder mit Snooper, Notepad oder einem anderen Tool ihrer Wahl.

Busy Logs auswerten

Wenn Sie dann mit dem Logger so eine Textdatei haben, dann ist die Auswertung und Suche darin die eigentliche Herausforderung. Wenn man aber im Log schaut, dann findet man viele Zeilen, die den gleichen String "BusyOnBusy" und "BusyOptions" verwenden:

Danach könnte ein Admin im Fehlerfall schon einmal suchen. Aber auch dann sind es noch sehr viele Zeilen. Ich habe mir folgende Codes gemerkt:

  • BusyOnBusy.OnSipAudioInvite
    Dieser String zeigt in der Regel einen neuen Call an. So finde ich schnell den Anrufer und das Ziel und ob der Eintrag für meinen Fall relevant ist. Interessant ist hier auch die CallID am Ende
  • BusyOptions,CallInfo.GetIsTeamCall
    Hier finden Sie dann die Informationen, ob dieser Anruf ein TeamCall war
  • BusyOptions,CallInfo.GetIsRgsCall
    Auch die Abfrage, ob es sich um einen "ResponsegroupCall" handelt, ist nützlich
  • BusyOptions,CallInfo.GetIsDelegateCall
    Auch Anrufe weil ich Stellvertreter bin, werden gesondert ausgewertet
  • BusyOptions,CallInfo.ShouldPrioritizeCall
    Dieser Text verrät dann auf einmal das "Ergebnis" der Anfrage

    Hier ist gut zu sehen, dass der Anruf an mich dennoch signalisiert wurde, weil es ein Konferenzanruf war. In dem Beispiel war es ein "MeetNow", wo mein Client den Status schon "In Conference" gesetzt hatte. Ohne diese Logik wäre ich selbst nicht in meine Konferenz gekommen.

Microsoft hat also nicht nur eine neue Funktion addiert, sondern auch sehr gute Analysemöglichkeiten eingebaut.

Weitere Links