search

redpanda-data / redpanda

Redpanda is a streaming data platform for developers. Kafka API compatible. 10x faster. No ZooKeeper. No JVM!
https://redpanda.com
9.15k stars 558 forks source link

High latencies seen when machine saturation is hit #608

Open rkruze opened 3 years ago

rkruze commented 3 years ago

When running something like rdkafka_performance, if you just let it run without specifying a rate you get some very high latencies, for example:

on 3 i3en.large instances, running the following: ./rdkafka_performance -P -b <broker> -t sfo -s 1024 -a -1 -c 10000000 -u will get you the following: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     500000 |  512000000 |          1 |          0 |          0 |       0.00 |          0 |         80 |     500000 |          0
|       2000 |     500000 |  512000000 |          0 |          0 |          0 |       0.00 |          0 |        180 |     500000 |          0
|       3001 |     583162 |  597157888 |       2529 |      83162 |      27710 |      28.38 |          0 |        301 |     500000 |    5261561
|       4001 |     701136 |  717963264 |       3104 |     201136 |      50265 |      51.47 |          0 |        434 |     500000 |    5379535
|       5001 |     821044 |  840749056 |       3750 |     321044 |      64185 |      65.73 |          0 |        566 |     500000 |    5499443
|       6002 |     939985 |  962544640 |       4415 |     439985 |      73304 |      75.06 |          0 |        694 |     500000 |    5618384
|       7002 |    1058020 | 1083412480 |       4573 |     558020 |      79688 |      81.60 |          0 |        821 |     500000 |    5736419
|       8002 |    1179862 | 1208178688 |       4194 |     679862 |      84952 |      86.99 |          0 |        956 |     500000 |    5858261
|       9002 |    1299770 | 1330964480 |       4194 |     800737 |      88942 |      91.08 |          0 |       1088 |     499033 |    5979136
|      10003 |    1424513 | 1458701312 |       4141 |     924513 |      92418 |      94.64 |          0 |       1219 |     500000 |    6102912
|      11003 |    1547383 | 1584520192 |       4104 |    1047383 |      95183 |      97.47 |          0 |       1351 |     500000 |    6225782
|      12004 |    1673093 | 1713247232 |       4063 |    1173093 |      97723 |     100.07 |          0 |       1485 |     500000 |    6351492
|      13004 |    1799770 | 1842964480 |       4028 |    1299770 |      99947 |     102.35 |          0 |       1619 |     500000 |    6478169
|      14004 |    1927414 | 1973671936 |       3985 |    1427414 |     101922 |     104.37 |          0 |       1755 |     500000 |    6605813
|      15005 |    2052218 | 2101471232 |       3964 |    1552218 |     103445 |     105.93 |          0 |       1886 |     500000 |    6730617
|      16005 |    2177928 | 2230198272 |       3953 |    1677928 |     104834 |     107.35 |          0 |       2018 |     500000 |    6856327
|      17005 |    2304605 | 2359915520 |       3960 |    1804605 |     106116 |     108.66 |          0 |       2154 |     500000 |    6983004

Now if we specify a rate of about 100 MB/s using the following command: ./rdkafka_performance -P -b <broker> -t sfo -s 1024 -a -1 -c 10000000 -r 100000 -u we then see the following: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |      98894 |  101267456 |          0 |      98121 |      98120 |     100.48 |          0 |          0 |        773 |   15032189
|       2000 |     197822 |  202569728 |          6 |     197193 |      98595 |     100.96 |          0 |          0 |        629 |   15131261
|       3000 |     296734 |  303855616 |          5 |     296039 |      98679 |     101.05 |          0 |          0 |        695 |   15230107
|       4000 |     395661 |  405156864 |          8 |     395108 |      98776 |     101.15 |          0 |          0 |        553 |   15329176
|       5000 |     494600 |  506470400 |          6 |     493556 |      98710 |     101.08 |          0 |          0 |       1044 |   15427624
|       6000 |     593532 |  607776768 |          6 |     592428 |      98737 |     101.11 |          0 |          0 |       1104 |   15526496

It seems we might not be creating back pressure on the client and thus allows for us to see very high latencies.

JIRA Link: CORE-589

rkruze commented 3 years ago

Just to compare, running the following on Kafka on the same hardware, with flushing after every message I get the following: 

./rdkafka_performance -P -b 10.0.0.15 -t sfo2 -s 1024 -a -1 -c 10000000 -u
% Sending 10000000 messages of size 1024 bytes
%4|1613105750.778|CONFWARN|rdkafka#producer-1| [thrd:app]: Configuration property session.timeout.ms is a consumer property and will be ignored by this producer instance
%4|1613105750.778|CONFWARN|rdkafka#producer-1| [thrd:app]: Configuration property queued.min.messages is a consumer property and will be ignored by this producer instance
%4|1613105750.778|CONFWARN|rdkafka#producer-1| [thrd:app]: Configuration property offset_commit_cb is a consumer property and will be ignored by this producer instance
|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1001 |     661613 |  677491712 |         15 |     161613 |     161417 |     165.29 |          0 |        152 |     500000 |       9669
|       2002 |     842868 |  863096832 |         14 |     342868 |     171210 |     175.32 |          0 |        348 |     500000 |      15471
|       3003 |    1008214 | 1032411136 |         14 |     509181 |     169519 |     173.59 |          0 |        540 |     499033 |      31910
|       4005 |    1186763 | 1215245312 |         14 |     686763 |     171452 |     175.57 |          0 |        738 |     500000 |      19647
emaxerrno commented 3 years ago

I think this is directly related to #542 -

@dotnwat posits that we use up all the memory and have to wait for all the chunks to come back specially when we do a flush()

rkruze commented 3 years ago

https://github.com/vectorizedio/redpanda/issues/977 looks to also be related.

rkruze commented 3 years ago

With 21.4.15 We get somewhat better results: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|      58051 |    9710734 | 9943791616 |        177 |    9212246 |     158690 |     162.50 |          0 |       1598 |     498488 |    1662210
|      59051 |    9866020 | 10102804480 |        177 |    9366987 |     158623 |     162.43 |          0 |       1637 |     499033 |    1736284
|      60051 |   10021803 | 10262326272 |        176 |    9522414 |     158570 |     162.38 |          0 |       1681 |     499389 |    1871279
|      61051 |   10180556 | 10424889344 |        174 |    9680692 |     158565 |     162.37 |          0 |       1720 |     499864 |    1826242
|      62051 |   10335960 | 10584023040 |        177 |    9836159 |     158515 |     162.32 |          0 |       1767 |     499801 |    1905924
|      63051 |   10491390 | 10743183360 |        176 |    9991508 |     158465 |     162.27 |          0 |       1815 |     499882 |    1895441
|      64058 |   10648033 | 10903585792 |        179 |   10149000 |     158433 |     162.24 |          0 |       1862 |     499034 |    1722690
|      65058 |   10804350 | 11063654400 |        173 |   10304509 |     158389 |     162.19 |          0 |       1906 |     499841 |    1720033
|      66058 |   10959877 | 11222914048 |        175 |   10460528 |     158353 |     162.15 |          0 |       1952 |     499349 |    1921925
|      67062 |   11115167 | 11381931008 |        176 |   10616134 |     158302 |     162.10 |          0 |       1998 |     499034 |    1824630
|      68062 |   11273036 | 11543588864 |        176 |   10775004 |     158311 |     162.11 |          0 |       2036 |     498032 |    1871624
|      69064 |   11430116 | 11704438784 |        177 |   10931083 |     158273 |     162.07 |          0 |       2077 |     499033 |    1941835
|      70064 |   11584122 | 11862140928 |        163 |   11085532 |     158219 |     162.02 |          0 |       2114 |     498590 |    1889022
|      71066 |   11739192 | 12020932608 |        173 |   11240158 |     158163 |     161.96 |          0 |       2152 |     499036 |    1798605
|      72066 |   11896105 | 12181611520 |        179 |   11396689 |     158140 |     161.94 |          0 |       2192 |     499416 |    1969864
|      73066 |   12053725 | 12343014400 |        178 |   11554024 |     158129 |     161.92 |          0 |       2226 |     499701 |    1878536
|      74066 |   12207790 | 12500776960 |        186 |   11707790 |     158070 |     161.86 |          0 |       2270 |     500000 |    1887363

