Postgresql query runs slow in LLBLGen but fast in PGAdmin or when using Npgsql directly

Posts   
 
    
clint
User
Posts: 150
Joined: 15-Nov-2005
# Posted on: 21-May-2024 16:35:38   

Using SD.LLBLGen.Pro.ORMSupportClasses Nuget package 5.6.0

Using .NET Core 3.1 and .NET Standard 2.0 Using Adapter. Using Postgresql. I don't know the actual version. It is an Amazon Web Service RDS database server.

We found a query in our software that times out when using LLBLGen with a Postgresql database. It runs for 1-2 minutes then gets a timeout exception.

We copied the query that LLBLGen wrote to the Visual Studio Output window into the pgAdmin 4 tool and ran it. It finished in less than half a second.

We also created a test program where we run the query using the Npgsql library (e.g. using NpgSqlConnection, NpgsqlCommand, NpgsqlDataReader) directly and the query also finishes immediately.

Do you have an explanation why the query takes so much longer to run using LLBLGen than it does using pgAdmin or the Npgsql library directly?

Looking at the execution plan in pgAdmin 4, we eventually discovered that we needed to add an index. Once we did that, our program that uses LLBLGen to run the query no longer timed out. But my question still remains.

Below is the timeout exception. The code that runs the query is GCS.PropertyAssessment.Reports.ReportValuationSummaryManager.GetDistrictValues(). The outermost exception is from our code. Its inner exception is from LLBLGen and it says "An exception was caught during the execution of a retrieval query". Its inner exception is from Mpgsql and it says "Exception while reading from stream". Its inner exception is System.TimeoutException and it says "Timeout during reading attempt".

EXCEPTION INFO

TYPE:

Gcs.Exception.GcsDatabaseException

MESSAGE:

The database operation failed.  See the inner exception for details.

SOURCE:

GCS.Data.CustomCode

TARGETSITE:

Void WrapException(SD.LLBLGen.Pro.ORMSupportClasses.ORMException)

STACKTRACE:

   at GCS.Data.CustomCode.LlblGenExceptionHandler.WrapException(ORMException ex) in /app/code/LLBLGen/GCS.DAL Solution/GCS.Data.CustomCode/LlblGenExceptionHandler.cs:line 53

   at GCS.PropertyAssessment.Reports.ReportValuationSummaryManager.GetDistrictValues(Int32 limitToMunicipalityId, Nullable`1 limitToDistrictId, IReportValuationSummaryManagerCriteria criteria, List`1& results) in /app/code/GCS.PropertyAssessment/GCS.PropertyAssessment Solution/GCS.PropertyAssessment.Reports/ReportValuationSummaryManager.cs:line 492

   at StatementOfAssessment.Processes.StatementOfAssessment.FillDistrictInformation(MunicipalityEntity municipality, Boolean includeStateAssessed, CalculatedData& soaCalcData) in /app/code/StatementOfAssessment/StatementOfAssessment Solution/StatementOfAssessment.Processes/StatementOfAssessment.cs:line 950

   at StatementOfAssessment.Processes.StatementOfAssessment.Run(StatementOfAssessmentProcessParameters criteria, Notification& notification, EntityCollection`1& filesCreated) in /app/code/StatementOfAssessment/StatementOfAssessment Solution/StatementOfAssessment.Processes/StatementOfAssessment.cs:line 147

   at StatementOfAssessment.Processes.StatementOfAssessmentProcess.Run(Notification& notification) in /app/code/StatementOfAssessment/StatementOfAssessment Solution/StatementOfAssessment.Processes/StatementOfAssessmentProcess.cs:line 42

   at GCS.ProcessQueue.QueuedProcess.Run(ProcessQueueEntity processQueue, EntityCollection`1& filesCreated, Notification& notification) in /app/code/GCS.ProcessQueue/GCS.ProcessQueue Solution/GCS.ProcessQueue/QueuedProcess.cs:line 117

--------------------------------------------------------------------------------
INNER EXCEPTION #1

EXCEPTION INFO

TYPE:

SD.LLBLGen.Pro.ORMSupportClasses.ORMQueryExecutionException

MESSAGE:

An exception was caught during the execution of a retrieval query: Exception while reading from stream. Check InnerException, QueryExecuted and Parameters of this exception to examine the cause of this exception.

SOURCE:

SD.LLBLGen.Pro.ORMSupportClasses

TARGETSITE:

System.Data.Common.DbDataReader Execute(System.Data.CommandBehavior)

