Entity Framework Null Reference When Adding New Record

Question

I currently have a project that uses Entity Framework 4.1 for logging to a database so we can track the web application which is deployed on more than one web server. I built it using Scott Gu's Code First solution.

So, I have code like this:

logging.Logs.Add(newLog);

which is sometimes throwing this error:

System.NullReferenceException : Object reference not set to an instance of an object. at System.Data.Objects.ObjectStateManager.DetectConflicts(IList1 entries) at System.Data.Objects.ObjectStateManager.DetectChanges() at System.Data.Entity.Internal.Linq.InternalSet1.ActOnSet(Action action, EntityState newState, Object entity, String methodName) at System.Data.Entity.Internal.Linq.InternalSet1.Add(Object entity) at System.Data.Entity.DbSet1.Add(TEntity entity)

Most of the time it works fine, but it will hiccup now and then. Is there a best practice I should be aware of when I have more than one server using this code to access/write to the same database?

The approach used right now is that each request causes the system to add several new log objects into the collection and then save a grouping of them, rather than save each individual log record. Here's an outline of my class.

public class LoggingService : ILoggingService
{
    Logging.Model.MyLogging logging;

    public LoggingService()
    {
        InitializeLog();
    }

    /// <summary>
    /// Save any pending log changes (only necessary if using the Add methods)
    /// </summary>
    public void SaveChanges()
    {
        //ensure that logging is not null
        InitializeLog();

        logging.SaveChanges();
    }

    #region Private Methods
    private void InitializeLog()
    {
        if (logging == null)
            logging = new Model.MyLogging();
    }

    private void Log(Level level, int sourceId, string message, bool save, int? siteId = null, int? epayCustomerId = null, 
        string sessionId = null, int? eventId = null, Exception exception = null)
    {
        if (sourceId == 0)
            throw new ArgumentNullException("sourceId", "The Source Id cannot be null and must be valid.");

        var source = (from s in logging.Sources
                     where s.SourceId == sourceId
                     select s).FirstOrDefault();

        if (source == null)
            throw new ArgumentNullException("sourceId", String.Format("No valid source found with Id [{0}].", sourceId));

        if (eventId.HasValue)
        {
            if (eventId.Value > 0)
            {
                var code = (from e in logging.Events
                            where e.EventId == eventId.Value
                            select e).FirstOrDefault();

                //if event id was passed in but no event exists, create a "blank" event
                if (code == null)
                {
                    Event newCode = new Event()
                    {
                        EventId = eventId.Value, 
                        Description = "Code definition not specified."
                    };

                    InitializeLog();
                    logging.Events.Add(newCode);
                    logging.SaveChanges();
                }
            }
        }

        var newLog = new Log()
        {
            Created = DateTime.Now,
            Message = message,
            Source = source,
            Level = level,
            EventId = eventId,
            SessionId = sessionId,
            SiteId = siteId,
            MachineName = System.Environment.MachineName,
        };

        if (exception != null)
            newLog.Exception = String.Format("{0}{1}{2}{1}", exception.Message, Environment.NewLine, exception.StackTrace);

        //ensure that the logging is not null
        InitializeLog();

        logging.Logs.Add(newLog);

        if (save)
        {
            logging.SaveChanges();
        }
    }

    #endregion

}

I am using IoC with StructureMap, and I did not initialize this class as a singleton.

For<ILoggingService>().Use<LoggingService>();

And my context class looks like this:

internal class MyLogging : DbContext
{
    public DbSet<Source> Sources { get; set; }
    public DbSet<Event> Events { get; set; }
    public DbSet<Log> Logs { get; set; }

    /// <summary>
    /// DO NOT ADD ITEMS TO THIS COLLECTION
    /// </summary>
    public DbSet<LogArchive> LogArchives { get; set; }

    protected override void OnModelCreating(DbModelBuilder modelBuilder)
    {
        Database.SetInitializer(new MyDbContextInitializer());

        modelBuilder.Entity<Event>().Property(p => p.EventId)
            .HasDatabaseGeneratedOption(DatabaseGeneratedOption.None);

        modelBuilder.Entity<Source>().Property(p => p.SourceId)
            .HasDatabaseGeneratedOption(DatabaseGeneratedOption.None);

        modelBuilder.Entity<LogArchive>().Property(p => p.LogId)
            .HasDatabaseGeneratedOption(DatabaseGeneratedOption.None);

        base.OnModelCreating(modelBuilder);
    }

