Dexter, Log4Net, Logging, Ottimizzazione, Configurazione, Windows Live Writer, FullTrust, OutOfBrowser, Silverlight, Eventi, MVP Summit 2010, UgiALT.net

Il logging è una parte fondamentale dell’applicazione; se implementato correttamente ed inserito nei posti giusti può salvare da lunghi down applicativi e molto altro ancora.

Pur potendo una persona essere bravissima a scrivere del codice, purtroppo (o per fortuna, dipende dai punti di vista) la stabilità e le problematiche dell’applicazione non dipendono soltanto dallo sviluppatore. Di fatto può cadere la connessione verso  il database, possono esserci problemi di rete verso la SAN, un update può destabilizzare l’applicativo, ma per l’utente finale la colpa sarà sempre dell’applicazione; del resto è un punto di vista comprensibile, in quanto ciò che interessa è usare l’applicazione e non le eventuali problematiche esterne che ne possono causare un crash.

Appreso il fatto che, qualsiasi sia il problema, sta a noi trovarlo, passando poi la palla a chi di dovere (sistemista, tecnico di rete, etc), è comunque utile sapere che proprio in questi casi il logging può aiutare a ridurre al minimo il tempo necessario per poter identificare un bug applicativo e/o un problema di infrastruttura.

Purtroppo io sono abituato ad aggiungere al Dictionary Data delle eccezioni alcune informazioni riguardo al contenuto della chiamata, come dei parametri o delle variabili calcolate (vedi qui); inoltre, per tutte le applicazioni web, mi piace essere a conoscenza dell’esatta richiesta che è stata effettuata, quindi, per entrare un po’ più nel dettaglio, per ogni errore voglio sapere:

• Url della richiesta;
• RawURL nel caso esista un sistema di routing o rewriting;
• UrlReferrer, se esiste;
• UserAgent, se esiste;
• UserHostName;
• Tutte le ServerVariables;
• Tutti i valori provenienti dalla Form;
• ServerName, nel caso mi trovi in un sistema di load balancing;
• ThreadLanguage;

Ovviamente tutte queste informazioni sono prensenti nel HttpContext, ma inserirle a mano ogni volta non è il massimo della comodità, così come non lo è crearsi una classe di helper perchè spesso il Logger può essere instanziato tramite un Framework di Inversion Of Control come Castle (che offre già una serie di facilities a riguardo). Per concludere, il Logger deve aggiungere da solo tutto ciò che è ripetitivo.

Purtroppo il Logger di default non salva queste informazioni (né le informazioni aggiuntive della collection data, né il contesto web), ma è comunque possibile realizzare un layout base che aggiunga all’output del Logger le informazioni necessarie.

Personalmente utilizzo come output un file xml (il discorso rimane lo stesso anche se si opta per un’altra soluzione) perchè è compatibile con il mio log viewer preferito, Log4View, che offre moltissime opzioni, tra cui la possibilità di effettuare logging tramite nettcp su un client remoto.

Chi segue il codice di Dexter può già trovare questa implementazione - che qui riporto solo per le parti relative all’argomento - al suo interno:

