Azure Function, either In-Process or Independent Worker, catches exception but then continues executing code after the throw reaching 200 OK.

[radumi]

Library name and version

.Net 6.0

Describe the bug

Azure Function, either In-Process or Independent Worker, catches exception but then continues executing code after the throw reaching 200 OK instead of just 400 BadRequest

`
[FunctionName(nameof(ChoiceInPHttpTrigger))]
public static async Task RunAsync([HttpTrigger(AuthorizationLevel.Anonymous, "get", "post", Route = null)] HttpRequest req, ILogger log)
{
Task tResp = ProcessInP.ProcessChoiceInPHttpTriggerAsync(req, log);
HttpResponseMessage resp = await tResp;
return resp;
}

public static async Task ProcessChoiceInPHttpTriggerAsync(HttpRequest req, ILogger log, Processor proc = null)
{
string signature = nameof(ProcessChoiceInPHttpTriggerAsync);

try
{
	signature = GetSignature(req);
	log.LogTrace($"{signature} BEGIN {req?.Method} content len={req?.ContentLength} type={req?.ContentType} isJson={req?.IsJsonContentType()}");

	LocalState lst = await LocalStateFactoryInP.CreateStateAsync(req);
	lst.ResultData = await Process.ApplyProcessorAsync(lst, proc ?? new Processor(log));  //Exception is just thrown from inside there from a synchronous static method

	log.LogWarning($"WARN {signature} IF YOU SEE THIS OK STATUS there should NOT be an exception in the scope above!");
	HttpResponseMessage resp = ResponseFactory.CreateResponse(HttpStatusCode.OK, lst.ResultData);

	log.LogTrace($"{signature} END status={resp.StatusCode} success={resp.IsSuccessStatusCode}");
	return resp;
}
catch (ArgumentException ex)
{
	log.LogError($"ERROR {signature} status={HttpStatusCode.BadRequest} message={ex.Message}");
	return ResponseFactory.CreateResponseString(HttpStatusCode.BadRequest, ex.Message);
}
catch (ApplicationException ex)
{
	log.LogError($"ERROR {signature} status={HttpStatusCode.ExpectationFailed} message={ex.Message}");
	return ResponseFactory.CreateResponseString(HttpStatusCode.ExpectationFailed, ex.Message);
}
catch (Exception ex)
{
	log.LogError($"ERROR {signature} status={HttpStatusCode.InternalServerError} message={ex.Message} {ex.StackTrace}");
	return ResponseFactory.CreateResponseString(HttpStatusCode.InternalServerError, "See log for details");
}

}

public static async Task ApplyProcessorAsync(LocalState lst = null, Processor proc = null)
{
Validator.ValidateInput(lst);

var res = new Result();

res.Data = await proc.SomeProc.HitSomeDBReadUpperCaseAsync(lst.RepresentationData.Data);

//Tests run in about 6 seconds
//res.Length = await proc.OtherProc.HitSomeStorageReadLengthAsync(res.Data);
//res.LenOverride = await proc.OtherProcInherit.HitSomeStorageReadLengthAsync(res.Data);

//Tests run in about 4.5 seconds
IOtherProcessor[] ops = new List<IOtherProcessor>() { proc.OtherProc, proc.OtherProcInherit }.ToArray();
int[] r = await ComputeAsync(res.Data, ops);
res.Length = r[0];
res.LenOverride = r[1];

Validator.ValidateResult(res);

return res;

}

public static bool ValidateInput(LocalState lst)
{
if (lst == null)
throw new ArgumentNullException("lst", "LocalState missing");

if (lst.RepresentationData == null)
	throw new ArgumentException("lst.RepresentationData", "Representation missing");

if (string.IsNullOrEmpty(lst.RepresentationData.Data))
	throw new ArgumentException("lst.RepresentationData.Data", "Representation data missing"); // IT THROWS HERE

return true;

}`

Expected behavior

Log from Debug in VStudio - works as expected also like in XUnit test - catches exception returning BadRequest

[2024-05-15T19:08:58.029Z] Found C:\Test\Choice-AzF-SMC_C#\ChoiceAzF_InProcess\ChoiceAzF_InProcess.csproj. Using for user secrets file configuration.
Functions:
ChoiceInPHttpTrigger: [GET,POST] http://localhost:7039/api/ChoiceInPHttpTrigger
For detailed output, run func with --verbose flag.
[2024-05-15T19:09:07.099Z] Host lock lease acquired by instance ID '000000000000000000000000153F1E48'.
[2024-05-15T19:09:28.090Z] Executing 'ChoiceInPHttpTrigger' (Reason='This function was programmatically called via the host APIs.', Id=30781b89-2059-4a5c-920e-6be3610eae91)

[2024-05-15T19:09:28.188Z] ERROR 0HN3L2A5CL2DU:00000002 Process status=BadRequest message=lst.RepresentationData.Data (Parameter 'Representation data missing')

