Using : LLBLGen 5.1 EAP, SQL Azure (Standard "S1" database)

Hi,

I'm having a very serious performance issue getting a list of records from SQL Azure.

As an example, This is the code for a very simple query that gets the Id (INT), Code (NVARCHAR(20)), and the Description/Extended Description (NVARCHAR(MAX)) from a table called Recipe :

       [TestMethod]
        public void GetAllRecipesIdCodeDesc_Using_LLBLGen_Sync_Entities()
        {
            var connstring = connstr.Replace("%tenant%", tenant);
            var catalogoverwrite = new CatalogNameOverwriteHashtable(CatalogNameUsage.ForceName) { { "*", tenant } };
            using (new StopWatchTimer($"Get list of recipe id/code/desc using LLBLGen directly (sync)"))
            {
                using (var adapter = new DataAccessAdapter(connstring, false, catalogoverwrite, null))
                {
                    var metadata = new LinqMetaData(adapter);
                    var query = metadata.Get<RecipeEntity>();
                    var recipes = query.IncludeFields(x => x.Id, x => x.Code, x => x.DescriptionsBlob, x => x.ExtendedDescriptionsBlob).ToList();
                }
            }
        }

There are 32000 records in the database, this yields the following query and execution time :

Method Enter: CreatePagingSelectDQ Method Enter: CreateSelectDQ Method Enter: CreateSelectDQ Generated Sql query: Query: SELECT NULL AS [ActiveVersion], NULL AS [AnalysisValuesBlob], NULL AS [AnimalGroupCode], [unittest_S1].[unittest].[Recipe].[AnimalTypeId], NULL AS [BatchWeight], [unittest_S1].[unittest].[Recipe].[Code], NULL AS [CompositionBlob], NULL AS [CreatedBy], NULL AS [CreatedOn], [unittest_S1].[unittest].[Recipe].[CustomerId], [unittest_S1].[unittest].[Recipe].[DescriptionsBlob], [unittest_S1].[unittest].[Recipe].[ExtendedDescriptionsBlob], [unittest_S1].[unittest].[Recipe].[FolderId], [unittest_S1].[unittest].[Recipe].[Id], [unittest_S1].[unittest].[Recipe].[IngredientPricelistId], NULL AS [IsModel], NULL AS [LocationCode], NULL AS [MaterialConstraintsBlob], NULL AS [Memo], NULL AS [ModifiedBy], NULL AS [ModifiedOn], NULL AS [NutrientConstraintsBlob], NULL AS [OptimizeMinPricePerRefNutr], NULL AS [ParameterValuesBlob], [unittest_S1].[unittest].[Recipe].[RecipeTemplateId], NULL AS [RecipeTypeName], [unittest_S1].[unittest].[Recipe].[ReferenceNutrientId], NULL AS [ReferenceNutrientValue], [unittest_S1].[unittest].[Recipe].[SiteId], NULL AS [Timestamp], NULL AS [Version] FROM [unittest_S1].[unittest].[Recipe]
Method Exit: CreateSelectDQ Method Exit: CreatePagingSelectDQ: no paging. [14:37:31.372][+15686 ms] [TIMING]: Get list of recipe id/code/desc using LLBLGen directly (sync) : total elapsed time : 15214 ms

So more than 15 seconds. (edit: the Description/ExtendedDescriptions are nvarchar(max), but in reality only contain on avarage 500 bytes per record)

When executing the same query in SQL Server Mangement Studio, from my local pc connected to the SQL Azure DB, the same query executes in merely a second.

See attachment for a dottrace screenshot of the executed unittest.

What direction should I go for trying to solve this ?

v5.1 EAP isn't supported, it's a preview. You're sure you're using a preview and not an RTM version?

Anyway, the trace shows that the majority of time is spent in reading data by the datareader, (in the GetValues() tree) so there's little we can do: the database is either slow or the network latency is massive. Also try without including the blob fields: the query executed in SSMS might not fetch the blob values (check in the resultset if you get the blob values in the resultset).

Does the app run in the same datacenter as the DB?

• The unittest is running off my local pc, so indeed there will be some latency, but the SSMS is also running off my local pc, so the latency is the same I would assume.

• When only including the Id, indeed the query is way faster (a little over 1 second).

• The query in SSMS is fetching the blobvalues, I verified, and does the whole query in approx. 1 second. When I only fetch the Id's in SSMS, it's almost instantly, and it reports 0 seconds (Can I get more accurate timings in SSMS besides the number of seconds in the bottom statusbar ?)

• When running in Azure, the appservice is running in the same resourcegroup/datacenter as the DBserver (NorthernEurope)

• Since it was long overdue, I just downloaded the 5.4 and will retry my findings.

HcD wrote:

• The unittest is running off my local pc, so indeed there will be some latency, but the SSMS is also running off my local pc, so the latency is the same I would assume.

It's not comparable, SSMS uses a different way of querying (not using ado.net), so if you want to test it, try to fetch the query using plain ADO.NET, e.g. using SqlDataAdapter and a datatable. Surround that with a Stopwatch start/stop and you have a very rudimentary way of determining what it takes. Also make sure to run it a couple of times, then time it.