    //public class MyDbContextInitializer : DropCreateDatabaseIfModelChanges<MyLogging>
    public class MyDbContextInitializer : CreateDatabaseIfNotExists<MyLogging>
    {
        protected override void Seed(MyLogging dbContext)
        {
            // seed data

            base.Seed(dbContext);
        }
    }
}

I'm probably doing something obviously wrong, but I just don't see it.

EDIT: As requested, here is a sample of how I call the logging service code. This particular method is logging information related to the HTTP Request. I append the the log items in one try catch and save in a separate try catch so if there is an issue it will at least save the additions that took. The handler is another service injected into this class through IoC that sends the details of the error to me via e-mail.

A single post to the server could log as many as 50-70 separate details separated into chunks of 10-15 (http request, data sent to a web service, result of the web service call, response back to the client), which is why I want to add a grouping and then save the grouping, rather than open and close a connection with each individual item.

public void LogHttpPostStart(HttpPostRequest request)
{
        try
        {
            //if no session is set, use the ASP.NET session
            request.SessionId = GetSessionId(request.SessionId);
            int eventId = (int)Model.Enums.Logging.Event.SubmittedByClient;

            var current = HttpContext.Current;

            if (current != null)
            {
                logService.AddDebug((int)request.Source, String.Format("{0}  HTTP Request Details  {0}", Header2Token.ToString().PadRight(HeaderTokenCount, Header2Token)),
                    siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                    eventId: eventId);

                //Server Information
                logService.AddDebug((int)request.Source, String.Format("Machine Name: {0}", current.Server.MachineName),
                    siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                    eventId: eventId);

                //User Information
                logService.AddDebug((int)request.Source, String.Format("User Host Address: {0}", current.Request.UserHostAddress),
                    siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                    eventId: eventId);
                logService.AddDebug((int)request.Source, String.Format("User Host Name: {0}", current.Request.UserHostName),
                    siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                    eventId: eventId);

                //Browser Information
                if (current.Request.Browser != null)
                {
                    logService.AddDebug((int)request.Source, String.Format("Browser: {0}", current.Request.Browser.Browser),
                        siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                        eventId: eventId);
                    logService.AddDebug((int)request.Source, String.Format("Browser Version: {0}", current.Request.Browser.Version),
                        siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                        eventId: eventId);
                    logService.AddDebug((int)request.Source, String.Format("User Agent: {0}", current.Request.UserAgent),
                        siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                        eventId: eventId);
                    logService.AddDebug((int)request.Source, String.Format("Is Mobile Device: {0}", current.Request.Browser.IsMobileDevice.ToString()),
                        siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                        eventId: eventId);

                    if (current.Request.Browser.IsMobileDevice)
                    {
                        logService.AddDebug((int)request.Source, String.Format("Mobile Device Manufacturer: {0}", current.Request.Browser.MobileDeviceManufacturer),
                            siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                            eventId: eventId);
                        logService.AddDebug((int)request.Source, String.Format("Mobile Device Model: {0}", current.Request.Browser.MobileDeviceModel),
                            siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                            eventId: eventId);
                    }

                    logService.AddDebug((int)request.Source, String.Format("Platform: {0}", current.Request.Browser.Platform),
                        siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                        eventId: eventId);
                    logService.AddDebug((int)request.Source, String.Format("Cookies Enabled: {0}", current.Request.Browser.Cookies.ToString()),
                        siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                        eventId: eventId);
                    logService.AddDebug((int)request.Source, String.Format("Frames Enabled: {0}", current.Request.Browser.Frames.ToString()),
                        siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                        eventId: eventId);

                    if (current.Request.Browser.JScriptVersion != null)
                    {
                        logService.AddDebug((int)request.Source, String.Format("Javascript Version: {0}", current.Request.Browser.JScriptVersion.ToString()),
                            siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                            eventId: eventId);
                    }

                }

                logService.AddDebug((int)request.Source, String.Format("{0}  End HTTP Request Details  {0}", Header2Token.ToString().PadRight(HeaderTokenCount, Header2Token)),
                    siteId: request.SiteId, epayCustomerId: request.EPayCustomerId, sessionId: request.SessionId,
                    eventId: eventId);
            }
        }
        catch (Exception ex)
        {
            handler.HandleError(true, ex);
        }

        try
        {
            logService.SaveChanges();
        }
        catch (Exception ex)
        {
            handler.HandleError(true, ex);
        }
    }

