XML-Logeinträge
Neulich meldete sich einer unserer Kunden weil seine Mitarbeiter sich nicht am WLAN anmelden konnten. Die Accesspoints strahlten mehrere SSID aus, aber nur an einer konnte sich niemand anmelden. Ich schaute auf dem WLAN-Controller (WLC) nach und sah, dass genau die betroffene SSID gegen einen Radius-Server authentisierte, während die anderen mit Pre-Shared-Keys arbeiteten.
Die Logs auf dem WLC halfen mir nicht weiter, also untersuchte ich als Nächstes den Datenverkehr zwischen WLC und Radius-Server. Der Paketmitschnitt zeigte Radius-Daten in beiden Richtungen, auf die Anfragen des WLC folgten Antworten des Radius-Servers. Entweder folgten Access-Challenges oder Access-Rejects.
Insgesamt sah dieser Datenverkehr normal aus, darum fragte ich den Admin des Radius-Servers nach den Logs. Ich bekam die Logs als Textdateien mit je einem XML-Element namens "Event" pro Zeile, die Zeilen waren weit über 1000 Zeichen lang.
Mit less,
meinem Lieblingswerkzeug für Textdateien,
konnte ich hier nicht viel ausrichten.
Mit Zeilenumbruch erstreckte sich ein Event über mehr als 10 Zeilen,
ohne Zeilenumbruch sah ich weniger als ein Zehntel der Zeile,
auch wenn ich nach links und rechts im Text wandern konnte.
Da ich die Struktur der Logeinträge nicht kannte,
kam ich so nicht weiter und überlegte,
wie ich die XML-Daten lesbar machen konnte.
Es gibt etliche Möglichkeiten,
XML so zu formatieren,
dass die Struktur gut lesbar ist.
Eine davon geht mit dem Programm xmllint,
das ich bei Ubuntu 20.04 über das Softwarepaket libxml2-utils bekomme.
Zu dieser Logdatei sagte xmllint nur:
IN210512.log:2: parser error : Extra content at the end of the document
<Event><Timestamp data_type="4">05/12/2021 07:56:15.495</Timestamp><Computer-Nam
^
So ging es also nicht, offensichtlich stellte die Logdatei keine valide XML-Datei dar und musste erst einmal "repariert" werden, bevor ich sie weiter verarbeiten konnte.
Eine valide XML-Datei hat genau ein Element in der obersten Ebene. In der Logdatei hingegen waren alle Event-Elemente in der obersten Ebene gleichrangig. Die Reparatur war einfach, ich fügte am Anfang der Datei die folgende Zeile ein:
<Events>
Am Ende hängte ich diese Zeile an:
</Events>
Damit hatte ich genau ein Element in der obersten Ebene,
welches seinerseits so viele Elemente enthielt,
wie die ursprüngliche Datei Zeilen.
Damit kann xmllint arbeiten.
xmllint --format clean-log.xml |less
<Event>
<Timestamp data_type="4">05/12/2021 08:26:50.032</Timestamp>
<Computer-Name data_type="1">FMDC11</Computer-Name>
<Event-Source data_type="1">IAS</Event-Source>
<User-Name data_type="1">host/FMCLP214.firma.local</User-Name>
<NAS-Port data_type="0">0</NAS-Port>
<Called-Station-Id data_type="1">A0-E4-CB-7F-A7-9B:fmoffice</Called-Station-Id>
<Vendor-Specific data_type="2">0000037A040964656661756C74</Vendor-Specific>
<Calling-Station-Id data_type="1">A0-A4-C5-A1-AB-49</Calling-Station-Id>
<Framed-MTU data_type="0">1400</Framed-MTU>
<NAS-Port-Type data_type="0">19</NAS-Port-Type>
<Connect-Info data_type="1">CONNECT 0Mbps 802.11b</Connect-Info>
<NAS-IP-Address data_type="3">127.0.0.1</NAS-IP-Address>
<Client-IP-Address data_type="3">10.116.129.200</Client-IP-Address>
<Client-Vendor data_type="0">0</Client-Vendor>
<Client-Friendly-Name data_type="1">fm-p-wifi01 (fmoffice)</Client-Friendly-Name>
<Proxy-Policy-Name data_type="1">SecureWirelessConnections</Proxy-Policy-Name>
<Provider-Type data_type="0">1</Provider-Type>
<SAM-Account-Name data_type="1">FIRMA\FMCLP214$</SAM-Account-Name>
<Class data_type="1">311 1 10.116.0.150 12/09/2020 15:40:30 33620</Class>
<Authentication-Type data_type="0">5</Authentication-Type>
<NP-Policy-Name data_type="1">WLAN_Authentication_over_Computer_Certs</NP-Policy-Name>
<Fully-Qualifed-User-Name data_type="1">firma.local/01_Computer/Firma_Ort/FMCLP214</Fully-Qualifed-User-Name>
<Packet-Type data_type="0">1</Packet-Type>
<Reason-Code data_type="0">0</Reason-Code>
</Event>
Jedes Event enthält ebenfalls wieder andere Elemente von denen mich zwei besonders interessierten:
<Client-IP-Address data_type="3">10.116.129.200</Client-IP-Address>
<Reason-Code data_type="0">0</Reason-Code>
Das eine war der Radius-Client, der die Lognachricht verursacht hatte, und das andere, hoffte ich, würde einen Hinweis liefern, was die Ursache des Problems ist.
Als nächstes schaute ich nach, für welche Radius-Clients ich Logeinträge hatte und welche Reason-Codes es gab.
xmllint --format clean-log.xml |grep Client-IP-Address|sort -u
<Client-IP-Address data_type="3">10.116.0.219</Client-IP-Address>
<Client-IP-Address data_type="3">10.116.129.200</Client-IP-Address>
xmllint --format clean-log.xml |grep Reason-Code|sort -u
<Reason-Code data_type="0">0</Reason-Code>
<Reason-Code data_type="0">259</Reason-Code>
Es gab mehrere Radius-Clients, also musste ich filtern. Außerdem gibt es nur einen interessanten Reason-Code (259). Interessant war für mich hier, ob der Reason-Code 259 bei der Client-IP-Address 10.116.129.200 vorkam, denn das war die Adresse des WLC.
Für diese Frage eignet sich das Programm xgrep,
das es bei Ubuntu 20.04 im gleichnamigen Software-Paket gibt.
Um meine Frage zu beantworten,
rief ich `xgrep wie folgt auf:
xgrep -s 'Event:Client-IP-Address/10.116.129.200/,Reason-Code/259/' \
clean-log.xml
| less
Das lieferte mir diese Ausgabe:
<Event>
<Timestamp data_type="4">05/12/2021 09:27:05.852</Timestamp>
<Computer-Name data_type="1">FMDC11</Computer-Name>
<Event-Source data_type="1">IAS</Event-Source>
<Class data_type="1">311 1 10.116.0.150 12/09/2020 15:40:30 33648</Class>
<EAP-Friendly-Name data_type="1">Microsoft: Smart Card or other certificate</EAP-Friendly-Name>
<Authentication-Type data_type="0">11</Authentication-Type>
<PEAP-Fast-Roamed-Session data_type="0">0</PEAP-Fast-Roamed-Session>
<Fully-Qualifed-User-Name data_type="1">firma.local/01_Computer/Firma_Ort/FMCLP211</Fully-Qualifed-User-Name>
<Client-IP-Address data_type="3">10.116.129.200</Client-IP-Address>
<Client-Vendor data_type="0">0</Client-Vendor>
<Client-Friendly-Name data_type="1">fm-p-wifi01 (fmoffice)</Client-Friendly-Name>
<Proxy-Policy-Name data_type="1">SecureWirelessConnections</Proxy-Policy-Name>
<Provider-Type data_type="0">1</Provider-Type>
<SAM-Account-Name data_type="1">FIRMA\FMCLP211$</SAM-Account-Name>
<NP-Policy-Name data_type="1">WLAN_Authentication_over_Computer_Certs</NP-Policy-Name>
<Packet-Type data_type="0">3</Packet-Type>
<Reason-Code data_type="0">259</Reason-Code>
</Event>
Packet-Type 3 bedeutet "Access-Reject". Das heißt, den Reason-Code gab der Radius-Server aus, wenn er eine WLAN-Anmeldung ablehnte.
Eine kurze Recherche im Internet förderte zwei Forum-Threads bei Microsoft Technet zutage, die auf ein Problem mit den Certificate Revocation Lists hinwiesen. Damit stand fest, dass es kein "Netzwerkproblem" war, und ich reichte das Ticket weiter. Der Radius-Administrator konnte mit den gefundenen Informationen das Problem lösen.
Posted 2021-06-21