components-contrib icon indicating copy to clipboard operation
components-contrib copied to clipboard

Kafka Binding v1.12.4: Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Malformed request: invalid headers.

Open Andemki opened this issue 1 year ago • 4 comments

Expected Behavior

Dapr and Azure Event Hub integration using Kafka binding works without errors in .Net applications.

Actual Behavior

I've created a new issue item based on the discussion in already resolved item: https://github.com/dapr/components-contrib/issues/2874

I've been using bindings.kafka component for recieving messages from Azure Event Hub in my application. Everything work properly in Dapr versions 1.8.7. But when I updated dapr components to any version which is greater than 1.8.7 (1.9.0 and higher), my ASP.Net Core (.Net 6 / 7 / 8) application stopped receiving new messages from EventHub. I've noticed the following error message in the sidecar container (daprd):

2024-01-31 20:40:13 time="2024-01-31T12:40:13.584601Z" level=debug msg="Processing Kafka message: my-eh-data/0/316246409 [key=MjAxMA==]" app_id=my-eventhublistener component="my-eventhub-receiver (bindings.kafka/v1)" instance=60ad509cd5a0 scope=dapr.contrib type=log ver=1.12.4
2024-01-31 20:40:13 time="2024-01-31T12:40:13.588342Z" level=debug msg="error from app consumer for binding [my-eventhub-receiver]: error invoking app: Post \"http://127.0.0.1:80/my-eventhub-receiver\": context canceled" app_id=my-eventhublistener instance=60ad509cd5a0 scope=dapr.runtime.processor.binding type=log ver=1.12.4
2024-01-31 20:40:13 time="2024-01-31T12:40:13.58847Z" level=error msg="Error processing Kafka message: my-eh-data/0/316246409 [key=MjAxMA==]. Error: error invoking app: Post \"http://127.0.0.1:80/my-eventhub-receiver\": context canceled." app_id=my-eventhublistener component="my-eventhub-receiver (bindings.kafka/v1)" instance=60ad509cd5a0 scope=dapr.contrib type=log ver=1.12.4

And I also noticed the following error message in my ASP.Net Core application's logs:

2024-01-31 20:42:08 [12:42:08 Debug] Microsoft.AspNetCore.Server.Kestrel.BadRequests
2024-01-31 20:42:08 Connection id "0HN12B6B2VHAL" bad request data: "Malformed request: invalid headers."
2024-01-31 20:42:08 Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Malformed request: invalid headers.
2024-01-31 20:42:08    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)
2024-01-31 20:42:08    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
2024-01-31 20:42:08    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)

