BYE-Telemetrie

Haben Sie sich im SIP-Trace schon mal das "BYE" angeschaut, welches mittlerweile von einem Skype for Business Client am Ende eines Anrufs an den Server sendet?. Die Bedeutung der meisten Felder ist leider nicht öffentlich dokumentiert.

QoE-Reports

Skype for Business kennt wie Lync schon die "Monitoring Rolle" sobald diese Rolle in ihrer Topologie installiert ist, sendet jeder kompatibel Client am Ende einer Verbindung nach dem BYE auch noch einen "SERVICE"-Request an den Server, in dem ein Voice Quality Report enthalten ist. Wenn Sie im UCCAPI-Trace nach "VQReport" suchen, sollten Sie den Eintrag auch finden. Diese Daten werden vom Server in die QoE-Datenbank übernommen und erlauben eine Auswertung durch den Administrator.

Mittlerweile sendet der Client aber auch mit dem BYE am Ende einer Verbindung eine "ms-client-diagnostics"-Meldung mit, die es durchaus in sich hat. Leider kommen Sie als Administrator nicht so einfach an diesen BYE-Befehl, es sei denn Sie würden auf dem Client das Log mit schnüffeln oder auf dem Frontend Server ein MSPL-Skript einbinden, welches diese Zusatzinformationen ausleitet. Wobei das Parsen des Clients gar keine so schlechte Idee wäre.

„ms-client-diagnostics“ Header

Ich habe mal einen BYE eines meiner Anrufe mitgeschnitten, bei dem ich hier eine Konferenz verlassen habe. Den Heaer "ms-client-diagnostics habe ich zu Lesbarkeit umgebrochen

10/12/2017|10:09:58.021 10B0:10B4 INFO  :: BYE sip:user1@netatwork.de;opaque=user:epid:xxxx;gruu SIP/2.0
Via: SIP/2.0/TLS 10.1.1.23:56423
Max-Forwards: 70
From: <sip:user2@uclabor.de>;tag=cf69xxx402c2e;epid=xxx
To: <sip:user1@netatwork.de>;epid=xxx;tag=xxx
Call-ID: xxxxxxxxxxxxxxxx
CSeq: 4 BYE
Route: <sip:sfbpool1.uclabor.de:5061;transport=tls;ms-fe=sfbfe1.uclabor.de;opaque=state:F:Ci.R221ef00;lr;ms-route-sig=xxxxxx>
Route: <sip:sfbedg1.uclabor.de:5061;transport=tls;lr>
Route: <sip:sip.netatwork.de:5061;transport=tls;epid=xxx;lr;ms-key-info=xxx-_jd-xxxxxx-xxxx;ms-route-sig=xxx-xxx>
Route: <sip:NAWLYNC002.netatwork.de:5061;transport=tls;opaque=state:T;lr>
User-Agent: UCCAPI/16.0.4585.1000 OC/16.0.4588.1000 (Skype for Business)
 
ms-client-diagnostics: 
   51004; 
   reason="Action initiated by user";
   UserType="Callee";
   MediaType="audio";
   MediaChanBlob="NetworkErr=no error,
      ErrTime=0,
      RTPSeq=0,
      SeqDelta=0,
      RTPTime=3716784597886,RTCPTime=3716784595506,
      TransptRecvErr=0x0,RecvErrTime=0,
      TransptSendErr=0x0,SendErrTime=0,
      InterfacesStall=0x0,InterfacesConnCheck=0x0,
      MediaTimeout=0,BlobVer=1";
   BaseAddress="10.1.1.23:50004";LocalAddress="62.160.243.12:55352";LocalSite="10.1.1.23:50009";NetworkName="ucabor.de";
   RemoteAddress="80.66.20.21:52457";RemoteSite="79.218.245.115:50005";
   MediaEpBlob="ICEWarn=0x20,ICEWarnEx=0x0,
      LocalMR=62.160.243.12:55352,RemoteMR=80.66.20.21:52457,
      PortRange=50000:50019,LocalMRTCPPort=55561,RemoteMRTCPPort=59327,
      LocalLocation=2,RemoteLocation=1,FederationType=1,
      StunVer=1,CsntRqOut=0,CsntRqIn=0,CsntRspOut=0,CsntRspIn=0,
      Interfaces=0x2,BaseInterface=0x2,Protocol=0,
      LocalInterface=0x2,LocalAddrType=2,RemoteAddrType=2,
      IceRole=1,RtpRtcpMux=1,AllocationTimeInMs=223,FirstHopRTTInMs=2,
      TransportBytesSent=12945,TransportPktsSent=429,IceConnCheckStatus=4,
      PrelimConnChecksSucceeded=0,IceInitTS=3716784483011,ContactSrvMs=175,
      AllocFinMs=225,PrelimAnsRcvMs=12681,FinalAnsRcvMs=15809,FirstPathMs=15811,
      ReinviteSntMs=21524,AckReinviteRcvMs=21899,BlobGenTime=3716784597891,
      MediaDllVersion=6.0.8953.268,BlobVer=1";
   MediaMgrBlob="MrDnsE=lyncav.uclabor.de,MrResE=1,MrErrE=0,
      MrBgnE=37167844830087856,MrEndE=37167844830095096,
      MrDnsI=sfbe1.uclabor.de,MrResI=1,MrErrI=0,
      MrBgnI=37167844830048400,MrEndI=37167844830056408,
      MrDnsCacheReadAttempt=0,BlobVer=1"