and with kafka_qdc_max_depth: 1 set I get: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|     665771 |  104712825 | 107225932800 |         79 |  104212825 |     156529 |     160.29 |          0 |     119620 |     500000 |    7294706
|     666772 |  104869129 | 107385988096 |         72 |  104369129 |     156528 |     160.29 |          0 |     119791 |     500000 |    7098821
|     667773 |  105025015 | 107545615360 |         79 |  104525015 |     156527 |     160.28 |          0 |     119962 |     500000 |    7176913
|     668775 |  105182581 | 107706962944 |         82 |  104682581 |     156528 |     160.29 |          0 |     120140 |     500000 |    7216410
|     669776 |  105339135 | 107867274240 |         86 |  104839135 |     156528 |     160.29 |          0 |     120322 |     500000 |    7243638
|     670777 |  105495022 | 108026902528 |         53 |  104995022 |     156527 |     160.28 |          0 |     120497 |     500000 |    7289783
|     671778 |  105650778 | 108186396672 |         50 |  105150778 |     156526 |     160.28 |          0 |     120672 |     500000 |    7239441
|     672779 |  105808524 | 108347928576 |         52 |  105308524 |     156527 |     160.28 |          0 |     120853 |     500000 |    7132326
|     673780 |  105963883 | 108507016192 |         65 |  105463883 |     156525 |     160.28 |          0 |     121027 |     500000 |    7558408
|     674781 |  106120399 | 108667288576 |         77 |  105620399 |     156525 |     160.28 |          0 |     121214 |     500000 |    7358862
|     675782 |  106277359 | 108828015616 |         63 |  105777359 |     156525 |     160.28 |          0 |     121384 |     500000 |    7593753
|     676784 |  106432824 | 108987211776 |         56 |  105932824 |     156523 |     160.28 |          0 |     121564 |     500000 |    7280979
|     677784 |  106588440 | 109146562560 |         56 |  106089406 |     156523 |     160.28 |          0 |     121738 |     499034 |    7186871
|     678786 |  106744663 | 109306534912 |        103 |  106244663 |     156521 |     160.28 |          0 |     121927 |     500000 |    7230118
|     679787 |  106901722 | 109467363328 |        103 |  106402689 |     156523 |     160.28 |          0 |     122104 |     499033 |    7608169
|     680788 |  107058667 | 109628075008 |         61 |  106558667 |     156522 |     160.28 |          0 |     122281 |     500000 |    7414929
|     681789 |  107214802 | 109787957248 |         54 |  106714802 |     156521 |     160.28 |          0 |     122461 |     500000 |    7414983
|     682791 |  107371404 | 109948317696 |         56 |  106871404 |     156521 |     160.28 |          0 |     122639 |     500000 |    7425238
|     683792 |  107526775 | 110107417600 |         60 |  107026775 |     156519 |     160.28 |          0 |     122814 |     500000 |    7505096
|     684793 |  107684024 | 110268440576 |         92 |  107184024 |     156520 |     160.28 |          0 |     122998 |     500000 |    7347958
|     685794 |  107840559 | 110428732416 |        117 |  107340559 |     156519 |     160.28 |          0 |     123183 |     500000 |    7345685
|     686794 |  107996739 | 110588660736 |        117 |  107496863 |     156519 |     160.28 |          0 |     123365 |     499876 |    7463882
dotnwat commented 3 years ago

with queue depth 1 we are effectively optimizing for latency at the kafka layer of the io path. that is really curious, though, because it means there might be some back pressure issues above kafka (ie rpc/network layer). driving throughput after latency is better will mean dealing with down stream io path issues. its a holistic challenge that's gonna take some dedicated time on.

dotnwat commented 3 years ago
dotnwat commented 3 years ago

Updated results are that the latest dev gives good latency on i3.2xlarge. we can drive that disk at 600+ mb/s. but on i3.large we can only push around 190 mb/s. i3.large has 2 cpu and 0.5tb disk. There is likely some new bottleneck on the more resource constrained machine like i3.large

emaxerrno commented 3 years ago

@rkruze ; should we update it w/ your recent findings.

dotnwat commented 3 years ago

The performance profile on i3.large is very similar to that of our machines with dm-crypt enabled which appears to do its own caching that we can't control. Since i3.large uses 0.5 TB disks, it's likely those are shared, leading to believe that there may be some caching that we can't control within the host. Credit to @BenPope for making this observation.

rkruze commented 3 years ago

Created a build with #1575 and #1496. Then ran on i3.large instances:

Redpanda: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     725991 |  743414784 |          0 |     226106 |     226106 |     231.53 |          0 |         37 |     499885 |     344231
|       2000 |     922510 |  944650240 |        128 |     427011 |     213505 |     218.63 |          0 |        143 |     495499 |     253390
|       3000 |    1128548 | 1155633152 |        249 |     628548 |     209511 |     214.54 |          0 |        242 |     500000 |     330005
|       4000 |    1344865 | 1377141760 |        341 |     845831 |     211453 |     216.53 |          0 |        334 |     499034 |     407758
|       5001 |    1503908 | 1540001792 |        418 |    1003908 |     200716 |     205.53 |          0 |        443 |     500000 |     411256
|       6001 |    1730693 | 1772229632 |        339 |    1231660 |     205213 |     210.14 |          0 |        550 |     499034 |     458262
|       7005 |    1926468 | 1972703232 |        340 |    1427435 |     203764 |     208.65 |          0 |        653 |     499033 |     285837
|       8008 |    2139952 | 2191310848 |        379 |    1639952 |     204782 |     209.70 |          0 |        744 |     500000 |     400294
|       9013 |    2290785 | 2345763840 |        305 |    1790785 |     198686 |     203.45 |          0 |        857 |     500000 |     329489
|      10013 |    2452820 | 2511687680 |        305 |    1953787 |     195122 |     199.81 |          0 |        973 |     499033 |     318714
|      11013 |    2656585 | 2720343040 |        248 |    2157551 |     195897 |     200.60 |          0 |       1091 |     499034 |     279192
|      12017 |    2869087 | 2937945088 |        200 |    2369087 |     197139 |     201.87 |          0 |       1207 |     500000 |     533216
|      13017 |    3075250 | 3149056000 |        200 |    2576217 |     197903 |     202.65 |          0 |       1335 |     499035 |     456429
|      14018 |    3231900 | 3309465600 |        178 |    2732867 |     194949 |     199.63 |          0 |       1467 |     499035 |     350827
|      15018 |    3430005 | 3512325120 |        152 |    2930971 |     195157 |     199.84 |          0 |       1594 |     499034 |     343721
|      16019 |    3601250 | 3687680000 |        134 |    3102217 |     193647 |     198.30 |          0 |       1718 |     499033 |     383491
|      17023 |    3834606 | 3926636544 |        236 |    3334606 |     195876 |     200.58 |          0 |       1828 |     500000 |     510427
|      18025 |    3978410 | 4073891840 |        227 |    3478410 |     192972 |     197.60 |          0 |       1934 |     500000 |     399170
|      19026 |    4171828 | 4271951872 |        291 |    3671828 |     192981 |     197.61 |          0 |       2034 |     500000 |     404972
|      20027 |    4341698 | 4445898752 |        291 |    3842665 |     191866 |     196.47 |          0 |       2144 |     499033 |     525127
|      21029 |    4583550 | 4693555200 |        158 |    4084517 |     194229 |     198.89 |          0 |       2235 |     499034 |     440535
|      22030 |    4785456 | 4900306944 |        337 |    4285456 |     194519 |     199.19 |          0 |       2333 |     500000 |     423328