And what I also found is that requests from different dapr versions have different headers: v.1.12.4 (doesn't work for me):

2024-01-31 20:58:03 [12:58:03 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2024-01-31 20:58:03 Request:
2024-01-31 20:58:03 Protocol: HTTP/1.1
2024-01-31 20:58:03 Method: OPTIONS
2024-01-31 20:58:03 Scheme: http
2024-01-31 20:58:03 PathBase: 
2024-01-31 20:58:03 Path: /my-eventhub-receiver
2024-01-31 20:58:03 Host: 127.0.0.1:80
2024-01-31 20:58:03 User-Agent: Go-http-client/1.1
2024-01-31 20:58:03 Accept-Encoding: gzip
2024-01-31 20:58:03 Content-Type: application/json
2024-01-31 20:58:03 traceparent: [Redacted]

And there is no following POST request in v.1.12.4.

v.1.8.7 (it works properly without errors):

2024-01-31 21:14:42 [13:14:42 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2024-01-31 21:14:42 Request:
2024-01-31 21:14:42 Protocol: HTTP/1.1
2024-01-31 21:14:42 Method: OPTIONS
2024-01-31 21:14:42 Scheme: http
2024-01-31 21:14:42 PathBase: 
2024-01-31 21:14:42 Path: /my-eventhub-receiver
2024-01-31 21:14:42 Host: 127.0.0.1:80
2024-01-31 21:14:42 User-Agent: fasthttp
2024-01-31 21:14:42 Content-Type: application/json
2024-01-31 21:14:42 traceparent: [Redacted]
2024-01-31 21:14:42 Content-Length: 0
2024-01-31 21:15:03 [13:15:03 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2024-01-31 21:15:03 Request:
2024-01-31 21:15:03 Protocol: HTTP/1.1
2024-01-31 21:15:03 Method: POST
2024-01-31 21:15:03 Scheme: http
2024-01-31 21:15:03 PathBase: 
2024-01-31 21:15:03 Path: /my-eventhub-receiver
2024-01-31 21:15:03 Host: 127.0.0.1:80
2024-01-31 21:15:03 User-Agent: fasthttp
2024-01-31 21:15:03 Content-Type: application/json
2024-01-31 21:15:03 traceparent: [Redacted]
2024-01-31 21:15:03 Content-Length: 281

The latest version which works properly is 1.8.7. Starting from Dapr v.1.9.0 the Kafka binding component doesn't work for us.

Yaml output of my bindings.kafka component:

apiVersion: dapr.io/v1alpha1
auth:
  secretStore: my-kv-secrets
kind: Component
metadata:
  annotations:
    meta.helm.sh/release-name: my-eventhublistener
    meta.helm.sh/release-namespace: my-namespace
  labels:
    app.kubernetes.io/managed-by: Helm
  name: my-eventhub-receiver
  namespace: my-namespace
spec:
  metadata:
  - name: version
    value: 1.0.0
  - name: brokers
    value: my-eh-namespace.servicebus.windows.net:9093
  - name: topics
    value: my-eh-data
  - name: consumerGroup
    value: my-eventhublistener
  - name: authRequired
    value: "true"
  - name: saslUsername
    value: $ConnectionString
  - name: saslPassword
    secretKeyRef:
      key: eventhub-connectionstring
      name: eventhub-connectionstring
  type: bindings.kafka
  version: v1

Steps to Reproduce the Problem

  1. Create a kafka.binding component to receive messages from Event Hub in your ASP.Net Core application
  2. Deploy your application and the component to the Kubernetes
  3. Check that your application doesn't receive messages from Event Hub

Andemki avatar Jan 31 '24 13:01 Andemki

@yaron2 @berndverst, Could you please take a look on this issue?

Andemki avatar Jan 31 '24 13:01 Andemki

My understanding is that some Dotnet frameworks are very picky about things like a missing Content-Length header or a content length header with a value of 0 reported.

Without a doubt the issue here is in the receiving code of your own application! So this should probably be moved to the Dapr DotNet SDK instead. The issue isn't really component specific - other than the fact that the component produces the header which trips up your app.

Content-Length: 0 might be the issue here.

berndverst avatar Feb 07 '24 01:02 berndverst

My understanding is that some Dotnet frameworks are very picky about things like a missing Content-Length header or a content length header with a value of 0 reported.

Without a doubt the issue here is in the receiving code of your own application! So this should probably be moved to the Dapr DotNet SDK instead. The issue isn't really component specific - other than the fact that the component produces the header which trips up your app.

Content-Length: 0 might be the issue here.

Content-Length: 0 is from a log file for v.1.8.7 which works properly for us. We have this issue for Dapr versions which are greater than 1.8.7.

Andemki avatar Feb 07 '24 06:02 Andemki

@berndverst I've also tried to send a POST request to the my-eventhub-receiver path using Postman and it worked.

2024-02-07 19:24:34 [11:24:01 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware 2024-02-07 19:24:34 Request: 2024-02-07 19:24:34 Protocol: HTTP/1.1 2024-02-07 19:24:34 Method: POST 2024-02-07 19:24:34 Scheme: http 2024-02-07 19:24:34 PathBase: 2024-02-07 19:24:34 Path: /my-eventhub-receiver 2024-02-07 19:24:34 Accept: / 2024-02-07 19:24:34 Connection: keep-alive 2024-02-07 19:24:34 Host: localhost:5101 2024-02-07 19:24:34 User-Agent: PostmanRuntime/7.36.1 2024-02-07 19:24:34 Accept-Encoding: gzip, deflate, br 2024-02-07 19:24:34 Content-Type: application/json 2024-02-07 19:24:34 Content-Length: 342 2024-02-07 19:24:34 Postman-Token: [Redacted]

Andemki avatar Feb 07 '24 15:02 Andemki

This issue has been automatically marked as stale because it has not had activity in the last 30 days. It will be closed in the next 7 days unless it is tagged (pinned, good first issue, help wanted or triaged/resolved) or other activity occurs. Thank you for your contributions.

github-actions[bot] avatar Mar 08 '24 16:03 github-actions[bot]

This issue has been automatically closed because it has not had activity in the last 37 days. If this issue is still valid, please ping a maintainer and ask them to label it as pinned, good first issue, help wanted or triaged/resolved. Thank you for your contributions.

github-actions[bot] avatar Mar 15 '24 16:03 github-actions[bot]