Completed questionnaire not able to accept or reject by supervisor or HQ

daniedk · June 28, 2024, 7:12am

Good morning,
We are using version 23.09.1 and have been experiencing the following case with a few survey officers.

The interview is collected and synced, then in its “completed” state the Supervisor can not accept or reject. It brings up the dialog box to reject and once reject is clicked the box disappears but the status stays the same as completed. The HQ role does the same.

I did look at the log and could find an err entry. but I am not an expert at log analysis and I am not sure if the error is related to the issue experienced:
2024-06-28 09:05:52.012 +02:00 [ERR] /interviews/nodes[8]/identifyingData[3]/entityUnexpected Execution Error

NHibernate.Exceptions.GenericADOException: could not execute query
[ select questionna0_.Id as id1_31_, questionna0_.QuestionnaireIdentity as questionnaireidentity2_31_, questionna0_.EntityId as entityid3_31_, questionna0_.ParentId as parentid4_31_, questionna0_.question_type as question5_31_, questionna0_.Featured as featured6_31_, questionna0_.question_scope as question7_31_, questionna0_.entity_type as entity8_31_, questionna0_.is_filtered_combobox as is9_31_, questionna0_.cascade_from_question_id as cascade10_31_, questionna0_.linked_to_roster_id as linked11_31_, questionna0_.linked_to_question_id as linked12_31_, questionna0_.stata_export_caption as stata13_31_, questionna0_.question_text as question14_31_, questionna0_.variable_label as variable15_31_, questionna0_.variable_type as variable16_31_, questionna0_.included_in_reporting_at_utc as included17_31_ from questionnaire_entities questionna0_ where questionna0_.Id in (:p0 , :p1 , :p2 , :p3 , :p4 , :p5 , :p6 , :p7 , :p8 , :p9 , :p10 , :p11 , :p12 , :p13 , :p14) ]
Name:p1_0_ - Value:1927 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_1_ - Value:1926 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_2_ - Value:1924 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_3_ - Value:1923 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_4_ - Value:1922 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_5_ - Value:1921 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_6_ - Value:1920 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_7_ - Value:1919 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_8_ - Value:1918 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_9_ - Value:1917 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_10_ - Value:1916 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_11_ - Value:1915 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_12_ - Value:1914 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_13_ - Value:1913 [Type: NHibernate.Type.Int32Type (SqlType: Int32)] Name:p1_14_ - Value:1912 [Type: NHibernate.Type.Int32Type (SqlType: Int32)]
[SQL: select questionna0_.Id as id1_31_, questionna0_.QuestionnaireIdentity as questionnaireidentity2_31_, questionna0_.EntityId as entityid3_31_, questionna0_.ParentId as parentid4_31_, questionna0_.question_type as question5_31_, questionna0_.Featured as featured6_31_, questionna0_.question_scope as question7_31_, questionna0_.entity_type as entity8_31_, questionna0_.is_filtered_combobox as is9_31_, questionna0_.cascade_from_question_id as cascade10_31_, questionna0_.linked_to_roster_id as linked11_31_, questionna0_.linked_to_question_id as linked12_31_, questionna0_.stata_export_caption as stata13_31_, questionna0_.question_text as question14_31_, questionna0_.variable_label as variable15_31_, questionna0_.variable_type as variable16_31_, questionna0_.included_in_reporting_at_utc as included17_31_ from questionnaire_entities questionna0_ where questionna0_.Id in (:p0 , :p1 , :p2 , :p3 , :p4 , :p5 , :p6 , :p7 , :p8 , :p9 , :p10 , :p11 , :p12 , :p13 , :p14)]
—> Npgsql.NpgsqlOperationInProgressException (0x80004005): A command is already in progress: select questionna0_.Id as id1_31_, questionna0_.QuestionnaireIdentity as questionnaireidentity2_31_, questionna0_.EntityId as entityid3_31_, questionna0_.ParentId as parentid4_31_, questionna0_.question_type as question5_31_, questionna0_.Featured as featured6_31_, questionna0_.question_scope as question7_31_, questionna0_.entity_type as entity8_31_, questionna0_.is_filtered_combobox as is9_31_, questionna0_.cascade_from_question_id as cascade10_31_, questionna0_.linked_to_roster_id as linked11_31_, questionna0_.linked_to_question_id as linked12_31_, questionna0_.stata_export_caption as stata13_31_, questionna0_.question_text as question14_31_, questionna0_.variable_label as variable15_31_, questionna0_.variable_type as variable16_31_, questionna0_.included_in_reporting_at_utc as included17_31_ from questionnaire_entities questionna0_ where questionna0_.Id in (:p0 , :p1 , :p2 , :p3 , :p4 , :p5 , :p6 , :p7 , :p8 , :p9 , :p10 , :p11 , :p12 , :p13 , :p14 , :p15 , :p16 , :p17 , :p18 , :p19 , :p20 , :p21 , :p22 , :p23 , :p24 , :p25 , :p26 , :p27)
at Npgsql.Internal.NpgsqlConnector.g__DoStartUserAction|279_0(ConnectorState newState, NpgsqlCommand command, <>c__DisplayClass279_0&)
at Npgsql.Internal.NpgsqlConnector.StartUserAction(ConnectorState newState, NpgsqlCommand command, CancellationToken cancellationToken, Boolean attemptPgCancellation)
at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)
at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)
at Npgsql.NpgsqlCommand.ExecuteDbDataReaderAsync(CommandBehavior behavior, CancellationToken cancellationToken)
at NHibernate.AdoNet.AbstractBatcher.DoExecuteReaderAsync(DbCommand cmd, CancellationToken cancellationToken)
at NHibernate.AdoNet.AbstractBatcher.ExecuteReaderAsync(DbCommand cmd, CancellationToken cancellationToken)
at NHibernate.Loader.Loader.GetResultSetAsync(DbCommand st, QueryParameters queryParameters, ISessionImplementor session, IResultTransformer forcedResultTransformer, CancellationToken cancellationToken)
at NHibernate.Loader.Loader.DoQueryAsync(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies, IResultTransformer forcedResultTransformer, QueryCacheResultBuilder queryCacheResultBuilder, CancellationToken cancellationToken)
at NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollectionsAsync(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies, IResultTransformer forcedResultTransformer, QueryCacheResultBuilder queryCacheResultBuilder, CancellationToken cancellationToken)
at NHibernate.Loader.Loader.DoListAsync(ISessionImplementor session, QueryParameters queryParameters, IResultTransformer forcedResultTransformer, QueryCacheResultBuilder queryCacheResultBuilder, CancellationToken cancellationToken)
— End of inner exception stack trace —
at NHibernate.Loader.Loader.DoListAsync(ISessionImplementor session, QueryParameters queryParameters, IResultTransformer forcedResultTransformer, QueryCacheResultBuilder queryCacheResultBuilder, CancellationToken cancellationToken)
at NHibernate.Loader.Loader.ListIgnoreQueryCacheAsync(ISessionImplementor session, QueryParameters queryParameters, CancellationToken cancellationToken)
at NHibernate.Hql.Ast.ANTLR.QueryTranslatorImpl.ListAsync(ISessionImplementor session, QueryParameters queryParameters, CancellationToken cancellationToken)
at NHibernate.Engine.Query.HQLQueryPlan.PerformListAsync(QueryParameters queryParameters, ISessionImplementor session, IList results, CancellationToken cancellationToken)
at NHibernate.Impl.SessionImpl.ListAsync(IQueryExpression queryExpression, QueryParameters queryParameters, IList results, Object filterConnection, CancellationToken cancellationToken)
at NHibernate.Impl.SessionImpl.ListAsync(IQueryExpression queryExpression, QueryParameters queryParameters, IList results, Object filterConnection, CancellationToken cancellationToken)
at NHibernate.Impl.AbstractSessionImpl.ListAsync[T](IQueryExpression query, QueryParameters parameters, CancellationToken cancellationToken)
at NHibernate.Impl.AbstractQueryImpl2.ListAsync[T](CancellationToken cancellationToken)
at NHibernate.Linq.DefaultQueryProvider.ExecuteListAsync[TResult](Expression expression, CancellationToken cancellationToken)
at NHibernate.Linq.LinqExtensionMethods.<>c__DisplayClass59_01.<<ToListAsync>g__InternalToListAsync|0>d.MoveNext() --- End of stack trace from previous location --- at WB.UI.Headquarters.Controllers.Api.PublicApi.Graphql.Interviews.AnswerObjectType.<>c__DisplayClass0_0.<<Configure>b__9>d.MoveNext() --- End of stack trace from previous location --- at GreenDonut.BatchDataLoader2.FetchAsync(IReadOnlyList1 keys, Memory1 results, CancellationToken cancellationToken)
at GreenDonut.DataLoaderBase2.<>c__DisplayClass21_0.<<DispatchBatchAsync>g__StartDispatchingAsync|0>d.MoveNext() --- End of stack trace from previous location --- at WB.UI.Headquarters.Controllers.Api.PublicApi.Graphql.WorkspaceGraphQlMiddleware.InvokeAsync(IMiddlewareContext context, IWorkspaceContextAccessor workspaceContextAccessor, IWorkspaceContextSetter workspaceContextSetter) at WB.UI.Headquarters.Controllers.Api.PublicApi.Graphql.Interviews.AnswerObjectType.<>c.<<Configure>b__0_2>d.MoveNext() --- End of stack trace from previous location --- at HotChocolate.Utilities.MiddlewareCompiler1.ExpressionHelper.AwaitTaskHelper(Task task)
at HotChocolate.Types.Helpers.FieldMiddlewareCompiler.<>c__DisplayClass9_0.<b__0>d.MoveNext()
— End of stack trace from previous location —
at HotChocolate.Execution.Processing.Tasks.ResolverTask.ExecuteResolverPipelineAsync(CancellationToken cancellationToken)
at WB.UI.Headquarters.Controllers.Api.PublicApi.Graphql.WorkspaceGraphQlMiddleware.InvokeAsync(IMiddlewareContext context, IWorkspaceContextAccessor workspaceContextAccessor, IWorkspaceContextSetter workspaceContextSetter)
at HotChocolate.Execution.Processing.Tasks.ResolverTask.TryExecuteAsync(CancellationToken cancellationToken)
at HotChocolate.Utilities.MiddlewareCompiler`1.ExpressionHelper.AwaitTaskHelper(Task task)
at HotChocolate.Execution.Processing.Tasks.ResolverTask.ExecuteResolverPipelineAsync(CancellationToken cancellationToken)
at HotChocolate.Execution.Processing.Tasks.ResolverTask.TryExecuteAsync(CancellationToken cancellationToken)
2024-06-28 09:05:52.013 +02:00 [ERR] /interviews/nodes[8]/identifyingData[12]/entityUnexpected Execution Error

daniedk · July 1, 2024, 10:40am

Good day,
More and more of these cases are occurring and the supervisors are complaining about not being able to accept or reject.

Any ideas or suggestions based on the log above?

Regards

vitalii · July 1, 2024, 2:27pm

The log record above shows an error on UI list of interviews. It has no relation to synchronization. Check your logs for the different entries.

daniedk · July 1, 2024, 5:08pm

Hi Vitalii
I have looked at the log(should have done that earlier)
and found
Exception data:
Severity: ERROR
SqlState: XX002
MessageText: heap tid from index tuple (576,2) points to unused heap page item at offset 141 of block 196 in index “interviewsummaries_pk”
File: heapam.c
Line: 7449
Routine: index_delete_check_htid
— End of inner exception stack trace —

daniedk · July 1, 2024, 5:12pm

I have tried to reindex the Interviewsummaries table but it complains about a duplicate primary key

daniedk · July 5, 2024, 7:24am

Thank you Vitalii for assisting and guiding me, Just to complete the post.
The duplicate record was not visible when doing a normal select from the interviewsummaries table, But when selecting duplicates using count(*) and group by it showed that there was a duplicate as the error indicate.

We ended up selecting ID ranges untill we found the duplicate and deleted it from the table.
Once deleted this error did not appear on the log anymore.

Thank you again Vitalii for your support