PHOENIX-6052 Include syscat time in mutation time #1546

mnpoonia · 2022-12-20T10:42:56Z

No description provided.

mnpoonia · 2022-12-21T05:31:18Z

@virajjasani @tkhurana a draft PR for the fix.

tkhurana · 2022-12-21T07:35:45Z

@mnpoonia would it make sense to introduce a separate metric to track the syscat time ? By clubbing the two metrics in one we will not know where we are spending time.

mnpoonia · 2022-12-21T10:46:50Z

@tkhurana i think it is upto us. Ultimately we care about how much time one mutation took. Now if we want to divide it in syscat and then htable.batch it is perfectly fine but not sure if we want to introduce a new metric.
As per the discussion in JIRA https://issues.apache.org/jira/browse/PHOENIX-6052 It looked like we are not in favor of new metric so i went ahead with this approach.
@virajjasani and @shahrs87 what do you guys think?

mnpoonia · 2023-01-02T10:27:27Z

@tkhurana do you mind if we include syscat time in the mutation commit time in this jira and create a seperate jira to track syscat time seperately as well.

virajjasani · 2023-01-04T20:40:42Z

create a seperate jira to track syscat time seperately as well

I think this should be good. Thoughts @gjacoby126 @tkhurana?

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java

tkhurana · 2023-01-04T21:40:48Z

@mnpoonia You have changed the scope of this metric. Let us say you are batching 1000 upserts. Phoenix internally in the sendMutations function groups them into sub batches of by default 100 and then calls htable.batch() on that sub batch. Earlier the metric was capturing the time taken by each individual sub-batch. Now the metric is capturing the time across all sub-batches. I am not sure if this is intended.

mnpoonia · 2023-01-09T05:42:35Z

@tkhurana Thanks for pointing that out. I completely missed that part. Have reverted to old behaviour of mini batch mutation time. Also created a new metric for syscat time. Open for all suggestions to get it to closure.
Will need your and @virajjasani help in getting it to closure. Thanks in advance

gourabtaparia

Few comments. @mnpoonia

gourabtaparia · 2023-01-09T16:03:06Z

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java

