Using latest build from V2.5., SQL 2005, VS 2005.

Hi,

I'm experiencing a very strange issue which I've never ran into before. In our EventLog, time-outs showed up for a specific query, so I debugged the code producing this error and found out that the adapter running the query was not able to perform the fetch within the defined time-out period. So ok, that's possible in real-life situations but now comes the strange part.

After raising the time-out, the query did run eventually (< 2 min) and I copy-pasted the exact SQL command from the SQL Profiler trace-window for this query and ran it in a query window from the SQL Management Studio. What do you think ? Got an answer within 2 seconds for the exact same query.....so I'm quite flabbergasted by this result as I can't explain why the same query runs differently.

In the screenshot attachment, you'll see on the second line the original query (RPC:Completed), stating 448224 reads and produced from code, and on the last line you'll see the result from the Management Studio query window, stating a lot less reads (16290). This is propably a part of the problem....but I can't explain why as the query is exactly the same.

Has anyone experienced this problem before ? Please help....

Grtz, Danny

I'm not sure about why this difference exists. The only difference I can see between these 2 queries is that the LLBLGen Query use Parameters, the other one doesn't.

Anyway high reads might indicate table scans or not optimal indexes chosen by query optimizer. Usually, you want to keep reads parameter as low as possible because operations related to accessing hard drives (reading and writing) are the slowest ones in the system.

Paste the statement you want to check into the Query Analyzer and select Show Execution Plan command from Query menu. Run the statement and tale a look at the query plan. It will show you if any table or index scans occur during the execution. Table scans can be fixed by applying proper index to the columns participated in the WHERE clause or joins. Index scans are much faster then table scans and some times can not be avoided, but when clustered index scan occur you must check it the columns you use in WHERE clause or joins are in the clustered index and if this is not the case, then creation of the separate non clustered index for this columns will boost query performance and decrease readsvolume.

Hee Walaa,

The 2 queries are exactly the same, that's the strange part here. The second query (run from the Management Studio) is an EXACT copy (copy-paste) from the SQL command executed in the SQL Profiler by the DataAccessAdapter in code. They are, as a result, both parameterized.

Query 1 runs for about 110 seconds, the 2nd runs for about 2 seconds. Believe me, they are exactly the same....I used a Diff-util to check on the exact SQL. Attached you'll find the queries.

grtz, Danny

If you re-run the query in llblgen pro code, does it then again take that much time? THe thing is that it might be that the query you copy/pasted into the management studio simply re-returned the cached resultset. If you cut off a join or remove a filter, does the query then again return immediately?

2 minutes is a lot. the query seems a bit heavy on the join-side, but 2 minutes suggests there are other problems like indeed a lack of indexes.

Ok, I re-ran the following situation, as visible in the attached .jpg (SQL Profiler trace) :

• 1st blue line : SQL command from DataAccessAdapter, runs for 62 seconds

• 2nd blue line : again the same SQL command from the DataAccessAdapter, runs for 64 seconds....did this just to make sure it's not a caching issue why the next step will run smooth.

• 3rd blue line : Hans Klok, the magician, in action -> now I copy the sql command from the query analyzer from step 2 to a query window within Management studio and Execute !! -> result within 2 seconds with much less reads and CPU. THE SAME SQL AS IN STEP 1 AND 2. I've been trying all sorts of things but can't figure out what's going on over here...

And yes, it looks pretty heavy in joins but the database is pretty tuned-off so it performs pretty well....and the last query shows that.

Suppose there is a lack of indexes, then both situations should lead to dramatic performance, right ?

grtz, Danny

Still odd indeed...

I don't know what happens. The second run should run as fast as the last one, as the query + result is in the cache. Very weird that the last one is so fast compared to the rest.

If the query is that heavy, 2 seconds seems too fast, right?

I just ran the query against a freshly restarted instance of SQL Server from a query window within SSMS....took 6 seconds the first time, 1 second the second time. The adapter-code version still takes over 1 minute....

What else can I try ?

The 1-2 seconds seem OK, the resultset contains only 70 rows....

gr. Danny

Could you try the query in a simple C# program? (remove the exec sp_executesql.... ) It might be the data is just 70 rows but still very huge due to perhaps blobs/image/text fields?

