You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@kafka.apache.org by "John Fung (JIRA)" <ji...@apache.org> on 2012/09/28 00:33:07 UTC

[jira] [Created] (KAFKA-535) Significant difference in time taken to produce messages between 1, -1 for request-num-acks

John Fung created KAFKA-535:
-------------------------------

             Summary: Significant difference in time taken to produce messages between 1, -1 for request-num-acks
                 Key: KAFKA-535
                 URL: https://issues.apache.org/jira/browse/KAFKA-535
             Project: Kafka
          Issue Type: Bug
            Reporter: John Fung
            Priority: Blocker


There is a significant difference in time taken for ProducerPerformance to produce messages between 1 & -1 for request-num-acks.

The following are the log4j messages from ProducerPerformance with consequent calls from the system test script.

** Please note the time elapsed in consequent timestamps of calling ProducerPerformance.

The overall test scenarios:
1. This test is set up to have 1 zookeeper, 1 broker cluster of 6 nodes (distributed systems, non-local), replica factor 6, 1 topic, 1 partition
2. The script will wait for ProducerPerformance to complete sending all messages (500 each call in this case) before calling the producer again. 


1. request-num-acks = -1. The rate is about 10 messages per second. The timestamp indicates that it takes 60+ seconds for ProducerPerformance to completely sending 500 messages and exit by itself.

2012-09-26 21:20:56,102 - INFO - #### [producer thread] status of stopBackgroundProducer : [False] => producing [500] messages with starting message id : [0] (kafka_system_test_utils)
2012-09-26 21:20:56,102 - DEBUG - executing command: [ssh host0996.mydomain 'JAVA_HOME=/export/apps/jdk/JDK-1_6_0_21 JMX_PORT=9997 /kafka_pst_wip/bin/kafka-run-class.sh kafka.perf.ProducerPerformance --broker-list host0997.mydomain:9091,host0998.mydomain:9092,host0999.mydomain:9093,host1000.mydomain:9094,host1001.mydomain:9095,host1002.mydomain:9096 --initial-message-id 0 --messages 500 --topic test_1 --threads 5 --compression-codec 0 --message-size 500 --request-num-acks -1   >> /kafka_pst_wip/system_test/replication_testsuite/testcase_0001/logs/producer_performance-7/producer_performance.log  & echo pid:$! > /kafka_pst_wip/system_test/replication_testsuite/testcase_0001/logs/producer_performance-7/entity_7_pid'] (kafka_system_test_utils)
. . .
2012-09-26 21:22:00,162 - INFO - #### [producer thread] status of stopBackgroundProducer : [False] => producing [500] messages with starting message id : [500] (kafka_system_test_utils)
2012-09-26 21:22:00,162 - DEBUG - executing command: [ssh host0996.mydomain 'JAVA_HOME=/export/apps/jdk/JDK-1_6_0_21 JMX_PORT=9997 /kafka_pst_wip/bin/kafka-run-class.sh kafka.perf.ProducerPerformance --broker-list host0997.mydomain:9091,host0998.mydomain:9092,host0999.mydomain:9093,host1000.mydomain:9094,host1001.mydomain:9095,host1002.mydomain:9096 --initial-message-id 500 --messages 500 --topic test_1 --threads 5 --compression-codec 0 --message-size 500 --request-num-acks -1   >> /kafka_pst_wip/system_test/replication_testsuite/testcase_0001/logs/producer_performance-7/producer_performance.log  & echo pid:$! > /kafka_pst_wip/system_test/replication_testsuite/testcase_0001/logs/producer_performance-7/entity_7_pid'] (kafka_system_test_utils)


2. request-num-acks = 1. The rate is about 150 ~ 200 messages per second. The timestamp indicates that it takes < 3 seconds for ProducerPerformance to completely sending 500 messages.

2012-09-26 21:29:23,698 - INFO - #### [producer thread] status of stopBackgroundProducer : [False] => producing [500] messages with starting message id : [500] (kafka_system_test_utils)
2012-09-26 21:29:23,698 - DEBUG - executing command: [ssh host0996.mydomain 'JAVA_HOME=/export/apps/jdk/JDK-1_6_0_21 JMX_PORT=9997 /kafka_pst_wip/bin/kafka-run-class.sh kafka.perf.ProducerPerformance --broker-list host0997.mydomain:9091,host0998.mydomain:9092,host0999.mydomain:9093,host1000.mydomain:9094,host1001.mydomain:9095,host1002.mydomain:9096 --initial-message-id 500 --messages 500 --topic test_1 --threads 5 --compression-codec 0 --message-size 500 --request-num-acks 1   >> /kafka_pst_wip/system_test/replication_testsuite/testcase_0002/logs/producer_performance-7/producer_performance.log  & echo pid:$! > /kafka_pst_wip/system_test/replication_testsuite/testcase_0002/logs/producer_performance-7/entity_7_pid'] (kafka_system_test_utils)
. . .
2012-09-26 21:29:26,576 - INFO - #### [producer thread] status of stopBackgroundProducer : [False] => producing [500] messages with starting message id : [1000] (kafka_system_test_utils)
2012-09-26 21:29:26,577 - DEBUG - executing command: [ssh host0996.mydomain 'JAVA_HOME=/export/apps/jdk/JDK-1_6_0_21 JMX_PORT=9997 /kafka_pst_wip/bin/kafka-run-class.sh kafka.perf.ProducerPerformance --broker-list host0997.mydomain:9091,host0998.mydomain:9092,host0999.mydomain:9093,host1000.mydomain:9094,host1001.mydomain:9095,host1002.mydomain:9096 --initial-message-id 1000 --messages 500 --topic test_1 --threads 5 --compression-codec 0 --message-size 500 --request-num-acks 1   >> /kafka_pst_wip/system_test/replication_testsuite/testcase_0002/logs/producer_performance-7/producer_performance.log  & echo pid:$! > /kafka_pst_wip/system_test/replication_testsuite/testcase_0002/logs/producer_performance-7/entity_7_pid'] (kafka_system_test_utils)


--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira