[pulsar-broker] capture managed-ledger add-latency #4419

rdhabalia · 2019-05-31T00:12:15Z

Motivation

With #4290 , now broker has capability to capture e2e publish latency since publish-request arrives till it completes. now, we can capture bk-client latency to find out exact break down for broker to bookie latency. Right now broker does capture ml-add latency but ml-add-latency starts timer as soon as add-ops inserted into queue which also adds waiting time at the queue and doesn't give correct broker to bookie latency.

Modification

To capture broker to bookie latency: start ml-add-ops latency timer when bk-add entry request initiates.

Result

with this change: broker is able to provide bookie-persistent latency.

It will add additional metrics: brk_ml_LedgerAddEntryLatencyBuckets

 "brk_ml_AddEntryErrors": 0.0,
        "brk_ml_AddEntryLatencyBuckets_0.0_0.5": 0.0,
        "brk_ml_AddEntryLatencyBuckets_0.5_1.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_1.0_5.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_10.0_20.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_100.0_200.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_20.0_50.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_200.0_1000.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_5.0_10.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_50.0_100.0": 0.0,
        "brk_ml_AddEntryLatencyBuckets_OVERFLOW": 0.0,
        "brk_ml_AddEntryMessagesRate": 0.0,
        "brk_ml_AddEntrySucceed": 0.0,
        "brk_ml_EntrySizeBuckets_0.0_128.0": 0.0,
        "brk_ml_EntrySizeBuckets_1024.0_2084.0": 0.0,
        "brk_ml_EntrySizeBuckets_102400.0_1232896.0": 0.0,
        "brk_ml_EntrySizeBuckets_128.0_512.0": 0.0,
        "brk_ml_EntrySizeBuckets_16384.0_102400.0": 0.0,
        "brk_ml_EntrySizeBuckets_2084.0_4096.0": 0.0,
        "brk_ml_EntrySizeBuckets_4096.0_16384.0": 0.0,
        "brk_ml_EntrySizeBuckets_512.0_1024.0": 0.0,
        "brk_ml_EntrySizeBuckets_OVERFLOW": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_0.0_0.5": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_0.5_1.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_1.0_5.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_10.0_20.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_100.0_200.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_20.0_50.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_200.0_1000.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_5.0_10.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_50.0_100.0": 0.0,
        "brk_ml_LedgerAddEntryLatencyBuckets_OVERFLOW": 0.0,

rdhabalia · 2019-05-31T01:14:17Z

rerun integration tests

merlimat · 2019-05-31T15:54:25Z

managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/OpAddEntry.java

