Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Don't fail on retry when the cluster is secured #545

Merged
merged 3 commits into from
Mar 2, 2018
Merged

Don't fail on retry when the cluster is secured #545

merged 3 commits into from
Mar 2, 2018

Conversation

sparrovv
Copy link
Contributor

@sparrovv sparrovv commented Mar 1, 2018

Steps to reproduce on master:

  • producing messages in the loop to a secured cluster with SASL.
  • sync producer options: { max_retries: 2, retry_backoff: 1, required_acks: :all, compression_codec: :gzip }
  • messages go on uk.test.bug.topic topic
  • shut down a broker that is a primary for the topic
  • getting an exception <Kafka::ConnectionError: Connection refused - connect(2) for 10.40.1.89:9093>

Log

...
D, [2018-03-01T15:46:32.895166 #17892] DEBUG -- : Current leader for uk.test.bug.topic/0 is node kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
I, [2018-03-01T15:46:32.895263 #17892]  INFO -- : Sending 1 messages to kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
D, [2018-03-01T15:46:32.895529 #17892] DEBUG -- : Sending produce API request 4 to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:46:32.895723 #17892] DEBUG -- : Waiting for response 4 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:46:32.972286 #17892] DEBUG -- : Received response 4 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:46:32.972411 #17892] DEBUG -- : Successfully appended 1 messages to uk.test.bug.topic/0 on kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
...
...
<shutting down the primary>
...
D, [2018-03-01T15:46:42.980285 #17892] DEBUG -- : Current leader for uk.test.bug.topic/0 is node kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
I, [2018-03-01T15:46:42.980409 #17892]  INFO -- : Sending 1 messages to kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
D, [2018-03-01T15:46:42.980770 #17892] DEBUG -- : Sending produce API request 5 to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:46:42.981029 #17892] DEBUG -- : Waiting for response 5 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:46:42.981223 #17892] DEBUG -- : Closing socket to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:46:42.981349 #17892] DEBUG -- : Closing socket to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:46:42.981668 #17892] DEBUG -- : Opening connection to kafka-integration-2.integration.simplybusiness.co.uk:9093 with client id uk-eventhorizon...
E, [2018-03-01T15:46:43.052774 #17892] ERROR -- : Failed to connect to kafka-integration-2.integration.simplybusiness.co.uk:9093: Connection refused - connect(2) for 10.40.1.89:9093

Exception:

 #<Kafka::ConnectionError: Connection refused - connect(2) for 10.40.1.89:9093>

 e.backtrace

 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/connection.rb:139:in `rescue in open'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/connection.rb:118:in `open'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/connection.rb:95:in `block in send_request'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/instrumenter.rb:21:in `instrument'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/connection.rb:94:in `send_request'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/sasl_authenticator.rb:39:in `authenticate!'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/connection_builder.rb:25:in `build_connection'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/broker.rb:159:in `connection'",

 ### fails on to_s
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/broker.rb:22:in `to_s'",
 ###

 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/produce_operation.rb:103:in `rescue in block in send_buffered_messages'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/produce_operation.rb:82:in `block in send_buffered_messages'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/produce_operation.rb:81:in `each'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/produce_operation.rb:81:in `send_buffered_messages'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/produce_operation.rb:47:in `block in execute'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/instrumenter.rb:21:in `instrument'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/produce_operation.rb:41:in `execute'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/producer.rb:298:in `block in deliver_messages_with_retries'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/producer.rb:286:in `loop'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/producer.rb:286:in `deliver_messages_with_retries'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/producer.rb:236:in `block in deliver_messages'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/instrumenter.rb:21:in `instrument'",
 "/Users/michal.wrobel/.rbenv/versions/2.4.3/lib/ruby/gems/2.4.0/gems/ruby-kafka-0.5.3/lib/kafka/producer.rb:229:in `deliver_messages'",

The log when fixed:

....
D, [2018-03-01T15:56:58.346598 #19120] DEBUG -- : Successfully appended 1 messages to uk.test.bug.topic/0 on kafka-integration-1.integration.simplybusiness.co.uk:9093 (node_id=101)
....
<shutting down the primary>
D, [2018-03-01T15:57:08.353907 #19120] DEBUG -- : Current leader for uk.test.bug.topic/0 is node kafka-integration-1.integration.simplybusiness.co.uk:9093 (node_id=101)
I, [2018-03-01T15:57:08.354028 #19120]  INFO -- : Sending 1 messages to kafka-integration-1.integration.simplybusiness.co.uk:9093 (node_id=101)
D, [2018-03-01T15:57:08.354282 #19120] DEBUG -- : Sending produce API request 5 to kafka-integration-1.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:08.354512 #19120] DEBUG -- : Waiting for response 5 from kafka-integration-1.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:08.354684 #19120] DEBUG -- : Closing socket to kafka-integration-1.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:08.354814 #19120] DEBUG -- : Closing socket to kafka-integration-1.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:08.355098 #19120] DEBUG -- : Opening connection to kafka-integration-1.integration.simplybusiness.co.uk:9093 with client id uk-eventhorizon...
E, [2018-03-01T15:57:08.423448 #19120] ERROR -- : Failed to connect to kafka-integration-1.integration.simplybusiness.co.uk:9093: Connection refused - connect(2) for 10.40.1.153:9093
E, [2018-03-01T15:57:08.423585 #19120] ERROR -- : Could not connect to broker  (node_id=101): Connection error EOFError: end of file reached
W, [2018-03-01T15:57:08.423663 #19120]  WARN -- : Failed to send all messages; attempting retry 1 of 2 after 1s
I, [2018-03-01T15:57:09.425837 #19120]  INFO -- : Fetching cluster metadata from kafka://kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:09.425984 #19120] DEBUG -- : Opening connection to kafka-integration-2.integration.simplybusiness.co.uk:9093 with client id uk-eventhorizon...
D, [2018-03-01T15:57:09.699255 #19120] DEBUG -- : Sending sasl_handshake API request 1 to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:09.699490 #19120] DEBUG -- : Waiting for response 1 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:09.766728 #19120] DEBUG -- : Received response 1 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:09.833724 #19120] DEBUG -- : SASL PLAIN authentication successful.
D, [2018-03-01T15:57:09.833828 #19120] DEBUG -- : Sending topic_metadata API request 2 to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:09.833973 #19120] DEBUG -- : Waiting for response 2 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:09.902261 #19120] DEBUG -- : Received response 2 from kafka-integration-2.integration.simplybusiness.co.uk:9093
I, [2018-03-01T15:57:09.902399 #19120]  INFO -- : Discovered cluster metadata; nodes: kafka-integration-0.integration.simplybusiness.co.uk:9093 (node_id=100), kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
D, [2018-03-01T15:57:09.902460 #19120] DEBUG -- : Closing socket to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:09.902626 #19120] DEBUG -- : Opening connection to kafka-integration-2.integration.simplybusiness.co.uk:9093 with client id uk-eventhorizon...
D, [2018-03-01T15:57:10.120196 #19120] DEBUG -- : Sending sasl_handshake API request 1 to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:10.120424 #19120] DEBUG -- : Waiting for response 1 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:10.188447 #19120] DEBUG -- : Received response 1 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:10.257069 #19120] DEBUG -- : SASL PLAIN authentication successful.
D, [2018-03-01T15:57:10.257163 #19120] DEBUG -- : Current leader for uk.test.bug.topic/0 is node kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
I, [2018-03-01T15:57:10.257246 #19120]  INFO -- : Sending 1 messages to kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)
D, [2018-03-01T15:57:10.257591 #19120] DEBUG -- : Sending produce API request 2 to kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:10.259293 #19120] DEBUG -- : Waiting for response 2 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:10.371570 #19120] DEBUG -- : Received response 2 from kafka-integration-2.integration.simplybusiness.co.uk:9093
D, [2018-03-01T15:57:10.371747 #19120] DEBUG -- : Successfully appended 1 messages to uk.test.bug.topic/0 on kafka-integration-2.integration.simplybusiness.co.uk:9093 (node_id=102)

@sparrovv
Disconnect only when there's a @connection
102fdea
@sparrovv
Don't fail on broker.to_s
a50454a 
This would fail if there's a problem with connecting to a broker
@sparrovv sparrovv mentioned this pull request Mar 1, 2018
Closed
@sparrovv sparrovv changed the title Don't fail on retry when a cluster is secured Don't fail on retry when the cluster is secured Mar 1, 2018
dasch
dasch reviewed Mar 1, 2018
View reviewed changes
lib/kafka/broker.rb Outdated
@@ -19,12 +19,17 @@ def address_match?(host, port)

# @return [String]
def to_s
"#{connection} (node_id=#{@node_id.inspect})"
"#{connection_to_s} (node_id=#{@node_id.inspect})"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just do #{@host}:#{@port} instead. and remove connection_to_s.

@sparrovv
@host and @PORT are available in the Broker
d451a9a 
No need for connection.to_s
@dasch dasch merged commit a617b31 into zendesk:master Mar 2, 2018
@dasch
Copy link
Contributor

dasch commented Mar 2, 2018

Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@dasch dasch dasch left review comments

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
2 participants
@sparrovv @dasch