@@ -1198,6 +1199,7 @@ private void sendBatch(Map<TableRef, MultiRowMutationState> commitBatch, long[]
        Map<TableInfo, List<Mutation>> physicalTableMutationMap = Maps.newLinkedHashMap();

        // add tracing for this operation
+        long startTime = EnvironmentEdgeManager.currentTimeMillis();


nitpick : the above L 1201 "add tracing" comment was for line L 1203 - maybe we can add your change just above that comment - to make the comment and code nearby as last time.

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java

gourabtaparia · 2023-01-09T16:07:47Z

phoenix-core/src/main/java/org/apache/phoenix/monitoring/MetricType.java

@@ -208,23 +209,23 @@ private MetricType(String shortName, String description, LogLevel logLevel, PDat
    public String description() {
        return description;
    }
-


nitpick : there are various changes fixing the extra spaces not part of the change - should we skip this as part of this change ?

Agree, good to keep only addition of MUTATION_SYSCAT_TIME for this file and remove all other formatting changes.

tkhurana · 2023-01-10T00:23:25Z

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java

@@ -1214,6 +1216,8 @@ private void sendBatch(Map<TableRef, MultiRowMutationState> commitBatch, long[]
                    serverTimeStamps == null ?
                        validateAndGetServerTimestamp(tableRef, multiRowMutationState) :
                        serverTimeStamps[i++];
+                long syscatTime = EnvironmentEdgeManager.currentTimeMillis() - startTime;


@mnpoonia This is not the only place where we call validateAndGetServerTimestamp. It is also called from here https://github.com/apache/phoenix/blob/master/phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java#L895

Also, this is being called in a loop so you need to reset the value of startTime for every iteration.

Agreed. instead of keeping the time here i pushed it down to the method validateAndGetServerTimestamp.

@tkhurana Let me know if it looks good now.

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java

tkhurana · 2023-01-11T00:30:40Z

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java

            }
            throw e;
+        } finally {
+            long endTime = EnvironmentEdgeManager.currentTimeMillis();
+            GLOBAL_MUTATION_SYSCAT_TIME.update(endTime - startTime);


This looks good

mnpoonia · 2023-01-20T07:51:31Z

@virajjasani @tkhurana I have addressed most of the review comments. Please have a look now.

virajjasani · 2023-01-23T18:09:18Z

I think we should remove formatting changes from this PR, to have smooth backports (including internal forks)

virajjasani · 2023-01-23T18:21:15Z

phoenix-core/src/main/java/org/apache/phoenix/monitoring/MetricType.java

@@ -208,23 +209,23 @@ private MetricType(String shortName, String description, LogLevel logLevel, PDat
    public String description() {
        return description;
    }
-


Agree, good to keep only addition of MUTATION_SYSCAT_TIME for this file and remove all other formatting changes.

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java

mnpoonia · 2023-02-06T08:42:17Z

@virajjasani I have removed all the whitespace and indentation changes. Please review now.
@tkhurana FYI

mnpoonia · 2023-02-06T08:52:06Z

PR for 5.1 branch
#1557

virajjasani requested review from tkhurana and gjacoby126 January 4, 2023 20:39

tkhurana reviewed Jan 4, 2023

View reviewed changes

phoenix-core/src/main/java/org/apache/phoenix/execute/MutationState.java Outdated Show resolved Hide resolved

mnpoonia force-pushed the include_syscat_time branch from 3ff36ac to 32f7c2c Compare January 9, 2023 05:40

gourabtaparia reviewed Jan 9, 2023

View reviewed changes

tkhurana requested changes Jan 10, 2023

View reviewed changes

tkhurana reviewed Jan 11, 2023

View reviewed changes

tkhurana approved these changes Jan 23, 2023

View reviewed changes

virajjasani reviewed Jan 23, 2023

View reviewed changes

mnpoonia force-pushed the include_syscat_time branch 3 times, most recently from 8761296 to 80063c4 Compare February 6, 2023 08:08

PHOENIX-6052 Include syscat time in mutation time

e16f4d6

mnpoonia force-pushed the include_syscat_time branch from 80063c4 to e16f4d6 Compare February 6, 2023 08:40

virajjasani approved these changes Feb 6, 2023

View reviewed changes

virajjasani merged commit 0e1996d into apache:master Feb 6, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

PHOENIX-6052 Include syscat time in mutation time #1546

PHOENIX-6052 Include syscat time in mutation time #1546

mnpoonia commented Dec 20, 2022

mnpoonia commented Dec 21, 2022

tkhurana commented Dec 21, 2022

mnpoonia commented Dec 21, 2022

mnpoonia commented Jan 2, 2023

virajjasani commented Jan 4, 2023

tkhurana commented Jan 4, 2023

mnpoonia commented Jan 9, 2023 •

edited

Loading

gourabtaparia left a comment

gourabtaparia Jan 9, 2023

gourabtaparia Jan 9, 2023

virajjasani Jan 23, 2023 •

edited

Loading

tkhurana Jan 10, 2023

tkhurana Jan 10, 2023

mnpoonia Jan 10, 2023

mnpoonia Jan 10, 2023

tkhurana Jan 11, 2023

mnpoonia commented Jan 20, 2023

virajjasani commented Jan 23, 2023 •

edited

Loading

virajjasani Jan 23, 2023 •

edited

Loading

mnpoonia commented Feb 6, 2023

mnpoonia commented Feb 6, 2023

PHOENIX-6052 Include syscat time in mutation time #1546

PHOENIX-6052 Include syscat time in mutation time #1546

Conversation

mnpoonia commented Dec 20, 2022

mnpoonia commented Dec 21, 2022

tkhurana commented Dec 21, 2022

mnpoonia commented Dec 21, 2022

mnpoonia commented Jan 2, 2023

virajjasani commented Jan 4, 2023

tkhurana commented Jan 4, 2023

mnpoonia commented Jan 9, 2023 • edited Loading

gourabtaparia left a comment

Choose a reason for hiding this comment

gourabtaparia Jan 9, 2023

Choose a reason for hiding this comment

gourabtaparia Jan 9, 2023

Choose a reason for hiding this comment

virajjasani Jan 23, 2023 • edited Loading

Choose a reason for hiding this comment

tkhurana Jan 10, 2023

Choose a reason for hiding this comment

tkhurana Jan 10, 2023

Choose a reason for hiding this comment

mnpoonia Jan 10, 2023

Choose a reason for hiding this comment

mnpoonia Jan 10, 2023

Choose a reason for hiding this comment

tkhurana Jan 11, 2023

Choose a reason for hiding this comment

mnpoonia commented Jan 20, 2023

virajjasani commented Jan 23, 2023 • edited Loading

virajjasani Jan 23, 2023 • edited Loading

Choose a reason for hiding this comment

mnpoonia commented Feb 6, 2023

mnpoonia commented Feb 6, 2023

mnpoonia commented Jan 9, 2023 •

edited

Loading

virajjasani Jan 23, 2023 •

edited

Loading

virajjasani commented Jan 23, 2023 •

edited

Loading

virajjasani Jan 23, 2023 •

edited

Loading