Kafka Binding v1.10.7: consumer/broker/0 disconnecting due to error processing FetchRequest: EOF\n #2874

Andemki · 2023-05-30T18:29:56Z

What version of Dapr?

1.10.7

Expected Behavior

Dapr and Azure Event Hub integration using Kafka binding work without errors

Actual Behavior

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 version 1.10.7, my application stopped receiving new messages from EventHub. I've noticed the following error message in the sidecar container (daprd):

2023-05-30 17:50:14 time="2023-05-30T16:50:14.5142882Z" level=debug msg="consumer/broker/0 disconnecting due to error processing FetchRequest: EOF\n" app_id=my-eventhublistener component="my-eventhub-receiver (bindings.kafka/v1)" instance=f3688891ba8e scope=dapr.contrib type=log ver=1.10.7

The last working version 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: 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

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

The text was updated successfully, but these errors were encountered:

berndverst · 2023-05-30T20:48:44Z

Possibly related to IBM/sarama#913

This shows that unexpected EOFs returned from the server could be due to version mismatch between client and server.

berndverst · 2023-05-30T20:48:57Z

The error itself comes from the sarama library

berndverst · 2023-05-30T20:54:53Z

@Andemki the sarama library used in the implementation defaults to Kafka version 2.0.0. It is unclear whether EventHubs actually supports this. In the documentation I can only find 1.0 and up - but it's unclear this is actually verified against 2.0.

Can you set the version in the kafka binding metadata to 1.0.0 and try that please?

berndverst · 2023-05-30T20:58:55Z

apiVersion: dapr.io/v1alpha1
kind: Component
metadata:
  name: kafka-binding
spec:
  type: bindings.kafka
  version: v1
  metadata:
  - name: version # YOU LIKELY MUST SET THIS FOR EVENTHUBS
    value: 1.0.0

I omitted the other metadata in this example - but I just wanted to highlight how this must be configured.

berndverst · 2023-05-30T21:07:13Z

Correction: In the Dapr Kafka components we default to version 2 protocol if the version is not specified.

components-contrib/internal/component/kafka/metadata.go