SQL Server? Or another DB and provider? Why do you have all these `InitializeLog` calls all over the place? You initialize the context in the constructor, isn't this enough? If you would really create a new context in your `SaveChanges` method and then immediately call `SaveChanges` of that context, nothing would happen because the context is empty. I'd prefer to let the application crash if the context is `null` because it's likely that something is wrong then. If you create silently a new context you miss perhaps an important error. — Slauma, Oct 17 '11 at 20:04
Sql Server 2008 R2. Thanks for the pointers. I'll get that cleaned up. — Josh, Oct 18 '11 at 13:07

score 1 · Accepted Answer · edited May 23 '17 at 12:10

1

The first problem is that you are keeping open your DbContext during the application. The best practice is to only instantiate it when needed and then dispose it. But the bigger problem here is that you use your LoggingService in a multithreaded enviroment (if I understood it correctly) but DbContext is NOT thread safe. See this SO question and also the comments on ScottGu's post (search for the word thread). So you should keep your log entries around in a thread safe way somewhere else not in the DbContext and only open a DbContext when you want to access the DB.

+1 Instead of the InitializeLog() method check out System.Lazy<T>

edited May 23 '17 at 12:10

Community

1
1

answered Oct 17 '11 at 19:50

nemesv

138,284
16
416
359

I don't see where I am violating thread safety. The IoC container does not create a singleton, so it is not shared across all threads of the application. The DBContext is a private instance variable that stays open for the life of the class. The context, as stated in http://msdn.microsoft.com/en-us/library/bb896325.aspx opens and closes the connection to the database automatically. I ran a query and I only have one connection per web server open, which is desired. I want to be able to add multiple records and save them all at once, so I cannot create and destroy my context on every call. – Josh Oct 18 '11 at 13:15
@Josh Ok I`ve missed the not singleton part. But the transient nature of the error - as you said: "is sometimes throwing this error" - still points to some concurency problem. Can you show us some sample code where you are using the `LoggingService`? – nemesv Oct 18 '11 at 13:36
@Josh Looking at the code I have no other idea right now. But you can still try to add your `Log` entities into a private List instance in the `LoggigService` and only add them to the context before you call `SaveChanges` (of course after the save clear the Log "buffer"). – nemesv Oct 18 '11 at 14:22

score 1 · Answer 2 · answered Oct 22 '11 at 00:46

Could be a bug in EF, could be a bug in your code, hard to tell. If you post your definitions of your entity classes maybe we can reproduce the problem otherwise it's really hard to see it. You could also try it by isolating your code and run the logging in an infinite loop with pseudo-random data until it happens again.

Few things though, if I may. You are a bit paranoid about the context being initialised in your logging service. If you initialise it in the constructor there is no way for it not to be initialised later. As you already are using a container why don't you have the context as a parameter to the constructor and let the container inject it for you. Your class is a Control-Freak(anti-pattern) basically.

    public class LoggingService : ILoggingService
    {
        Logging.Model.MyLogging logging;

        public LoggingService(MyLogging logging)
        {
            // check for null here
            this.logging = logging; 
            //no further null checks 
        }
        ....
     }

Further when you register the your components with the container set their lifecycle to be http request scoped.

For<ILoggingService>().HttpContextScoped().Use<LoggingService>();

Don't forget to destroy the objects at the end of request if you do this:

protected void Application_EndRequest()
{
    ObjectFactory.ReleaseAndDisposeAllHttpScopedObjects();
}

This way you get fresh set of objects for every request that also get properly disposed at the end.

Entity Framework Null Reference When Adding New Record

2 Answers2