Unable to make .NET LINQ logging to work

[crazypit]

Hello,

I’m trying to make the .NET LINQ SQL logging feature to work but i can’t. I use the sample code presented in the What’s New page for version 3.

I need to use the feature in a WCF architecture where all clients get database access through Service functions. In each function, i create and dispose a DataContext object.
e.g.

public int? ValidateCredentials(string UserName, string Password, out List AllPermissions,
out List UserPermissions, out User user)
{
AllPermissions = null;
UserPermissions = null;
user = null;

        ExrayDataContext dataContext = null;

        try
        {
            dataContext = new ExrayDataContext(DBConnectionString);
            dataContext.ObjectTrackingEnabled = false;

            AllPermissions = new List<string>();
            UserPermissions = new List<string>();

            User objUser =
                User.ClientsService_ValidateCredentials(dataContext, UserName,
                                                        Convert.ToBase64String(Encoding.ASCII.GetBytes(Password))).SingleOrDefault();
            if (objUser == null) return 1;

            if (SiAuto.Si.GetSession(UserName) == null) SiAuto.Si.AddSession(UserName, true);
            dataContext.Log = new SmartInspectLinqToSqlAdapter(SiAuto.Si.GetSession(UserName))
                                  {TitleLimit = 0, TitlePrefix = "ValidateCredentials"};

            List<Permission> objPermissions = Permission.ClientsService_ValidateCredentials(dataContext, objUser.Id).Distinct().ToList();

            foreach (Permission permission in objPermissions)
            {
                UserPermissions.Add(permission.ObjectId + "_" + permission.ObjectType + "_" +
                    permission.Type.ToUpper() + (permission.Path == null ? "" : "^" + permission.Path));
            }

            foreach (Permission permission in dataContext.Permissions)
            {
                AllPermissions.Add(permission.ObjectId + "_" + permission.ObjectType + "_" +
                    permission.Type.ToUpper() + (permission.Path == null ? "" : "^" + permission.Path));
            }

            user = objUser;
            return 0;
        }
        catch (Exception exc)
        {
            HandleException(UserName, exc);
            return null;
        }
        finally
        {
            if (dataContext != null) dataContext.Dispose();
        }
    }

Do i have to do something more? What is the purpose of Write & WriteLine methods? Aren’t all the LINQ queries automatically written to log?

I use file logging. Even if i can get the LINQ SQL logging to work, to what level are these statements logged? I really need to enable them only for Debug level.

[crazypit]

Permission.ClientsService_ValidateCredentials is a call to a CompiledQuery delegate.

[crazypit]

I don’t know if this is relevant but the DataContext i use, is NOT the Microsoft implementation. It comes from Devart and i use it to connect to an Oracle database. Nevertheless, their classes are heavily based on the Microsoft implementation and have nearly the same contract with some extensions.

[tgurock]

Hello,

Is the Si object properly configured and enabled?

I don’t know if this is relevant but the DataContext i use, is NOT the Microsoft implementation.

This may be relevant in case your custom DataContext implementation does not use the Log property to write out the sql statements. I’m not familiar with the internals of DataContext or requirements to implement this class, so it may be that your custom class does not use the Log feature. You could try to use the following simple SmartInspect for LINQ example to check if its generally working for you:

http://blog.gurock.com/postings/linq-logging-with-smartinspect-30/328/

If it does, you could try it with your custom DataContext class and see it if still works.

Regards,
Tobias

[crazypit]

Hello,

Everything about the SmartInspect module is properly configured. The application is already full of logging statements and i’ve extensively used almost all of the supplied features. I just recently read about the LINQ SQL logging feature and decided to add it. In fact, if i insert a LogDebug statement somewhere in the aforementioned function code, information is properly registered to the file.

Log implementation of the Devart provider is the same as in the Microsoft one and used in exactly the same way. Let me quote to you the relevant info from the help file:

“Use the Log property of the DataContext class to output SQL statements generated by LinqConnect. Assign any TextWriter descendant to it, and SQL statement will be logged by this TextWriter. For example you may assign Console.Out or Debug.Out TextWriter to it, or StreamWriter that writes to the file.”

[tgurock]

Thanks for the additional information. Have you also tried reproducing this behavior in the minimal example?

http://blog.gurock.com/postings/linq-logging-with-smartinspect-30/328/

It’s probably the easiest way to isolate the problem. I will also take another look at the SmartInspectLinqToSqlAdapter and figure out what might be going wrong.

Regards,
Tobias

[crazypit]

I really don’t see any point in testing the sample code or the conclusions that can be derived from the result. My function code is also pretty simple and practically the same.

I’ll try to define the characteristics of my test case and maybe you can help:

1). Gurock.SmartInspect.LinqToSql.dll is properly referenced and copied to the application directory.
2). Console View is checked and no Filters are applied.
3). A LogDebug statement is present in the body of the function and the relevant information is properly logged in the sil file.
4). Log property of the Devart Datacontext class seems to have the same implementation to the one provided by Microsoft. The relevant documentation entry is already mentioned in this thread.
5). “Append in File” SmartInspect Connection as well as Pipe Connection are configured through code and not through sic file.
6). new SmartInspectLinqToSqlAdapter object is properly assigned to Log property and no error occurs.

