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

Disconnect logs from kafka client #1089

Closed
9 tasks
tejas3190 opened this issue Mar 3, 2017 · 18 comments
Closed
9 tasks

Disconnect logs from kafka client #1089

tejas3190 opened this issue Mar 3, 2017 · 18 comments

Comments

@tejas3190
Copy link

tejas3190 commented Mar 3, 2017 •
edited
Loading

Description

This are the logs, also check the config parameters, I am using omkafka of rsyslog and facing this issue.

Mar 3 07:17:01 tbehra-r8-v4 rsyslogd: omkafka: kafka message 2/2 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 07:47:07 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 07:47:07 tbehra-r8-v4 rsyslogd: message repeated 2 times: [ omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]]
Mar 3 07:47:07 tbehra-r8-v4 rsyslogd: omkafka: kafka message 2/2 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:17:01 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:17:01 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:17:01 tbehra-r8-v4 rsyslogd: omkafka: kafka message 2/2 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:37:09 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:37:09 tbehra-r8-v4 rsyslogd: omkafka: kafka message localhost:9092/0: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:37:09 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:57:10 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 08:57:10 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 09:17:01 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 09:47:03 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 09:47:03 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 09:57:03 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 09:57:03 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 10:17:01 tbehra-r8-v4 rsyslogd: omkafka: kafka message localhost:9092/0: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 10:17:04 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 10:51:19 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 10:51:19 tbehra-r8-v4 rsyslogd: omkafka: kafka message 2/2 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 10:52:06 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 3 10:52:06 tbehra-r8-v4 rsyslogd: omkafka: kafka message kafka.dn-services.internal:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]

How to reproduce

Checklist

Please provide the following information:

  • librdkafka version (release number or git tag): 0.9.2

  • Apache Kafka version: 0.10

  • librdkafka client configuration:
    "socket.keepalive.enable=true",
    "queue.buffering.max.messages=1000",
    "log.connection.close=true"

  • Operating system: Ubuntu 14

  • Using the legacy Consumer

  • Using the high-level KafkaConsumer

  • Provide logs (with debug=.. as necessary) from librdkafka

  • Provide broker log excerpts

  • Critical issue
@edenhill
Copy link
Contributor

edenhill commented Mar 7, 2017

Looking at the timestamp it seems that's the broker's idle connection reaper kicking in.
Since this only closes idle connection, and librdkafka immediately reconnects, there is no harm in this at all.

Set log.connection.close=false to suppress these error messages.

@edenhill edenhill closed this as completed Mar 7, 2017
@djenriquez
Copy link

djenriquez commented Mar 14, 2017 •
edited
Loading

Hi @edenhill