[2024-05-15T19:09:28.220Z] Executed 'ChoiceInPHttpTrigger' (Succeeded, Id=30781b89-2059-4a5c-920e-6be3610eae91, Duration=148ms)

Only works in Individual Worker model by adding [FromBody] RData representationData parameter
Still, I see the ERROR BadRequest logged twice
ProcessChoiceInWHttpTriggerAsync status=BadRequest message=lst.RepresentationData.Data (Parameter 'Representation data missing')

Connected!
2024-05-15T18:50:51Z [Information] Executing 'Functions.ChoiceInWHttpTrigger' (Reason='This function was programmatically called via the host APIs.', Id=9498f5d3-3b2d-4506-851e-a128d1f06ddc)
2024-05-15T18:50:51Z [Verbose] Sending invocation id: '9498f5d3-3b2d-4506-851e-a128d1f06ddc
2024-05-15T18:50:51Z [Verbose] Posting invocation id:9498f5d3-3b2d-4506-851e-a128d1f06ddc on workerId:1473cb2a-03a8-4bef-9aa5-3cff83557996
2024-05-15T18:50:51Z [Information] 00-92640c9328aa71d06d492cce580bf5a4-f50925cec95a7974-00 ProcessChoiceInWHttpTriggerAsync BEGIN verb=POST

2024-05-15T18:50:51Z [Error] ERROR 00-92640c9328aa71d06d492cce580bf5a4-f50925cec95a7974-00 ProcessChoiceInWHttpTriggerAsync status=BadRequest message=lst.RepresentationData.Data (Parameter 'Representation data missing')

2024-05-15T18:50:51Z [Information] Executed 'Functions.ChoiceInWHttpTrigger' (Succeeded, Id=9498f5d3-3b2d-4506-851e-a128d1f06ddc, Duration=258ms)
2024-05-15T18:50:52Z [Information] Executing 'Functions.ChoiceInWHttpTrigger' (Reason='This function was programmatically called via the host APIs.', Id=bf9dcb41-917b-4a95-b4ea-5855e9fa6c0e)
2024-05-15T18:50:52Z [Verbose] Sending invocation id: 'bf9dcb41-917b-4a95-b4ea-5855e9fa6c0e
2024-05-15T18:50:52Z [Verbose] Posting invocation id:bf9dcb41-917b-4a95-b4ea-5855e9fa6c0e on workerId:1473cb2a-03a8-4bef-9aa5-3cff83557996
2024-05-15T18:50:52Z [Information] 00-997a8f60572f4daaa1ddc4c448cf827a-f6ed3b529d0f24bc-01 ProcessChoiceInWHttpTriggerAsync BEGIN verb=POST

2024-05-15T18:50:52Z [Error] ERROR 00-997a8f60572f4daaa1ddc4c448cf827a-f6ed3b529d0f24bc-01 ProcessChoiceInWHttpTriggerAsync status=BadRequest message=lst.RepresentationData.Data (Parameter 'Representation data missing')

2024-05-15T18:50:52Z [Information] Executed 'Functions.ChoiceInWHttpTrigger' (Succeeded, Id=bf9dcb41-917b-4a95-b4ea-5855e9fa6c0e, Duration=12ms)

`[Function(nameof(ChoiceInWHttpTrigger))]
//public HttpResponseData Run([HttpTrigger(AuthorizationLevel.Anonymous, "get", "post", Route = null)] HttpRequestData req, [FromBody] RData representationData, FunctionContext ctx)
public async Task RunAsync(
[HttpTrigger(AuthorizationLevel.Anonymous, "get", "post", Route = null)] HttpRequestData req,
[FromBody] RData representationData,
FunctionContext ctx)
{
try
{
Task tResp = ProcessInW.ProcessChoiceInWHttpTriggerAsync(req, Log, representationData, Procs);
HttpResponseData resp = await tResp;
return resp;
}
catch (Exception ex)
{
Log.LogError($"ERROR {nameof(ChoiceInWHttpTrigger)} ex={ex.Message} {ex.StackTrace}");
return req.CreateResponse(HttpStatusCode.InternalServerError);
}
}

public static async Task ProcessChoiceInWHttpTriggerAsync(HttpRequestData req, ILogger log, IData payload, Processor proc = null)
{
string signature = nameof(ProcessChoiceInWHttpTriggerAsync);

try
{
	signature = GetSignature(req, nameof(ProcessChoiceInWHttpTriggerAsync));
	log.LogInformation($"{signature} BEGIN verb={req?.Method}");

	LocalState lst = LocalStateFactoryInW.CreateState(req, payload);
	lst.ResultData = await Process.ApplyProcessorAsync(lst, proc ?? new Processor(log)); //Exception is just thrown from inside there from a synchronous static method

	log.LogWarning($"WARN {signature} IF YOU SEE THIS OK STATUS there should NOT be an exception in the scope above!");
	HttpResponseData resp = ResponseFactory.Response(req.CreateResponse(HttpStatusCode.OK), lst.ResultData);

	log.LogInformation($"{signature} END status={resp.StatusCode}");
	return resp;
}
catch (ArgumentException ex)
{
	log.LogError($"ERROR {signature} status={HttpStatusCode.BadRequest} message={ex.Message}");
	return ResponseFactory.ResponseString(req.CreateResponse(HttpStatusCode.BadRequest), ex.Message);
}
catch (ApplicationException ex)
{
	log.LogError($"ERROR {signature} status={HttpStatusCode.ExpectationFailed} message={ex.Message}");
	return ResponseFactory.ResponseString(req.CreateResponse(HttpStatusCode.ExpectationFailed), ex.Message);
}
catch (Exception ex)
{
	log.LogError($"ERROR {signature} status={HttpStatusCode.InternalServerError} message={ex.Message} {ex.StackTrace}");
	return ResponseFactory.ResponseString(req.CreateResponse(HttpStatusCode.InternalServerError), "See log for details");
}

}

Program.cs of the Independent Worker example is :

using Microsoft.Extensions.Hosting;
using System.Diagnostics.CodeAnalysis;

//var host = new HostBuilder().ConfigureFunctionsWorkerDefaults().Build();
//await host.RunAsync();
//host.Run();

namespace ChoiceAzFIndividualWorker
{
[ExcludeFromCodeCoverage]
static class Program
{
static async Task Main(string[] args)
{
var host = new HostBuilder().ConfigureFunctionsWorkerDefaults().Build();
await host.RunAsync();
//host.Run();
}
}
}`