Kafka: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     158987 |  162802688 |         14 |      58987 |      58958 |      60.37 |          0 |        123 |     100000 |      58986
|       2001 |     224743 |  230136832 |         12 |     124743 |      62335 |      63.83 |          0 |        264 |     100000 |     124742
|       3002 |     308872 |  316284928 |         20 |     208872 |      69572 |      71.24 |          0 |        405 |     100000 |      34811
|       4003 |     421443 |  431557632 |         13 |     321443 |      80295 |      82.22 |          0 |        567 |     100000 |      95732
|       5004 |     539417 |  552363008 |         14 |     439417 |      87808 |      89.92 |          0 |        722 |     100000 |      58986
|       6004 |     650830 |  666449920 |         14 |     551021 |      91771 |      93.97 |          0 |        874 |      99809 |     128610
|       7006 |     783500 |  802304000 |         12 |     683500 |      97554 |      99.90 |          0 |       1033 |     100000 |     199201
|       8007 |     880599 |  901733376 |         12 |     780599 |      97487 |      99.83 |          0 |       1188 |     100000 |     325310
|       9008 |     972464 |  995803136 |         18 |     872464 |      96849 |      99.17 |          0 |       1330 |     100000 |      37712
|      10009 |    1082134 | 1108105216 |         14 |     982134 |      98120 |     100.48 |          0 |       1486 |     100000 |      99600
|      11010 |    1215580 | 1244753920 |         12 |    1115580 |     101319 |     103.75 |          0 |       1636 |     100000 |     290498
|      12011 |    1327265 | 1359119360 |         11 |    1227265 |     102174 |     104.63 |          0 |       1762 |     100000 |     368825
|      13012 |    1407526 | 1441306624 |         11 |    1308493 |     100558 |     102.97 |          0 |       1877 |      99034 |     450053
|      14012 |    1495523 | 1531415552 |          9 |    1395523 |      99588 |     101.98 |          0 |       1988 |     100000 |     537083
|      15012 |    1589323 | 1627466752 |          9 |    1491256 |      99331 |     101.72 |          0 |       2107 |      98067 |     623146
|      16012 |    1680432 | 1720762368 |         52 |    1580619 |      98709 |     101.08 |          0 |       2246 |      99813 |      83161
|      17015 |    1754111 | 1796209664 |         11 |    1654111 |      97211 |      99.54 |          0 |       2403 |     100000 |     138280
|      18016 |    1840573 | 1884746752 |          9 |    1740573 |      96611 |      98.93 |          0 |       2527 |     100000 |      58019
|      19017 |    1981755 | 2029317120 |         11 |    1881755 |      98950 |     101.32 |          0 |       2676 |     100000 |      69623

So we are seeing some really nice throughput but the latency is pretty high.

mmaslankaprv commented 3 years ago

@rkruze can you include command that you used to generate latencies report for latest comment, also what is the topic setup for this case.

This is what I get from latest redpanda release: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     282792 |  289579008 |          0 |     205971 |     205970 |     210.91 |          0 |          0 |      76821 |  548054866
|       2000 |     484324 |  495947776 |          3 |     384866 |     192432 |     197.05 |          0 |        172 |      99458 |  548233761
|       3002 |     689870 |  706426880 |          4 |     590837 |     196762 |     201.48 |          0 |        387 |      99033 |  548439732
|       4002 |     880211 |  901336064 |          3 |     780368 |     194955 |     199.63 |          0 |        589 |      99843 |  548629263
|       5003 |    1071414 | 1097127936 |          4 |     972800 |     194419 |     199.09 |          0 |        781 |      98614 |  548821695
|       6003 |    1258553 | 1288758272 |          4 |    1159430 |     193121 |     197.76 |          0 |        972 |      99123 |  549008325
|       7003 |    1465026 | 1500186624 |          4 |    1365401 |     194956 |     199.64 |          0 |       1168 |      99625 |  549214296
|       8004 |    1662664 | 1702567936 |          4 |    1563635 |     195342 |     200.03 |          0 |       1380 |      99029 |  549412530
|       9007 |    1858001 | 1902593024 |          4 |    1758001 |     195172 |     199.86 |          0 |       1582 |     100000 |  549606896
|      10007 |    2035288 | 2084134912 |          4 |    1935928 |     193449 |     198.09 |          0 |       1761 |      99360 |  549784823
|      11013 |    2242865 | 2296693760 |          5 |    2142865 |     194564 |     199.23 |          0 |       1924 |     100000 |  549991760
|      12014 |    2432396 | 2490773504 |          4 |    2332396 |     194124 |     198.78 |          0 |       2127 |     100000 |  550181291
|      13016 |    2619026 | 2681882624 |          4 |    2519993 |     193597 |     198.24 |          0 |       2327 |      99033 |  550368888
|      14026 |    2820161 | 2887844864 |          3 |    2720161 |     193928 |     198.58 |          0 |       2541 |     100000 |  550569056
|      15026 |    3007505 | 3079685120 |          4 |    2907758 |     193506 |     198.15 |          0 |       2741 |      99747 |  550756653
|      16028 |    3205025 | 3281945600 |          4 |    3105025 |     193714 |     198.36 |          0 |       2948 |     100000 |  550953920
|      17029 |    3397457 | 3478995968 |          4 |    3297457 |     193631 |     198.28 |          0 |       3148 |     100000 |  551146352
|      18029 |    3577259 | 3663113216 |          4 |    3477318 |     192867 |     197.50 |          0 |       3339 |      99941 |  551326213
|      19029 |    3780216 | 3870941184 |          3 |    3680387 |     193403 |     198.05 |          0 |       3543 |      99829 |  551529282
|      20033 |    3973786 | 4069156864 |          4 |    3873786 |     193369 |     198.01 |          0 |       3735 |     100000 |  551722681
|      21033 |    4166218 | 4266207232 |          4 |    4066218 |     193318 |     197.96 |          0 |       3929 |     100000 |  551915113
|      22034 |    4358650 | 4463257600 |          4 |    4258650 |     193272 |     197.91 |          0 |       4132 |     100000 |  552107545
|      23035 |    4551082 | 4660307968 |          4 |    4451082 |     193230 |     197.87 |          0 |       4330 |     100000 |  552299977
|      24035 |    4741580 | 4855377920 |          4 |    4642547 |     193152 |     197.79 |          0 |       4536 |      99033 |  552491442
|      25035 |    4927213 | 5045466112 |          4 |    4827243 |     192815 |     197.44 |          0 |       4731 |      99970 |  552676138
|      26038 |    5128378 | 5251459072 |          3 |    5028378 |     193114 |     197.75 |          0 |       4913 |     100000 |  552877273
|      27038 |    5320810 | 5448509440 |          4 |    5220810 |     193084 |     197.72 |          0 |       5117 |     100000 |  553069705
|      28039 |    5513242 | 5645559808 |          4 |    5413242 |     193056 |     197.69 |          0 |       5314 |     100000 |  553262137
|      29040 |    5705674 | 5842610176 |          4 |    5605674 |     193030 |     197.66 |          0 |       5519 |     100000 |  553454569
|      30040 |    5893271 | 6034709504 |          4 |    5794238 |     192879 |     197.51 |          0 |       5715 |      99033 |  553643130
|      31042 |    6090538 | 6236710912 |          4 |    5990538 |     192978 |     197.61 |          0 |       5911 |     100000 |  553839430
|      32043 |    6282970 | 6433761280 |          4 |    6182970 |     192956 |     197.59 |          0 |       6115 |     100000 |  554031862
|      33043 |    6475402 | 6630811648 |          4 |    6375402 |     192936 |     197.57 |          0 |       6322 |     100000 |  554224294
|      34044 |    6667834 | 6827862016 |          4 |    6567834 |     192918 |     197.55 |          0 |       6531 |     100000 |  554416726
|      35045 |    6860266 | 7024912384 |          4 |    6760266 |     192900 |     197.53 |          0 |       6742 |     100000 |  554609158
|      36046 |    7052698 | 7221962752 |          3 |    6952698 |     192883 |     197.51 |          0 |       6957 |     100000 |  554801590
|      37046 |    7245130 | 7419013120 |          4 |    7145130 |     192867 |     197.50 |          0 |       7174 |     100000 |  554994022
|      38048 |    7424991 | 7603190784 |          4 |    7325958 |     192542 |     197.16 |          0 |       7368 |      99033 |  555174850
|      39048 |    7618669 | 7801517056 |          3 |    7519358 |     192564 |     197.19 |          0 |       7573 |      99311 |  555368250
|      40048 |    7813390 | 8000911360 |          4 |    7713725 |     192609 |     197.23 |          0 |       7773 |      99665 |  555562617

