Entity Framework: logging

I use EF4 CTP5 and I’d like to log ANY!!! SQL commands sent to the DB. You can use the method ToTraceString() to display the SQL commands of any ObjectQuery, but … you are not able to see the queries generated i.e. while saving changes OR lazy loading. You need to use i.e. EFProfiler to log it. EFProfiler is very cool tool but … I need to log it by my application.

So I found out the Tracing and Caching implementation by Jaroslaw Kowalski here which extends EF with tracing/logging and caching capabilities. The main disadvantages I found out are:
a) you need to you both! features otherwise logging/tracing will not work. I wanted to use only logging! After doing so I started to get strange exception (or I had to do something wrong). After enabling also tracing, it started to work. Shame because I needed to use ONLY tracing.
b) your Context classes HAS to be derived from his special classes.

Honestly, I don’t use this solution. It’s too much work.

MS guys, I’m sorry but I must say: IT’S BIG SHAME EF WAS NOT DEVELOPED IN EASY EXTENSIBLE MANNER with i.e. ServiceLocator, interceptors, etc. in place.

As far as I know, and correct me if I’m wrong, adding logging capabilities fits to AOP interceptors.

I.e. EFProfiler has quite hardly injects itself into creating new DB connection logic and then it has a capability to log everything. Their solution is more transparent than a by Mr. Kowalski.

My solution
I used the ideas from NHProfiler and I generalized it little bit. I made base AOP filter called IAopFilter.

public interface IAopFilter

    {

        void CommandDurationAndRowCount(Guid connectionId, long milliseconds, int? rowCount);

        void ConnectionDisposed(Guid connectionId);

        void ConnectionStarted(Guid connectionId);

        void DtcTransactionCompleted(Guid connectionId, TransactionStatus status);

        void DtcTransactionEnlisted(Guid connectionId, IsolationLevel isolationLevel);

        void StatementError(Guid connectionId, Exception exception);

        void StatementExecuted(Guid connectionId, Guid statementId, string statement);

        void StatementRowCount(Guid connectionId, Guid statementId, int rowCount);

        void TransactionBegan(Guid connectionId, System.Data.IsolationLevel isolationLevel);

        void TransactionCommit(Guid connectionId);

        void TransactionDisposed(Guid connectionId);

        void TransactionRolledBack(Guid connectionId);

    }

Due to the short of the time, I made only 1 its implementation and it was using Log4Net capabilities. Then I had to create AOP capable DbProviderFactory class called DbProviderFactoryEx which uses IAopFilters. In addition I had to create whole family of the classes following abstract factory pattern implemented in DbProviderFactory.

The main class is called EntityFrameworkExtender. This class wires-up AOP capabilities into EF. You just need to call:
EntityFrameworkExtender.Initialize();

The class by default uses Log4NetFilter as only the one filter but you can freely configure it.

EntityFrameworkExtender.Filters = () => new[] {new Log4NetFilter(“MyClass”)};

            EntityFrameworkExtender.Initialize();

Using it you are able transparently trace/log every SQL command sent from EF to DB.

I think, we, EF users would profit very much IF the EF team would develope the framework on enterprise level – easily extensible, configurable and if we could get also the unit tests! together with the framework.

[UPDATED!]
I bundled the whole source code into 1 project. The whole source code can be found here – save it as a file to the local disk  and delete .doc extension. It’s  normal zip file.
To use it you will need: log4net 1.2.10.0, EF4 CTP5, .NET 4.0

Entity Framework: Problem/Solution of default connection closing !

I use EF CTP5 on my last project together with NCommon and its UnitOfWork, Repositories, IoC and DI abstracted by MS P&P team and StructureMap as the concrete implemetation of IoC and DI.

Problem :
Let’s have the following example (I took the example from the NCommon unit tests and extend it to do the same Linq query twice):

using (var scope = new UnitOfWorkScope())

{

    var repository = new EFRepository<User>();

 

    User user;

    user = repository.Where(u => u.ComsiID == "login").FirstOrDefault();

    user = repository.Where(u => u.ComsiID == "login").FirstOrDefault();

 

}

 