protected override void FormatXml(XmlWriter writer, LoggingEvent loggingEvent)
{
    if (DexterEnvironment.Context.IsSafe)
    {
        try
        {
            loggingEvent.Properties["Url"] = DexterEnvironment.Context.CurrentRequestUri;
            loggingEvent.Properties["UrlReferrer"] = DexterEnvironment.Context.CurrentUrlReferrer;
            loggingEvent.Properties["UserAgent"] = DexterEnvironment.Context.CurrentUserAgent;
            loggingEvent.Properties["UserHostName"] = DexterEnvironment.Context.CurrentUserHostName;
            loggingEvent.Properties["ServerVariables"] = ServerVariables(DexterEnvironment.Context.CurrentServerVariables);
            loggingEvent.Properties["Form"] = ServerVariables(DexterEnvironment.Context.CurrentForm);
            loggingEvent.Properties["RawURL"] = DexterEnvironment.Context.CurrentRawUrl;//ctx.Request.RawUrl;
            loggingEvent.Properties["ServerName"] = DexterEnvironment.Context.CurrentServerMachineName;
            loggingEvent.Properties["ThreadLanguage"] = Thread.CurrentThread.CurrentCulture.DisplayName;
        }
        catch
        {
            //needed because the logging called from the appliction start che throw a new exception
            //more info here:http://mvolo.com/blogs/serverside/archive/2007/11/10/Integrated-mode-Request-is-not-available-in-this-context-in-Application_5F00_Start.aspx
        }
    }

    writer.WriteStartElement(mElmEvent);
    writer.WriteAttributeString("logger", loggingEvent.LoggerName);
    writer.WriteAttributeString("timestamp", XmlConvert.ToString(loggingEvent.TimeStamp, XmlDateTimeSerializationMode.Local));
    writer.WriteAttributeString("level", loggingEvent.Level.DisplayName);
    writer.WriteAttributeString("thread", loggingEvent.ThreadName);
    
    if (!string.IsNullOrEmpty(loggingEvent.Domain))
        writer.WriteAttributeString("domain", loggingEvent.Domain);

    if (!string.IsNullOrEmpty(loggingEvent.Identity))
        writer.WriteAttributeString("identity", loggingEvent.Identity);

    if (!string.IsNullOrEmpty(loggingEvent.UserName))
        writer.WriteAttributeString("username", loggingEvent.UserName);

    writer.WriteStartElement(mElmMessage);

    if (!Base64EncodeMessage)
        Transform.WriteEscapedXmlString(writer, loggingEvent.RenderedMessage, InvalidCharReplacement);
    else
    {
        byte[] bytes = Encoding.UTF8.GetBytes(loggingEvent.RenderedMessage);
        string textData = Convert.ToBase64String(bytes, 0, bytes.Length);
        Transform.WriteEscapedXmlString(writer, textData, InvalidCharReplacement);
    }
    writer.WriteEndElement();
    
    PropertiesDictionary properties = loggingEvent.GetProperties();
    if (properties.Count > 0)
    {
        writer.WriteStartElement(mElmProperties);
        foreach (DictionaryEntry entry in properties)
        {
            writer.WriteStartElement(mElmData);
            writer.WriteAttributeString("name", Transform.MaskXmlInvalidCharacters((string) entry.Key, InvalidCharReplacement));
            string str2;
            if (!Base64EncodeProperties)
                str2 = Transform.MaskXmlInvalidCharacters(loggingEvent.Repository.RendererMap.FindAndRender(entry.Value), InvalidCharReplacement);
            else
            {
                byte[] inArray = Encoding.UTF8.GetBytes(loggingEvent.Repository.RendererMap.FindAndRender(entry.Value));
                str2 = Convert.ToBase64String(inArray, 0, inArray.Length);
            }
            writer.WriteAttributeString("value", str2);
            writer.WriteEndElement();
        }
        writer.WriteEndElement();
    }
    
    if (loggingEvent.ExceptionObject != null)
    {
        StringBuilder exceptionString = new StringBuilder();

        exceptionString.Append(loggingEvent.ExceptionObject);
        exceptionString.Append(Environment.NewLine);

        foreach (DictionaryEntry de in loggingEvent.ExceptionObject.Data)
        {
            exceptionString.Append(de.Key.ToString());
            exceptionString.Append(": ");
            exceptionString.Append(de.Value.ToString());
            exceptionString.Append(Environment.NewLine);
        }
        if ((exceptionString.Length > 0))
        {
            writer.WriteStartElement(mElmException);
            Transform.WriteEscapedXmlString(writer, exceptionString.ToString(), InvalidCharReplacement);
            writer.WriteEndElement();
        }
    }
    if (LocationInfo)
    {
        LocationInfo locationInformation = loggingEvent.LocationInformation;
        writer.WriteStartElement(mElmLocation);
        writer.WriteAttributeString("class", locationInformation.ClassName);
        writer.WriteAttributeString("method", locationInformation.MethodName);
        writer.WriteAttributeString("file", locationInformation.FileName);
        writer.WriteAttributeString("line", locationInformation.LineNumber);
        writer.WriteEndElement();
    }
    writer.WriteEndElement();
}

Come potete vedere tutto si svolge nel metodo FormatXml, dove è possibile aggiungere, rimuovere e leggere alcune informazioni. Nella prima parte vado ad inserire le informazioni inerenti il contesto web, quindi la url richiesta, il rawurl, useragent, etc, mentre più avanti renderizzo tutte le informazioni del Dictionary Data dell’eccezione.

Per poter utilizzare questa customizzazione è sufficiente specificare nel file di log4net la classe per il rendering delle informazioni, come mostrato di seguito:

<appender name="NHibernateFileLog" type="log4net.Appender.RollingFileAppender">
    <file value="Logs/nHibernate.txt" />
    <maximumFileSize value="1000KB" />
    <rollingStyle value="Size" />
    <maxSizeRollBackups value="5" />
    <layout type="Dexter.Shared.Log.Log4Net.XmlLayout">
    </layout>
</appender>

Chi è interessato all’implementazione completa del XmlLayout può guardare qui.

Ciauz

This entry was posted on Tuesday, 09 March, 2010 and is filed under .NET . You can follow any responses to this entry through here . You can leave a response.