Setup is 1 partition, replication-factor = 1 command:

./examples/rdkafka_performance -P -b 172.31.46.165:9092 -t test -s 1024 -a -1 -u -X max.in.flight=1
rkruze commented 3 years ago

The command used is: ./rdkafka_performance -P -b <broker> -t <topic> -s 1024 -a all -c 10000000 -r 1000000 -u

what machine type was this running on?

mmaslankaprv commented 3 years ago

I am running on i3.large

rkruze commented 2 years ago

I reran this just now on v21.7.6 and got the following: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     243394 |  249235456 |          0 |     144083 |     144083 |     147.54 |          0 |        117 |      99311 |     144082
|       2001 |     398803 |  408374272 |         69 |     298803 |     149321 |     152.91 |          0 |        258 |     100000 |     298802
|       3001 |     553523 |  566807552 |         70 |     453523 |     151091 |     154.72 |          0 |        402 |     100000 |     453522
|       4002 |     701474 |  718309376 |         71 |     601474 |     150285 |     153.89 |          0 |        545 |     100000 |     601473
|       5002 |     856194 |  876742656 |         67 |     756194 |     151153 |     154.78 |          0 |        685 |     100000 |     756193
|       6003 |    1013815 | 1038146560 |         66 |     913815 |     152216 |     155.87 |          0 |        831 |     100000 |     913814
|       7004 |    1172403 | 1200540672 |         69 |    1072403 |     153108 |     156.78 |          0 |        975 |     100000 |    1072402
|       8004 |    1334859 | 1366895616 |         71 |    1234859 |     154265 |     157.97 |          0 |       1117 |     100000 |    1234858
|       9005 |    1495381 | 1531270144 |         71 |    1396348 |     155063 |     158.78 |          0 |       1263 |      99033 |    1396347
|      10005 |    1653002 | 1692674048 |         70 |    1553002 |     155207 |     158.93 |          0 |       1405 |     100000 |    1553001
|      11006 |    1805788 | 1849126912 |         72 |    1705788 |     154978 |     158.70 |          0 |       1549 |     100000 |    1705787
|      12006 |    1963409 | 2010530816 |         72 |    1864376 |     155279 |     159.01 |          0 |       1689 |      99034 |    1864375
|      13007 |    2121997 | 2172924928 |         73 |    2021997 |     155448 |     159.18 |          0 |       1834 |     100000 |    2021996

This was with replication of 3 and 1 partition.

If I added -X max.in.flight=1, then I get the following: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     194766 |  199440384 |          4 |      94766 |      94724 |      97.00 |          0 |        102 |     100000 |    4213218
|       2000 |     287741 |  294646784 |          4 |     188565 |      94261 |      96.52 |          0 |        223 |      99176 |    4307017
|       3001 |     384298 |  393521152 |          9 |     284298 |      94715 |      96.99 |          0 |        340 |     100000 |    4402750
|       4002 |     479064 |  490561536 |          9 |     379064 |      94714 |      96.99 |          0 |        448 |     100000 |    4497516
|       5002 |     576731 |  590572544 |          9 |     476731 |      95294 |      97.58 |          0 |        561 |     100000 |    4595183
|       6003 |     676332 |  692563968 |          9 |     576332 |      96002 |      98.31 |          0 |        667 |     100000 |    4694784
|       7003 |     777867 |  796535808 |          9 |     677867 |      96785 |      99.11 |          0 |        776 |     100000 |    4796319
|       8004 |     879402 |  900507648 |          9 |     779402 |      97371 |      99.71 |          0 |        893 |     100000 |    4897854

This still brings up why we are getting latencies of 70ms when Kafka sees latencies of 10ms when we don't have -X max.in.flight=1.

rkruze commented 2 years ago

Ok, so running v28.8.2-beta1 release I set the following: 

  kafka_qdc_enable: true
  kafka_qdc_max_depth: 8
  kafka_qdc_idle_depth: 8
  kafka_qdc_max_latency_ms: 20
  rpc_server_tcp_recv_buf=102400

I get the following on Redpanda: 

./rdkafka_performance -P -b 10.0.0.224:9092 -t sfo -s 1024 -a -1 -c 10000000 -u
% Sending 10000000 messages of size 1024 bytes
%4|1630705794.078|CONFWARN|rdkafka#producer-1| [thrd:app]: Configuration property session.timeout.ms is a consumer property and will be ignored by this producer instance
%4|1630705794.078|CONFWARN|rdkafka#producer-1| [thrd:app]: Configuration property queued.min.messages is a consumer property and will be ignored by this producer instance
%4|1630705794.078|CONFWARN|rdkafka#producer-1| [thrd:app]: Configuration property offset_commit_cb is a consumer property and will be ignored by this producer instance
%4|1630705794.078|CONFWARN|rdkafka#producer-1| [thrd:app]: Configuration property auto.offset.reset is a consumer property and will be ignored by this producer instance
|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     267291 |  273705984 |         30 |     167291 |     167218 |     171.23 |          0 |        151 |     100000 |     167290
|       2001 |     445220 |  455905280 |         34 |     345220 |     172513 |     176.65 |          0 |        303 |     100000 |     345218
|       3002 |     642488 |  657907712 |         82 |     542488 |     180702 |     185.04 |          0 |        470 |     100000 |      97667
|       4002 |     829518 |  849426432 |         43 |     729518 |     182252 |     186.63 |          0 |        616 |     100000 |     284298
|       5003 |    1027753 | 1052419072 |         43 |     927753 |     185429 |     189.88 |          0 |        782 |     100000 |      97666
|       6004 |    1219617 | 1248887808 |         58 |    1119617 |     186458 |     190.93 |          0 |        920 |     100000 |     289131
|       7004 |    1398601 | 1432167424 |         58 |    1299478 |     185516 |     189.97 |          0 |       1070 |      99123 |     468992
|       8006 |    1570637 | 1608332288 |         65 |    1470637 |     183688 |     188.10 |          0 |       1224 |     100000 |     640151
|       9007 |    1777575 | 1820236800 |         91 |    1677575 |     186249 |     190.72 |          0 |       1417 |     100000 |     102501
|      10008 |    1926298 | 1972529152 |         46 |    1826298 |     182483 |     186.86 |          0 |       1563 |     100000 |     250451
|      11009 |    2149675 | 2201267200 |         77 |    2049675 |     186178 |     190.65 |          0 |       1749 |     100000 |     115072
|      12010 |    2314463 | 2370010112 |         36 |    2214463 |     184384 |     188.81 |          0 |       1912 |     100000 |     279461
|      13010 |    2487556 | 2547257344 |         59 |    2387556 |     183507 |     187.91 |          0 |       2072 |     100000 |     350052
|      14010 |    2645697 | 2709193728 |         59 |    2546543 |     181757 |     186.12 |          0 |       2225 |      99154 |     670529

