Multi Tenant Logging in log4net

Question

I am a bit surprised this question hasn't been asked more before. The only relevant topic that I could find is this one.

My tenant strategy on database level is shared database / separate schemas. I want logging to be on tenant level, so each tenant will have its own log table (= I am using a AdoNetAppender to log to the database).

Basically what I need is to resolve the tenant for every HTTP Request that comes into my ASP.NET MVC / ASP.NET Web API application (both are hosted in the same project) and then order log4net to log to the tenant's database schema. I'm able to do both but I am starting to wonder if log4net was designed to support this scenario.

The key concept in this scenario is the HTTP request: every time log4net is called, it should uniquely set the schema without affecting the other users on other threads. But I'm not sure log4net is able to handle this. For the moment, I've gotten this far to achieve this:

public class MultiTenantAdoNetAppender : AdoNetAppender
{        
    protected override void Append(LoggingEvent loggingEvent)
    {     
        // Code to retrieve the tenant from the context omitted
        string tenant = "";
        this.CommandText = this.CommandText.Replace("[dbo]", string.Format("[{0}]", tenant));       
        base.Append(loggingEvent);
    }    
}

This works but I am fairly sure this will have some unwanted consequences. All requests go to the same logger via a singleton class (see code below). I am not familiar enough with the log4net's internal architecture to know if this is a feasible approach to ensure each request gets served independently from other tenants at the same. So in the code sample above, what happens if two users execute the this.CommandText = ... at the same time?

public class Singleton
{
    private Singleton()
    {
        if (this.Logger == null)
        {
            this.Logger = new Logger("Trace Logger");
        }            
    }

    public static Singleton Instance()
    {
        if (instance == null)
        {
            lock (syncRoot)
            {
                if (instance == null)
                {
                    instance = new Singleton();
                }
            }
        }
        return instance;
    }
    public ILogger Logger { get; set; }    
}

The ILogger interface is a custom wrapper around the log4net assembly:

private readonly ILog Log;
public Logger()
{
  this.Log = log4net.LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
}

With this approach I think the tenants will end up writing logs in each others schemas, resulting in logs from tenant A in the database schema of tenant B, etc. Are my suspicions correct about this?

Before I go write a custom logging component, are there any alternatives for multi tenant logging or does log4net provide a way to ensure my requirement?

You are correct: appenders are shared between loggers on different threads, so there is the possibility that one thread will change the `CommandText` while another thread is using it. Adding a lock around that code would remove that possibility and the logging would be OK, though you would want to make sure this didn't impact performance, as if you have many tenants and lots of logging, performance could be adversely affected by the lock. — stuartd, Feb 11 '16 at 22:41
.. other than that, this seems a promising way to do what you need. One thing I wonder, though, once you have replaced `dbo` in CommandText with say `tenant1` and then `tenant2` comes along expecting `dbo` - perhaps you should restore the schema after the logging event? — stuartd, Feb 11 '16 at 22:49
I have just read the question you linked to, and using one logger per tenant (like in the second example) would preclude the need to lock on the Append method - do you really need a singleton? — stuartd, Feb 11 '16 at 22:53
Restoring the schema wouldn't really be effective since it will be set to the right schema on every request, it would also increase the risk that the default schema is used to log when it shouldn't. I think the best way would be to instantiate a new object of the logging class on every request with the right parameters, so I'll need to step away from the singleton pattern when it comes to logging. Is there a way to dynamically create an appender and attach it to the log instance you think? — hbulens, Feb 11 '16 at 23:06

score 1 · Answer 1 · answered Sep 16 '16 at 12:50

Because appenders are shared, do not modify Append method. Modify internal AdoNetAppender SendBuffer method like this:

public class MultiTenantAdoNetAppender : AdoNetAppender
{

    override protected void SendBuffer(IDbTransaction dbTran, LoggingEvent[] events)
    {

        // run for all events
        foreach (LoggingEvent e in events)
        {
            // Code to retrieve the tenant from the context omitted
            string tenant = "";

            using (IDbCommand dbCmd = Connection.CreateCommand())
            {
                // Set the command string
                dbCmd.CommandText = this.CommandText.Replace("[dbo]", string.Format("[{0}]", tenant));

                // Set the command type
                dbCmd.CommandType = CommandType;
                // Send buffer using the prepared command object
                if (dbTran != null)
                {
                    dbCmd.Transaction = dbTran;
                }

                // Set the parameter values
                foreach (AdoNetAppenderParameter param in m_parameters)
                {
                    param.Prepare(dbCmd);
                    param.FormatValue(dbCmd, e);
                }

                // Execute the query
                dbCmd.ExecuteNonQuery();
            }
        }
    }
}

This will modify CommandText property for each Execute call. For faster logging, you must group events by tenant and create command for each tenant and reuse prepared command lite this:

override protected void SendBuffer(IDbTransaction dbTran, LoggingEvent[] events)
{
    // Code to retrieve the tenant from the context omitted
    string[] usedTenants = GetTenantsFromEvents(events);

    foreach (string tenant in usedTenants)
    {

        using (IDbCommand dbCmd = Connection.CreateCommand())
        {
            // Set the command string
            dbCmd.CommandText = this.CommandText.Replace("[dbo]", string.Format("[{0}]", tenant));

            // Set the command type
            dbCmd.CommandType = CommandType;
            // Send buffer using the prepared command object
            if (dbTran != null)
            {
                dbCmd.Transaction = dbTran;
            }
            // prepare the command, which is significantly faster
            dbCmd.Prepare();

            // run for all events for tenant, code for select omitted
            foreach (LoggingEvent e in GetEventsForTenant(events, tenant))
            {

                // clear parameters that have been set
                dbCmd.Parameters.Clear();

                // Set the parameter values
                foreach (AdoNetAppenderParameter param in m_parameters)
                {
                    param.Prepare(dbCmd);
                    param.FormatValue(dbCmd, e);
                }

                // Execute the query
                dbCmd.ExecuteNonQuery();
            }
        }
    }
}

Seems like the SendBuffer method is never called. Any configuration that might be necessary for this to work? — hbulens, Jun 12 '17 at 19:48

Multi Tenant Logging in log4net

1 Answers1