@@ -201,7 +199,7 @@ public void closeComplete(int rc, LedgerHandle lh, Object ctx) {
    }

    private void updateLatency() {
-        ml.mbean.addAddEntryLatencySample(System.nanoTime() - startTime, TimeUnit.NANOSECONDS);
+        ml.mbean.addAddEntryLatencySample(System.nanoTime() - lastInitTime, TimeUnit.NANOSECONDS);


I think both latencies could be reported.
Right now, I think the addEntry is correct in that it's the time it takes to persist an entry, including the time of ledger append and the eventual queuing, if we don't have a ledger ready.
It would be good to add a new metric to account just for the Ledger.addEntry() operation, though we shouldn't remove the current one since, in the end, it's the total time that matters to users.

sure, added new metrics for ledger::addEntry

codelipenghui · 2019-06-13T02:44:20Z

@rdhabalia do we need this issue for 2.4.0? or can we move it to 2.5.0?

sijie · 2019-06-14T10:45:23Z

ping @rdhabalia

rdhabalia · 2019-06-14T17:55:19Z

moving to 2.5 for now and I will address the change.

rdhabalia · 2020-01-30T01:23:57Z

addressed all changes .. can we please review this PR.

rdhabalia · 2020-01-30T07:52:45Z

rerun java8 tests
rerun integration tests

codelipenghui · 2020-05-19T05:48:27Z

@rdhabalia Looks this PR is related to #6705, can you help to confirm this?

codelipenghui · 2020-06-04T03:46:26Z

@rdhabalia I moved this PR to 2.7.0. Looks #6705 have added these metrics. Feel free to move it back if need.

rdhabalia · 2020-10-29T05:54:29Z

@codelipenghui this is additionally metrics to capture ml add latency.

rdhabalia · 2020-10-29T05:54:34Z

/pulsarbot run-failure-checks

rdhabalia · 2020-10-29T06:30:03Z

/pulsarbot run-failure-checks

rdhabalia · 2020-10-29T18:44:37Z

/pulsarbot run-failure-checks

rdhabalia · 2020-10-29T18:46:23Z

/pulsarbot run-failure-checks

codelipenghui · 2020-11-04T02:37:18Z

/pulsarbot run-failure-checks

codelipenghui · 2020-11-04T02:42:45Z

@rdhabalia Looks the failed CI can't be triggered again, I'm not sure what the problem is. And I try to merge the apache/master to this branch, it still nothing happens in this branch. Interesting thing!

add additional metrics for ledger::addEntry

rdhabalia · 2020-11-04T06:41:42Z

@codelipenghui I have rebased the PR. I think this should fix it.

### Motivation With apache#4290 , now broker has capability to capture e2e publish latency since publish-request arrives till it completes. now, we can capture bk-client latency to find out exact break down for broker to bookie latency. Right now broker does capture ml-add latency but ml-add-latency starts timer as soon as add-ops inserted into queue which also adds waiting time at the queue and doesn't give correct broker to bookie latency. ### Modification To capture broker to bookie latency: start ml-add-ops latency timer when bk-add entry request initiates. ### Result with this change: broker is able to provide bookie-persistent latency. It will add additional metrics: `brk_ml_LedgerAddEntryLatencyBuckets` ``` "brk_ml_AddEntryErrors": 0.0, "brk_ml_AddEntryLatencyBuckets_0.0_0.5": 0.0, "brk_ml_AddEntryLatencyBuckets_0.5_1.0": 0.0, "brk_ml_AddEntryLatencyBuckets_1.0_5.0": 0.0, "brk_ml_AddEntryLatencyBuckets_10.0_20.0": 0.0, "brk_ml_AddEntryLatencyBuckets_100.0_200.0": 0.0, "brk_ml_AddEntryLatencyBuckets_20.0_50.0": 0.0, "brk_ml_AddEntryLatencyBuckets_200.0_1000.0": 0.0, "brk_ml_AddEntryLatencyBuckets_5.0_10.0": 0.0, "brk_ml_AddEntryLatencyBuckets_50.0_100.0": 0.0, "brk_ml_AddEntryLatencyBuckets_OVERFLOW": 0.0, "brk_ml_AddEntryMessagesRate": 0.0, "brk_ml_AddEntrySucceed": 0.0, "brk_ml_EntrySizeBuckets_0.0_128.0": 0.0, "brk_ml_EntrySizeBuckets_1024.0_2084.0": 0.0, "brk_ml_EntrySizeBuckets_102400.0_1232896.0": 0.0, "brk_ml_EntrySizeBuckets_128.0_512.0": 0.0, "brk_ml_EntrySizeBuckets_16384.0_102400.0": 0.0, "brk_ml_EntrySizeBuckets_2084.0_4096.0": 0.0, "brk_ml_EntrySizeBuckets_4096.0_16384.0": 0.0, "brk_ml_EntrySizeBuckets_512.0_1024.0": 0.0, "brk_ml_EntrySizeBuckets_OVERFLOW": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_0.0_0.5": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_0.5_1.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_1.0_5.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_10.0_20.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_100.0_200.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_20.0_50.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_200.0_1000.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_5.0_10.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_50.0_100.0": 0.0, "brk_ml_LedgerAddEntryLatencyBuckets_OVERFLOW": 0.0, ```

Anonymitaet · 2022-02-21T08:01:44Z

Hi @momo-jun can you follow up on the docs? Thanks

rdhabalia added the area/broker label May 31, 2019

rdhabalia added this to the 2.4.0 milestone May 31, 2019

rdhabalia requested review from merlimat, sijie, jiazhai and massakam May 31, 2019 00:12

rdhabalia self-assigned this May 31, 2019

merlimat reviewed May 31, 2019

View reviewed changes

rdhabalia modified the milestones: 2.4.0, 2.5.0 Jun 14, 2019

sijie modified the milestones: 2.5.0, 2.6.0 Nov 25, 2019

rdhabalia force-pushed the ml_stat branch 2 times, most recently from 64b314d to 5a8541a Compare January 30, 2020 01:19

rdhabalia force-pushed the ml_stat branch 2 times, most recently from 789743a to 0a2c9a0 Compare April 15, 2020 02:23

codelipenghui modified the milestones: 2.6.0, 2.7.0 Jun 4, 2020

codelipenghui approved these changes Nov 4, 2020

View reviewed changes

[pulsar-broker] capture managed-ledger add-latency

e7daae5

add additional metrics for ledger::addEntry

rdhabalia force-pushed the ml_stat branch from 0a2c9a0 to e7daae5 Compare November 4, 2020 06:29

codelipenghui added the doc-required Your PR changes impact docs and you will update later. label Nov 4, 2020

codelipenghui merged commit 04b6468 into apache:master Nov 4, 2020

momo-jun mentioned this pull request Feb 22, 2022

[Doc] Add a new metric for managed-ledger add latency #14414

Merged

1 task

Anonymitaet added doc-complete Your PR changes impact docs and the related docs have been already added. and removed doc-required Your PR changes impact docs and you will update later. labels Feb 23, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[pulsar-broker] capture managed-ledger add-latency #4419

[pulsar-broker] capture managed-ledger add-latency #4419

rdhabalia commented May 31, 2019 •

edited

rdhabalia commented May 31, 2019

merlimat May 31, 2019

rdhabalia Jan 30, 2020

codelipenghui commented Jun 13, 2019

sijie commented Jun 14, 2019

rdhabalia commented Jun 14, 2019

rdhabalia commented Jan 30, 2020 •

edited

rdhabalia commented Jan 30, 2020

codelipenghui commented May 19, 2020

codelipenghui commented Jun 4, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

codelipenghui commented Nov 4, 2020

codelipenghui commented Nov 4, 2020

rdhabalia commented Nov 4, 2020

Anonymitaet commented Feb 21, 2022

[pulsar-broker] capture managed-ledger add-latency #4419

[pulsar-broker] capture managed-ledger add-latency #4419

Conversation

rdhabalia commented May 31, 2019 • edited

Motivation

Modification

Result

rdhabalia commented May 31, 2019

merlimat May 31, 2019

Choose a reason for hiding this comment

rdhabalia Jan 30, 2020

Choose a reason for hiding this comment

codelipenghui commented Jun 13, 2019

sijie commented Jun 14, 2019

rdhabalia commented Jun 14, 2019

rdhabalia commented Jan 30, 2020 • edited

rdhabalia commented Jan 30, 2020

codelipenghui commented May 19, 2020

codelipenghui commented Jun 4, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

rdhabalia commented Oct 29, 2020

codelipenghui commented Nov 4, 2020

codelipenghui commented Nov 4, 2020

rdhabalia commented Nov 4, 2020

Anonymitaet commented Feb 21, 2022

rdhabalia commented May 31, 2019 •

edited

rdhabalia commented Jan 30, 2020 •

edited