STACKTRACE:

   at SD.LLBLGen.Pro.ORMSupportClasses.RetrievalQuery.Execute(CommandBehavior behavior)

   at SD.LLBLGen.Pro.ORMSupportClasses.DataAccessAdapterCore.ExecuteMultiRowDataTableRetrievalQuery(IRetrievalQuery queryToExecute, DbDataAdapter dataAdapterToUse, DataTable tableToFill, IFieldPersistenceInfo[] fieldsPersistenceInfo)

   at SD.LLBLGen.Pro.ORMSupportClasses.DataAccessAdapterCore.FetchTypedList(DataTable dataTableToFill, QueryParameters parameters)

   at SD.LLBLGen.Pro.ORMSupportClasses.DataAccessAdapterCore.FetchTypedList(IEntityFields2 fieldCollectionToFetch, DataTable dataTableToFill, IRelationPredicateBucket filterBucket, Int32 maxNumberOfItemsToReturn, ISortExpression sortClauses, Boolean allowDuplicates, IGroupByCollection groupByClause)

   at GCS.PropertyAssessment.Reports.ReportValuationSummaryManager.GetDistrictValues(Int32 limitToMunicipalityId, Nullable`1 limitToDistrictId, IReportValuationSummaryManagerCriteria criteria, List`1& results) in /app/code/GCS.PropertyAssessment/GCS.PropertyAssessment Solution/GCS.PropertyAssessment.Reports/ReportValuationSummaryManager.cs:line 486

--------------------------------------------------------------------------------
INNER EXCEPTION #2

EXCEPTION INFO

TYPE:

Npgsql.NpgsqlException

MESSAGE:

Exception while reading from stream

SOURCE:

Npgsql

TARGETSITE:

Void MoveNext()