So execute a datareader using the query? Perhaps network latency takes into account? Though I find the read # differences very weird...

    Sub Main()

        Dim conn As New SqlClient.SqlConnection("data source=tddb01\sql2005;initial catalog=AvalancheAgora;integrated security=SSPI;persist security info=False;packet size=4096")
        Dim reader As SqlClient.SqlDataReader
        Dim cmd As New SqlClient.SqlCommand

        cmd.Connection = conn
        conn.Open()
        cmd.CommandText = My.Computer.FileSystem.ReadAllText("c:\sql_from_adapter_code.sql")

        reader = cmd.ExecuteReader()
        While reader.Read
            Console.WriteLine(reader.Item("TransactionId"))
        End While
        conn.Close()

    End Sub

Frans....same result, 1-2 seconds. I'll try to extract the LLBLGen code that produced this query into an external application and see how that works out.

Though that's not the same query. You have to do some typing, but you've to declare the parameters separately and the query WITHOUT sp_executesql, so just the query in teh commandtext and all parameters + values separately as separate parameters.

If nothing helps, please build a debugbuild of the ormsupportclasses dll and step into the fetch method. It will end up in teh Execute... routine in DataAccessAdapter. You there can see if it indeed takes ages to complete or if it returns quickly and then chokes somewhere else...

Frans,

I got it down to the following code :

            {
                ((IDbDataAdapter)dataAdapterToUse).SelectCommand = queryToExecute.Command;

                if(queryToExecute.RequiresClientSidePaging || queryToExecute.RequiresClientSideLimitation)
                {
                    DataSet dummyDS = new DataSet();
                    dummyDS.Tables.Add(tableToFill);
                    if(queryToExecute.RequiresClientSidePaging)
                    {
                        // client side paging.
                        dataAdapterToUse.Fill(dummyDS, queryToExecute.ManualPageSize * (queryToExecute.ManualPageNumber-1), queryToExecute.ManualPageSize, tableToFill.TableName);
                    }
                    else
                    {
                        // client side limitation
                        dataAdapterToUse.Fill(dummyDS, 0, (int)queryToExecute.MaxNumberOfItemsToReturnClientSide, tableToFill.TableName);
                    }
                    dummyDS.Tables.Remove(tableToFill);
                }
                else
                {
                    dataAdapterToUse.Fill(tableToFill);
                }
            }

On dataAdapterToUse.Fill(tableToFill), I copied the CommandText and filled out the parameters by hand and ran this query in a query window : bang....2 seconds. Then I let loose the .Fill method....bang.... > 60 seconds.

I'm done with it....after an almost full day of debugging, testing, trial-and-error....

grtz, Danny

What do you mean with: "Then I let loose the .Fill method" ? Skipping it?

This is a typedlist/dyn. list fetch I pressume? (according at the select list in the query) So it uses datatable.fill anyway, UNLESS you use a typeconverter somewhere. Do you use a typeconverter in that query?

I meant : I executed the dataAdapterToUse.Fill statement. I had a breakpoint here to inspect the properties and extract the CommandText. And no, I'm not using a Type converter.

I've built a stand-alone console app in the meanwhile with the exact same code.....and what do you think......IT WORKS dammit. Why ? Only God knows I guess.... I think I've got to come up with some alternative way to achieve the same goal. We'll get there....

Thanks for the support and thinking by the way !

grtz, Danny

DvK wrote:

I meant : I executed the dataAdapterToUse.Fill statement. I had a breakpoint here to inspect the properties and extract the CommandText. And no, I'm not using a Type converter.

I've built a stand-alone console app in the meanwhile with the exact same code.....and what do you think......IT WORKS dammit. Why ? Only God knows I guess.... I think I've got to come up with some alternative way to achieve the same goal. We'll get there....

So, llblgen pro code in that console app worked OK? Very strange. Still, the mistery is there that the profiler showed a heck of a lot of reads compared to a second run of the same query in hte query tool.

Yes, that's correct...the LLBLGen'd console app works fine ! The unsolved SQL mystery killed me yesterday....maybe today I'll give it a fresh investigative start, see what comes out ! I'll keep you informed.

This might be a long shot but here it goes: did you have ANY event handler bound to the typedlist/dyn. list datatable's events? Or did you have the object bound to a control? If so, that's the killer

Hi, did you solve this issue? I'm having the same issue with sql server 2k.

Would you please start a new thread, and with this kind of problems, it would be better of you can provide a simple repro solution using Northwind database.

Thanks.