Ajarn Mark Caldwell Blog

Bringing Business Sense to the IT World…

Odd Profiler Results with EF4

I have been doing some testing of using the Microsoft Entity Framework 4 with stored procedures and ran across some really odd results in SQL Server Profiler.

The application that is running which uses Entity Framework 4 is a simple Web Application written in C#, and the Entity Data Model is actually contained in a referenced class library of its own.  I’ll write more about my experiences with this later.  For now the question is, why does SQL Profiler think that the stored procedure is running in Master, and not in my application database?

While analyzing the effects of using custom helper methods on my EDM classes to call the stored procedure, I decided to run Profiler while I stepped through the code so that I had a clear understanding of exactly when and what calls were made to the SQL Server.  I ran Profiler switching back and forth between the TSQL and TSQL_SP templates.  However, to reduce the amount of results rows I needed to wade through, I set a filter on DatabaseID to be equal to my application’s database.  Each time I ran this, the only thing that I saw was an Audit:Login to the database, but no procedure or T-SQL statements executed, yet I was definitely getting results back to my web page.  I tried other Profiler templates, still filtering on DatabaseID (tangent: I found, at least back in SQL 2000 Profiler, that filtering on DatabaseID was more reliable than filtering on DatabaseName.  Even though I’m now running SQL 2008, that habit sticks with me).  Still no results other than the Login.  Very weird!

Finally, I decided to run Profiler with no filtering and discovered that that lines which represent my stored procedure and its T-SQL commands are all marked with DatabaseID = 1, which is Master.  Why in the world would that be?  My procedure is definitely in the application database, and not in Master, and there is nothing funny about the call to the procedure evident in Profiler (i.e. it is not called as MyAppDB.dbo.MyProcName, but rather just dbo.MyProcName).  There must be something funny with the way the Entity Framework is wrapping this call, and I don’t like it…I don’t like it one bit.  My primary PROD server contains 40+ databases on it, and when I need to profile something, I expect to be able to filter based on DatabaseID (for the record, I displayed DatabaseName in my results, too, and it also shows Master).

I find the same pattern of everything except the Login showing up as being in Master when I run my version that uses standard LINQ to Entities instead of stored procedures, so that suggests it is not my code, but rather something funny with SQL Server 2008 Profiler or the Entity Framework.

If you have any ideas about why this might be so, please comment below.

UPDATE

Trying to isolate variables, I pushed the web application out to a test server with a fresh install of .NET Framework 4, and pushed the database to a few different servers.  I have test instances where the database and web server are on the same machine and some where they are on separate machines.  That distinction did not make any difference in the results.  But the interesting thing is that when the database resides on a SQL 2000 SP3 instance, then Profiler shows that the stored procedure is properly attributed to the application database ID, but when the database resides on a SQL 2008 SP1 instance, then Profiler shows that the stored procedure is attributed as if it were in Master.  I used the same instance of SQL 2008 Profiler for all tests, so this is not a discrepancy in the Profiler application itself, although it suggests that there may be something funny in the server that is being monitored.  Another variable which I have not yet ruled out is that the SQL 2008 instances are Developer Edition while the SQL 2000 instances are Enterprise Edition.  That should not matter, but it is a variable.

UPDATE #2

I have replicated the results using a simpler project where the Entity Data Model is directly part of the Web Application and not contained in a separate class library, and using straight LINQ to Entities and a connection string using a trusted connection as a member of System Administrators server role (previous tests were using SQLAuth with a variety of permissions levels).  Still getting the result that Profiler thinks the query is being executed in Master and not in the application database.

UPDATE #3

I have replicated the results on a SQL Server 2008 R2 instance, so this isn’t something that went away with any service pack update so far.  I have sent this to James Senior at Microsoft that I met at the Redmond WebCamp to see if he has any insight.

UPDATE #4

This issue has been posted to Microsoft Connect.  Also, I created a new web page that loops through several records and updates them.  Interestingly, all of the updates except for the first line item for the first update, show as occurring in the application database; but the SELECT and the initial RPC:Starting for the first update show as occurring in Master.  This information plus a trace file have been added to the Connect item. 

UPDATE #5

A work-around has been identified.

UPDATE #6 – FINAL

Microsoft has announced that they have a fix for this and that it will be coming in the next Cumulative Update. 

Legacy Comments


Jack Corbett
2010-06-03
re: Odd Profiler Results with EF4
Interesting to hear this. This would concern me as well. I am currently on a project using Linq to SQL which DOES NOT have this issue, so it has to be an EF issue. Keep us informed what you find.

AjarnMark
2010-06-03
re: Odd Profiler Results with EF4
Jack, what version of SQL Server are you running where LINQ to SQL does NOT have this issue? Is it SQL 2008 by any chance? In my update, you'll see that this problem doesn't exist for LINQ to Entities on SQL 2000. I haven't tested 2005 yet.

Thomas Williams
2010-06-03
re: Odd Profiler Results with EF4
Hey AjarnMark - long shot - what is the default database in your login on the different servers? In SQL 2008, under Security > Logins. What happens when you change the default database for the login? And what is your connection string from EF?

AjarnMark
2010-06-03
re: Odd Profiler Results with EF4
Thomas, it doesn't seem to matter. I initially had the default database for the login set to tempdb. I also changed it to the application's database and got the same results. What part of the connection string are you interested in? The connection string includes the Initial Catalog setting and sets it to the application database. It also specifies a user and password because I am using SQL Authentication in this case.

Thomas Williams
2010-06-07
re: Odd Profiler Results with EF4
Hi AjarnMark - I wasn't interested in knowing details of the connection string, just wondering if the default database was set differently anywhere. Sounds like you've got that part covered, though.

Jack Corbett
2010-06-24
re: Odd Profiler Results with EF4
Mark,

Turns out I AM having the same behavior using Linq to SQL against a SQL Server 2005 database. I was filtering on Database Name and didn't have Database ID showing. When I added Database ID it was 1!

Definitely interested in hearing what is going on.

Olaf Tinnemeyer
2010-08-04
re: Odd Profiler Results with EF4
Contains your connectionstring the option 'MultipleActiveResultSets=True'? If yes, try to remove it and look at sql profiler

AjarnMark
2010-08-09
re: Odd Profiler Results with EF4
@Olaf, YES! That work-around fixes this concern. Thanks! I still think this is a bug in SQL Server, but I can live with this work-around for now.