Just for the completion: creating new UnitOfWorkScope starts the DB transaction. In the above example, using UnitOfWork we create and start the transaction. Then we create new EFRepository instance which creates the ObjectContext. ObjectContext uses the connection identified by the same name AppDb and handles the connection on its own. Then we query the DB. EF opens the connection (this implies that the connection is enlisted into the current running transaction), reads the data and then close the connection. Fine! But then next (in this demo case) same query does the same: opens the connection. Because we run inside the transaction, so the connection is also enlisted into the transaction. And because there was already enlisted connection the transaction mechanism propagates it into DTS.

The result of the above code is that it works and sometimes not! The exception is following:
System.Data.EntityException: The underlying provider failed on Open.
---> System.InvalidOperationException: The connection object can not be enlisted in transaction scope.


THE PROBLEM IS IN ENTITY FRAMEWORK!!!!! and the result of the test depends on the underlying DB. If you use SQLExpress edition (as is used by default in NCommon unit tests), everything works fine! SQLExpress can not elevate the transaction to MS DTC. But if you change the connection to the real SQL server you starts to have the problems.

The problem is that in case you don’t send the concrete connection instance to EF, EF handles the connection status on his own => closes as soon as possible. I understand it but in case of Transaciton is fails! It would be good to have there a switch to configure that behavior. Anyway, the reality is different so how to fix it.

The solution is to manage the connection by your own and while creating the ObjectContext pass already created and open connection. You can find many examples about it on the internet.

Hm, fine but … not so nice. You need manually on all places where ObjectContext, or your class derived from ObjectContext, is used to manage the connection

With NCommon and it’s configuration capabilities you can do the following:

NCommon.Configure.Using(adapter)

    .ConfigureData<EFConfiguration>(config => config.WithObjectContext(

        () =>

        {

            AppDb db = new AppDb();

            if (Transaction.Current != null)

            {

                db.Connection.Open();

            }

            return db;

        }))

.ConfigureUnitOfWork<DefaultScopeUnitOfWorkConfiguration>();

 

 

So you don’t need to do open the connection over and over and on different places. Just configure NCommon on one place and use it. That’s the power of the centralized factory code-enabled configurations. In this case, thanks to StructureMap and NCommon!

---

Here is my full unit test class (using MS Tests):