Actual behavior

Log running in Azure - after exception caught, still executes "Process IF YOU SEE THIS OK STATUS there should NOT be an exception in the scope above!"

Connected!
2024-05-15T19:15:50Z [Information] Executing 'ChoiceInPHttpTrigger' (Reason='This function was programmatically called via the host APIs.', Id=fdef415e-1402-4943-8edf-200fd9796ba3)
2024-05-15T19:15:51Z [Verbose] 4000020e-0000-ec00-b63f-84710c7967bb Process BEGIN POST content len=0 type=application/json isJson=True

2024-05-15T19:15:51Z [Error] ERROR 4000020e-0000-ec00-b63f-84710c7967bb Process status=BadRequest message=lst.RepresentationData.Data (Parameter 'Representation data missing')

2024-05-15T19:15:51Z [Information] Executed 'ChoiceInPHttpTrigger' (Succeeded, Id=fdef415e-1402-4943-8edf-200fd9796ba3, Duration=62ms)
2024-05-15T19:15:51Z [Information] Executing 'ChoiceInPHttpTrigger' (Reason='This function was programmatically called via the host APIs.', Id=d7fb7cb6-12f7-4821-a218-925c011f0f49)
2024-05-15T19:15:51Z [Verbose] 4000020f-0000-ec00-b63f-84710c7967bb Process BEGIN POST content len=2 type=application/json isJson=True

2024-05-15T19:15:51Z [Warning] WARN 4000020f-0000-ec00-b63f-84710c7967bb Process IF YOU SEE THIS OK STATUS there should NOT be an exception in the scope above!

2024-05-15T19:15:51Z [Verbose] 4000020f-0000-ec00-b63f-84710c7967bb Process END status=OK success=True
2024-05-15T19:15:51Z [Information] Executed 'ChoiceInPHttpTrigger' (Succeeded, Id=d7fb7cb6-12f7-4821-a218-925c011f0f49, Duration=242ms)

Reproduction Steps

Function is https://choiceaesb.azurewebsites.net/api/ChoiceInPHttpTrigger
POST with nothing in the body to see the 200 OK coming after the throw.

The one that works is https://choiceiwaesb.azurewebsites.net/api/ChoiceInWHttpTrigger
POST { "Data": "" } or { "Data": null } in the body to get the clean 400 Bad Request
POST { "Data": "test" } to get the clean 200 OK

Environment

Runtime 4.34.1.22669, .Net 6.0 hosted on Windows, AustraliaEastPlan (Y1: 0)

[jsquire]

Hi @radumi. Thanks for reaching out and we regret that you're experiencing difficulties. As this inquiry is unrelated to one of the Azure SDK packages maintained in this repository, I've transferred this to the Azure Functions repository as #2484. This will ensure that the folks best able to assist have visibility.

[radumi]

Thanks Jesse. Thanks/Regards, Radu.

…

On Fri, 17 May 2024, 01:10 Jesse Squire, ***@***.***> wrote: Hi @radumi <https://github.com/radumi>. Thanks for reaching out and we regret that you're experiencing difficulties. As this inquiry is unrelated to one of the Azure SDK packages maintained in this repository, I've transferred this to the Azure Functions repository as #2484 <Azure/Azure-Functions#2484>. This will ensure that the folks best able to assist have visibility. — Reply to this email directly, view it on GitHub <#44059 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AC4STLTWYEJW4IXCHWUCSJTZCSV5HAVCNFSM6AAAAABHYZWG2GVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMJVGIYDQOBUGY> . You are receiving this because you were mentioned.Message ID: ***@***.***>