Skip to content
Closed
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 14 additions & 11 deletions tests/kafkatest/services/console_consumer.py
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@

from ducktape.services.background_thread import BackgroundThreadService
from ducktape.utils.util import wait_until
from kafkatest.services.performance.jmx_mixin import JmxMixin

import os
import subprocess
Expand Down Expand Up @@ -71,7 +72,7 @@ def is_int(msg):
"""


class ConsoleConsumer(BackgroundThreadService):
class ConsoleConsumer(JmxMixin):
# Root directory for persistent output
PERSISTENT_ROOT = "/mnt/console_consumer"
STDOUT_CAPTURE = os.path.join(PERSISTENT_ROOT, "console_consumer.stdout")
Expand All @@ -93,7 +94,8 @@ class ConsoleConsumer(BackgroundThreadService):
"collect_default": True}
}

def __init__(self, context, num_nodes, kafka, topic, message_validator=None, from_beginning=True, consumer_timeout_ms=None):
def __init__(self, context, num_nodes, kafka, topic, message_validator=None, from_beginning=True,
client_id="console-consumer", consumer_timeout_ms=None, jmx_object_name=None, jmx_attributes=None):
"""
Args:
context: standard context
Expand All @@ -107,7 +109,7 @@ def __init__(self, context, num_nodes, kafka, topic, message_validator=None, fro
waiting for the consumer to stop is a pretty good way to consume all messages
in a topic.
"""
super(ConsoleConsumer, self).__init__(context, num_nodes)
super(ConsoleConsumer, self).__init__(context, num_nodes, jmx_object_name, jmx_attributes)
self.kafka = kafka
self.args = {
'topic': topic,
Expand All @@ -118,6 +120,7 @@ def __init__(self, context, num_nodes, kafka, topic, message_validator=None, fro
self.from_beginning = from_beginning
self.message_validator = message_validator
self.messages_consumed = {idx: [] for idx in range(1, num_nodes + 1)}
self.client_id = client_id

@property
def start_cmd(self):
Expand All @@ -126,10 +129,11 @@ def start_cmd(self):
args['stdout'] = ConsoleConsumer.STDOUT_CAPTURE
args['stderr'] = ConsoleConsumer.STDERR_CAPTURE
args['config_file'] = ConsoleConsumer.CONFIG_FILE
args['jmx_port'] = self.jmx_port

cmd = "export LOG_DIR=%s;" % ConsoleConsumer.LOG_DIR
cmd += " export KAFKA_LOG4J_OPTS=\"-Dlog4j.configuration=file:%s\";" % ConsoleConsumer.LOG4J_CONFIG
cmd += " /opt/kafka/bin/kafka-console-consumer.sh --topic %(topic)s --zookeeper %(zk_connect)s" \
cmd += " JMX_PORT=%(jmx_port)d /opt/kafka/bin/kafka-console-consumer.sh --topic %(topic)s --zookeeper %(zk_connect)s" \
" --consumer.config %(config_file)s" % args

if self.from_beginning:
Expand All @@ -153,10 +157,7 @@ def _worker(self, idx, node):
node.account.ssh("mkdir -p %s" % ConsoleConsumer.PERSISTENT_ROOT, allow_fail=False)

# Create and upload config file
if self.consumer_timeout_ms is not None:
prop_file = self.render('console_consumer.properties', consumer_timeout_ms=self.consumer_timeout_ms)
else:
prop_file = self.render('console_consumer.properties')
prop_file = self.render('console_consumer.properties', consumer_timeout_ms=self.consumer_timeout_ms, client_id=self.client_id)

self.logger.info("console_consumer.properties:")
self.logger.info(prop_file)
Expand All @@ -170,24 +171,26 @@ def _worker(self, idx, node):
cmd = self.start_cmd
self.logger.debug("Console consumer %d command: %s", idx, cmd)
for line in node.account.ssh_capture(cmd, allow_fail=False):
self.maybe_start_jmx_tool(idx, node)
msg = line.strip()
if self.message_validator is not None:
msg = self.message_validator(msg)
if msg is not None:
self.messages_consumed[idx].append(msg)

self.read_jmx_output(idx, node)

def start_node(self, node):
super(ConsoleConsumer, self).start_node(node)

def stop_node(self, node):
node.account.kill_process("java", allow_fail=True)
node.account.kill_process("console-consumer", allow_fail=True)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

There is now one sanity check which fails both remotely and on my mac:
http://jenkins.confluent.io/job/kafka_system_tests_branch_builder/94/console

This is fixed by changing console-consumer to console_consumer (dash to underscore)

wait_until(lambda: not self.alive(node), timeout_sec=10, backoff_sec=.2,
err_msg="Timed out waiting for consumer to stop.")

def clean_node(self, node):
if self.alive(node):
self.logger.warn("%s %s was still alive at cleanup time. Killing forcefully..." %
(self.__class__.__name__, node.account))
node.account.kill_process("java", clean_shutdown=False, allow_fail=True)
super(JmxMixin, self).clean_node(node)
node.account.ssh("rm -rf %s" % ConsoleConsumer.PERSISTENT_ROOT, allow_fail=False)

6 changes: 4 additions & 2 deletions tests/kafkatest/services/kafka.py
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ class KafkaService(Service):
"collect_default": False}
}

def __init__(self, context, num_nodes, zk, topics=None):
def __init__(self, context, num_nodes, zk, topics=None, quota_config=None):
"""
:type context
:type zk: ZookeeperService
Expand All @@ -42,6 +42,7 @@ def __init__(self, context, num_nodes, zk, topics=None):
super(KafkaService, self).__init__(context, num_nodes)
self.zk = zk
self.topics = topics
self.quota_config = quota_config

def start(self):
super(KafkaService, self).start()
Expand All @@ -56,7 +57,8 @@ def start(self):
self.create_topic(topic_cfg)

def start_node(self, node):
props_file = self.render('kafka.properties', node=node, broker_id=self.idx(node))
props_file = self.render('kafka.properties', node=node, broker_id=self.idx(node), quota_config=self.quota_config)

self.logger.info("kafka.properties:")
self.logger.info(props_file)
node.account.create_file("/mnt/kafka.properties", props_file)
Expand Down
78 changes: 78 additions & 0 deletions tests/kafkatest/services/performance/jmx_mixin.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,78 @@
# Licensed to the Apache Software Foundation (ASF) under one or more
# contributor license agreements. See the NOTICE file distributed with
# this work for additional information regarding copyright ownership.
# The ASF licenses this file to You under the Apache License, Version 2.0
# (the "License"); you may not use this file except in compliance with
# the License. You may obtain a copy of the License at
#
# http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.

from kafkatest.services.performance import PerformanceService


class JmxMixin(PerformanceService):

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I don't think JmxMixin should subclass PerformanceService, for a couple reasons:

  • Some classes that might want to use this logic won't be performance services
  • The idea with mixins is to make use of multiple inheritance and provide reusable functionality

In other words, this class should subclass object

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Sure. Will fix it.


def __init__(self, context, num_nodes, jmx_object_name=None, jmx_attributes=None):
super(JmxMixin, self).__init__(context, num_nodes)
self.jmx_object_name = jmx_object_name
self.jmx_attributes = jmx_attributes
self.jmx_port = 9192

self.started = [False] * self.num_nodes
self.jmx_stats = [{} for x in range(self.num_nodes)]
self.maximum_jmx_value = None
self.average_jmx_value = None

def clean_node(self, node):
super(JmxMixin, self).clean_node(node)
node.account.kill_process("jmx", clean_shutdown=False, allow_fail=True)
node.account.ssh("rm -rf /mnt/jmx_tool.log", allow_fail=False)

def maybe_start_jmx_tool(self, idx, node):
if self.started[idx-1] == True or self.jmx_object_name == None:
return
self.started[idx-1] = True

cmd = "/opt/kafka/bin/kafka-run-class.sh kafka.tools.JmxTool " \
"--reporting-interval 1000 --jmx-url service:jmx:rmi:///jndi/rmi://127.0.0.1:%d/jmxrmi " \
"--object-name %s " % (self.jmx_port, self.jmx_object_name)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

JmxTool allows multiple jmx object names - should this do the same?

Also, we may want to support running the tool with no object-name specified (so that it queries all objects)

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Yes, JmxTool allows multiple object names and no object name as argument. But should we make it full-fledged from the beginning?

I currently implemented in such a way to only satisfy the use case where we query exactly one attribute. Can we expand it later when we have use case for multiple object names or attributes?

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Ah, I realized there is a better interface for JmxMixin to provide min, avg, and max value for every queried object-attribute. I will update the patch to support this. Thanks for the suggestion.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

@granders JmxMixin has been updated to support query with arbitrary object name and attributes. Thanks for the suggestion.

if self.jmx_attributes != None:
cmd += "--attributes %s " % self.jmx_attributes
cmd += "> /mnt/jmx_tool.log &"

self.logger.debug("Start JmxTool %d command: %s", idx, cmd)
for l in node.account.ssh_capture(cmd, allow_fail=False):

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

since you're not capturing output, use node.account.ssh(cmd ...)

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Even though I don't need output, if I don't wait for output, then the cmd will not be executed by ssh_capture. Does it make sense? I will test it again and get back to you.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

I just double checked it by running the test case -- simply do node.account.ssh_capture(cmd, allow_fail=False) without waiting for output Ducktape will not execute the cmd. I couldn't explain this though -- most likely this is related to how python execute the function with yield.

Can we fix it in Ducktape side so that node.account.ssh(cmd ...) always execute the cmd? Are you able to reproduce the problem I found?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Maybe I'm misunderstanding - did you try node.account.ssh or node.account.ssh_capture, or both?

The first simply runs the command; the second tries to capture output.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Ah.. my bad. Problem fixed after using node.account.ssh. Thanks for the suggestion.

break

def read_jmx_output(self, idx, node):
if self.started[idx-1] == False:
return

cmd = "grep -v time /mnt/jmx_tool.log"
self.logger.debug("Read jmx output %d command: %s", idx, cmd)

for line in node.account.ssh_capture(cmd, allow_fail=False):
time_sec = int(line.split(',')[0])/1000
value = float(line.split(',')[1])
self.jmx_stats[idx-1][time_sec] = value

if any(len(dict)==0 for dict in self.jmx_stats):
return

# since we have read jmx stats from all nodes, calculate average and maximum of jmx stats
start_time_sec = min([min(dict.keys()) for dict in self.jmx_stats])

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Rename "dict" here since it is a reserved keyword

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Thanks for noting this. Will fix it.

end_time_sec = max([max(dict.keys()) for dict in self.jmx_stats])
values = []

for time_sec in xrange(start_time_sec, end_time_sec+1):
collection = [dict.get(time_sec, 0) for dict in self.jmx_stats]
values.append(sum(collection))

self.average_jmx_value = sum(values)/len(values)
self.maximum_jmx_value = max(values)
19 changes: 11 additions & 8 deletions tests/kafkatest/services/performance/producer_performance.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,19 +13,19 @@
# See the License for the specific language governing permissions and
# limitations under the License.

from kafkatest.services.performance import PerformanceService
from kafkatest.services.performance.jmx_mixin import JmxMixin


class ProducerPerformanceService(PerformanceService):
class ProducerPerformanceService(JmxMixin):

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Inherit from both PerformanceService and JmxMixin (see comment on mixin above)
i.e.
class ProducerPerformanceService(PerformanceService, JmxMixin)

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Will fix it.


logs = {
"producer_performance_log": {
"path": "/mnt/producer-performance.log",
"collect_default": True},
}

def __init__(self, context, num_nodes, kafka, topic, num_records, record_size, throughput, settings={}, intermediate_stats=False):
super(ProducerPerformanceService, self).__init__(context, num_nodes)
def __init__(self, context, num_nodes, kafka, topic, num_records, record_size, throughput, settings={},
intermediate_stats=False, client_id="producer-performance", jmx_object_name=None, jmx_attributes=None):
super(ProducerPerformanceService, self).__init__(context, num_nodes, jmx_object_name, jmx_attributes)
self.kafka = kafka
self.args = {
'topic': topic,
Expand All @@ -35,12 +35,13 @@ def __init__(self, context, num_nodes, kafka, topic, num_records, record_size, t
}
self.settings = settings
self.intermediate_stats = intermediate_stats
self.client_id = client_id

def _worker(self, idx, node):
args = self.args.copy()
args.update({'bootstrap_servers': self.kafka.bootstrap_servers()})
cmd = "/opt/kafka/bin/kafka-run-class.sh org.apache.kafka.clients.tools.ProducerPerformance "\
"%(topic)s %(num_records)d %(record_size)d %(throughput)d bootstrap.servers=%(bootstrap_servers)s"\
args.update({'bootstrap_servers': self.kafka.bootstrap_servers(), 'jmx_port': self.jmx_port, 'client_id': self.client_id})
cmd = "JMX_PORT=%(jmx_port)d /opt/kafka/bin/kafka-run-class.sh org.apache.kafka.clients.tools.ProducerPerformance "\
"%(topic)s %(num_records)d %(record_size)d %(throughput)d bootstrap.servers=%(bootstrap_servers)s client.id=%(client_id)s"\
" | tee /mnt/producer-performance.log" % args

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

@lindong28
I tried this a bit locally, and realized the command now has two pipes to tee (see line 58 as well)

When I drop the pipe to tee here on line 51 and keep the one below, the producer runs as expected.


for key, value in self.settings.items():
Expand All @@ -62,6 +63,7 @@ def parse_stats(line):
}
last = None
for line in node.account.ssh_capture(cmd):
self.maybe_start_jmx_tool(idx, node)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Calling maybe_start_jmx_tool after each line that gets read from the producer process doesn't seem quite right.

I think we want the behavior to be:

  • start producer "asynchronously"
  • start jmx tool asynchronously
  • wait for producer to finish
  • process each line of producer output

I think it would look something like:

cmd = "same_as_before &"  # now the cmd is "async"
node.account.ssh(cmd)
wait_until(producer is alive)

self.start_jmx_tool(node)

wait_until(producer is finished)
for line in node.account.ssh_capture("cat /mnt/producer-performance.log"):
  # same as the previous for loop

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Yes I have thought of the approach as you described -- I didn't implement it because it required the test case developer to specifically redirect output to a file and read from that file, which should not be required for developer to do if we can the right support from Ducktape. This is the reason I asked for asynchronous ssh in Ducktape during our discussion in the email.

I am thinking of something like this:

cmd = "same_as_before"
output = node.account.ssh_asynchrous(cmd)
self.start_jmx_tool(node)
for line in output:
   # same as the previous for loop

Does it make sense?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

@lindong28 Now it's a lot clearer what you meant in your original email. You're basically saying that since RemoteAccount.ssh() blocks, RemoteAccount.ssh_output() blocks until all output is collected and RemoteAccount.ssh_capture() drives the whole process despite acting as a generator, there's no way to start a second process between when you start the first and when you start reading its output?

I think it makes a lot of sense to provide support for that. More generally, I think the current set of RemoteAccount.ssh* methods could use some cleanup and potentially renaming to simplify things. Originally I thought the blocking RemoteAccount.ssh() would be the most widely used, but it turns out we've found more and more uses for capturing the output.

@granders, a patch just to add Ducktape support for the approach @lindong28 is looking for should be quick and easy. I think it can look a lot like ssh_capture, but it'll have to return an iterable object after invoking the ssh command rather than treating the entire method call as a generator using yield. It might even make sense to just return the subprocess object and allow the user to do whatever they want with it, so the example would look something like

cmd = "same_as_before"
proc = node.account.ssh_async(cmd)
self.start_jmx_tool(node)
for line in iter(proc.stdout.readline, ''):
   # same as the previous for loop

I think there are cleaner ways to expose this, but given how many ssh* variants we're ending up with, we may want to hold off on introducing much more until we sort out how to capture all of them with a minimum of methods.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

@ewencp Thanks for your comment. As you mentioned in the ticket, I can file a follow up patch after Ducktape is updated.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

@ewencp In response to your question, yeah that is what I have in mind when I was thinking about the test, and is the reason I wanted to have support for "asynchronous" ssh command from Ducktape. But I didn't stated it very clearly in the email, partly because something become clearer only after I started implementation -- for example, I once thought that adding "&" would solve problem cleanly but it didn't.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

@lindong28 Thanks for this observation. I added a fix in confluentinc/ducktape#107

The fix is now available from pypi as version 0.3.5 - you'll want to update the ducktape dependency in tests/setup.py

Note this is actually asynchronous even without running command as a background process with "&", so you should be able to run:

producer_output = node.account.ssh_capture(cmd)
wait_until(producer is alive)
self.start_jmx_tool(node)

for line in producer_output:
  process(line)

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Thanks @granders for the patch. Will use the new API.

if self.intermediate_stats:
try:
self.stats[idx-1].append(parse_stats(line))
Expand All @@ -74,3 +76,4 @@ def parse_stats(line):
self.results[idx-1] = parse_stats(last)
except:
raise Exception("Unable to parse aggregate performance statistics on node %d: %s" % (idx, last))
self.read_jmx_output(idx, node)
Original file line number Diff line number Diff line change
Expand Up @@ -17,3 +17,10 @@
{% if consumer_timeout_ms is defined and consumer_timeout_ms is not none %}
consumer.timeout.ms={{ consumer_timeout_ms }}
{% endif %}

group.id={{ group_id|default('test-consumer-group') }}

{% if client_id is defined and client_id is not none %}
client.id={{ client_id }}
{% endif %}

16 changes: 16 additions & 0 deletions tests/kafkatest/services/templates/kafka.properties
Original file line number Diff line number Diff line change
Expand Up @@ -39,3 +39,19 @@ log.cleaner.enable=false

zookeeper.connect={{ zk.connect_setting() }}
zookeeper.connection.timeout.ms=2000

{% if quota_config.quota_producer_default is defined and quota_config.quota_producer_default is not none %}
quota.producer.default={{ quota_config.quota_producer_default }}
{% endif %}

{% if quota_config.quota_consumer_default is defined and quota_config.quota_consumer_default is not none %}
quota.consumer.default={{ quota_config.quota_consumer_default }}
{% endif %}

{% if quota_config.quota_producer_bytes_per_second_overrides is defined and quota_config.quota_producer_bytes_per_second_overrides is not none %}
quota.producer.bytes.per.second.overrides={{ quota_config.quota_producer_bytes_per_second_overrides }}
{% endif %}

{% if quota_config.quota_consumer_bytes_per_second_overrides is defined and quota_config.quota_consumer_bytes_per_second_overrides is not none %}
quota.consumer.bytes.per.second.overrides={{ quota_config.quota_consumer_bytes_per_second_overrides }}
{% endif %}
Loading