[TestClass]

    public class SimpleTests

    {

        public IServiceLocator MyServiceLocator;

 

        [TestInitialize]

        public void Setup()

        {

            var _state = new FakeState();

            var _unitOfWorkFactory = new EFUnitOfWorkFactory();

            var _connectionString = ConfigurationManager.ConnectionStrings["AppDb"].ConnectionString;

            _unitOfWorkFactory.RegisterObjectContextProvider(

                () =>

                        {

                            var ctx = new AppDb(_connectionString);

                            if (Transaction.Current != null)

                            {

                                ctx.Connection.Open();

                            }

                            return ctx;

                        });

            var _locator = MockRepository.GenerateStub<IServiceLocator>();

            _locator.Stub(x => x.GetInstance<IUnitOfWorkFactory>()).Return(_unitOfWorkFactory);

            _locator.Stub(x => x.GetInstance<IState>()).Do(new Func<IState>(() => _state));

            ServiceLocator.SetLocatorProvider(() => _locator);

        }

 

        [TestCleanup]

        public void Cleanup()

        {

        }

 

        [TestMethod]

        public void Can_perform_simple_query()

        {

                using (var scope = new UnitOfWorkScope())

                {

                    var repository = new EFRepository<User>();

 

                    User user;

                    user = repository.Where(u => u.ComsiID == "a").FirstOrDefault();

                    user = repository.Where(u => u.ComsiID == "a").FirstOrDefault();

 

                }

        }

I must again say, NCommon and StructureMap rocks!

Happy coding…

NCommon: read-only operations = Unit Of Work without DB transaction

Using NCommon I found one feature which can be an issue in some cases.

Repository can ONLY be used when you started an unit of work around it. Example:

using (var scope = new UnitOfWorkScope())

            {

                var savedCustomer = new EFRepository<Customer>()

                    .First(x => x.CustomerID == customer.CustomerID);

                scope.Commit();

            }

When new unit of work is created then it automatically starts the database transaction in the mode ReadCommited. Issue is that in case I need ONLY to read a data then I think, it’s too heavy. In other words why to pay the performance costs of creating a transaction when I want only to read the data from DB. In the default NCommon implementation this wouldn’t work:

var savedCustomer = new EFRepository<Customer>()

                    .First(x => x.CustomerID == customer.CustomerID);

I think it would be good avoid creating the DB transactions in case of read-only queries. It’s quite generic/DB-provider independed functionality so it fits into the base NCommon Repository classes. Unfortunatelly, I didnt want to change the base classes because in case new NCommon is releases and I changed the core functionality then I need to be in sync with latest NCommon verions. So I created my derived implementation for Entiry Framework v4. If there is no unit of the work created I create a single call unit of work without any transaction. Again, I think the change should be in the base NCommon classes but I wanted to stay compactible with the base classes as much as possible so I changed only the concrete Repository implementation for Entity Framework.

So using my changes the previous example works!

What do u think?

The changed NCommon for EFv4 can be found here

EFv4 with Repository and UnitOfWork pattern, IoC, DI

Entity Framework itself implements unit of work pattern in form of the ObjectContext class. That’s fine but it has the following main disadvantages:
a) if you will use it from your business layer then you will be very tightly connected to the concrete DB layer implementation (in this case Entity Framework)
b) it will be much harder or impossible to do TDD.

It’s good practice to wrap the data access logic using Repository pattern. In other words it’s good to use the Repository pattern in order to abstract out/decouple the business layer from the data access layer. Fine, there is one Repository patter definition but many implementers and you can implement it also by your own. The basic idea is the same but many slightly different implementations.

When you work on different projects developed by the different people it’s good to establish enterprise-wide implementation of any common patterns/areas. Additionaly, it would be better if ti would be world-wide known implementation. So that’s NCommon which you can find on ncommon.codeplex.com.

NCommon provides, we could say, abstraction of the common programming areas like Repository, UnitOfWork, Guards, States, etc. In this entry I’ll focus on Repository.

NCommon provides the abstract Repository implementation – independent from any specific/concrete DB access implementation PLUS it contains implementations for Entity Framework, NHibernate, Db4O, etc. All specific implementations are located in its own projects. The advantage is that you can use out of the box implementation of your favorite implementation.

In addition, the base abstract Repository class offers LINQ provider on Class Level, not property level. Honestly, I like it ;o). Here is a sample:

using (var scope = new UnitOfWorkScope())

{

    var savedCustomer = new EFRepository<Customer>()

        .First(x => x.CustomerID == customer.CustomerID);

    scope.Commit();

}

 

In addition the base NCommon Repository classes are tightly connected with UnitOfWork pattern which is also abstracted into NCommon in form of UnitOfWork classes. You can get it also out of the box together with the different DB access specific implementations!

The unit of work implementation IS NOT ONLY 1 CONNECTION specific but spreads over different repositories and over different DB connections (if it’s your case). In other words, you can have i.e. a users repository implemented by NHibernate and connecting to UsersDB and OrdersRepostory implemented via EntiryFramework connecting to OrdersDB and the following example works:

In other words, one connection transaction will be elevated to the distributed transaction transparently and automatically. I like it! It seems to me really robust.

ALL is supported by standard service locators implemented by Microsoft Patterns and Practices team and with the NUnit tests!

I think, NCommon is really cool set of classes which collects the common aspects you will face while development. It’s really worth studying it! Here is a list of the links you can use:

• http://code.google.com/p/ncommon/
• http://www.codeinsanity.com/search/label/NCommon

Anyway, cool way how to check the latest library description is to look at the unit tests from GitHub.

Happy common coding !