EF6.1: Delay between query completed and connection close

Question

We are using EF6.1 and dotConnect for Oracle.

Trying to debug why our development performs poorly in one of customers server, I turned on the DatabaseLogger Interceptor feature to get the queries executed in DB and try to improve them. One thing I've found is that in some queries there is some delay of seconds between the query has been executed and the connection has been closed. For example:

Connection opened at 17/06/2014 9:47:42 +02:00
SELECT 
    "top". (...)
FROM ( SELECT 
    "Project1". (...)
    FROM ( SELECT 
        "Extent1". (...)
        "Extent2". (...)
        FROM  (...)
        WHERE (...)
    )  "Project1"
    ORDER BY (...)
)  "top"
WHERE  ROWNUM <= 1

-- p__linq__0: '589' (Type = Int32, IsNullable = false)
-- Executing in 17/06/2014 9:47:43 +02:00
-- Completed in 288 ms with result: aj

Connection closed at 17/06/2014 9:47:51 +02:00

As you can see, there's a delay of many seconds. This query is runned many times, but the delay does not appear in every instance, others just have 2 or 3 seconds of delay, and others just none.

I don't really know where to begin to investigate. Is it something related to EF or to dotConnect Oracle? What job is done after the query has been executed and the connection closed?

EDIT: This is the code I'm using to retrieve the info from DB:

var users = db.USUARIO
    .Where(x => x.COORDENADA.Any(c => c.LATITUD != 0 && c.LONGITUD != 0))
    .OrderBy(x => x.NOMBRE).AsQueryable();

(...)

var list = users.ToList()
           .Select(x => new
            {
                Usuario = x,
                LastCoord = db.COORDENADA
                    .Include(c => c.TIPO)
                    .Where(c => c.USUARIOID == x.USUARIOID && c.LATITUD != 0 && c.LONGITUD != 0)
                    .OrderByDescending(c => c.FECHAHORAPDA)
                    .ThenBy(c => c.TIPO.RUTA).FirstOrDefault()
            })
            .Select(x => new ListItem
            {
                ID = x.LastCoord.COORDENADAID,
                Marcadores = new List<COORDENADA>(new[] { x.LastCoord }),
                Principal = x.Usuario.NOMBRE.ToTitleCase(),
                Inferior1 = x.LastCoord.FECHAHORAPDA.ToString("dd/MM HH:mm"),
                Color = x.LastCoord.TIPO.COLOR
            });

The db.COORDENADA... is the query I exposed before.

After you run this query, are you disposing of the DbContext straight away, or is this being disposed of after some other processes run? It could be that this is being prevented which is holding the connection open. — Lyise, Jun 17 '14 at 08:42
I've added some code to show how the query is generated. As this is executed in a MVC Controller, the context is created on Controller creation and disposed in the Dispose() method — Farlop, Jun 17 '14 at 08:59
In which dispose method? You should wrap this operation inside a using block, to warranty that the context is disposed of as soon as possible. Please, translate the log in your question: seguramente la mayoría de la gente no lo entiende ;) — JotaBe, Jun 17 '14 at 09:05
Log translated :). As in every MVC Controller generated using the Scaffolding templates, the DbContext is declared as a class variable and instantiated upon creation: DbEntities db = new DbEntities(); .Then, when the request has finished, the dispose method for the controller is executed, which has been overrided in class definition to dispose the context: protected override void Dispose(bool disposing) { db.Dispose(); base.Dispose(disposing); } — Farlop, Jun 17 '14 at 09:19

EF6.1: Delay between query completed and connection close

0 Answers0