• When only including the Id, indeed the query is way faster (a little over 1 second).

• The query in SSMS is fetching the blobvalues, I verified, and does the whole query in approx. 1 second. When I only fetch the Id's in SSMS, it's almost instantly, and it reports 0 seconds (Can I get more accurate timings in SSMS besides the number of seconds in the bottom statusbar ?)

You could use sqlprofiler (available through ssms menu) for looking at what the number of reads are but network traffic isn't measured. The trace you posted shows the datareader is waiting for data and it takes that long to read it. We sadly can't make that any faster, that part of the pipeline is out of our hands.

Please try what I said at the top of this post, it would give a better overview of what it takes, it likely will show about the same amount of time taken (as the majority of time taken is inside the datareader, that won't be different with a dataadapter/datatable)

Also try to run this dbdataadapter console test app on the VM your app is running on, not locally. It might very well be the latency is bigger there than to your box (no idea if that's the case, but it would give a realistic overview of what's happening compared to fetching data to a local box...

Hi,

I've upgraded to the latest LLBLGen 5.4 hotfix version of june 18th, but the problem remains the same.

I've had a kind of similar problem a long time ago, which I posted on SO ( https://stackoverflow.com/questions/42415969/horrible-performance-when-using-sqlcommand-async-methods ) and so I started playing with the packet size in the connection string.

And indeed, when I set the packet size to the maximum of 32767 , the query takes "only" 7 seconds instead of 15. When setting the packet size to 1024, the execution time rises to over 100 seconds !

But while in my SO question, there was a big difference between async and non-async, in this case it remains the same. And I see in the dotTrace tracing that there is still some async code called ?

I will try to recreate the queries using plain SqlCommand and post my findings here ...

Hi,

here are my findings on timings.

I've used the same database in 4 different environments, one on Azure SQL "Basic", one on Azure SQL "Standard S1", one on a SQL2016 server on a dual CPU virtual machine in our company lan, and one on a SQL2016 on my local machine (Core i7-7700K, 16gb ram)

I'm querying a table that holds 32500 records, with 2 queries, one that only gets the "Id" column, and one that gets the Id, Code, DescriptionsBlob and ExtendedDescriptionsBlob fields (those "blob" fields are actually just a varchar(max) that hold a Json snippet of around 500bytes)

I've noticed that the LLBGen generated query also always includes all ForeignKeyId Fields, even if I instructed on the query .IncludeFields(x=> x.Id);

For every environment, I run the queries in unittests using LLBLGen and using SQLCommand (both Sync & Async versions) and using SqlServer Management Studio.

Here are the timings :

Timings in ms       Database    Azure "Basic"   Azure "S1"  SQL on VM in LAN    SQL on localhost
Query (table w/32000 records)                       
Using LLBLGen in unittest:                      
Select Id (sync)            1398 ms 611 ms  2185 ms 6 ms
Select Id (async)           911 ms  600 ms  2406 ms     7 ms
Select Id,Code,Descr (sync)         7609 ms 7650 ms 2339 ms 226 ms
Select Id, Code, Descr (async)          7795 ms 7502 ms 2373 ms 284 ms
Using SQLCommand in unittest:                       
Select id  (sync)           92 ms   95 ms   13 ms   9 ms
Select id  (async)          145 ms  90 ms   19 ms   6 ms
Select Id, Code, Descr (sync)           7977 ms 7062 ms 2366 ms 34 ms
Select Id, Code, Descr (async)          7017 ms 6979 ms 2388 ms 38 ms
Using SSMS connected to DB                      
Select id           1 sec   0 sec   0 sec   0 sec
Select Id, Code, Descr          4 sec   3 sec    2 sec  0 sec

(I've also include a screenshots because the formatting of the timings table is not really readable)

How would I start trying to optimize this, because they will never accept 7 seconds for just getting the code/description of the list of entities ...

EDIT: while trying thing out, I've changed the "MultipleActiveResultSets" to "false" in the connectionstring, and suddenly, it all goes way faster (more like the SSMS timings) ... I have no idea why it was set to true in the first place, will investigate further ...

Please run the queries a couple of times and as release builds, the ID query should be way faster than the rest, but it picks up the initial warm up of the connection as time for the query.

FK fields are always included, even if you exclude them. That's by design.

I'm afraid that the network latency is the problem here, as I said above: transporting the data over the network seems to be the main issue. This can be due to the fact the data is very very large (but I read above it's not that) so it might be due to other things, but sadly there's not much we can do about this: sql client itself as you can see is just as slow. the time it needs extra in the llblgen pro part is materialization, entity creation etc, but that's not the bottleneck. (you didn't include the code you used for tests so I don't know if you have read the data from the datareader in the sqlclient test, but in case not, that might be the reason the timings are lower than with the llblgen pro fetch. Our own benchmarks show that fetching entities is pretty much as fast as it can possibly be)