For reference, with Kafka you get the following: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     158987 |  162802688 |         14 |      58987 |      58958 |      60.37 |          0 |        123 |     100000 |      58986
|       2001 |     224743 |  230136832 |         12 |     124743 |      62335 |      63.83 |          0 |        264 |     100000 |     124742
|       3002 |     308872 |  316284928 |         20 |     208872 |      69572 |      71.24 |          0 |        405 |     100000 |      34811
|       4003 |     421443 |  431557632 |         13 |     321443 |      80295 |      82.22 |          0 |        567 |     100000 |      95732
|       5004 |     539417 |  552363008 |         14 |     439417 |      87808 |      89.92 |          0 |        722 |     100000 |      58986
|       6004 |     650830 |  666449920 |         14 |     551021 |      91771 |      93.97 |          0 |        874 |      99809 |     128610
|       7006 |     783500 |  802304000 |         12 |     683500 |      97554 |      99.90 |          0 |       1033 |     100000 |     199201
|       8007 |     880599 |  901733376 |         12 |     780599 |      97487 |      99.83 |          0 |       1188 |     100000 |     325310
|       9008 |     972464 |  995803136 |         18 |     872464 |      96849 |      99.17 |          0 |       1330 |     100000 |      37712
|      10009 |    1082134 | 1108105216 |         14 |     982134 |      98120 |     100.48 |          0 |       1486 |     100000 |      99600
|      11010 |    1215580 | 1244753920 |         12 |    1115580 |     101319 |     103.75 |          0 |       1636 |     100000 |     290498
|      12011 |    1327265 | 1359119360 |         11 |    1227265 |     102174 |     104.63 |          0 |       1762 |     100000 |     368825
|      13012 |    1407526 | 1441306624 |         11 |    1308493 |     100558 |     102.97 |          0 |       1877 |      99034 |     450053
|      14012 |    1495523 | 1531415552 |          9 |    1395523 |      99588 |     101.98 |          0 |       1988 |     100000 |     537083
|      15012 |    1589323 | 1627466752 |          9 |    1491256 |      99331 |     101.72 |          0 |       2107 |      98067 |     623146
|      16012 |    1680432 | 1720762368 |         52 |    1580619 |      98709 |     101.08 |          0 |       2246 |      99813 |      83161
|      17015 |    1754111 | 1796209664 |         11 |    1654111 |      97211 |      99.54 |          0 |       2403 |     100000 |     138280
|      18016 |    1840573 | 1884746752 |          9 |    1740573 |      96611 |      98.93 |          0 |       2527 |     100000 |      58019
|      19017 |    1981755 | 2029317120 |         11 |    1881755 |      98950 |     101.32 |          0 |       2676 |     100000 |      69623

Am I doing something wrong? @jcsp thoughts?

jcsp commented 2 years ago

I was a bit surprised by those redpanda numbers so I did another round of tests here.

Here's what I get on redpanda 21.8.2_beta1 with 3 nodes, one topic with r=3 p=12, on a i3.xlarge running three redpanda instance on one core each, all config default apart from TCP queue depth set to 102400 in both send and recv directions.

I used a i3.xlarge instance, which I regret in hindsight because that instance type shares a drive instead of having an nvme device to itself. They're also relatively low performance drives, which tends to make redpanda look worse compared with running on current gen hardware.

The rdkafka_performance client runs from a separate node: running on the same node tends to produce worse numbers (combination of resource contention and gratuitously large MTU/window on loopback networking).

rdkafka_performance -P -b $BROKERS -t testtopic -s 1024 -a -1 -c 1000000 -u
|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset 
|       1000 |     146743 |  150264832 |          0 |      47383 |      47382 |      48.52 |          0 |         67 |      99360 |    1235940 
|       2002 |     196701 |  201421824 |         13 |      96701 |      48285 |      49.44 |          0 |        172 |     100000 |    1285257 
|       3003 |     268259 |  274697216 |         13 |     169226 |      56351 |      57.70 |          0 |        281 |      99033 |    1176725 
|       4006 |     342718 |  350943232 |         34 |     242718 |      60574 |      62.03 |          0 |        389 |     100000 |    1359716 
|       5008 |     409840 |  419676160 |         30 |     309840 |      61867 |      63.35 |          0 |        500 |     100000 |     692450 
|       6009 |     462058 |  473147392 |         20 |     362058 |      60251 |      61.70 |          0 |        610 |     100000 |     736932 
|       7009 |     513309 |  525628416 |         21 |     413309 |      58960 |      60.38 |          0 |        717 |     100000 |     644357 
|       8010 |     564560 |  578109440 |         21 |     464560 |      57992 |      59.38 |          0 |        826 |     100000 |     768843 
|       9012 |     639019 |  654355456 |         21 |     539986 |      59916 |      61.35 |          0 |        936 |      99033 |    1422003 
|      10014 |     715811 |  732990464 |         36 |     615811 |      61492 |      62.97 |          0 |       1050 |     100000 |    1459716 
|      11015 |     792204 |  811216896 |         37 |     692204 |      62838 |      64.35 |          0 |       1159 |     100000 |    1498396 
|      12016 |     868597 |  889443328 |         36 |     768597 |      63960 |      65.50 |          0 |       1274 |     100000 |    1138034 
|      13017 |     918930 |  940984320 |         28 |     818930 |      62908 |      64.42 |          0 |       1379 |     100000 |    1147324 
|      14018 |     969214 |  992475136 |         27 |     869214 |      62004 |      63.49 |          0 |       1487 |     100000 |    1190839 
|      15019 |    1045607 | 1070701568 |         27 |     946574 |      63021 |      64.53 |          0 |       1595 |      99033 |    1495420

The kafka (2.13-2.8.0) numbers I see on the same server node (3 kafka brokers) with the same benchmark are much closer to yours:

rdkafka_performance -P -b $BROKERS -t testtopic -s 1024 -a -1 -c 1000000 -u
|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset 
|       1000 |     138680 |  142008320 |          0 |      39647 |      39641 |      40.59 |          0 |         77 |      99033 |    1447779 
|       2001 |     192837 |  197465088 |         10 |      93804 |      46874 |      48.00 |          0 |        196 |      99033 |    1501931 
|       3001 |     252791 |  258857984 |         82 |     152791 |      50903 |      52.13 |          0 |        314 |     100000 |    2549841 
|       4007 |     312745 |  320250880 |         12 |     212745 |      53087 |      54.36 |          0 |        415 |     100000 |    2598191 
|       5008 |     401709 |  411350016 |         17 |     301709 |      60236 |      61.68 |          0 |        523 |     100000 |     835851 
|       6009 |     495907 |  507808768 |         17 |     396874 |      66035 |      67.62 |          0 |        635 |      99033 |     880333 
|       7009 |     594969 |  609248256 |         16 |     495508 |      70685 |      72.38 |          0 |        743 |      99461 |    2116323 
|       8014 |     721066 |  738371584 |         15 |     622033 |      77613 |      79.48 |          0 |        863 |      99033 |    2190782 
|       9018 |     845809 |  866108416 |         10 |     746776 |      82808 |      84.80 |          0 |        978 |      99033 |    2256538 
|      10018 |     942732 |  965357568 |         11 |     842908 |      84138 |      86.16 |          0 |       1076 |      99824 |    2089408 
|      11021 |    1025103 | 1049705472 |          8 |     925103 |      83935 |      85.95 |          0 |       1170 |     100000 |    1023297 
|      12021 |    1108215 | 1134812160 |          8 |    1008265 |      83871 |      85.88 |          0 |       1266 |      99950 |    1066812 
|      13023 |    1207881 | 1236870144 |          8 |    1108848 |      85141 |      87.18 |          0 |       1379 |      99033 |    1102590 
|      14023 |    1324628 | 1356419072 |         14 |    1225272 |      87372 |      89.47 |          0 |       1475 |      99356 |    1912875 
|      15029 |    1410368 | 1444216832 |          7 |    1310368 |      87188 |      89.28 |          0 |       1569 |     100000 |    1973796 
|      16029 |    1501053 | 1537078272 |          7 |    1401665 |      87445 |      89.54 |          0 |       1666 |      99388 |    2796115 
|      17029 |    1587728 | 1625833472 |          7 |    1488695 |      87418 |      89.52 |          0 |       1762 |      99033 |    2861871 
|      18029 |    1680103 | 1720425472 |          7 |    1580959 |      87687 |      89.79 |          0 |       1859 |      99144 |    2152468 
|      19030 |    1798933 | 1842107392 |          7 |    1699900 |      89327 |      91.47 |          0 |       1978 |      99033 |    2213389 
|      20033 |    1902801 | 1948468224 |         12 |    1803768 |      90037 |      92.20 |          0 |       2083 |      99033 |    1269298

We still have room for improvement to deliver lower saturated latency than Kafka even when providing stronger data safety guarantees (Kafka latency goes way worse than ours if you set it to fsync every message), but I think we're moving along the spectrum from "bug" to "enhancement".

jcsp commented 2 years ago

For reference, wwitching to an i3en.3xlarge instance for the server makes a big difference (much faster drive, as well as more cores). This is still 12 partitions. 3 cores and 3GB RAM per redpanda process.

    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset 
|       1000 |     199601 |  204391424 |          4 |     100568 |     100545 |     102.96 |          0 |         53 |      99034 |     100567 
|       2000 |     304041 |  311337984 |          5 |     205008 |     102454 |     104.91 |          0 |        161 |      99033 |     205003 
|       3000 |     408750 |  418560000 |          5 |     309444 |     103114 |     105.59 |          0 |        269 |      99306 |     309439 
|       4002 |     512913 |  525222912 |         12 |     412913 |     103151 |     105.63 |          0 |        377 |     100000 |     412908 
|       5004 |     617349 |  632165376 |         13 |     517349 |     103384 |     105.87 |          0 |        485 |     100000 |      68656 
|       6005 |     721785 |  739107840 |         13 |     621785 |     103540 |     106.03 |          0 |        593 |     100000 |     491235 
|       7005 |     892027 |  913435648 |         13 |     794310 |     113387 |     116.11 |          0 |        660 |      97717 |      86062 
|       8009 |    1015019 | 1039379456 |         16 |     915019 |     114242 |     116.98 |          0 |        763 |     100000 |     191465 
|       9009 |    1121681 | 1148601344 |         16 |    1022356 |     113476 |     116.20 |          0 |        873 |      99325 |     298802 
|      10012 |    1228726 | 1258215424 |         12 |    1128726 |     112732 |     115.44 |          0 |        984 |     100000 |     405172 
|      11012 |    1335374 | 1367422976 |         12 |    1236063 |     112242 |     114.94 |          0 |       1094 |      99311 |     471895 
|      12015 |    1441865 | 1476469760 |         13 |    1341865 |     111677 |     114.36 |          0 |       1205 |     100000 |     113138
rkruze commented 2 years ago

I believe @jcsp setup is on a single machine with redpanda pinned to a single core. I've been running on 3 machines. The current setup is with 3 i3en.large instances running with the following settings: 

  kafka_qdc_enable: true
  kafka_qdc_max_depth: 8
  kafka_qdc_idle_depth: 8
  kafka_qdc_max_latency_ms: 20
  rpc_server_tcp_recv_buf=102400

When I run against a topic with 12 partitions I see the following: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     295334 |  302422016 |         15 |     195334 |     195237 |     199.92 |          0 |        169 |     100000 |     195333
|       2000 |     490215 |  501980160 |         15 |     391636 |     195769 |     200.47 |          0 |        342 |      98579 |     391634
|       3001 |     686970 |  703457280 |         15 |     586970 |     195531 |     200.22 |          0 |        523 |     100000 |      96699
|       4002 |     886004 |  907268096 |         15 |     786004 |     196377 |     201.09 |          0 |        690 |     100000 |     294934
|       5003 |    1051361 | 1076593664 |         36 |     951361 |     190138 |     194.70 |          0 |        838 |     100000 |      70590
|       6004 |    1199711 | 1228504064 |         40 |    1099711 |     183156 |     187.55 |          0 |        972 |     100000 |     213706
|       7005 |    1355398 | 1387927552 |         18 |    1255398 |     179212 |     183.51 |          0 |       1127 |     100000 |     113138
|       8005 |    1514953 | 1551311872 |         19 |    1414953 |     176741 |     180.98 |          0 |       1286 |     100000 |     239815
|       9006 |    1680310 | 1720637440 |         36 |    1580310 |     175457 |     179.67 |          0 |       1435 |     100000 |     308472
|      10007 |    1832528 | 1876508672 |         30 |    1732528 |     173118 |     177.27 |          0 |       1586 |     100000 |     611542
|      11008 |    1985314 | 2032961536 |         18 |    1885314 |     171261 |     175.37 |          0 |       1745 |     100000 |     605173
|      12009 |    2141001 | 2192385024 |         18 |    2041001 |     169955 |     174.03 |          0 |       1903 |     100000 |     729916
|      13009 |    2300725 | 2355942400 |         18 |    2200955 |     169186 |     173.25 |          0 |       2064 |      99770 |      58986
|      14009 |    2454794 | 2513709056 |         18 |    2355675 |     168153 |     172.19 |          0 |       2215 |      99119 |     210805
|      15010 |    2612329 | 2675024896 |         18 |    2512329 |     167366 |     171.38 |          0 |       2373 |     100000 |     114105
|      16011 |    2769950 | 2836428800 |         17 |    2669950 |     166750 |     170.75 |          0 |       2527 |     100000 |     243683
|      17012 |    2926604 | 2996842496 |         34 |    2826604 |     166147 |     170.13 |          0 |       2669 |     100000 |     297835
|      18013 |    3083657 | 3157664768 |         27 |    2983657 |     165633 |     169.61 |          0 |       2815 |     100000 |     210805
|      19013 |    3246814 | 3324737536 |         27 |    3147080 |     165516 |     169.49 |          0 |       2953 |      99734 |     393000
|      20015 |    3399298 | 3480881152 |         28 |    3299298 |     164836 |     168.79 |          0 |       3102 |     100000 |     525479
|      21016 |    3558853 | 3644265472 |         18 |    3458853 |     164580 |     168.53 |          0 |       3261 |     100000 |     802440
|      22016 |    3714939 | 3804097536 |         19 |    3614939 |     164189 |     168.13 |          0 |       3420 |     100000 |     925249