Lines 109 to 113 in 1ac92a8

    
           func (k *Kafka) getKafkaMetadata(meta map[string]string) (*KafkaMetadata, error) { 
        
           	m := KafkaMetadata{ 
        
           		ConsumeRetryInterval: 100 * time.Millisecond, 
        
           		internalVersion:      sarama.V2_0_0_0, //nolint:nosnakecase 
        
           	}

berndverst · 2023-05-30T21:09:19Z

the component metadata value 1.0.0 would be translated to the internal library constant sarama.V1_0_0_0 by means of the sarama.ParseKafkaVersion(version str) function

berndverst · 2023-05-30T21:12:43Z

You mentioned this was working in 1.8.7. But it used Kafka protocol v2 then too when not specified. Hmm..

components-contrib/internal/component/kafka/metadata.go

Lines 268 to 276 in 9350f2e

    
           if val, ok := metadata["version"]; ok && val != "" { 
        
           	version, err := sarama.ParseKafkaVersion(val) 
        
           	if err != nil { 
        
           		return nil, errors.New("kafka error: invalid kafka version") 
        
           	} 
        
           	meta.Version = version 
        
           } else { 
        
           	meta.Version = sarama.V2_0_0_0 
        
           }

This code is unchanged in 1.10.7:

components-contrib/internal/component/kafka/metadata.go

Lines 280 to 288 in 7ce4e49

    
           if val, ok := metadata["version"]; ok && val != "" { 
        
           	version, err := sarama.ParseKafkaVersion(val) 
        
           	if err != nil { 
        
           		return nil, errors.New("kafka error: invalid kafka version") 
        
           	} 
        
           	meta.Version = version 
        
           } else { 
        
           	meta.Version = sarama.V2_0_0_0 //nolint:nosnakecase 
        
           }

berndverst · 2023-05-30T21:18:54Z

I still would try changing the kafka version to 1.0.0 anyway to be sure.

Andemki · 2023-05-30T21:25:00Z

@berndverst, Thank you for a quick reply. I've set version to 1.0.0 in the kafka binding metadata but now I see the following error messages:

2023-05-30 22:15:47 time="2023-05-30T21:15:47.6910139Z" level=debug msg="Processing Kafka message: my-eh-data/25/232488288 [key=NTg4Mw==]" app_id=my-eventhublistener component="my-eventhub-receiver (bindings.kafka/v1)" instance=f9e3a81d24c7 scope=dapr.contrib type=log ver=1.10.7
2023-05-30 22:15:47 time="2023-05-30T21:15:47.6972687Z" level=debug msg="error from app consumer for binding [my-eventhub-receiver]: fails to send binding event to http app channel, status code: 400 body: " app_id=my-eventhublistener instance=f9e3a81d24c7 scope=dapr.runtime type=log ver=1.10.7
2023-05-30 22:15:47 time="2023-05-30T21:15:47.6973089Z" level=error msg="Error processing Kafka message: my-eh-data/25/232488288 [key=NTg4Mw==]. Error: fails to send binding event to http app channel, status code: 400 body: ." app_id=my-eventhublistener component="my-eventhub-receiver (bindings.kafka/v1)" instance=f9e3a81d24c7 scope=dapr.contrib type=log ver=1.10.7

berndverst · 2023-05-30T21:27:48Z

@berndverst, Thank you for a quick reply. I've set version to 1.0.0 in the kafka binding metadata but now I see the following error messages:

2023-05-30 22:15:47 time="2023-05-30T21:15:47.6910139Z" level=debug msg="Processing Kafka message: my-eh-data/25/232488288 [key=NTg4Mw==]" app_id=my-eventhublistener component="my-eventhub-receiver (bindings.kafka/v1)" instance=f9e3a81d24c7 scope=dapr.contrib type=log ver=1.10.7
2023-05-30 22:15:47 time="2023-05-30T21:15:47.6972687Z" level=debug msg="error from app consumer for binding [my-eventhub-receiver]: fails to send binding event to http app channel, status code: 400 body: " app_id=my-eventhublistener instance=f9e3a81d24c7 scope=dapr.runtime type=log ver=1.10.7
2023-05-30 22:15:47 time="2023-05-30T21:15:47.6973089Z" level=error msg="Error processing Kafka message: my-eh-data/25/232488288 [key=NTg4Mw==]. Error: fails to send binding event to http app channel, status code: 400 body: ." app_id=my-eventhublistener component="my-eventhub-receiver (bindings.kafka/v1)" instance=f9e3a81d24c7 scope=dapr.contrib type=log ver=1.10.7

@Andemki that however seems more promising! This error indicates there is an issue delivering the event to your app - so it seems the Kafka binding at least is getting events from EventHubs now!

Can you check the logs of your app? The HTTP 400 seems to be returned by your app.

Andemki · 2023-05-30T21:38:51Z

@berndverst Yes, I see the error messages in the app:

2023-05-30 22:34:57 info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
2023-05-30 22:34:57 Request finished HTTP/1.1 OPTIONS http://127.0.0.1:80/my-eventhub-receiver application/json - - 405 0 - 32.6566ms
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel[17]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K6" bad request data: "Malformed request: invalid headers."
2023-05-30 22:35:12 Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Malformed request: invalid headers.
2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelBadHttpRequestException.Throw(RequestRejectionReason reason)
2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)
2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication1 application) 2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication1 application)
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel[10]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K6" disconnecting.
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K6" received FIN.
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K6" sending FIN because: "The client closed the connection."
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel[39]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K7" accepted.
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel[1]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K7" started.
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel[17]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K7" bad request data: "Malformed request: invalid headers."
2023-05-30 22:35:12 Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Malformed request: invalid headers.
2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelBadHttpRequestException.Throw(RequestRejectionReason reason)
2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)
2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication1 application) 2023-05-30 22:35:12 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication1 application)
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel[10]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K7" disconnecting.
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel[2]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K7" stopped.
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K7" received FIN.
2023-05-30 22:35:12 dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
2023-05-30 22:35:12 Connection id "0HMR1AMRD02K7" sending FIN because: "The Socket transport's send loop completed gracefully."

berndverst · 2023-05-30T21:40:31Z

@Andemki Your app must allow the OPTIONS request or else it cannot subscribe to the input binding.

https://docs.dapr.io/developing-applications/building-blocks/bindings/bindings-overview/

On startup, Dapr sends an OPTIONS request for all defined input bindings to the application. If the application wants to subscribe to the binding, Dapr expects a status code of 2xx or 405.

EDIT: Looks like it's returning the 405 so that part is working.

I'm not used to reading DotNet server logs. Somewhere it should be receiving a POST request but is responding with 400.

It seems that when the sidecar is delivering the event to your app - your app isn't happy with the headers the sidecar is sending. Can you somehow logs the raw request without parsing it?

berndverst · 2023-05-30T21:57:48Z