STACKTRACE:

   at Npgsql.NpgsqlConnector.<ReadMessage>g__ReadMessageLong|194_0(NpgsqlConnector connector, Boolean async, DataRowLoadingMode dataRowLoadingMode, Boolean readingNotifications, Boolean isReadingPrependedMessage)

   at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)

   at Npgsql.NpgsqlDataReader.NextResult()

   at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)

   at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)

   at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior)

   at SD.LLBLGen.Pro.ORMSupportClasses.RetrievalQuery.TagAndExecuteCommand[TReturn](Func`1 toExecute)

   at SD.LLBLGen.Pro.ORMSupportClasses.RetrievalQuery.Execute(CommandBehavior behavior)

--------------------------------------------------------------------------------
INNER EXCEPTION #3

EXCEPTION INFO

TYPE:

System.TimeoutException

MESSAGE:

Timeout during reading attempt

SOURCE:


TARGETSITE:


STACKTRACE:

Below is the query. It does a lot of table joins to get the data it needs.

We ended up adding an index that consists of MunicipalityId, TaxYear, and IsRE.

There was an existing index that just used MunicipalityId. PGAdmin's execution plan would show that it would use that index first. The query in LLBLGen would run quickly when using a MunicipalityId that doesn't exist, that's because no data would be returned. But if it did find Parcel records that used the specified MunicipalityId, then it would end up having to scan the Parcel table to find records with the given TaxYear and IsRE values.

SELECT DISTINCT "dbo"."ParcelDistrictMap"."DistrictID" AS "DistrictId", SUM("dbo"."Valuation"."LandValue") AS "LandValueSum", SUM("dbo"."Valuation"."ImprovementValue") AS "ImprvValueSum" 
FROM ((((("dbo"."Parcel" 
INNER JOIN "dbo"."ParcelDistrictMap" ON "dbo"."Parcel"."ParcelID"="dbo"."ParcelDistrictMap"."ParcelID") 
INNER JOIN "dbo"."District" ON "dbo"."District"."DistrictID"="dbo"."ParcelDistrictMap"."DistrictID") 
INNER JOIN "dbo"."Assessment" ON "dbo"."Parcel"."ParcelID"="dbo"."Assessment"."ParcelID") 
INNER JOIN "dbo"."Valuation" ON "dbo"."Assessment"."AssessmentID"="dbo"."Valuation"."AssessmentID") 
INNER JOIN "dbo"."ValuationClass" ON "dbo"."ValuationClass"."ValuationClassID"="dbo"."Valuation"."ValuationClassID") 
WHERE ( ( "dbo"."Parcel"."IsRE" = 1 AND "dbo"."Parcel"."TaxYear" = 2024 AND "dbo"."Parcel"."MunicipalityID" = 2) 
AND "dbo"."ValuationClass"."Class" IN ('G', 'P') AND "dbo"."District"."Inactive" = False) 
GROUP BY "dbo"."ParcelDistrictMap"."DistrictID"
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39638
Joined: 17-Aug-2003
# Posted on: 22-May-2024 08:30:42   

pgAdmin uses a different connection system to the database, so it might have a different execution context. It's interesting that the npgsql test program is fast... You're sure you used parameters in that query? The llblgen query has parameters, the query you posted at the bottom doesn't, so I have the suspicion you used the query with hard-coded values for speed testing.

Frans Bouma | Lead developer LLBLGen Pro
clint
User
Posts: 150
Joined: 15-Nov-2005
# Posted on: 22-May-2024 20:38:46   

Otis wrote:

It's interesting that the npgsql test program is fast... You're sure you used parameters in that query? The llblgen query has parameters, the query you posted at the bottom doesn't, so I have the suspicion you used the query with hard-coded values for speed testing.

I did NOT use parameters in my test using the Npgsql library. I just hardcoded the values in the SQL Statement used by the NpgsqlCommand object.

Below is some test code using Npgsql. The query I'm using is one that was generated by LLBLGen by one of the methods in our software. I copied what the LLBLGen tracing writes to the Visual Studio Output window and hardcoded the values when making the SQL statement.

private static void TestBarronCountyQueryTimeout()
{
    // Test Postgresql
    string connectionString = "omitted for privacy";
    using NpgsqlConnection npgsqlConnection = new NpgsqlConnection(connectionString);
    npgsqlConnection.Open();

    // build the query.  Hardcoding criteria values.
    // Looks ugly because I have to escape all the double quotes that postgresql wants you to use
    // around the table and field names.
    StringBuilder sb = new StringBuilder();
    sb.AppendLine("SELECT DISTINCT \"dbo\".\"ParcelDistrictMap\".\"DistrictID\" AS \"DistrictId\", SUM(\"dbo\".\"Valuation\".\"LandValue\") AS \"LandValueSum\", SUM(\"dbo\".\"Valuation\".\"ImprovementValue\") AS \"ImprvValueSum\" ");
    sb.AppendLine("FROM (((((\"dbo\".\"Parcel\" ");
    sb.AppendLine("INNER JOIN \"dbo\".\"ParcelDistrictMap\" ON \"dbo\".\"Parcel\".\"ParcelID\"=\"dbo\".\"ParcelDistrictMap\".\"ParcelID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"District\" ON \"dbo\".\"District\".\"DistrictID\"=\"dbo\".\"ParcelDistrictMap\".\"DistrictID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"Assessment\" ON \"dbo\".\"Parcel\".\"ParcelID\"=\"dbo\".\"Assessment\".\"ParcelID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"Valuation\" ON \"dbo\".\"Assessment\".\"AssessmentID\"=\"dbo\".\"Valuation\".\"AssessmentID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"ValuationClass\" ON \"dbo\".\"ValuationClass\".\"ValuationClassID\"=\"dbo\".\"Valuation\".\"ValuationClassID\") ");
    sb.AppendLine("WHERE ( ( \"dbo\".\"Parcel\".\"IsRE\" = 1 AND \"dbo\".\"Parcel\".\"TaxYear\" = 2024 AND \"dbo\".\"Parcel\".\"MunicipalityID\" = 2) ");
    sb.AppendLine("AND \"dbo\".\"ValuationClass\".\"Class\" IN ('G', 'P') AND \"dbo\".\"District\".\"Inactive\" = False) ");
    sb.AppendLine("GROUP BY \"dbo\".\"ParcelDistrictMap\".\"DistrictID\"");
    
    string sql = sb.ToString();

    // run the query
    using NpgsqlCommand npgsqlCmd = new NpgsqlCommand(sql, npgsqlConnection);
    using NpgsqlDataReader npgsqlReader = npgsqlCmd.ExecuteReader();

    // read the query results
    while (npgsqlReader.Read())
    {
        string data = $"{npgsqlReader["DistrictId"]}  {npgsqlReader["LandValueSum"]}  {npgsqlReader["ImprvValueSum"]}";
        Console.WriteLine(data);
    }
}

clint
User
Posts: 150
Joined: 15-Nov-2005
# Posted on: 22-May-2024 21:30:15   

Here is the same code but using parameters. This also ran quickly. I used positional parameters instead of named parameters because that is what this page recommended:https://www.npgsql.org/doc/basic-usage.html

private static void TestBarronCountyQueryTimeoutWithParameters()
{
    // Test Postgresql
    string connectionString = "omitted for privacy";
    using NpgsqlConnection npgsqlConnection = new NpgsqlConnection(connectionString);
    npgsqlConnection.Open();


    // build the query.  Hardcoding criteria values.
    // Looks ugly because I have to escape all the double quotes that postgresql wants you to use
    // around the table and field names.
    StringBuilder sb = new StringBuilder();
    sb.AppendLine("SELECT DISTINCT \"dbo\".\"ParcelDistrictMap\".\"DistrictID\" AS \"DistrictId\", SUM(\"dbo\".\"Valuation\".\"LandValue\") AS \"LandValueSum\", SUM(\"dbo\".\"Valuation\".\"ImprovementValue\") AS \"ImprvValueSum\" ");
    sb.AppendLine("FROM (((((\"dbo\".\"Parcel\" ");
    sb.AppendLine("INNER JOIN \"dbo\".\"ParcelDistrictMap\" ON \"dbo\".\"Parcel\".\"ParcelID\"=\"dbo\".\"ParcelDistrictMap\".\"ParcelID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"District\" ON \"dbo\".\"District\".\"DistrictID\"=\"dbo\".\"ParcelDistrictMap\".\"DistrictID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"Assessment\" ON \"dbo\".\"Parcel\".\"ParcelID\"=\"dbo\".\"Assessment\".\"ParcelID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"Valuation\" ON \"dbo\".\"Assessment\".\"AssessmentID\"=\"dbo\".\"Valuation\".\"AssessmentID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"ValuationClass\" ON \"dbo\".\"ValuationClass\".\"ValuationClassID\"=\"dbo\".\"Valuation\".\"ValuationClassID\") ");
    sb.AppendLine("WHERE ( ( \"dbo\".\"Parcel\".\"IsRE\" = $1 AND \"dbo\".\"Parcel\".\"TaxYear\" = $2 AND \"dbo\".\"Parcel\".\"MunicipalityID\" = $3) ");
    sb.AppendLine("AND \"dbo\".\"ValuationClass\".\"Class\" IN ($4, $5) AND \"dbo\".\"District\".\"Inactive\" = $6) ");
    sb.AppendLine("GROUP BY \"dbo\".\"ParcelDistrictMap\".\"DistrictID\"");

    string sql = sb.ToString();

    // run the query
    using NpgsqlCommand npgsqlCmd = new NpgsqlCommand(sql, npgsqlConnection);
    npgsqlCmd.Parameters.AddWithValue(NpgsqlDbType.Smallint, 1);    // $1 Parcel.IsRE
    npgsqlCmd.Parameters.AddWithValue(NpgsqlDbType.Smallint, 2024); // $2 Parcel.TaxYear
    npgsqlCmd.Parameters.AddWithValue(NpgsqlDbType.Integer, 2);     // $3 Parcel.MunicipalityId
    npgsqlCmd.Parameters.AddWithValue(NpgsqlDbType.Varchar, "G");   // $4 ValuationClass.Class
    npgsqlCmd.Parameters.AddWithValue(NpgsqlDbType.Varchar, "P");   // $5 ValuationClass.Class
    npgsqlCmd.Parameters.AddWithValue(NpgsqlDbType.Boolean, false); // $6 District.Inactive

    using NpgsqlDataReader npgsqlReader = npgsqlCmd.ExecuteReader();

    // read the query results
    while (npgsqlReader.Read())
    {
        string data = $"{npgsqlReader["DistrictId"]}  {npgsqlReader["LandValueSum"]}  {npgsqlReader["ImprvValueSum"]}";
        Console.WriteLine(data);
    }
}

clint
User
Posts: 150
Joined: 15-Nov-2005
# Posted on: 22-May-2024 21:55:38   

Here is a version of the code using named parameters instead of positional parameters. This went fast too.

private static void TestBarronCountyQueryTimeoutWithNamedParameters()
{
    // Test Postgresql
    string connectionString = "omitted for privacy";
    using NpgsqlConnection npgsqlConnection = new NpgsqlConnection(connectionString);
    npgsqlConnection.Open();


    // build the query.  Hardcoding criteria values.
    // Looks ugly because I have to escape all the double quotes that postgresql wants you to use
    // around the table and field names.
    StringBuilder sb = new StringBuilder();
    sb.AppendLine("SELECT DISTINCT \"dbo\".\"ParcelDistrictMap\".\"DistrictID\" AS \"DistrictId\", SUM(\"dbo\".\"Valuation\".\"LandValue\") AS \"LandValueSum\", SUM(\"dbo\".\"Valuation\".\"ImprovementValue\") AS \"ImprvValueSum\" ");
    sb.AppendLine("FROM (((((\"dbo\".\"Parcel\" ");
    sb.AppendLine("INNER JOIN \"dbo\".\"ParcelDistrictMap\" ON \"dbo\".\"Parcel\".\"ParcelID\"=\"dbo\".\"ParcelDistrictMap\".\"ParcelID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"District\" ON \"dbo\".\"District\".\"DistrictID\"=\"dbo\".\"ParcelDistrictMap\".\"DistrictID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"Assessment\" ON \"dbo\".\"Parcel\".\"ParcelID\"=\"dbo\".\"Assessment\".\"ParcelID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"Valuation\" ON \"dbo\".\"Assessment\".\"AssessmentID\"=\"dbo\".\"Valuation\".\"AssessmentID\") ");
    sb.AppendLine("INNER JOIN \"dbo\".\"ValuationClass\" ON \"dbo\".\"ValuationClass\".\"ValuationClassID\"=\"dbo\".\"Valuation\".\"ValuationClassID\") ");
    sb.AppendLine("WHERE ( ( \"dbo\".\"Parcel\".\"IsRE\" = @p1 AND \"dbo\".\"Parcel\".\"TaxYear\" = @p2 AND \"dbo\".\"Parcel\".\"MunicipalityID\" = @p3) ");
    sb.AppendLine("AND \"dbo\".\"ValuationClass\".\"Class\" IN (@p4, @p5) AND \"dbo\".\"District\".\"Inactive\" = @p6) ");
    sb.AppendLine("GROUP BY \"dbo\".\"ParcelDistrictMap\".\"DistrictID\"");

    string sql = sb.ToString();

    // run the query
    using NpgsqlCommand npgsqlCmd = new NpgsqlCommand(sql, npgsqlConnection);
    npgsqlCmd.Parameters.AddWithValue("@p1", NpgsqlDbType.Smallint, 1);    // @p1 Parcel.IsRE
    npgsqlCmd.Parameters.AddWithValue("@p2", NpgsqlDbType.Smallint, 2024); // @p2 Parcel.TaxYear
    npgsqlCmd.Parameters.AddWithValue("@p3", NpgsqlDbType.Integer, 2);     // @p3 Parcel.MunicipalityId
    npgsqlCmd.Parameters.AddWithValue("@p4", NpgsqlDbType.Varchar, "G");   // @p4 ValuationClass.Class
    npgsqlCmd.Parameters.AddWithValue("@p5", NpgsqlDbType.Varchar, "P");   // @p5 ValuationClass.Class
    npgsqlCmd.Parameters.AddWithValue("@p6", NpgsqlDbType.Boolean, false); // @p6 District.Inactive

    using NpgsqlDataReader npgsqlReader = npgsqlCmd.ExecuteReader();

    // read the query results
    while (npgsqlReader.Read())
    {
        string data = $"{npgsqlReader["DistrictId"]}  {npgsqlReader["LandValueSum"]}  {npgsqlReader["ImprvValueSum"]}";
        Console.WriteLine(data);
    }
}

Walaa avatar
Walaa
Support Team
Posts: 14962
Joined: 21-Aug-2005
# Posted on: 22-May-2024 22:56:44   

Could you please test the the code using llblgen against Postgresql hosted locally, without the new index?

clint
User
Posts: 150
Joined: 15-Nov-2005
# Posted on: 23-May-2024 00:12:44   

Walaa wrote:

Could you please test the the code using llblgen against Postgresql hosted locally, without the new index?

I'm going to ignore your request for now because I discovered the problem seems to have something to do with "row level security".

I noticed that the postgresql database has ROW LEVEL SECURITY enabled for all those tables in the query.

Example:

ALTER TABLE IF EXISTS dbo."Parcel" ENABLE ROW LEVEL SECURITY;

All those tables have a policy that filters rows based on a tenant id.

Example:

CREATE POLICY pt_rls_policy ON dbo."Parcel" AS PERMISSIVE FOR ALL TO public USING (("TenantID" = ANY ((string_to_array(current_setting('my.tenantid'::text), ','::text))::integer[])));

The version of our software that uses that postgresql database seems to have a step where it sets the filter value for row level security:

adapter.ExecuteSQL($"SET my.tenantid = '{tenantID}';SET my.defaulttenantid = '{tenantID}';");

I noticed if I disable row level security on all the tables involved in the query, the query runs quickly in our software.

When I re-enable the row level security, then the query times out in our software.

I also discovered the reason why my Npgsql test programs didn't have any problems, is because I was connecting as a different user than our software was. It appears the user I was using with my Npgcsl test program isn't affected by that row level security filter.

I don't really know much about row level security. I'll have to talk to the programmers that set that stuff up

You can close this ticket.

Thanks!