If I increase the number of partitions to 16 the latency ~ doubles.

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     283730 |  290539520 |         15 |     183730 |     183640 |     188.05 |          0 |        157 |     100000 |     183729
|       2001 |     470361 |  481649664 |         15 |     370361 |     185076 |     189.52 |          0 |        324 |     100000 |     370360
|       3001 |     697606 |  714348544 |         15 |     598573 |     199403 |     204.19 |          0 |        512 |      99033 |     128610
|       4002 |     873999 |  894974976 |         21 |     773999 |     193397 |     198.04 |          0 |        678 |     100000 |     303637
|       5003 |    1027752 | 1052418048 |         60 |     927752 |     185421 |     189.87 |          0 |        814 |     100000 |      54151
|       6004 |    1185772 | 1214230528 |         57 |    1085772 |     180837 |     185.18 |          0 |        949 |     100000 |     211772
|       7004 |    1344495 | 1376762880 |         57 |    1248228 |     178212 |     182.49 |          0 |       1076 |      96267 |     285264
|       8005 |    1500446 | 1536456704 |         53 |    1400446 |     174936 |     179.13 |          0 |       1209 |     100000 |     213706
|       9006 |    1661935 | 1701821440 |         76 |    1561935 |     173423 |     177.59 |          0 |       1351 |     100000 |     295901
|      10007 |    1819955 | 1863633920 |         63 |    1719955 |     171867 |     175.99 |          0 |       1484 |     100000 |     219508
|      11008 |    1970807 | 2018106368 |         72 |    1870807 |     169942 |     174.02 |          0 |       1626 |     100000 |     304604
|      12009 |    2130761 | 2181899264 |         64 |    2030761 |     169096 |     173.15 |          0 |       1759 |     100000 |     524512
|      13010 |    2286448 | 2341322752 |         81 |    2186448 |     168052 |     172.09 |          0 |       1908 |     100000 |     597037
|      14011 |    2448336 | 2507096064 |         63 |    2348336 |     167600 |     171.62 |          0 |       2044 |     100000 |     216607
|      15012 |    2604990 | 2667509760 |         41 |    2504990 |     166864 |     170.87 |          0 |       2167 |     100000 |     373261
|      16012 |    2761644 | 2827923456 |         41 |    2661644 |     166220 |     170.21 |          0 |       2294 |     100000 |     529915
|      17013 |    2917331 | 2987346944 |         41 |    2818298 |     165652 |     169.63 |          0 |       2427 |      99035 |     381396
|      18014 |    3075351 | 3149159424 |         42 |    2975351 |     165168 |     169.13 |          0 |       2554 |     100000 |     531281
|      19015 |    3229104 | 3306602496 |         75 |    3129104 |     164559 |     168.51 |          0 |       2688 |     100000 |      65755
|      20016 |    3383256 | 3464454144 |         66 |    3283256 |     164030 |     167.97 |          0 |       2825 |     100000 |     204036
|      21017 |    3543778 | 3628828672 |         80 |    3443778 |     163855 |     167.79 |          0 |       2953 |     100000 |      78326
|      22018 |    3696963 | 3785690112 |         60 |    3596963 |     163363 |     167.28 |          0 |       3096 |     100000 |     211772
|      23019 |    3857485 | 3950064640 |         97 |    3757485 |     163232 |     167.15 |          0 |       3220 |     100000 |     389132

For both runs I'm executing the following command from a c5n.2xlarge instance: 

./rdkafka_performance -P -b 10.0.0.190:9092 -t sfo16 -s 1024 -a -1 -c 10000000 -u
jcsp commented 2 years ago

I've taken a look at your cluster and nothing jumps out at me as being misconfigured.

When I ran three i3en.3xlarge instances, my latencies were about the same as when I was running on one instance, a tiny bit better.

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset 
|       1000 |     200568 |  205381632 |          0 |     101535 |     101511 |     103.95 |          0 |         57 |      99033 |     413188 
|       2002 |     305004 |  312324096 |         10 |     205004 |     102356 |     104.81 |          0 |        165 |     100000 |     516657 
|       3004 |     507107 |  519277568 |         11 |     407107 |     135516 |     138.77 |          0 |        264 |     100000 |     102501 
|       4005 |     613876 |  628609024 |          8 |     513876 |     128301 |     131.38 |          0 |        376 |     100000 |     208871 
|       5006 |     813078 |  832591872 |         11 |     713078 |     142421 |     145.84 |          0 |        462 |     100000 |      98633 
|       6007 |     918880 |  940933120 |          8 |     818880 |     136298 |     139.57 |          0 |        572 |     100000 |     204036 
|       7009 |    1120983 | 1147886592 |          8 |    1021950 |     145803 |     149.30 |          0 |        654 |      99033 |     413307 
|       8009 |    1229668 | 1259180032 |         11 |    1129686 |     141050 |     144.44 |          0 |        766 |      99982 |     520644 
|       9011 |    1336056 | 1368121344 |          8 |    1237023 |     137276 |     140.57 |          0 |        878 |      99033 |     627981 
|      10012 |    1442426 | 1477044224 |         10 |    1343393 |     134173 |     137.39 |          0 |        988 |      99033 |     734351

The two big differences between my cluster and Roko's are:

rkruze commented 2 years ago

Again for reference here is Kafka on 3 i3en.large instances version 2.8.0 with flush.messages=1

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     245341 |  251229184 |          0 |     146017 |     146017 |     149.52 |          0 |        155 |      99324 |     146016
|       2000 |     417176 |  427188224 |          5 |     318143 |     159028 |     162.84 |          0 |        335 |      99033 |     318142
|       3001 |     595104 |  609386496 |          4 |     495104 |     164947 |     168.91 |          0 |        521 |     100000 |     495103
|       4002 |     770131 |  788614144 |          4 |     671098 |     167680 |     171.70 |          0 |        703 |      99034 |     671097
|       5002 |     948059 |  970812416 |          4 |     848059 |     169519 |     173.59 |          0 |        888 |     100000 |     848058
|       6002 |    1125020 | 1152020480 |          4 |    1025987 |     170917 |     175.02 |          0 |       1073 |      99033 |    1025986
|       7003 |    1304882 | 1336199168 |          4 |    1204882 |     172030 |     176.16 |          0 |       1262 |     100000 |    1204881
|       8004 |    1485711 | 1521368064 |          4 |    1385711 |     173117 |     177.27 |          0 |       1450 |     100000 |    1385710
|       9005 |    1641398 | 1680791552 |          4 |    1541398 |     171170 |     175.28 |          0 |       1615 |     100000 |    1541397
|      10005 |    1796119 | 1839225856 |          4 |    1697085 |     169623 |     173.69 |          0 |       1776 |      99034 |    1697084
|      11006 |    1951805 | 1998648320 |          4 |    1851805 |     168251 |     172.29 |          0 |       1942 |     100000 |    1851804
|      12006 |    2107492 | 2158071808 |          4 |    2007492 |     167196 |     171.21 |          0 |       2104 |     100000 |    2007491
|      13007 |    2262212 | 2316505088 |          4 |    2162212 |     166230 |     170.22 |          0 |       2265 |     100000 |    2162211
|      14007 |    2417899 | 2475928576 |          4 |    2317899 |     165470 |     169.44 |          0 |       2427 |     100000 |    2317898
|      15008 |    2572619 | 2634361856 |          4 |    2473586 |     164817 |     168.77 |          0 |       2588 |      99033 |    2473585
|      16009 |    2728306 | 2793785344 |          4 |    2628306 |     164176 |     168.12 |          0 |       2750 |     100000 |    2628305
|      17009 |    2883993 | 2953208832 |          4 |    2783993 |     163671 |     167.60 |          0 |       2912 |     100000 |    2783992
|      18010 |    3038713 | 3111642112 |          4 |    2939680 |     163223 |     167.14 |          0 |       3073 |      99033 |    2939679

