Quels champs des logs IIS sont recommandés / Which IIS log fields are recommended ?

Le premier endroit pour diagnostiquer un problème sur IIS est le log du site qui pose problème (à l’aide de LogParser), encore faut-il que les paramètres de ce fichier de log soient bien configurés. D’expérience je sais que c’est rarement le cas. Je me propose donc dans cet article de parcourir rapidement les champs disponibles et de vous indiquer ceux qui sont recommandés (Pour résumer, tous sauf les trois derniers – pour ceux-ci c’est en fonction des besoins) :

  • Date (date) : La date de la requête en temps UTC (cf. point suivant)
  • Time (time) : L’heure requête au format UTC. Il n’y a aucun moyen de forcer un horodatage en heure locale (La rotation des logs à minuit heure locale est toutefois possible). Pensez bien au décalage en analysant vos logs IIS (H+2 en été / H+1 en hiver pour la France).
  • Client IP Address (c-ip) : L’adresse IP du client. En réalité plutôt l’adresse IP de l’équipement ayant émis la requête. Dans le cadre d’un environnement avec repartition de charge vous risquez de voir uniquement les adresses IP de vos load-balancers. Il existe des moyens de relayer la veritable adresse IP des clients comme ici et ici.
  • User Name (cs-username) : L’utilisateur authentifié lorsque cela est possible. Un « – » signifie généralement une authentification anonyme.
  • Service Name (s-sitename) : L’identifiant du site ayant pris en charge la requête (1 pour le « Default Web Site » puis de manière séquentielle pour les autres – Il est toutefois possible de changer l’identifiant d’un site de manière programmatique).
  • Server Name (s-computername) : Le nom du serveur ayant pris en charge la requête. Si vous analysez les logs d’un site hébergé dans une ferme de serveurs, cette information est capitale.
  • Server IP (s-ip) : L’adresse IP ayant pris en charge la requête. En effet un site web peut écouter sur plusieurs adresses IP.
  • Server Port (s-port) : Le port d’écoute qui a pris en charge la requête. En effet un site web peut écouter sur plusieurs ports.
  • Method (cs-method) : Le « verbe » HTTP associé à la requête.
  • URI Stem (cs-uri-stem) : L’URI demandée sans le nom de domaine (/images/logo.png pour l’URI http://www.contoso.com/images/logo.png)
  • URI Query (cs-uri-query) : La query string si applicable (param1=value1&param2=value2 pour l’URI http://www.contoso.com/forms/default.aspx?param1=value1&param2=value2)
  • Protocol Status (sc-status) : Le code statut de la réponse (« 200 » indiquant que tout va bien)
  • Protocol Substatus (sc-substatus) : Le code de sous-statut de la réponse (2 dans la réponse « 401.2« )
  • Win32 Status (sc-win32-status) : Le statut Windows de la réponse (Statut propre à Windows)
  • Bytes Sent (sc-bytes) : La volumétrie sortante en octets. Information cruciale pour évaluer les gains en termes de compression(s) statique/dynamique et les effets des niveau de compression (allant de 0 à 10 – Ne jamais dépasser 9, en effet le gain entre 9 et 10 est minime en comparaison de la surcharge CPU engendrée. Une petite lecture intéressante est disponible ici. – Moyen mnémotechnique : sc-bytes – SC pour Server to Client)
  • Bytes Received (cs-bytes) : La volumétrie entrante (taille de la requête – Moyen mnémotechnique : cs-bytes – CS pour Client to Server)
  • Time Taken (time-taken) : Le temps de traitement de la requête (en millisecondes) dans sa totalité : incluant le temps d’attente dans la file d’attente HTTP.sys, le temps de traitement par les serveurs Middle-Office, Back-Office (si applicable) et le temps réseau entre les équipements. Le compteur ne s’arrêtera que lorsque le client acquittera la trame réseau (« ACK ») comme précisé ici. Ce qui implique qu’un time-taken élevé n’est pas forcément un problème au niveau du serveur IIS (les causes peuvent être multiples : latence réseau, requêtes SQL non optimisées …)
  • Procol Version (cs-version) : La version du protocole HTTP utilisée : 0.9, 1.0, 1.1, 2.0 …
  • Host (cs-host) : Le host header name (si applicable). Un host header name est utilisé pour différencier deux sites qui écoutent sur le même couple IP/Port de manière à router le trafic sur le bon site. En effet le host-header name doit correspondre à l’entrée DNS demandait par les clients pour chaque site. Si on a deux sites correspondant aux entrée DNS www.contoso.com et www.northwindtraders.com écoutant sur le même couple IP:Port, il est necessaire de valoriser le host header name de chaque site avec la valeur DNS associée (www.contoso.com ou www.northwindtraders.com) de manière à être sûr que le trafic est routé sur le bon site.
  • User Agent(cs(User-Agent)) : La chaîne d’identification du navigateur / client
  • Cookie (cs(Cookie)) : Le cookie reçu ou envoyé associé à la requête.
  • Referer(cs(Referer)) : La page où l’on a cliqué précédemment pour arriver à cette page.

Maintenant expliquons pourquoi je déconseille (dans la majorité des cas) l’activation des trois derniers champs : User Agent, Cookie et Referer. Généralement ses champs ne sont quasiment pas exploités dans le cadre de démarche de troubleshooting ou de reporting. De plus chaque requête va enregistrer dans les logs IIS les informations relatives à ces champs et les valeurs associées sont relativement grandes (plusieurs dizaines de caractères pour chacun d’eux). Ce qui induit des I/O inutiles. Le but étant toujours de réduire la consommation de ressources en production.

Votre configuration doit donc au minima ressembler à cela. Je vous laisse libre de sélectionner les autres champs si vous les exploitez réellement.

iislogfields

Vous vous demandez certainement s’il n’existe pas à un moyen d’automatiser cette configuration ? La réponse est naturellement oui et je vous propose même deux moyens de le faire (via appcmd et PowerShell) en modifiant directement les options de journalisation par défaut (appliquées à tous les sites) :

    • Nativement avec appcmd.exe
 
REM Changing default logging fields to enable all fields except User-Agent, Cookie and Referer 
%WINDIR%\system32\inetsrv\appcmd.exe set config /section:sites -siteDefaults.logFile.logExtFileFlags:Date,Time,ClientIP,UserName,SiteName,ComputerName,BytesRecv,BytesSent,ServerIP,Method,UriStem,UriQuery,TimeTaken,HttpStatus,Win32Status,ServerPort,HttpSubStatus,ProtocolVersion,Host
    • Avec PowerShell

 
# Changing default logging fields to enable all fields except User-Agent, Cookie and Referer 
Import-Module WebAdministration 
Set-WebConfigurationProperty -pspath 'MACHINE/WEBROOT/APPHOST' -filter "system.applicationHost/sites/siteDefaults/logFile" -name "logExtFileFlags" -value "Date,Time,ClientIP,UserName,SiteName,ComputerName,ServerIP,Method,UriStem,UriQuery,HttpStatus,Win32Status,BytesSent,BytesRecv,TimeTaken,ServerPort,ProtocolVersion,Host,HttpSubStatus"

The first place to diagnose a problem on IIS is the log of the site that is the problem (using LogParser), but it is necessary that the settings of the log file are well configured. From my own experience I know that this is rarely the case. I propose in this article to quickly browse the available fields and tell you those recommended (To summarize, all except the the last three ones – for them it is as needed):

  • Date (date) : The date, in coordinated universal time (UTC) (cf. next point
  • Time (time) : The time, in coordinated universal time (UTC), at which the request occurred. There is no way to force a timestamp in local time(Nevertheless, using local time for file naming and rollover is possible). Take this time shifting into consideration when analyzing your IIS logs (H+2 in summer / H+1 in winter for France).
  • Client IP Address (c-ip) : IP addresse of the client. In fact rather the IP address of the device that issued the request. As part of a load distribution with environment you may see only the IP addresses of your load-balancers. There are ways to relay the real client IP address as explained here and here.
  • User Name (cs-username): The name of the authenticated user who accessed your server. Anonymous users are indicated by a hyphen.
  • Service Name (s-sitename) : The ID of the site that handled the request (1 for the « Default Web Site » and then sequentially for the other sites – it is possible to change the identifier of a site programmatically).
  • Server Name (s-computername) : The name of the server that handled the request. If you analyze the logs of a site hosted on a web farm then this information is important.
  • Server IP (s-ip) : The IP address has handled the request. Indeed a web site can listen on multiple IP addresses.
  • Server Port (s-port) : The listener that has handled the request. Indeed a web site can listen on multiple ports.
  • Method (cs-method) : The HTTP « verb » HTTP associated to the request.
  • URI Stem (cs-uri-stem) : The URI requested without the domain name (/images/logo.png for http://www.contoso.com/images/logo.png)
  • URI Query (cs-uri-query) : The query, if any, that the client was trying to perform (param1 = value1 & param2 = value2 for http://www.contoso.com/forms/default.aspx?param1=value1&param2=value2)
  • Protocol Status (sc-status) : The HTTP status code. (« 200 » is OK)
  • Win32 Status (sc-win32-status) : The Windows status code.
  • Bytes Sent (sc-bytes) : The number of bytes that the server sent. Crucial information to assess gains when working with static and / or  dynamic compression and monitr the effects of compression level (from 0 to 10 – Do not exceed a level of 9, because the gain between the levels 9 and 10 is minimal compared to the generated CPU overload. An interesting reading is available here– mnemonic: sc-bytes – SC for Server to Client)
  • Bytes Received (cs-bytes) : The number of bytes that the server received (mnemonic  : cs-bytes – CS for Client to Server)
  • Time Taken (time-taken) : The processing time of the request (in milliseconds) in its entirety: including the waiting time in the HTTP.sys request queue, the processing time by the middle-office servers, back office (if any) and network time between equipments. The counter will be stopped only when the client will acknowledge the last response packet send operation as specified here. This implies that a high time-taken is not necessarily a problem with the IIS server (the causes can be many: network latency, non-optimized SQL queries …)
  • Procol Version (cs-version) : The HTTP protocol version that the client used: 0.9, 1.0, 1.1, 2.0 …
  • Host (cs-host) : The host header name, if any. A host header name is used to differentiate the two sites listening on the same IP / port couple to route traffic to the right web site. Indeed the host-header name must match the DNS entry requested by client for each site. If two sites corresponding to the DNS entry www.contoso.com and www.northwindtraders.com are listening on the same couple IP:Port, it is necessary to set the host header name of each site with the associated DNS value (www.contoso .com or www.northwindtraders.com) to be sure that the traffic is routed to the right site.
  • User Agent(cs(User-Agent)) : The browser type that the client used
  • Cookie (cs(Cookie)) : The content of the cookie sent or received, if any.
  • Referer(cs(Referer)) : The site that the user last visited. This site provided a link to the current site.
Now I will explain why I don’t recommend (in most cases) the activation of the last three fields: User Agent, Cookie and Referer. Generally these fields are not exploited as part of troubleshooting or reporting process. Moreover each request will register the information for these fields in the IIS logs and associated values are relatively large (several tens of characters for each one). Which cause more I/O. The goal is always to reduce the use of production resources.
Your configuration should look like this at minimum. Feel free to select other fields if you actually operate them.
iislogfields

You’re probably wondering if there is not a way to automate this configuration? The answer is yes, and I even offers two ways to do this (by using appcmd and PowerShell) by modifying the default logging options (applied to all sites):

    • With appcmd.exe

 
REM Changing default logging fields to enable all fields except User-Agent, Cookie and Referer 
%WINDIR%\system32\inetsrv\appcmd.exe set config /section:sites -siteDefaults.logFile.logExtFileFlags:Date,Time,ClientIP,UserName,SiteName,ComputerName,BytesRecv,BytesSent,ServerIP,Method,UriStem,UriQuery,TimeTaken,HttpStatus,Win32Status,ServerPort,HttpSubStatus,ProtocolVersion,Host
    • With PowerShell

 
# Changing default logging fields to enable all fields except User-Agent, Cookie and Referer 
Import-Module WebAdministration 
Set-WebConfigurationProperty -pspath 'MACHINE/WEBROOT/APPHOST' -filter "system.applicationHost/sites/siteDefaults/logFile" -name "logExtFileFlags" -value "Date,Time,ClientIP,UserName,SiteName,ComputerName,ServerIP,Method,UriStem,UriQuery,HttpStatus,Win32Status,BytesSent,BytesRecv,TimeTaken,ServerPort,ProtocolVersion,Host,HttpSubStatus"

Laurent.

Feel free to share:)
Tweet
Étiqueté avec , , ,