[tgurock]

I will try to test the SmartInspectLinqToSqlAdapter against the Devart DataContext class. Which particular Devart product do you use?

You could also try to attach a standard StreamWriter to db.Log instead of using the SmartInspectLinqToSqlAdapter and see if the data is logged correctly in this case. If so, it may be related to the SmartInspectLinqToSqlAdapter implementation.

For example:

[code]…

var log = new StreamWriter(“c:\Dev\linq.txt”);

using (log)
{
using (var db = new TestRailDataContext())
{
db.Log = log;
var query = from s in db.suites select s;
return query.ToList();
}
}

…
[/code]

Regards,
Tobias

[crazypit]

Odd result:

Using the StreamWriter to a file, nothing is written. The file is created but is empty. I have all the relevant privileges to open and write to the file.

Nevertheless, my application (in today’s form) is a console application so i assigned the Log property to the Console.Out and everything worked!

I will open a ticket in their forum in order to examine the situation.

Can you think of anything else about the issue?

[tgurock]

Are you closing the file (explicitly or by putting it into a using statement)? StreamWriter buffers the data until it reaches a certain amount or until it is flushed/closed.

Also, which product of Devart do you use so that I can try to reproduce the issue here with their custom DataContext class?

Thanks,
Tobias

[crazypit]

Oops,

That is correct! When i flushed the Log, everything worked as expected for the StreamWriter. Nevertheless, the SmartInspectLinqToSqlAdapter still does not work.

You can download a demo version of LinqConnect product from http://www.devart.com/linqconnect/download.html.

[tgurock]

Thanks for the link. I installed the product and will try to reproduce the behavior. Hopefully I will have some results by tomorrow at the latest.

Regards,
Tobias

[tgurock]

So, this was quicker than I thought, but here are the first results. The problem/difference with the implementation of Devart’s DataContext is that it does not provide some kind of “end-of-message” line/indication. The DataContext implementation of Microsoft always sends a special SQL comment at the end of the message as you can see in this screenshot:

http://blog.gurock.com/wp-content/uploads/2008/07/linq-to-sql.png

Some background information: A single SQL query/statement is not passed to the Log object in one method call but the DataContext class usually calls the WriteLine method multiple times. Since the SmartInspectLinqToSqlAdapter cannot just write each line to the Console (because you want the SQL query in one single log message) it needs to buffer the WriteLine calls and sends a combined log message when a query was completely logged:

[code]public override void Write(string value)
{
this.fText.Append(value);
this.fText.Append(Environment.NewLine);

if (value.StartsWith(CONTEXT_PREFIX))
{
    string sql = fText.ToString();
    this.fSession.LogSql(FormatTitle(sql), sql);
    this.fText.Length = 0; /* Reset buffer */
}

}
[/code]

This is easy to do with the Microsoft implementation because it always calls the Log object with a special line to end a SQL query (as you can see in the code above). At a first glance, I unfortunately found no way to accomplish this with the Devart provider though.

Regards,
Tobias

[crazypit]

I understand the problem.

Allow me to say that the method of checking the line that starts with “Context” string in order to buffer the complete SQL statement, seems a little bit awkward. At first, the relevant string is possible to change in further implementations of LINQ to SQL by Microsoft. At second, your library is probably not compatible with any other LINQ implementation.

Nevertheless, i also understand that you need to buffer the lines and write the complete SQL statement in a nice and meaningful way.

Let me propose an other solution. You can check for SELECT, INSERT, UPDATE strings on the next statement and flush the previous buffer data and statement whenever these are encountered. The last statement and buffer data can be flushed when the adapter object goes out of scope and is disposed and/or when a special method is called.

I know that this is not the best solution to the problem. I will try to convince Devart to provide an end-of-SQL-statement indicator like an “;”. Nevertheless, i truly believe that Gurock & Devart can work better on this in order to provide the best support and solution to your customers.

[tgurock]

Good point and I agree that this is not a universal solution. However, just checking for SELECTS etc. would be equally problematic because of nested/inner selects and similar issues. To make this work correctly in all cases, we would probably need to implement a full SQL parser (that also supports all flavors of SQL) and this would be both very complicated and a bit slow.

We’ve just started http://code.gurock.com/ and I think the Linq to SQL adapter would be a good addition, so that we and other users can make changes to the code (without waiting for a new SmartInspect release).

It would be great if Devart could add some kind of end-of-statement indicator (such as a special comment) so it would work better with tracing/logging tools.

Regards,
Tobias

[crazypit]

I’ll try to convince Devart to provide the same “context” indicator as in the Microsoft implementation.

Thanks for you effort!

[crazypit]

For your information, i managed to convince Devart to include the same end-of-line indicator as in the Microsoft implementation and now everything works as expected for dotConnect for Oracle product version 5.70.152 and above and LinqConect product version 1.0.39 and above.

[tgurock]

Great to hear that you got Devart to change the logging behavior and that it works for you now. Thanks for the update and have a nice week!

Regards,
Tobias