The dapr sidecar message you are seeing comes from here:

https://github.com/dapr/dapr/blob/f551d4030d5a4333815a0474ca6af6739329027c/pkg/runtime/runtime.go#L1383-L1385

Given that you didn't specify a route for the binding I expect all events to be going to your app at path /my-eventhub-receiver.

You should be seeing POST requests on this path with the event received from EventHubs via the Kafka binding.

I am not sure how to further troubleshoot this. To me it seems the component is now working correctly and the remaining problem is in the app.

Perhaps you can enable HTTP logging in the app to see the complete request your app is receiving from the sidecar.
I found this link for DotNet Core to do so: https://learn.microsoft.com/en-us/aspnet/core/fundamentals/http-logging/?view=aspnetcore-6.0#enabling-http-logging

Andemki · 2023-05-30T22:04:43Z

@berndverst Ok, thank you. I will try it. But it's still not clear to me why the app works properly with Dapr v1.8.7 and doesn't work with more recent versions.

berndverst · 2023-05-31T03:37:39Z

@berndverst Ok, thank you. I will try it. But it's still not clear to me why the app works properly with Dapr v1.8.7 and doesn't work with more recent versions.

Not sure, but with the release of Dapr 1.11 in one week 1.8.7 won't be supported anyway.

Probably because we use an old
version of the Kafka library in 1.8.7 - but we must upgrade this for other reasons beyond this issue. Not much we can do. Beyond the library version changes there is not much that is different between 1.8.7 and 1.10.7.

Does this still work 1.8.7 today?

Either way, it's clear there is some sort of issue with your app that receives events from EventHub via the Dapr Binding. You can experiment with other Kafka version values. But something seems wrong with your app from the errors we can see regardless.

DeepanshuA · 2023-05-31T08:38:23Z

Ok, I am able to see messages coming with version 1.0.0.
It seems that we should update Kafka binding dapr docs to let users know that it should be mandatory property for Input Binding.

DeepanshuA · 2023-05-31T10:22:19Z

Tested by using upgraded version of sarama library as well (v1.38.1) and using version 1.0.0 as metadata, publish and subscribe both worked fine.
So, main part is using version 1.0.0 in metadata, as @berndverst had pointed out correctly.

berndverst · 2023-05-31T15:25:43Z

@DeepanshuA nit a mandatory property. Only mandatory for fake Kafka like EventHubs.

Andemki · 2023-05-31T15:55:18Z

@berndverst Ok, thank you. I will try it. But it's still not clear to me why the app works properly with Dapr v1.8.7 and doesn't work with more recent versions.

Not sure, but with the release of Dapr 1.11 in one week 1.8.7 won't be supported anyway.

Probably because we use an old version of the Kafka library in 1.8.7 - but we must upgrade this for other reasons beyond this issue. Not much we can do. Beyond the library version changes there is not much that is different between 1.8.7 and 1.10.7.

Does this still work 1.8.7 today?

Either way, it's clear there is some sort of issue with your app that receives events from EventHub via the Dapr Binding. You can experiment with other Kafka version values. But something seems wrong with your app from the errors we can see regardless.

@berndverst Yes, the application works properly on 1.8.7 (I only changed Dapr version back to 1.8.7 and nothing else and it started to work properly as before).
So I've added HTTP Logging middleware to my application and then I compared log files from 1.10.7 with the log files from 1.8.7 to see what the difference is:
At the beginning I saw similar HTTP requests and response for both versions:

2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:16:10 Request:
2023-05-31 16:16:10 Protocol: HTTP/1.1
2023-05-31 16:16:10 Method: GET
2023-05-31 16:16:10 Scheme: http
2023-05-31 16:16:10 PathBase:
2023-05-31 16:16:10 Path: /dapr/config
2023-05-31 16:16:10 Host: 127.0.0.1:80
2023-05-31 16:16:10 User-Agent: Go-http-client/1.1
2023-05-31 16:16:10 Accept-Encoding: gzip
2023-05-31 16:16:10 Content-Type: application/json
2023-05-31 16:16:10 traceparent: [Redacted]
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:16:10 Response:
2023-05-31 16:16:10 StatusCode: 404
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Debug] Microsoft.AspNetCore.Server.Kestrel.Connections
2023-05-31 16:16:10 Connection id "0HMR1T7RJ7286" completed keep alive response.
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.Hosting.Diagnostics
2023-05-31 16:16:10 Request finished HTTP/1.1 GET http://127.0.0.1:80/dapr/config application/json - - 404 0 - 70.6528ms
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.Hosting.Diagnostics
2023-05-31 16:16:10 Request starting HTTP/1.1 GET http://127.0.0.1:80/dapr/subscribe application/json -
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Debug] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware
2023-05-31 16:16:10 The request path does not match the path filter
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Debug] Microsoft.AspNetCore.Routing.Matching.DfaMatcher
2023-05-31 16:16:10 No candidates found for the request path '/dapr/subscribe'
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Debug] Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware
2023-05-31 16:16:10 Request did not match any endpoints
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:16:10 Request:
2023-05-31 16:16:10 Protocol: HTTP/1.1
2023-05-31 16:16:10 Method: GET
2023-05-31 16:16:10 Scheme: http
2023-05-31 16:16:10 PathBase:
2023-05-31 16:16:10 Path: /dapr/subscribe
2023-05-31 16:16:10 Host: 127.0.0.1:80
2023-05-31 16:16:10 User-Agent: Go-http-client/1.1
2023-05-31 16:16:10 Accept-Encoding: gzip
2023-05-31 16:16:10 Content-Type: application/json
2023-05-31 16:16:10 traceparent: [Redacted]
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:16:10 Response:
2023-05-31 16:16:10 StatusCode: 404

And then:

2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:16:10 Request:
2023-05-31 16:16:10 Protocol: HTTP/1.1
2023-05-31 16:16:10 Method: OPTIONS
2023-05-31 16:16:10 Scheme: http
2023-05-31 16:16:10 PathBase:
2023-05-31 16:16:10 Path: /my-eventhub-receiver
2023-05-31 16:16:10 Host: 127.0.0.1:80
2023-05-31 16:16:10 User-Agent: Go-http-client/1.1
2023-05-31 16:16:10 Accept-Encoding: gzip
2023-05-31 16:16:10 Content-Type: application/json
2023-05-31 16:16:10 traceparent: [Redacted]
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.Routing.EndpointMiddleware
2023-05-31 16:16:10 Executing endpoint '405 HTTP Method Not Supported'
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.Routing.EndpointMiddleware
2023-05-31 16:16:10 Executed endpoint '405 HTTP Method Not Supported'
2023-05-31 16:16:10
2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:16:10 Response:
2023-05-31 16:16:10 StatusCode: 405
2023-05-31 16:16:10 Allow: POST

And the difference started from here
v. 1.10.7:

2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.Hosting.Diagnostics
2023-05-31 16:16:10 Request finished HTTP/1.1 OPTIONS http://127.0.0.1:80/my-eventhub-receiver application/json - - 405 0 - 12.1920ms
2023-05-31 16:16:10
2023-05-31 16:16:27 [15:16:27 Debug] Microsoft.AspNetCore.Server.Kestrel.BadRequests
2023-05-31 16:16:27 Connection id "0HMR1T7RJ7286" bad request data: "Malformed request: invalid headers."
2023-05-31 16:16:27 Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Malformed request: invalid headers.
2023-05-31 16:16:27 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)
2023-05-31 16:16:27 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication1 application) 2023-05-31 16:16:27 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication1 application)

v.1.8.7:

2023-05-31 16:19:46 [15:19:46 Information] Microsoft.AspNetCore.Hosting.Diagnostics
2023-05-31 16:19:46 Request finished HTTP/1.1 OPTIONS http://127.0.0.1:80/my-eventhub-receiver application/json 0 - 405 0 - 13.5882ms
2023-05-31 16:20:00 [15:20:00 Information] Microsoft.AspNetCore.Hosting.Diagnostics
2023-05-31 16:20:00 Request starting HTTP/1.1 POST http://127.0.0.1:80/my-eventhub-receiver application/json 263
2023-05-31 16:20:00
2023-05-31 16:20:00 [15:20:00 Debug] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware
2023-05-31 16:20:00 POST requests are not supported
2023-05-31 16:20:00
2023-05-31 16:20:00 [15:20:00 Debug] Microsoft.AspNetCore.Routing.Matching.DfaMatcher
2023-05-31 16:20:00 1 candidate(s) found for the request path '/my-eventhub-receiver'
2023-05-31 16:20:00
2023-05-31 16:20:00 [15:20:00 Debug] Microsoft.AspNetCore.Routing.Matching.DfaMatcher
2023-05-31 16:20:00 Endpoint 'Project.EventHubListener.Controllers.SubscriberController.Subscriber (Project.EventHubListener)' with route pattern 'my-eventhub-receiver' is valid for the request path '/my-eventhub-receiver'
2023-05-31 16:20:00
2023-05-31 16:20:00 [15:20:00 Debug] Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware
2023-05-31 16:20:00 Request matched endpoint 'Project.EventHubListener.Controllers.SubscriberController.Subscriber (Project.EventHubListener)'
2023-05-31 16:20:00
2023-05-31 16:20:00 [15:20:00 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:20:00 Request:
2023-05-31 16:20:00 Protocol: HTTP/1.1
2023-05-31 16:20:00 Method: POST
2023-05-31 16:20:00 Scheme: http
2023-05-31 16:20:00 PathBase:
2023-05-31 16:20:00 Path: /my-eventhub-receiver
2023-05-31 16:20:00 Host: 127.0.0.1:80
2023-05-31 16:20:00 User-Agent: fasthttp
2023-05-31 16:20:00 Content-Type: application/json
2023-05-31 16:20:00 traceparent: [Redacted]
2023-05-31 16:20:00 Content-Length: 263
2023-05-31 16:20:00
2023-05-31 16:20:00 [15:20:00 Information] Microsoft.AspNetCore.Routing.EndpointMiddleware
2023-05-31 16:20:00 Executing endpoint 'Project.EventHubListener.Controllers.SubscriberController.Subscriber (Project.EventHubListener)'
2023-05-31 16:20:00
2023-05-31 16:20:00 [15:20:00 Information] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker
2023-05-31 16:20:00 Route matched with {action = "Subscriber", controller = "Subscriber"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] Subscriber(Project.Predictions.Model.TaipMessage, System.Threading.CancellationToken) on controller Project.EventHubListener.Controllers.SubscriberController (Project.EventHubListener).

Andemki · 2023-05-31T19:00:06Z

I've also noticed different request headers in different versions:
v.1.10.7:

2023-05-31 16:16:10 [15:16:10 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:16:10 Request:
2023-05-31 16:16:10 Protocol: HTTP/1.1
2023-05-31 16:16:10 Method: OPTIONS
2023-05-31 16:16:10 Scheme: http
2023-05-31 16:16:10 PathBase:
2023-05-31 16:16:10 Path: /my-eventhub-receiver
2023-05-31 16:16:10 Host: 127.0.0.1:80
2023-05-31 16:16:10 User-Agent: Go-http-client/1.1
2023-05-31 16:16:10 Accept-Encoding: gzip
2023-05-31 16:16:10 Content-Type: application/json
2023-05-31 16:16:10 traceparent: [Redacted]

v.1.8.7:

2023-05-31 16:19:46 [15:19:46 Information] Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware
2023-05-31 16:19:46 Request:
2023-05-31 16:19:46 Protocol: HTTP/1.1
2023-05-31 16:19:46 Method: OPTIONS
2023-05-31 16:19:46 Scheme: http
2023-05-31 16:19:46 PathBase:
2023-05-31 16:19:46 Path: /my-eventhub-receiver
2023-05-31 16:19:46 Host: 127.0.0.1:80
2023-05-31 16:19:46 User-Agent: fasthttp
2023-05-31 16:19:46 Content-Type: application/json
2023-05-31 16:19:46 traceparent: [Redacted]
2023-05-31 16:19:46 Content-Length: 0

DeepanshuA · 2023-05-31T20:31:17Z

@Andemki What I understand here is that this seems to be an issue specifically with your App side of things.
I have a very simple js app, which is able to receive messages: dapr/quickstarts@master...DeepanshuA:quickstarts:kafka_eh_sasl

I have opened a docs PR to specify the versoin with EH with kafka: dapr/docs#3474

DeepanshuA · 2023-05-31T20:34:19Z

@DeepanshuA nit a mandatory property. Only mandatory for fake Kafka like EventHubs.

Yup, agree.

PS: Seems I by mistake updated your comment directly. Probably selected Edit instead of Quote Reply. Reverted my edit.

Andemki · 2023-05-31T20:56:22Z

@Andemki What I understand here is that this seems to be an issue specifically with your App side of things. I have a very simple js app, which is able to receive messages: dapr/quickstarts@master...DeepanshuA:quickstarts:kafka_eh_sasl

I have opened a docs PR to specify the versoin with EH with kafka: dapr/docs#3474

I've updated "Steps to Reproduce the Problem" and pointed out that this issue is reproducible on the ASP.Net Core application.
Can you try to reproduce this issue on ASP.Net Core application (.Net 5/6/7) ?

Or it would be better to create a new bug item because it is a different error and the error from the description has been resolved?

berndverst · 2023-06-20T21:25:23Z

@Andemki please do create a new bug. You probably should file that in dapr/dapr repo as it isn't specific to the component.

The change in request headers is expected by the way as we switched to the underlying HTTP server.

For the bug you can state that the pubsub OPTIONS request sends different headers (expected) which cause an exception / error in your ASP.Net Core application (unexpected). You can also add that between the two Dapr versions you are using this is a difference of fasthttp vs Go-http-client/1.1.

It seems to me that the missing Content-Length header on the OPTIONS request is causing the exception in your app.

Please do open that issue in dapr/dapr for this (that's where the relevant code lives also).

FYI @ItalyPaleAle

I will close this issue here so that we do not talk about multiple different problems in this issue. It's long enough as is :)

Andemki added the kind/bug Something isn't working label May 30, 2023

Andemki mentioned this issue May 30, 2023

Kafka Binding v1.10.4: kafka: client has run out of available brokers to talk to #2755

Closed

DeepanshuA mentioned this issue May 31, 2023

Specifying Kafka version as 1.0.0 in Note for Kafka with EH dapr/docs#3474

Merged

7 tasks

berndverst closed this as completed Jun 20, 2023

This was referenced Aug 29, 2023

chore(deps): bump sarama to v1.41.0 #3108

Merged

Update Kafka sarama package to 1.41 #3104

Closed

Andemki mentioned this issue Oct 2, 2023

Kafka Binding v1.11.3: Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Malformed request: invalid headers. #3161

Closed

Andemki mentioned this issue Jan 31, 2024

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

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Kafka Binding v1.10.7: consumer/broker/0 disconnecting due to error processing FetchRequest: EOF\n #2874

Kafka Binding v1.10.7: consumer/broker/0 disconnecting due to error processing FetchRequest: EOF\n #2874

Andemki commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023

berndverst commented May 30, 2023

berndverst commented May 30, 2023

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023

Andemki commented May 30, 2023

berndverst commented May 30, 2023 •

edited

Loading

Andemki commented May 30, 2023

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

Andemki commented May 30, 2023

berndverst commented May 31, 2023

DeepanshuA commented May 31, 2023

DeepanshuA commented May 31, 2023

berndverst commented May 31, 2023 •

edited by DeepanshuA

Loading

Andemki commented May 31, 2023 •

edited

Loading

Andemki commented May 31, 2023 •

edited

Loading

DeepanshuA commented May 31, 2023

DeepanshuA commented May 31, 2023

Andemki commented May 31, 2023 •

edited

Loading

berndverst commented Jun 20, 2023 •

edited

Loading

Kafka Binding v1.10.7: consumer/broker/0 disconnecting due to error processing FetchRequest: EOF\n #2874

Kafka Binding v1.10.7: consumer/broker/0 disconnecting due to error processing FetchRequest: EOF\n #2874

Comments

Andemki commented May 30, 2023 • edited Loading

What version of Dapr?

Expected Behavior

Actual Behavior

Steps to Reproduce the Problem

berndverst commented May 30, 2023 • edited Loading

berndverst commented May 30, 2023

berndverst commented May 30, 2023 • edited Loading

berndverst commented May 30, 2023

berndverst commented May 30, 2023

berndverst commented May 30, 2023

berndverst commented May 30, 2023 • edited Loading

berndverst commented May 30, 2023

Andemki commented May 30, 2023

berndverst commented May 30, 2023 • edited Loading

Andemki commented May 30, 2023

berndverst commented May 30, 2023 • edited Loading

berndverst commented May 30, 2023 • edited Loading

Andemki commented May 30, 2023

berndverst commented May 31, 2023

DeepanshuA commented May 31, 2023

DeepanshuA commented May 31, 2023

berndverst commented May 31, 2023 • edited by DeepanshuA Loading

Andemki commented May 31, 2023 • edited Loading

Andemki commented May 31, 2023 • edited Loading

DeepanshuA commented May 31, 2023

DeepanshuA commented May 31, 2023

Andemki commented May 31, 2023 • edited Loading

berndverst commented Jun 20, 2023 • edited Loading

Andemki commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 30, 2023 •

edited

Loading

berndverst commented May 31, 2023 •

edited by DeepanshuA

Loading

Andemki commented May 31, 2023 •

edited

Loading

Andemki commented May 31, 2023 •

edited

Loading

Andemki commented May 31, 2023 •

edited

Loading

berndverst commented Jun 20, 2023 •

edited

Loading