A few things to note. This is running with Redhat 8.3 and kernel 4.18.0-240.1.1.el8_3.x86_64 and running with Java 11 openjdk version "11.0.12" 2021-07-20 LTS

rkruze commented 2 years ago

Just to see the difference with log flushing on vs off here is Kafka 2.8.0 with no flushing: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     319509 |  327177216 |          2 |     219509 |     219431 |     224.70 |          0 |        220 |     100000 |     219508
|       2000 |     545787 |  558885888 |          2 |     445787 |     222792 |     228.14 |          0 |        455 |     100000 |     445786
|       3001 |     778834 |  797526016 |          2 |     678834 |     226168 |     231.60 |          0 |        697 |     100000 |     678833
|       4001 |    1010914 | 1035175936 |          2 |     910914 |     227615 |     233.08 |          0 |        938 |     100000 |     910913
|       5002 |    1224621 | 1254011904 |          2 |    1125588 |     225015 |     230.42 |          0 |       1164 |      99033 |    1125587
|       6003 |    1445097 | 1479779328 |          3 |    1345097 |     224065 |     229.44 |          0 |       1393 |     100000 |    1345096
|       7003 |    1664606 | 1704556544 |          3 |    1564606 |     223397 |     228.76 |          0 |       1621 |     100000 |    1564605
rkruze commented 2 years ago

With -X queue.buffering.max.kbytes=16384 -X linger.ms=10 I saw the following: 

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     254124 |  260222976 |         20 |     237740 |     237541 |     243.24 |          0 |        216 |      16384 |    1062907
|       2001 |     497747 |  509692928 |         21 |     481363 |     240458 |     246.23 |          0 |        427 |      16384 |     659024
|       3002 |     679094 |  695392256 |         32 |     662710 |     220691 |     225.99 |          0 |        602 |      16384 |      22367
|       4004 |     836685 |  856765440 |         33 |     820301 |     204866 |     209.78 |          0 |        762 |      16384 |      30103
|       5005 |     989716 | 1013469184 |         35 |     973332 |     194469 |     199.14 |          0 |        910 |      16384 |      70053
|       6006 |    1147073 | 1174602752 |         35 |    1130689 |     188250 |     192.77 |          0 |       1065 |      16384 |     388223
|       7007 |    1306802 | 1338165248 |         35 |    1290418 |     184154 |     188.57 |          0 |       1226 |      16384 |      57067
|       8008 |    1461884 | 1496969216 |         33 |    1445500 |     180501 |     184.83 |          0 |       1388 |      16384 |     738307
|       9009 |    1624247 | 1663228928 |         33 |    1607863 |     178468 |     182.75 |          0 |       1543 |      16384 |      96518
|      10010 |    1770123 | 1812605952 |         31 |    1753739 |     175195 |     179.40 |          0 |       1695 |      16384 |     711639
|      11011 |    1934393 | 1980818432 |         36 |    1918009 |     174187 |     178.37 |          0 |       1846 |      16384 |    1151864
|      12012 |    2085458 | 2135508992 |         34 |    2069074 |     172246 |     176.38 |          0 |       1993 |      16384 |     432287
|      13013 |    2250399 | 2304408576 |         31 |    2234015 |     171672 |     175.79 |          0 |       2142 |      16384 |     473872
rkruze commented 2 years ago

Reran with Fedora 34 and saw the following:

with -X queue.buffering.max.kbytes=16384 -X linger.ms=10

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     339859 |  348015616 |         39 |     323475 |     323161 |     330.92 |          0 |        243 |      16384 |     143777
|       2002 |     566175 |  579763200 |         63 |     549791 |     274604 |     281.19 |          0 |        426 |      16384 |     347653
|       3003 |     722977 |  740328448 |         63 |     707560 |     235591 |     241.25 |          0 |        565 |      15418 |      68844
|       4004 |     877257 |  898311168 |         94 |     860873 |     214977 |     220.14 |          0 |        696 |      16384 |    1011546
|       5005 |    1033924 | 1058738176 |         97 |    1017540 |     203281 |     208.16 |          0 |        827 |      16384 |      89896
|       6006 |    1191050 | 1219635200 |         90 |    1174666 |     195553 |     200.25 |          0 |        956 |      16384 |     209641
|       7008 |    1349985 | 1382384640 |         97 |    1333601 |     190296 |     194.86 |          0 |       1089 |      16384 |     114591
|       8009 |    1500343 | 1536351232 |         98 |    1483959 |     185283 |     189.73 |          0 |       1222 |      16384 |    1050936
|       9010 |    1657459 | 1697238016 |         93 |    1641075 |     182134 |     186.51 |          0 |       1352 |      16384 |     234728
|      10011 |    1818728 | 1862377472 |         99 |    1802344 |     180029 |     184.35 |          0 |       1484 |      16384 |     171169
|      11011 |    1974045 | 2021422080 |         99 |    1963042 |     178274 |     182.55 |          0 |       1620 |      11003 |     499167
|      12011 |    2134960 | 2186199040 |         92 |    2118576 |     176372 |     180.60 |          0 |       1751 |      16384 |     208388

without:

|    elapsed |       msgs |      bytes |        rtt |         dr |     dr_m/s |    dr_MB/s |     dr_err |     tx_err |       outq |     offset
|       1000 |     354321 |  362824704 |         43 |     254321 |     254208 |     260.31 |          0 |        166 |     100000 |     254320
|       2001 |     618313 |  633152512 |         44 |     518313 |     259018 |     265.24 |          0 |        335 |     100000 |     518311
|       3002 |     771099 |  789605376 |        173 |     671099 |     223541 |     228.91 |          0 |        464 |     100000 |     596638
|       4003 |     927185 |  949437440 |        185 |     827185 |     206631 |     211.59 |          0 |        578 |     100000 |     208871
|       5003 |    1083839 | 1109851136 |        135 |     983839 |     196616 |     201.34 |          0 |        696 |     100000 |     365525
|       6004 |    1246295 | 1276206080 |        136 |    1146295 |     190906 |     195.49 |          0 |        816 |     100000 |     527981
|       7005 |    1403916 | 1437609984 |        213 |    1303916 |     186125 |     190.59 |          0 |        939 |     100000 |     686968
|       8005 |    1556133 | 1593480192 |        213 |    1456133 |     181888 |     186.25 |          0 |       1060 |     100000 |     828149
|       9006 |    1715687 | 1756863488 |        162 |    1616654 |     179494 |     183.80 |          0 |       1182 |      99033 |      69622
|      10007 |    1871993 | 1916920832 |        200 |    1771993 |     177068 |     181.32 |          0 |       1305 |     100000 |     203067
|      11009 |    2015109 | 2063471616 |        199 |    1915109 |     173949 |     178.12 |          0 |       1433 |     100000 |     273658
|      12010 |    2192469 | 2245088256 |        209 |    2092469 |     174220 |     178.40 |          0 |       1553 |     100000 |     844589
|      13011 |    2334618 | 2390648832 |        212 |    2234618 |     171741 |     175.86 |          0 |       1677 |     100000 |      64788
|      14012 |    2500373 | 2560381952 |        191 |    2400373 |     171304 |     175.42 |          0 |       1800 |     100000 |     207903