search

Azure / azure-functions-durable-extension

Durable Task Framework extension for Azure Functions
MIT License
710 stars 263 forks source link

Exception: System.ObjectDisposedException: IFeatureCollection has been disposed. Object name: 'Collection' #2828

Closed jaliyaudagedara closed 1 month ago

jaliyaudagedara commented 1 month ago

Created a Durable Function App using Visual Studio 2022, and updated packages to their latest. 

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <TargetFramework>net8.0</TargetFramework>
    <AzureFunctionsVersion>v4</AzureFunctionsVersion>
    <OutputType>Exe</OutputType>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>
  <ItemGroup>
    <FrameworkReference Include="Microsoft.AspNetCore.App" />
    <PackageReference Include="Microsoft.Azure.Functions.Worker" Version="1.22.0" />
    <PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.DurableTask" Version="1.1.3" />
    <PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http" Version="3.2.0" />
    <PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.3.0" />
    <PackageReference Include="Microsoft.Azure.Functions.Worker.Sdk" Version="1.17.2" />
    <PackageReference Include="Microsoft.ApplicationInsights.WorkerService" Version="2.22.0" />
    <PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.2.0" />
  </ItemGroup>
  <ItemGroup>
    <None Update="host.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
    </None>
    <None Update="local.settings.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
      <CopyToPublishDirectory>Never</CopyToPublishDirectory>
    </None>
  </ItemGroup>
  <ItemGroup>
    <Using Include="System.Threading.ExecutionContext" Alias="ExecutionContext" />
  </ItemGroup>
</Project>

Upon executing the HTTP Trigger, getting the following exception.

System.Private.CoreLib: Exception while executing function: Functions.Function1_HttpStart. System.Private.CoreLib: Result: Failure
Exception: System.ObjectDisposedException: IFeatureCollection has been disposed.
 Object name: 'Collection'.
    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ContextDisposed()
    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.Fetch[TFeature](TFeature& cached, Func`2 factory)
    at Microsoft.AspNetCore.Http.DefaultHttpResponse.get_StatusCode()
    at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.AspNetCoreHttpResponseData.get_StatusCode() in D:\a\_work\1\s\extensions\Worker.Extensions.Http.AspNetCore\src\HttpDataModel\AspNetCoreHttpResponseData.cs:line 39
    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcHttpAsync(HttpResponseData response, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 88
    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcAsync(Object value, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 35
    at Microsoft.Azure.Functions.Worker.Handlers.InvocationHandler.InvokeAsync(InvocationRequest request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\Handlers\InvocationHandler.cs:line 110
Stack:    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ContextDisposed()
    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.Fetch[TFeature](TFeature& cached, Func`2 factory)
    at Microsoft.AspNetCore.Http.DefaultHttpResponse.get_StatusCode()
    at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.AspNetCoreHttpResponseData.get_StatusCode() in D:\a\_work\1\s\extensions\Worker.Extensions.Http.AspNetCore\src\HttpDataModel\AspNetCoreHttpResponseData.cs:line 39
    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcHttpAsync(HttpResponseData response, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 88
    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcAsync(Object value, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 35
    at Microsoft.Azure.Functions.Worker.Handlers.InvocationHandler.InvokeAsync(InvocationRequest request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\Handlers\InvocationHandler.cs:line 110.

Verbose logging:


                  %%%%%%
                 %%%%%%
            @   %%%%%%    @
          @@   %%%%%%      @@
       @@@    %%%%%%%%%%%    @@@
     @@      %%%%%%%%%%        @@
       @@         %%%%       @@
         @@      %%%       @@
           @@    %%      @@
                %%
                %

Azure Functions Core Tools
Core Tools Version:       4.0.5801 Commit hash: N/A +5ac2f09758b98257e728dd1b5576ce5ea9ef68ff (64-bit)
Function Runtime Version: 4.34.1.22669

[2024-05-22T09:57:16.720Z] Found C:\Users\Jaliya\Desktop\FunctionApp1\FunctionApp1\FunctionApp1.csproj. Using for user secrets file configuration.
[2024-05-22T09:57:17.009Z] Building host: version spec: , startup suppressed: 'False', configuration suppressed: 'False', startup operation id: 'b8c05e8d-fcef-4cec-9505-2592dce9cbf0'
[2024-05-22T09:57:17.015Z] Reading host configuration file 'C:\Users\Jaliya\Desktop\FunctionApp1\FunctionApp1\bin\Debug\net8.0\host.json'
[2024-05-22T09:57:17.016Z] Host configuration file read:
[2024-05-22T09:57:17.017Z] {
[2024-05-22T09:57:17.017Z]   "version": "2.0",
[2024-05-22T09:57:17.018Z]   "logging": {
[2024-05-22T09:57:17.018Z]     "applicationInsights": {
[2024-05-22T09:57:17.019Z]       "samplingSettings": {
[2024-05-22T09:57:17.020Z]         "isEnabled": true,
[2024-05-22T09:57:17.020Z]         "excludedTypes": "Request"
[2024-05-22T09:57:17.021Z]       },
[2024-05-22T09:57:17.022Z]       "enableLiveMetricsFilters": true
[2024-05-22T09:57:17.023Z]     }
[2024-05-22T09:57:17.024Z]   }
[2024-05-22T09:57:17.025Z] }
[2024-05-22T09:57:17.039Z] Extension Bundle not loaded. Loading extensions from C:\Users\Jaliya\Desktop\FunctionApp1\FunctionApp1\bin\Debug\net8.0. BundleConfigured: False, PrecompiledFunctionApp: False, LegacyBundle: False, DotnetIsolatedApp: True, isLogicApp: False
[2024-05-22T09:57:17.041Z] Script Startup resetting load context with base path: 'C:\Users\Jaliya\Desktop\FunctionApp1\FunctionApp1\bin\Debug\net8.0\.azurefunctions'.
[2024-05-22T09:57:17.050Z] Loading startup extension 'DurableTask'
[2024-05-22T09:57:17.097Z] Loaded extension 'DurableTask' (2.0.0.0)
[2024-05-22T09:57:17.107Z] Loading startup extension 'Startup'
[2024-05-22T09:57:17.108Z] Loaded extension 'Startup' (1.0.0.0)
[2024-05-22T09:57:17.118Z] Reading host configuration file 'C:\Users\Jaliya\Desktop\FunctionApp1\FunctionApp1\bin\Debug\net8.0\host.json'
[2024-05-22T09:57:17.118Z] Host configuration file read:
[2024-05-22T09:57:17.119Z] {
[2024-05-22T09:57:17.120Z]   "version": "2.0",
[2024-05-22T09:57:17.121Z]   "logging": {
[2024-05-22T09:57:17.122Z]     "applicationInsights": {
[2024-05-22T09:57:17.123Z]       "samplingSettings": {
[2024-05-22T09:57:17.124Z]         "isEnabled": true,
[2024-05-22T09:57:17.128Z]         "excludedTypes": "Request"
[2024-05-22T09:57:17.129Z]       },
[2024-05-22T09:57:17.144Z]       "enableLiveMetricsFilters": true
[2024-05-22T09:57:17.145Z]     }
[2024-05-22T09:57:17.145Z]   }
[2024-05-22T09:57:17.146Z] }
[2024-05-22T09:57:17.561Z] Using the default storage provider: AzureStorage.
[2024-05-22T09:57:18.119Z] Initializing Warmup Extension.
[2024-05-22T09:57:18.128Z] Resolved secret storage provider BlobStorageSecretsRepository
[2024-05-22T09:57:18.255Z] Durable extension configuration loaded: {"httpSettings":{"defaultAsyncRequestSleepTimeMilliseconds":30000},"hubName":"TestHubName","storageProvider":{"connectionName":null,"connectionStringName":null,"controlQueueBatchSize":32,"partitionCount":4,"controlQueueBufferThreshold":256,"controlQueueVisibilityTimeout":"00:05:00","workItemQueueVisibilityTimeout":"00:05:00","trackingStoreConnectionName":null,"trackingStoreConnectionStringName":null,"trackingStoreNamePrefix":null,"fetchLargeMessagesAutomatically":true,"maxQueuePollingInterval":"00:00:30","useLegacyPartitionManagement":false,"useTablePartitionManagement":false},"tracing":{"traceInputsAndOutputs":false,"allowVerboseLinuxTelemetry":false,"traceReplayEvents":false,"distributedTracingEnabled":false,"distributedTracingProtocol":"HttpCorrelationProtocol","version":"V1"},"notifications":{"eventGrid":null},"maxConcurrentActivityFunctions":160,"maxConcurrentOrchestratorFunctions":160,"maxConcurrentEntityFunctions":160,"localRpcEndpointEnabled":null,"maxEntityOperationBatchSize":5000,"extendedSessionsEnabled":false,"extendedSessionIdleTimeoutInSeconds":30,"maxOrchestrationActions":100000,"overridableExistingInstanceStates":"NonRunningStates","entityMessageReorderWindowInMinutes":30,"useGracefulShutdown":false,"rollbackEntityOperationsOnExceptions":true,"throwStatusExceptionsOnRaiseEvent":null,"useAppLease":true,"storeInputsInOrchestrationHistory":false,"appLeaseOptions":{"renewInterval":"00:00:25","acquireInterval":"00:05:00","leaseInterval":"00:01:00"}}. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3.
[2024-05-22T09:57:18.318Z] Opened local gRPC endpoint: http://localhost:4001. InstanceId: . Function: . HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 0.
[2024-05-22T09:57:18.357Z] Initializing Host. OperationId: 'b8c05e8d-fcef-4cec-9505-2592dce9cbf0'.
[2024-05-22T09:57:18.367Z] Host initialization: ConsecutiveErrors=0, StartupCount=1, OperationId=b8c05e8d-fcef-4cec-9505-2592dce9cbf0
[2024-05-22T09:57:18.415Z] Loading functions metadata
[2024-05-22T09:57:18.417Z] Worker indexing is enabled
[2024-05-22T09:57:18.423Z] Fetching metadata for workerRuntime: dotnet-isolated
[2024-05-22T09:57:18.424Z] Reading functions metadata (Worker)
[2024-05-22T09:57:20.790Z] {
[2024-05-22T09:57:20.792Z]   "ProcessId": 2892,
[2024-05-22T09:57:20.793Z]   "RuntimeIdentifier": "win-x64",
[2024-05-22T09:57:20.794Z]   "WorkerVersion": "1.18.0.0",
[2024-05-22T09:57:20.800Z]   "ProductVersion": "1.18.0\u002B1e81e6133d75399dc71a808ae9d06db8f4566d99",
[2024-05-22T09:57:20.801Z]   "FrameworkDescription": ".NET 8.0.5",
[2024-05-22T09:57:20.802Z]   "OSDescription": "Microsoft Windows 10.0.22621",
[2024-05-22T09:57:20.803Z]   "OSArchitecture": "X64",
[2024-05-22T09:57:20.805Z]   "CommandLine": "C:\\Users\\Jaliya\\Desktop\\FunctionApp1\\FunctionApp1\\bin\\Debug\\net8.0\\FunctionApp1.dll --host 127.0.0.1 --port 29733 --workerId 0f25a6f8-093a-4eff-9f27-9e37ab2e0b41 --requestId bc0b7274-32cf-4b80-903b-3d809ed51b68 --grpcMaxMessageLength 2147483647 --functions-uri http://127.0.0.1:29733/ --functions-worker-id 0f25a6f8-093a-4eff-9f27-9e37ab2e0b41 --functions-request-id bc0b7274-32cf-4b80-903b-3d809ed51b68 --functions-grpc-max-message-length 2147483647"
[2024-05-22T09:57:20.806Z] }
[2024-05-22T09:57:20.995Z] 3 functions found (Worker)
[2024-05-22T09:57:21.011Z] Reading functions metadata (Custom)
[2024-05-22T09:57:21.024Z] 1 functions found (Custom)
[2024-05-22T09:57:21.034Z] 3 functions loaded
[2024-05-22T09:57:21.037Z] Azure Functions .NET Worker (PID: 2892) initialized in debug mode. Waiting for debugger to attach...
[2024-05-22T09:57:21.040Z] LoggerFilterOptions
[2024-05-22T09:57:21.041Z] {
[2024-05-22T09:57:21.042Z]   "MinLevel": "None",
[2024-05-22T09:57:21.043Z]   "Rules": [
[2024-05-22T09:57:21.044Z]     {
[2024-05-22T09:57:21.045Z]       "ProviderName": null,
[2024-05-22T09:57:21.046Z]       "CategoryName": null,
[2024-05-22T09:57:21.050Z]       "LogLevel": null,
[2024-05-22T09:57:21.051Z]       "Filter": "<AddFilter>b__0"
[2024-05-22T09:57:21.052Z]     },
[2024-05-22T09:57:21.052Z]     {
[2024-05-22T09:57:21.053Z]       "ProviderName": "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider",
[2024-05-22T09:57:21.054Z]       "CategoryName": null,
[2024-05-22T09:57:21.055Z]       "LogLevel": "None",
[2024-05-22T09:57:21.056Z]       "Filter": null
[2024-05-22T09:57:21.057Z]     },
[2024-05-22T09:57:21.058Z]     {
[2024-05-22T09:57:21.059Z]       "ProviderName": "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider",
[2024-05-22T09:57:21.059Z]       "CategoryName": null,
[2024-05-22T09:57:21.060Z]       "LogLevel": null,
[2024-05-22T09:57:21.067Z]       "Filter": "<AddFilter>b__0"
[2024-05-22T09:57:21.068Z]     },
[2024-05-22T09:57:21.069Z]     {
[2024-05-22T09:57:21.070Z]       "ProviderName": "Azure.Functions.Cli.Diagnostics.ColoredConsoleLoggerProvider",
[2024-05-22T09:57:21.071Z]       "CategoryName": null,
[2024-05-22T09:57:21.072Z]       "LogLevel": null,
[2024-05-22T09:57:21.073Z]       "Filter": "<AddFilter>b__0"
[2024-05-22T09:57:21.074Z]     }
[2024-05-22T09:57:21.075Z]   ]
[2024-05-22T09:57:21.076Z] }
[2024-05-22T09:57:21.080Z] LoggerFilterOptions
[2024-05-22T09:57:21.081Z] {
[2024-05-22T09:57:21.082Z]   "MinLevel": "None",
[2024-05-22T09:57:21.083Z]   "Rules": [
[2024-05-22T09:57:21.084Z]     {
[2024-05-22T09:57:21.085Z]       "ProviderName": null,
[2024-05-22T09:57:21.085Z]       "CategoryName": null,
[2024-05-22T09:57:21.086Z]       "LogLevel": null,
[2024-05-22T09:57:21.087Z]       "Filter": "<AddFilter>b__0"
[2024-05-22T09:57:21.088Z]     },
[2024-05-22T09:57:21.089Z]     {
[2024-05-22T09:57:21.090Z]       "ProviderName": "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider",
[2024-05-22T09:57:21.091Z]       "CategoryName": null,
[2024-05-22T09:57:21.092Z]       "LogLevel": "None",
[2024-05-22T09:57:21.098Z]       "Filter": null
[2024-05-22T09:57:21.099Z]     },
[2024-05-22T09:57:21.099Z]     {
[2024-05-22T09:57:21.100Z]       "ProviderName": "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider",
[2024-05-22T09:57:21.101Z]       "CategoryName": null,
[2024-05-22T09:57:21.102Z]       "LogLevel": null,
[2024-05-22T09:57:21.103Z]       "Filter": "<AddFilter>b__0"
[2024-05-22T09:57:21.104Z]     },
[2024-05-22T09:57:21.105Z]     {
[2024-05-22T09:57:21.105Z]       "ProviderName": "Azure.Functions.Cli.Diagnostics.ColoredConsoleLoggerProvider",
[2024-05-22T09:57:21.106Z]       "CategoryName": null,
[2024-05-22T09:57:21.112Z]       "LogLevel": null,
[2024-05-22T09:57:21.112Z]       "Filter": "<AddFilter>b__0"
[2024-05-22T09:57:21.113Z]     }
[2024-05-22T09:57:21.114Z]   ]
[2024-05-22T09:57:21.115Z] }
[2024-05-22T09:57:21.116Z] LanguageWorkerOptions
[2024-05-22T09:57:21.117Z] {
[2024-05-22T09:57:21.118Z]   "WorkerConfigs": [
[2024-05-22T09:57:21.119Z]     {
[2024-05-22T09:57:21.120Z]       "Description": {
[2024-05-22T09:57:21.121Z]         "Language": "dotnet-isolated",
[2024-05-22T09:57:21.122Z]         "DefaultRuntimeName": null,
[2024-05-22T09:57:21.127Z]         "DefaultRuntimeVersion": null,
[2024-05-22T09:57:21.144Z]         "SupportedArchitectures": null,
[2024-05-22T09:57:21.145Z]         "SupportedOperatingSystems": null,
[2024-05-22T09:57:21.146Z]         "SupportedRuntimeVersions": null,
[2024-05-22T09:57:21.147Z]         "SanitizeRuntimeVersionRegex": null,
[2024-05-22T09:57:21.148Z]         "WorkerIndexing": "true",
[2024-05-22T09:57:21.149Z]         "Extensions": [
[2024-05-22T09:57:21.150Z]           ".dll"
[2024-05-22T09:57:21.152Z]         ],
[2024-05-22T09:57:21.153Z]         "UseStdErrorStreamForErrorsOnly": false,
[2024-05-22T09:57:21.165Z]         "DefaultExecutablePath": "C:\\Program Files\\dotnet\\dotnet.exe",
[2024-05-22T09:57:21.167Z]         "DefaultWorkerPath": "C:\\Users\\Jaliya\\Desktop\\FunctionApp1\\FunctionApp1\\bin\\Debug\\net8.0\\FunctionApp1.dll",
[2024-05-22T09:57:21.169Z]         "WorkerDirectory": "C:\\Users\\Jaliya\\Desktop\\FunctionApp1\\FunctionApp1\\bin\\Debug\\net8.0",
[2024-05-22T09:57:21.178Z]         "Arguments": [],
[2024-05-22T09:57:21.180Z]         "WorkerArguments": null
[2024-05-22T09:57:21.182Z]       },
[2024-05-22T09:57:21.183Z]       "Arguments": {
[2024-05-22T09:57:21.185Z]         "ExecutablePath": "C:\\Program Files\\dotnet\\dotnet.exe",
[2024-05-22T09:57:21.187Z]         "ExecutableArguments": [],
[2024-05-22T09:57:21.189Z]         "WorkerPath": "C:\\Users\\Jaliya\\Desktop\\FunctionApp1\\FunctionApp1\\bin\\Debug\\net8.0\\FunctionApp1.dll",
[2024-05-22T09:57:21.190Z]         "WorkerArguments": []
[2024-05-22T09:57:21.191Z]       },
[2024-05-22T09:57:21.192Z]       "CountOptions": {
[2024-05-22T09:57:21.193Z]         "SetProcessCountToNumberOfCpuCores": false,
[2024-05-22T09:57:21.194Z]         "ProcessCount": 1,
[2024-05-22T09:57:21.195Z]         "MaxProcessCount": 10,
[2024-05-22T09:57:21.197Z]         "ProcessStartupInterval": "00:00:10",
[2024-05-22T09:57:21.198Z]         "ProcessStartupTimeout": "30.00:00:00",
[2024-05-22T09:57:21.199Z]         "InitializationTimeout": "30.00:00:00",
[2024-05-22T09:57:21.208Z]         "EnvironmentReloadTimeout": "00:00:30",
[2024-05-22T09:57:21.210Z]         "ProcessRestartInterval": "00:00:10",
[2024-05-22T09:57:21.211Z]         "ProcessShutdownTimeout": "00:00:10"
[2024-05-22T09:57:21.212Z]       }
[2024-05-22T09:57:21.213Z]     }
[2024-05-22T09:57:21.214Z]   ]
[2024-05-22T09:57:21.218Z] }
[2024-05-22T09:57:21.220Z] ConcurrencyOptions
[2024-05-22T09:57:21.221Z] {
[2024-05-22T09:57:21.222Z]   "DynamicConcurrencyEnabled": false,
[2024-05-22T09:57:21.223Z]   "MaximumFunctionConcurrency": 500,
[2024-05-22T09:57:21.224Z]   "CPUThreshold": 0.8,
[2024-05-22T09:57:21.226Z]   "SnapshotPersistenceEnabled": true
[2024-05-22T09:57:21.227Z] }
[2024-05-22T09:57:21.228Z] FunctionResultAggregatorOptions
[2024-05-22T09:57:21.230Z] {
[2024-05-22T09:57:21.236Z]   "BatchSize": 1000,
[2024-05-22T09:57:21.237Z]   "FlushTimeout": "00:00:30",
[2024-05-22T09:57:21.238Z]   "IsEnabled": true
[2024-05-22T09:57:21.239Z] }
[2024-05-22T09:57:21.240Z] SingletonOptions
[2024-05-22T09:57:21.242Z] {
[2024-05-22T09:57:21.243Z]   "LockPeriod": "00:00:15",
[2024-05-22T09:57:21.244Z]   "ListenerLockPeriod": "00:00:15",
[2024-05-22T09:57:21.245Z]   "LockAcquisitionTimeout": "10675199.02:48:05.4775807",
[2024-05-22T09:57:21.250Z]   "LockAcquisitionPollingInterval": "00:00:05",
[2024-05-22T09:57:21.251Z]   "ListenerLockRecoveryPollingInterval": "00:01:00"
[2024-05-22T09:57:21.252Z] }
[2024-05-22T09:57:21.254Z] ScaleOptions
[2024-05-22T09:57:21.255Z] {
[2024-05-22T09:57:21.256Z]   "ScaleMetricsMaxAge": "00:02:00",
[2024-05-22T09:57:21.257Z]   "ScaleMetricsSampleInterval": "00:00:10",
[2024-05-22T09:57:21.258Z]   "MetricsPurgeEnabled": true,
[2024-05-22T09:57:21.259Z]   "IsTargetScalingEnabled": true,
[2024-05-22T09:57:21.260Z]   "IsRuntimeScalingEnabled": false
[2024-05-22T09:57:21.266Z] }
[2024-05-22T09:57:21.268Z] Starting JobHost
[2024-05-22T09:57:21.270Z] Starting Host (HostId=ravanatpp15-1692265145, InstanceId=c7142731-d45a-4411-8bd7-84323216e57e, Version=4.34.1.22669, ProcessId=45980, AppDomainId=1, InDebugMode=False, InDiagnosticMode=False, FunctionsExtensionVersion=(null))
[2024-05-22T09:57:21.316Z] Generating 3 job function(s)
[2024-05-22T09:57:21.317Z] Worker process started and initialized.
[2024-05-22T09:57:21.368Z] Found the following functions:
[2024-05-22T09:57:21.369Z] Host.Functions.Function1
[2024-05-22T09:57:21.371Z] Host.Functions.Function1_HttpStart
[2024-05-22T09:57:21.372Z] Host.Functions.SayHello
[2024-05-22T09:57:21.374Z]
[2024-05-22T09:57:21.388Z] HttpOptions
[2024-05-22T09:57:21.389Z] Initializing function HTTP routes
[2024-05-22T09:57:21.392Z] Mapped function route 'api/Function1_HttpStart' [get,post] to 'Function1_HttpStart'
[2024-05-22T09:57:21.393Z]
[2024-05-22T09:57:21.391Z] {
[2024-05-22T09:57:21.396Z]   "DynamicThrottlesEnabled": false,
[2024-05-22T09:57:21.397Z]   "EnableChunkedRequestBinding": false,
[2024-05-22T09:57:21.398Z]   "MaxConcurrentRequests": -1,
[2024-05-22T09:57:21.399Z]   "MaxOutstandingRequests": -1,
[2024-05-22T09:57:21.400Z]   "RoutePrefix": "api"
[2024-05-22T09:57:21.401Z] }
[2024-05-22T09:57:21.402Z] Host initialized (121ms)
[2024-05-22T09:57:21.411Z] Starting task hub worker. Extension GUID ae1483da-e617-4831-884b-148d2df1adfd. InstanceId: . Function: . HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 1.

Functions:

        Function1_HttpStart: [GET,POST] http://localhost:7001/api/Function1_HttpStart

        Function1: orchestrationTrigger

        SayHello: activityTrigger

[2024-05-22T09:57:21.614Z] Task hub worker started. Latency: 00:00:00.1975825. Extension GUID ae1483da-e617-4831-884b-148d2df1adfd. InstanceId: . Function: . HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 2.
[2024-05-22T09:57:21.618Z] Host started (345ms)
[2024-05-22T09:57:21.620Z] Job host started
[2024-05-22T09:57:26.064Z] Host lock lease acquired by instance ID '000000000000000000000000CF6A328F'.
[2024-05-22T09:57:29.295Z] Executing HTTP request: {
[2024-05-22T09:57:29.297Z]   "requestId": "5e818f60-0f53-4c64-8436-ff9bf5dfaad1",
[2024-05-22T09:57:29.298Z]   "method": "GET",
[2024-05-22T09:57:29.300Z]   "userAgent": "PostmanRuntime/7.39.0",
[2024-05-22T09:57:29.301Z]   "uri": "/api/Function1_HttpStart"
[2024-05-22T09:57:29.302Z] }
[2024-05-22T09:57:29.391Z] Executing 'Functions.Function1_HttpStart' (Reason='This function was programmatically called via the host APIs.', Id=839b4cf7-d25f-41d3-904c-d60df46b5d2b)
[2024-05-22T09:57:29.670Z] Scheduling new Function1 orchestration with instance ID 'bc01902905a941cb884413484a5ce6fd' and 0 bytes of input data.
[2024-05-22T09:57:29.771Z] bc01902905a941cb884413484a5ce6fd: Function 'Function1 (Orchestrator)' scheduled. Reason: NewInstance. IsReplay: False. State: Scheduled. RuntimeStatus: Pending. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 3.
[2024-05-22T09:57:29.841Z] Started orchestration with ID = 'bc01902905a941cb884413484a5ce6fd'.
[2024-05-22T09:57:29.887Z] bc01902905a941cb884413484a5ce6fd: Function 'Function1 (Orchestrator)' started. IsReplay: False. Input: (null). State: Started. RuntimeStatus: Running. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 4. TaskEventId: -1
[2024-05-22T09:57:29.905Z] Executing 'Functions.Function1' (Reason='(null)', Id=bdd07b33-818c-46ab-a83d-e814a354223e)
[2024-05-22T09:57:29.939Z] Executed 'Functions.Function1_HttpStart' (Failed, Id=839b4cf7-d25f-41d3-904c-d60df46b5d2b, Duration=563ms)
[2024-05-22T09:57:29.941Z] System.Private.CoreLib: Exception while executing function: Functions.Function1_HttpStart. System.Private.CoreLib: Result: Failure
Exception: System.ObjectDisposedException: IFeatureCollection has been disposed.
[2024-05-22T09:57:29.942Z] Object name: 'Collection'.
[2024-05-22T09:57:29.943Z]    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
[2024-05-22T09:57:29.944Z]    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ContextDisposed()
[2024-05-22T09:57:29.945Z]    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.Fetch[TFeature](TFeature& cached, Func`2 factory)
[2024-05-22T09:57:29.947Z]    at Microsoft.AspNetCore.Http.DefaultHttpResponse.get_StatusCode()
[2024-05-22T09:57:29.948Z]    at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.AspNetCoreHttpResponseData.get_StatusCode() in D:\a\_work\1\s\extensions\Worker.Extensions.Http.AspNetCore\src\HttpDataModel\AspNetCoreHttpResponseData.cs:line 39
[2024-05-22T09:57:29.949Z]    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcHttpAsync(HttpResponseData response, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 88
[2024-05-22T09:57:29.950Z]    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcAsync(Object value, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 35
[2024-05-22T09:57:29.952Z]    at Microsoft.Azure.Functions.Worker.Handlers.InvocationHandler.InvokeAsync(InvocationRequest request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\Handlers\InvocationHandler.cs:line 110
Stack:    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
[2024-05-22T09:57:29.954Z]    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ContextDisposed()
[2024-05-22T09:57:29.955Z]    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.Fetch[TFeature](TFeature& cached, Func`2 factory)
[2024-05-22T09:57:29.956Z]    at Microsoft.AspNetCore.Http.DefaultHttpResponse.get_StatusCode()
[2024-05-22T09:57:29.958Z]    at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.AspNetCoreHttpResponseData.get_StatusCode() in D:\a\_work\1\s\extensions\Worker.Extensions.Http.AspNetCore\src\HttpDataModel\AspNetCoreHttpResponseData.cs:line 39
[2024-05-22T09:57:29.960Z]    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcHttpAsync(HttpResponseData response, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 88
[2024-05-22T09:57:29.970Z]    at Microsoft.Azure.Functions.Worker.Rpc.RpcExtensions.ToRpcAsync(Object value, ObjectSerializer serializer) in D:\a\_work\1\s\src\DotNetWorker.Grpc\RpcExtensions.cs:line 35
[2024-05-22T09:57:29.972Z]    at Microsoft.Azure.Functions.Worker.Handlers.InvocationHandler.InvokeAsync(InvocationRequest request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\Handlers\InvocationHandler.cs:line 110.
[2024-05-22T09:57:30.003Z] Saying hello.
[2024-05-22T09:57:30.060Z] Executed 'Functions.Function1' (Succeeded, Id=bdd07b33-818c-46ab-a83d-e814a354223e, Duration=168ms)
[2024-05-22T09:57:30.063Z] bc01902905a941cb884413484a5ce6fd: Function 'Function1 (Orchestrator)' awaited. IsReplay: False. State: Awaited. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 5.
[2024-05-22T09:57:30.093Z] bc01902905a941cb884413484a5ce6fd: Function 'SayHello (Activity)' started. IsReplay: False. Input: (36 bytes). State: Started. RuntimeStatus: Running. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 6. TaskEventId: 0
[2024-05-22T09:57:30.099Z] Executing 'Functions.SayHello' (Reason='(null)', Id=e13db173-7acb-48f2-8b4a-0dd2fd218c89)
[2024-05-22T09:57:30.123Z] Saying hello to Tokyo.
[2024-05-22T09:57:30.126Z] Executed 'Functions.SayHello' (Succeeded, Id=e13db173-7acb-48f2-8b4a-0dd2fd218c89, Duration=29ms)
[2024-05-22T09:57:30.128Z] bc01902905a941cb884413484a5ce6fd: Function 'SayHello (Activity)' completed. ContinuedAsNew: False. IsReplay: False. Output: (56 bytes). State: Completed. RuntimeStatus: Completed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 7. TaskEventId: 0
[2024-05-22T09:57:30.151Z] Executing 'Functions.Function1' (Reason='(null)', Id=a6b75b13-6505-4de5-822f-5bf6ec1a2031)
[2024-05-22T09:57:30.179Z] Executed 'Functions.Function1' (Succeeded, Id=a6b75b13-6505-4de5-822f-5bf6ec1a2031, Duration=29ms)
[2024-05-22T09:57:30.181Z] bc01902905a941cb884413484a5ce6fd: Function 'Function1 (Orchestrator)' awaited. IsReplay: False. State: Awaited. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 8.
[2024-05-22T09:57:30.194Z] bc01902905a941cb884413484a5ce6fd: Function 'SayHello (Activity)' started. IsReplay: False. Input: (44 bytes). State: Started. RuntimeStatus: Running. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 9. TaskEventId: 1
[2024-05-22T09:57:30.196Z] Executing 'Functions.SayHello' (Reason='(null)', Id=3c796aaf-fc6a-4840-8166-c6e868ae5722)
[2024-05-22T09:57:30.214Z] Saying hello to Seattle.
[2024-05-22T09:57:30.216Z] Executed 'Functions.SayHello' (Succeeded, Id=3c796aaf-fc6a-4840-8166-c6e868ae5722, Duration=20ms)
[2024-05-22T09:57:30.227Z] bc01902905a941cb884413484a5ce6fd: Function 'SayHello (Activity)' completed. ContinuedAsNew: False. IsReplay: False. Output: (64 bytes). State: Completed. RuntimeStatus: Completed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 10. TaskEventId: 1
[2024-05-22T09:57:30.238Z] Executing 'Functions.Function1' (Reason='(null)', Id=2b50a17a-a27b-4b4c-b202-b2f9c420c287)
[2024-05-22T09:57:30.262Z] Executed 'Functions.Function1' (Succeeded, Id=2b50a17a-a27b-4b4c-b202-b2f9c420c287, Duration=23ms)
[2024-05-22T09:57:30.263Z] bc01902905a941cb884413484a5ce6fd: Function 'Function1 (Orchestrator)' awaited. IsReplay: False. State: Awaited. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 11.
[2024-05-22T09:57:30.272Z] bc01902905a941cb884413484a5ce6fd: Function 'SayHello (Activity)' started. IsReplay: False. Input: (40 bytes). State: Started. RuntimeStatus: Running. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 12. TaskEventId: 2
[2024-05-22T09:57:30.274Z] Executing 'Functions.SayHello' (Reason='(null)', Id=feb00102-80d4-47b7-a9b8-5aabd5b01c60)
[2024-05-22T09:57:30.292Z] Saying hello to London.
[2024-05-22T09:57:30.294Z] Executed 'Functions.SayHello' (Succeeded, Id=feb00102-80d4-47b7-a9b8-5aabd5b01c60, Duration=19ms)
[2024-05-22T09:57:30.295Z] bc01902905a941cb884413484a5ce6fd: Function 'SayHello (Activity)' completed. ContinuedAsNew: False. IsReplay: False. Output: (60 bytes). State: Completed. RuntimeStatus: Completed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 13. TaskEventId: 2
[2024-05-22T09:57:30.306Z] Executing 'Functions.Function1' (Reason='(null)', Id=5f2b84b8-4a62-4d48-84da-2058041e5398)
[2024-05-22T09:57:30.331Z] Executed 'Functions.Function1' (Succeeded, Id=5f2b84b8-4a62-4d48-84da-2058041e5398, Duration=24ms)
[2024-05-22T09:57:30.332Z] bc01902905a941cb884413484a5ce6fd: Function 'Function1 (Orchestrator)' completed. ContinuedAsNew: False. IsReplay: False. Output: (196 bytes). State: Completed. RuntimeStatus: Completed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.13.3. SequenceNumber: 14. TaskEventId: -1

Example Project: FunctionApp1.zip

jaliyaudagedara commented 1 month ago

The culprit seems to be,

<!--Works-->
<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.2.0" />

<!--Breaks-->
<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.3.0" />

Believe we can close this issue, as it's not caused by durable extensions. But will leave it up for you guys.

jviau commented 1 month ago

Thanks @jaliyaudagedara. I agree, I don't believe this is durable related. I'll leave this issue open though so anyone else encountering this will see this and be directed to the correct issue.

jaliyaudagedara commented 1 month ago

@jviau, no problem. Sounds good!

aiden-vchandran commented 1 month ago

It is not durable related. 1.3.0 does indeed have this issue. I am running a few HTTP-triggered functions and some timer-triggered ones.

jaliyaudagedara commented 1 month ago

This is now fixed with,

<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.3.1" />