C# StackTrace method names do not align with source code

0

I have a case where a stack trace contains a method name that does not align with the method in the source code. The source calls .FirstOrDefault() and a DbUpdateException gets thrown (a timeout) with a stack trace that shows .SingleOrDefault() instead.

This is not a case of the source code being misaligned with the version of the DLL that is being loaded into the process space. I know this for sure because:

  1. There was never a time that this source code called .SingleOrDefault()
  2. To verify that the DLL actually contains a call to .FirstOrDefault() and not a call to .SingleOrDefault() instead, I did the following:
    • Launch the app
    • Find the DLL in the running process space using Sysinternals Process Explorer
    • Copy the full path of the loaded DLL from Process Explorer
    • Load that DLL into JustDecompile and find the call to .FirstOrDefault()

Here is the JustDecompiled code (notice the last line calling .FirstOrDefault()):

    private QueueEntry FetchNextQueueEntryOrDefault(long? queueEntryId, BatchProcessingQueueDefinition? queueDefinition, DefaultDbContext context)
    {
        DateTimeOffset now = DateTimeOffset.get_Now();
        IQueryable<QueueEntry> queryable = Queryable.Where<QueueEntry>(context.QueueEntries.Include<QueueEntry, QueueDefinitionSchedule>((QueueEntry x) => x.QueueDefinitionSchedule), (QueueEntry o) => (Int32)o.Status == 0);
        if (queueEntryId.get_HasValue())
        {
            queryable = Queryable.Where<QueueEntry>(queryable, (QueueEntry o) => (long?)o.Id == queueEntryId);
        }
        if (queueDefinition.get_HasValue())
        {
            queryable = Queryable.Where<QueueEntry>(queryable, (QueueEntry o) => (int?)o.QueueDefinitionId == (int?)queueDefinition);
        }
        queryable = Queryable.Where<QueueEntry>(queryable, (QueueEntry o) => (o.DoNotExecuteUntilMoment == null) || (o.DoNotExecuteUntilMoment <= (DateTimeOffset?)now));
        return Queryable.FirstOrDefault<QueueEntry>(queryable);
    }

With my process running, I forced the timeout exception to occur by locking the database table from within SSMS (I just started a transaction to lock the proper table and didn't commit). The call to .FirstOrDefault() timed out and produced the following exception (I added the 6 asterisks on the offending line):

Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.   
---> System.ComponentModel.Win32Exception (258): The wait operation timed out.  
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)  
   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)  
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)  
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)  
   at Microsoft.Data.SqlClient.SqlDataReader.TryConsumeMetaData()  
   at Microsoft.Data.SqlClient.SqlDataReader.get_MetaData()  
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)  
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)  
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method)  
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)  
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader(RelationalCommandParameterObject parameterObject)  
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.InitializeReader(DbContext _, Boolean result)  
   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)  
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.MoveNext()  
   at *** System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source) ***  
   at DataAccess.Repositories.QueueEntryExecutionRepository.FetchNextQueueEntryOrDefault(Nullable`1 queueEntryId, Nullable`1 queueDefinition, DefaultDbContext context) in E:\Work\Clients\Schaneville\CryptoBot\src\DataAccess\Repositories\QueueEntryExecutionRepository.cs:line 103  
   at DataAccess.Repositories.QueueEntryExecutionRepository.FetchNextQueueEntryOrDefaultWithConcurrencyCheck(Nullable`1 queueEntryId, Nullable`1 queueDefinition, DefaultDbContext context, TransactionScope scope) in E:\Work\Clients\Schaneville\CryptoBot\src\DataAccess\Repositories\QueueEntryExecutionRepository.cs:line 83  
   at DataAccess.Repositories.QueueEntryExecutionRepository.TryFetchNextQueueEntryForExecution(Nullable`1 queueEntryId, Nullable`1 queueDefinition) in E:\Work\Clients\Schaneville\CryptoBot\src\DataAccess\Repositories\QueueEntryExecutionRepository.cs:line 54  
   at DataAccess.Repositories.QueueEntryExecutionRepository.TryFetchNextQueueEntryForExecution(BatchProcessingQueueDefinition queueDefinition) in E:\Work\Clients\Schaneville\CryptoBot\src\DataAccess\Repositories\QueueEntryExecutionRepository.cs:line 42  
   at Core.Framework.Commands.BatchProcessing.Services.ExecuteNextQueueEntryService.Execute(BatchProcessingQueueDefinition queueDefinition) in E:\Work\Clients\Schaneville\CryptoBot\src\Core\Framework\Commands\BatchProcessing\Services\ExecuteNextQueueEntryService.cs:line 98  
   at Core.Framework.Commands.BatchProcessing.Services.ExecutePendingQueueEntriesService.InvokeService(IExecuteNextQueueEntryService service) in E:\Work\Clients\Schaneville\CryptoBot\src\Core\Framework\Commands\BatchProcessing\Services\ExecutePendingQueueEntriesService.cs:line 100  
   at Core.Framework.Commands.BatchProcessing.Services.ExecutePendingQueueEntriesService.ProcessOneQueueEntry() in E:\Work\Clients\Schaneville\CryptoBot\src\Core\Framework\Commands\BatchProcessing\Services\ExecutePendingQueueEntriesService.cs:line 75  
   at Core.Framework.Commands.BatchProcessing.Services.ExecutePendingQueueEntriesService.TryProcessOneQueueEntry() in E:\Work\Clients\Schaneville\CryptoBot\src\Core\Framework\Commands\BatchProcessing\Services\ExecutePendingQueueEntriesService.cs:line 61  ClientConnectionId:2c8ecfdc-2b17-4371-913c-a34158a53600  Error Number:-2,State:0,Class:11

So, can anyone explain why the runtime is recording .SingleOrDefault() instead of .FirstOrDefault() into the stack trace?

I don't have any functional issues here, the code is behaving as I expect. The code does not throw the InvalidOperationException that you would expect from .SingleOrDefault() when there is more than 1 item that passes the .Where(...) clause of the query in question. So the code is behaving as if it is a call to .FirstOrDefault(), just as I expect and want. It is only that the stack trace is showing it incorrectly that bothers me (and it only bothers me because I don't understand it!!).

One last thing... I have another instance of this same weird behavior. In short, my code calls .LastOrDefault() but the stack shows System.Linq.Enumerable.TryGetLast[TSource](IEnumerable`1 source, Boolean& found). I would understand this if I saw .LastOrDefault() in the stack and then saw .LastOrDefault() calling .TryGetLast() in turn, but no, it appears that my code calls .TryGetLast() directly according to the stack. So, that's weird.

Thoughts? Thanks!!!

~Steve

c#
stack
stack-trace
asked on Stack Overflow Sep 4, 2020 by schaneville • edited Sep 4, 2020 by schaneville

0 Answers

Nobody has answered this question yet.


User contributions licensed under CC BY-SA 3.0