Proxy-Authorization: TLS-DSK qop="auth", realm="SIP Communications Service", opaque="0153610A", targetname="sfbfe1.uclabor.de", crand="xxx", cnum="160", response="xxx"
Content-Length: 0

Interessante Felder im Detail

Sie finden in der Zeile jede Menge Felder, die durch ein Semikolon ";" getrennt sind. Weiterhin gibt es "BLOB-Felder, die ihrerseits in Anführungsstrichen stehen und die inneren Werte mittels Komma getrennt sind. Es sollte also nicht so schwer sein, diese Felder zu parsen, wenn man denn Zugriff auf diese Daten hat. Das könnte aber für ein "Debugging-Tool" oder den Helpdesk durchaus interessant sein. Eine Auswahl

Feld Bedeutung

RemoteAddress="80.66.20.21:52457"

Das ist die IP-Adresse des Edge-Servers, bei dem ich im Meeting "drin" war

RemoteSite="79.218.245.115:50005";

Das war in dem Moment die IP-Adresse des DSL-Routers, über den ich im Internet war

BaseAddress="10.1.1.23:50004"
LocalAddress="62.160.243.12:55352"
LocalSite="10.1.1.23:50009

10.1.1.23 war meine interne IP-Adresse, die der Client hatte nud er hat die 62.160.243.12 als Edge-Server verwendet

Daten zur Verbindung selbst finden sich in dem Blog "MediaEpBlob ". Hier wiederholen sich zwar auch wieder die IP-Adressen und Ports aber andere Felder geben schnell Aufschluss, wie der Client verbunden war. Aber es gibt auch Felder, die gar keinen Sinn machen:

Feld Bedeutung

LocalLocation=2

Ich war "extern" im Internet

RemoteLocation=1

Die KonferenzMCU war natürlich "intern"

FederationType=1

Die Verbindung war eine "Federation", d.h. ich war angemeldet und habe meinen eigenen Edge-Server verwendet nud nicht als Gast in der Konferenz über den Edge des Konferenzsystems.

FirstHopRTTInMs=2

Interessanter Wert, den ich so interpretiere, dass der Client einen Ping zum Default Gateway macht, 2ms ist klein aber größere Werte weisen schon auf ein direktes lokalen Problem hin, z.B. ein überlastetes WLAN

TransportBytesSent=12945
TransportPktsSent=429

Irgendwie erscheint mir das nicht stimmig, denn 12945 Bytes in 429 Pakete ergibt 30 Bytes pro Paket. Das ist viel zu klein für SIP. Der Header ist schon größer. Aber auch für Audio sind es zu wenig Bytes/Sekunde.

ContactSrvMs=175

175ms wären in meiner Umgebung zu lange zum Edge Server, der Quasi "neben" mir stand.

Leider sind die öffentlichen Dokumente von Microsoft sehr sparsam, was die Bedeutung der Felder betrifft. Ich habe Sie eigentlich auch eher zufällig gesehen, als ich mal wieder einen Trace auf dem Client analysieren durfte. Ich kann also gar nicht genau sagen, seit wann diese Daten im Feld "ms-client-diagnostics" im BYE mittlerweile so ausführlich geworden sind. Früher gab es die noch nicht.

In einem Trace mit dem Lync 2010 Client aus dem Jahr 2012 finde ich nur spärliche Informationen

User-Agent: UCCAPI/4.0.7577.4103 OC/4.0.7577.4103 (Microsoft Lync 2010) 
ms-client-diagnostics: 51007;
   reason="Callee media connectivity diagnosis info";
   CalleeMediaDebug="
      audio:ICEWarn=0x0,
      LocalSite=79.208.121.113:29324,
      LocalMR=80.66.20.21:55355,
      RemoteSite=10.0.0.20:20019,
      RemoteMR=80.10.1.5:50414,
      PortRange=1025:65000,
      LocalMRTCPPort=55355,
      RemoteMRTCPPort=50414,
      LocalLocation=1,
      RemoteLocation=2,
      FederationType=1"

Der Lync 2013 Client in einem Trace von Februar 2013 war schon etwas gesprächiger.

User-Agent: UCCAPI/15.0.4454.1504 OC/15.0.4454.1506 (Microsoft Lync)
ms-client-diagnostics: 51000;
   reason="Call terminated by transferee on successful transfer";
   CalleeMediaDebug="
      audio:ICEWarn=0x2,
      LocalSite=192.168.178.32:50014,
      LocalMR=80.156.221.251:51661,
      RemoteSite=172.16.1.29:53022,
      RemoteMR=80.156.221.251:53444,
      PortRange=50000:50019,
      LocalMRTCPPort=51661,
      RemoteMRTCPPort=53444,
      LocalLocation=1,
      RemoteLocation=2,
      ederationType=0,
      NetworkName=Bohnenbrot,
      Interfaces=20,
      BaseInterface=4,
      BaseAddress=192.168.178.32:50012"

Aber erst der Skype for Business Client liefert noch mehr Informationen. Allerdings sind nur ein Teil der Daten auswertbar.

Weitere Links