Azure Function Custom Handler not marking function run as complete

Question

I am attempting to develop an Azure Function for processing Kafka messages using a custom handler. Currently the Kafka Trigger reads messages from my topic and successfully triggers my function, which at the moment does some parsing and outputs the message to the console. My handler then returns a 200 response code back to the Functions Host which I can see reflected in the logs. However it does not mark my function run as complete, causing it to timeout. Here is a Trace level log from the run with my topic name and actual data stripped:

[2021-08-12T20:11:17.114Z] HttpWorker is Initialized.
[2021-08-12T20:11:17.114Z] Adding http worker channel. workerId:73835199-cfb0-45fa-9470-0e0f81afd874
[2021-08-12T20:11:17.115Z] Worker process started and initialized.
[2021-08-12T20:11:17.119Z] Host initialized (292ms)
[2021-08-12T20:11:17.124Z] FunctionExecutor Loaded: SingleItemFunctionExecutor
[2021-08-12T20:11:17.128Z] Host started (306ms)
[2021-08-12T20:11:17.128Z] Job host started
[2021-08-12T20:11:17.211Z] File event source initialized.
[2021-08-12T20:11:17.296Z] Debug file watch initialized.
[2021-08-12T20:11:17.374Z] Diagnostic file watch initialized.
[2021-08-12T20:11:17.374Z] Hosting started
[2021-08-12T20:11:17.375Z] Startup operation '6961a37c-9468-45c0-a8aa-1fee5ac9050d' completed.

Functions:

        Kafka: kafkaTrigger

For detailed output, run func with --verbose flag.
[2021-08-12T20:11:22.145Z] Host lock lease acquired by instance ID '000000000000000000000000C8A8E294'.
[2021-08-12T20:11:33.180Z] Assigned partitions: [<my kafka partations>]
[2021-08-12T20:11:34.201Z] Executing 'Functions.Kafka' (Reason='(null)', Id=cb9ebab0-046e-4da1-bd72-b6b29652e62c)
[2021-08-12T20:11:34.213Z] Executing 'Functions.Kafka' (Reason='(null)', Id=7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc)
[2021-08-12T20:11:34.221Z] Sending invocation id:cb9ebab0-046e-4da1-bd72-b6b29652e62c
[2021-08-12T20:11:34.221Z] Sending invocation id:7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc
[2021-08-12T20:11:34.235Z] Invocation Request:Method: POST, RequestUri: 'http://127.0.0.1:51190/Kafka', Version: 1.1, Content: System.Net.Http.ObjectContent`1[Microsoft.Azure.WebJobs.Script.Workers.Http.HttpScriptInvocationContext], Headers:
[2021-08-12T20:11:34.235Z] Invocation Request:Method: POST, RequestUri: 'http://127.0.0.1:51190/Kafka', Version: 1.1, Content: System.Net.Http.ObjectContent`1[Microsoft.Azure.WebJobs.Script.Workers.Http.HttpScriptInvocationContext], Headers:
[2021-08-12T20:11:34.235Z] {
[2021-08-12T20:11:34.235Z] {
[2021-08-12T20:11:34.235Z]   X-Azure-Functions-HostVersion: 3.0.15828.0
[2021-08-12T20:11:34.235Z]   X-Azure-Functions-InvocationId: 7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc
[2021-08-12T20:11:34.235Z]   X-Azure-Functions-HostVersion: 3.0.15828.0
[2021-08-12T20:11:34.235Z]   User-Agent: Azure-Functions-Host/3.0.15828.0
[2021-08-12T20:11:34.235Z]   X-Azure-Functions-InvocationId: cb9ebab0-046e-4da1-bd72-b6b29652e62c
[2021-08-12T20:11:34.235Z]   Content-Type: application/json; charset=utf-8
[2021-08-12T20:11:34.235Z] }
[2021-08-12T20:11:34.235Z]   User-Agent: Azure-Functions-Host/3.0.15828.0
[2021-08-12T20:11:34.235Z]   Content-Type: application/json; charset=utf-8
[2021-08-12T20:11:34.235Z] }
[2021-08-12T20:11:34.246Z] {"Data": {"eventData": "mydata"},"Metadata": {"Partition": "\"0\"","Topic": "my topic","Timestamp": "\"08/12/2021 19:41:25\"","Offset": "\"61\"", "sys": {"MethodName": "Kafka","UtcNow": "2021-08-12T20:11:34.226978Z","RandGuid": "2ec3a20d-51db-4d1d-94ec-cd21a8af82e5"},"Value": "mydata"}}
[2021-08-12T20:11:34.246Z] {"Data": {"eventData": "mydata"},"Metadata": {"Partition": "\"0\"","Topic": "my topic","Timestamp": "\"08/12/2021 19:41:25\"","Offset": "\"61\"", "sys": {"MethodName": "Kafka","UtcNow": "2021-08-12T20:11:34.226978Z","RandGuid": "2ec3a20d-51db-4d1d-94ec-cd21a8af82e5"},"Value": "mydata"}}
[2021-08-12T20:11:34.254Z] Sending invocation for function: 'Kafka' invocationId: '7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc'
[2021-08-12T20:11:34.254Z] Sending invocation for function: 'Kafka' invocationId: 'cb9ebab0-046e-4da1-bd72-b6b29652e62c'
[2021-08-12T20:11:34.258Z] "my data properly outputed from my function"
[2021-08-12T20:11:34.259Z] "my data properly outputed from my function"
[2021-08-12T20:11:34.259Z] Invocation Response:StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
[2021-08-12T20:11:34.259Z] Invocation Response:StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
[2021-08-12T20:11:34.259Z] {
[2021-08-12T20:11:34.259Z] {
[2021-08-12T20:11:34.260Z]   Date: Thu, 12 Aug 2021 20:11:34 GMT
[2021-08-12T20:11:34.260Z]   Date: Thu, 12 Aug 2021 20:11:34 GMT
[2021-08-12T20:11:34.260Z]   Content-Length: 0
[2021-08-12T20:11:34.260Z] }
[2021-08-12T20:11:34.260Z]   Content-Length: 0
[2021-08-12T20:11:34.260Z] }
[2021-08-12T20:11:34.260Z] Received invocation response for function: 'Kafka' invocationId: '7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc'
[2021-08-12T20:11:34.260Z] Received invocation response for function: 'Kafka' invocationId: 'cb9ebab0-046e-4da1-bd72-b6b29652e62c'
[2021-08-12T20:11:44.211Z] Timeout value of 00:00:10 exceeded by function 'Functions.Kafka' (Id: 'cb9ebab0-046e-4da1-bd72-b6b29652e62c'). Initiating cancellation.
[2021-08-12T20:11:44.214Z] Timeout value of 00:00:10 exceeded by function 'Functions.Kafka' (Id: '7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc'). Initiating cancellation.
[2021-08-12T20:11:44.250Z] Executed 'Functions.Kafka' (Failed, Id=cb9ebab0-046e-4da1-bd72-b6b29652e62c, Duration=10082ms)
[2021-08-12T20:11:44.250Z] Microsoft.Azure.WebJobs.Host: Timeout value of 00:00:10 was exceeded by function: Functions.Kafka.
[2021-08-12T20:11:44.250Z] Executed 'Functions.Kafka' (Failed, Id=7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc, Duration=10027ms)
[2021-08-12T20:11:44.250Z] Microsoft.Azure.WebJobs.Host: Timeout value of 00:00:10 was exceeded by function: Functions.Kafka.
[2021-08-12T20:11:46.265Z] A function timeout has occurred. Restarting worker process executing invocationId '7e4ee428-61c6-4a2f-a4e6-18fa5e2378fc'.
[2021-08-12T20:11:46.265Z] A function timeout has occurred. Restarting worker process executing invocationId 'cb9ebab0-046e-4da1-bd72-b6b29652e62c'.

I have tried timeouts significantly longer but despite my handler returning a 200 status the function is never marked as succeeded.

Here are the config files from my function:

host.json:

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "default": "Trace"
    }
  },
  "functionTimeout": "00:00:10",
  "functions": [ "Kafka" ],
  "customHandler": {
    "description": {
      "defaultExecutablePath": "handler",
      "arguments": [
        "-c",
        "./config.yaml"
      ]
    },
    "enableForwardingHttpRequest": true
  },
  "extensions": {
    "http": {
      "routePrefix": ""
    }
  }
}

Kafka/function.json:

{
  "bindings": [
    {
      "name": "eventData",
      "type": "kafkaTrigger",
      "direction": "in",
      "brokerList": "broker url",
      "topic": "topic name",
      "protocol": "ssl",
      "authenticationMode": "NOTSET",
      "SslKeyLocation": "./ssl/key.pem",
      "SslCertificateLocation": "./ssl/cert.pem",
      "SslCaLocation": "./ssl/ca.crt",
      "consumerGroup": "consumer group"
    },
    {
      "type": "http",
      "direction": "out",
      "name": "res"
    }
  ]
}

local.settings.json:

{
  "IsEncrypted": false,
  "Values": {
    "UseDevelopmentStorage": "true",
    "FUNCTIONS_WORKER_RUNTIME": "Custom"
  }
}

Answer 1

Yes I was able to resolve by changing the status code my underlying executable returned upon consuming a message