We had this issue happen today, luckily in our dev environment when our Kafka broker went down. However, it was NOT harmless at all. In fact, every instance in our datacenter pretty much DoS'd itself. When we spun up a new instance, we saw:

Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message 4/4 brokers are down [v8.24.0 try http://www.rsyslog.com/e/2422 ]
Mar 13 20:30:23 ip-10-2-11-103 rsyslogd: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.24.0 try http://www.rsyslog.com/e/2422 ]

Those lines repeated a few hundred times a second. Its as if the errors from omkafka initiated another attempt and an endless loop began. All instances' connection tables filled up and queued forever.

Our rsyslog config looks like:

template(name="tokafka" type="list") {
    property(name="pri")
    constant(value=" ")
    property(name="timestamp" dateFormat="rfc3339")
    constant(value=" ")
    property(name="hostname")
    constant(value=" ")
    property(name="programname")
    constant(value=" ")
    property(name="procid")
    constant(value=" ")
    property(name="msgid")
    constant(value=" ")
    property(name="msg")
    constant(value="\n")
}

main_queue(
  queue.workerthreads="1"      # threads to work on the queue
  queue.dequeueBatchSize="100" # max number of messages to process at once
  queue.size="10000"           # max queue size
)

action(
  broker=["{{KAFKA_DEST}}"]
  type="omkafka"
  topic="logs"
  template="tokafka"
  partitions.auto="on"
)

#### GLOBAL DIRECTIVES ####

# Use default timestamp format
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

# File syncing capability is disabled by default. This feature is usually not required,
# not useful and an extreme performance hit
#$ActionFileEnableSync on

# Include all config files in /etc/rsyslog.d/
$IncludeConfig /etc/rsyslog.d/*.conf



#### RULES ####

# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.*                                                 /dev/console

# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none                /var/log/messages

# The authpriv file has restricted access.
authpriv.*                                              /var/log/secure

# Log all the mail messages in one place.
mail.*                                                  /var/log/maillog


# Log cron stuff
cron.*                                                  /var/log/cron

# Everybody gets emergency messages
*.emerg                                                 :omusrmsg:*

# Save news errors of level crit and higher in a special file.
uucp,news.crit                                          /var/log/spooler

# Save boot messages also to boot.log
local7.*                                                /var/log/boot.log

Is there anything obvious you see that we did wrong in this configuration??

@djenriquez
Copy link

Also, i'm not sure if this is the right place for this, but this issue is the closest i've seen to what we experienced today.

@djenriquez
Copy link

Reference: rsyslog/rsyslog#1464

@edenhill
Copy link
Contributor

@djenriquez attempting to produce new messages when the broker is down will not directly try to initiate a new connection, that's handled by its own retry interval (reconnect.backoff.jitter.ms) in the background regardless of messages being queued.
So this does not explain the behviour you are seeing.

Are you using multiple rd_kafka_t producer instances, or are all those logs from the same producer instance?

@djenriquez
Copy link

djenriquez commented Mar 15, 2017 •
edited
Loading

Hi @edenhill, that makes sense. All the logs that are causing the instance to experience this behavior originate from the producer instance itself.

We did some more investigation and we're pretty sure that new logs aren't generated, omkafka looks to just be retrying immediately and indefinitely when it receives dropped connections from the ELB that it's trying to connect through to get to Kafka.

When we change the scenario such that it gets a reject/refuse rather than a drop, it behaves how we expect, it tries once then backs off and doesn't try again for a few minutes, maybe once per new log received. We can simulate this drop by changing the port the ELB is listening on.

Also when DNS can't be resolved, it looks to try once per attempt and that's it. It's only when connections are dropped from the upstream that this behavior ensues, but when it does, it's destructive.

It's very easy to reproduce:

  • Throw Kafka behind a load balancer.
  • Set rsyslog-omkafka to output to that kafka cluster through the load balancer
  • Remove the upstream instances from the load balancer

@djenriquez
Copy link

I repro'd the problem again today with more diagnostic tools and dumped out the conntrack table. To my surprise, it held tens of thousands of these:

udp      17 108 src=10.5.9.100 dst=10.5.0.2 sport=48552 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=48552 [ASSURED] mark=0 use=1
udp      17 98 src=10.5.9.100 dst=10.5.0.2 sport=54860 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=54860 [ASSURED] mark=0 use=1
udp      17 96 src=10.5.9.100 dst=10.5.0.2 sport=40820 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=40820 [ASSURED] mark=0 use=1
udp      17 72 src=10.5.9.100 dst=10.5.0.2 sport=39765 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=39765 [ASSURED] mark=0 use=1
udp      17 108 src=10.5.9.100 dst=10.5.0.2 sport=40950 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=40950 [ASSURED] mark=0 use=1
udp      17 99 src=10.5.9.100 dst=10.5.0.2 sport=57370 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=57370 [ASSURED] mark=0 use=1
udp      17 68 src=10.5.9.100 dst=10.5.0.2 sport=36855 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=36855 [ASSURED] mark=0 use=1
udp      17 105 src=10.5.9.100 dst=10.5.0.2 sport=49935 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=49935 [ASSURED] mark=0 use=1
udp      17 73 src=10.5.9.100 dst=10.5.0.2 sport=60146 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=60146 [ASSURED] mark=0 use=1
udp      17 101 src=10.5.9.100 dst=10.5.0.2 sport=55288 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=55288 [ASSURED] mark=0 use=1
udp      17 100 src=10.5.9.100 dst=10.5.0.2 sport=51532 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=51532 [ASSURED] mark=0 use=1
udp      17 102 src=10.5.9.100 dst=10.5.0.2 sport=54822 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=54822 [ASSURED] mark=0 use=1
udp      17 100 src=10.5.9.100 dst=10.5.0.2 sport=53479 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=53479 [ASSURED] mark=0 use=1
udp      17 87 src=10.5.9.100 dst=10.5.0.2 sport=47258 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=47258 [ASSURED] mark=0 use=1
udp      17 100 src=10.5.9.100 dst=10.5.0.2 sport=45814 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=45814 [ASSURED] mark=0 use=1
udp      17 85 src=10.5.9.100 dst=10.5.0.2 sport=33595 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=33595 [ASSURED] mark=0 use=1
udp      17 104 src=10.5.9.100 dst=10.5.0.2 sport=60080 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=60080 [ASSURED] mark=0 use=1
udp      17 94 src=10.5.9.100 dst=10.5.0.2 sport=60367 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=60367 [ASSURED] mark=0 use=1
udp      17 93 src=10.5.9.100 dst=10.5.0.2 sport=55504 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=55504 [ASSURED] mark=0 use=1
udp      17 88 src=10.5.9.100 dst=10.5.0.2 sport=56223 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=56223 [ASSURED] mark=0 use=1
udp      17 104 src=10.5.9.100 dst=10.5.0.2 sport=37039 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=37039 [ASSURED] mark=0 use=1
udp      17 103 src=10.5.9.100 dst=10.5.0.2 sport=36044 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=36044 [ASSURED] mark=0 use=1
udp      17 107 src=10.5.9.100 dst=10.5.0.2 sport=54903 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=54903 [ASSURED] mark=0 use=1
udp      17 88 src=10.5.9.100 dst=10.5.0.2 sport=58682 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=58682 [ASSURED] mark=0 use=1
udp      17 85 src=10.5.9.100 dst=10.5.0.2 sport=45953 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=45953 [ASSURED] mark=0 use=1
udp      17 71 src=10.5.9.100 dst=10.5.0.2 sport=36582 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=36582 [ASSURED] mark=0 use=1
udp      17 92 src=10.5.9.100 dst=10.5.0.2 sport=57425 dport=53 src=10.5.0.2 dst=10.5.9.100 sport=53 dport=57425 [ASSURED] mark=0 use=1

The conntrack table seems to fill up because every immediate retry from rsyslog instantiates a new DNS lookup. I implemented stateless rules in iptables to NOTRACK these, and the connection table is no longer filling up. HOWEVER, this is purely a mitigation practice. The problem still persists that rsyslog-omkafka continues to endlessly retry immediately.

@djenriquez
Copy link

Yea....so NOTRACK won't work for us. Applying NOTRACK breaks Docker container DNS. Looks like we're back to square 1, ticking time-bomb rsyslog kafka producer.

Any ideas what I can do to mitigate this?

@edenhill
Copy link
Contributor

I think I know what the issue is, the reconnect jitter delay might be cut short by internal librdkafka signaling.
If I push a fix can you try to verify it?

@djenriquez
Copy link

Yes! Absolutely!

@djenriquez djenriquez mentioned this issue Mar 16, 2017
Closed
@edenhill edenhill reopened this Mar 16, 2017
edenhill added a commit that referenced this issue Mar 16, 2017
@edenhill
Improve reconnect delay handling (#1089)
ee511d4
@edenhill
Copy link
Contributor

@djenriquez Please give latest master a try.

@edenhill
Copy link
Contributor

You might want to increase reconnect.backoff.jitter.ms so it is more evident that a backoff is taking place, maybe 5000ms or so

@taotetek
Copy link

@edenhill @djenriquez I'm also using librdkafka with rsyslog in production. I haven't experienced this issue but I may have just not hit the right set of circumstances to trigger it. I'm working on new rsyslog builds for 8.25 for us now so I'm super interested in hearing the result of this fix - as I'd love to incorporate it in my build. Big thanks to both of you for digging into this.

@djenriquez
Copy link

djenriquez commented Mar 17, 2017 •
edited
Loading

Hey guys, working on this now. I'm not sure where to actually increase reconnect.backoff.jitter.ms, since that property is not exposed to omkafka configs. It probably just uses a default.

I'll take a look, got a friend @alexunwin helping out 👍

@djenriquez
Copy link

djenriquez commented Mar 17, 2017 •
edited
Loading

@edenhill

That seems to have done the trick! I'm still getting some error logs but it DOES NOT burn the instances to the ground anymore:

Mar 17 23:26:30 ip-10-5-8-95 telegraf[12957]: 2017-03-17T23:26:30Z E! Error writing to output [influxdb]: Could not write to any InfluxDB server in cluster
Mar 17 23:26:40 ip-10-5-8-95 telegraf[12957]: 2017-03-17T23:26:40Z E! Database creation failed: Post http://influxdb.<REDACTED>:8086/query?db=&q=CREATE+DATABASE+%22telegraf%22: dial tcp: lookup influxdb.<REDACTED> on 10.5.0.2:53: no such host
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:40 ip-10-5-8-95 telegraf[12957]: 2017-03-17T23:26:40Z E! Error writing to output [influxdb]: Could not write to any InfluxDB server in cluster
Mar 17 23:26:40 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 telegraf[12957]: 2017-03-17T23:26:50Z E! Database creation failed: Post http://influxdb.<REDACTED>:8086/query?db=&q=CREATE+DATABASE+%22telegraf%22: dial tcp: lookup influxdb.<REDACTED> on 10.5.0.2:53: no such host
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message 1/1 brokers are down [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]
Mar 17 23:26:50 ip-10-5-8-95 liblogging-stdlog: omkafka: kafka message kafka.logging.<REDACTED>:9092/bootstrap: Receive failed: Disconnected [v8.25.0 try http://www.rsyslog.com/e/2422 ]

As you can see, errors are still reporting, but there are only a handful now every 10 seconds, wheras before there were hundreds.

Thanks @alexunwin for helping build everything!

@edenhill
Copy link
Contributor

You can silence the disconnect logs by setting log.connection.close=false

@edenhill
Copy link
Contributor

You will still see the "1/1 brokers are down" log message though.

If you register an error_cb you can filter this error out manually.

@djenriquez
Copy link

Sure, thanks @edenhill

edenhill added a commit that referenced this issue Apr 7, 2017
@edenhill
Improve reconnect delay handling (#1089)
eb9fc97 
(cherry picked from commit ee511d4)
@djenriquez djenriquez mentioned this issue May 26, 2017
Closed
9 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@taotetek @edenhill @djenriquez @tejas3190