Add cpu and io indicates to audit log #531

chenhao7253886 · 2019-01-14T12:04:09Z

Record query consumption into fe audit log. Its basic mode of work is as follows, one of instance of parent plan is responsible for accumulating sub plan's consumption and send to it's parent, BE coordinator will get total consumption because it's a single instance.

chenhao7253886 · 2019-01-14T12:44:21Z

fe/src/main/java/org/apache/doris/planner/Planner.java

+            }
+        }
+
+        private boolean hasLimit(PlanNode planNode) {


it should judge limit by it's immediate parent. i will fix it.

imay · 2019-01-14T12:39:36Z

gensrc/proto/data.proto


+message PQueryStatistic {
+    optional int64 cpu_by_row = 1;
+    optional int64 io_by_byte = 2;


Suggested change

optional int64 io_by_byte = 2;

optional int64 scan_rows = 2;

imay · 2019-01-14T12:39:42Z

gensrc/proto/data.proto

 package doris;

+message PQueryStatistic {
+    optional int64 cpu_by_row = 1;


process_rows

imay · 2019-01-14T12:40:11Z

fe/src/main/java/org/apache/doris/rpc/PQueryStatistic.java

+    @Protobuf(order = 1, required = false)
+    public long cpu;
+    @Protobuf(order = 2, required = false)
+    public long io;


Suggested change

public long io;

public long scanRows;

imay · 2019-01-14T12:40:21Z

fe/src/main/java/org/apache/doris/rpc/PQueryStatistic.java

+@ProtobufClass
+public class PQueryStatistic {
+    @Protobuf(order = 1, required = false)
+    public long cpu;


processRows

ok, i will fix it.

imay · 2019-01-14T13:53:11Z

be/src/runtime/data_stream_sender.cpp

            || sink.output_partition.type == TPartitionType::RANGE_PARTITIONED);
    // TODO: use something like google3's linked_ptr here (scoped_ptr isn't copyable)
    for (int i = 0; i < destinations.size(); ++i) {
+        bool is_transfer_chain = false;


Suggested change

bool is_transfer_chain = false;

bool is_transfer_stats = (i == 0);

ok, i will modify it.

imay · 2019-01-14T14:02:16Z

be/src/service/internal_service.cpp

            eos ? nullptr : &done);
    }
+
+    if (request->has_query_statistic()) {


you should update query statistics in add_data function

Now add_data is used for add batch, when eos is true and request does't contain batch, add_data will not be called, but request may contains query statistics, so it is more simple to handle query statistics update separately.

imay · 2019-01-14T14:04:08Z

fe/src/main/java/org/apache/doris/qe/ConnectProcessor.java

        ctx.getAuditBuilder().put("time", elapseMs);
+        Preconditions.checkNotNull(queryStatistic); 
+        ctx.getAuditBuilder().put("cpu", queryStatistic.getFormattingCpu());
+        ctx.getAuditBuilder().put("io", queryStatistic.getFormattingIo());


use scanRows, processRows instead of cpu and io. because a man can't know what's io/cpu stand for

ok, i will fix it.

imay · 2019-01-15T08:55:17Z

be/src/exec/analytic_eval_node.h

    virtual Status prepare(RuntimeState* state);
    virtual Status open(RuntimeState* state);
    virtual Status get_next(RuntimeState* state, RowBatch* row_batch, bool* eos);
+    virtual Status collect_query_statistics(QueryStatistics* statistics);


Suggested change

virtual Status collect_query_statistics(QueryStatistics* statistics);

Status collect_query_statistics(QueryStatistics* statistics) override;

imay · 2019-01-15T08:57:12Z

be/src/runtime/query_statistics.h

+
+        void add(const Statistics& other) {
+            process_rows += other.process_rows;
+            scan_bytes += other.scan_bytes;


scan rows？

imay · 2019-01-15T09:00:08Z

be/src/runtime/query_statistics.h

+
+    void serialize(PQueryStatistics* statistics) { 
+        DCHECK(statistics != nullptr);
+        boost::lock_guard<SpinLock> l(_lock);


boost::lock_guard -> std::lock_guard

imay · 2019-01-15T09:21:11Z

be/src/exec/exchange_node.h

    RuntimeProfile::Counter* _merge_rows_counter;
+
+    // Query statistics from sub plan.
+    boost::scoped_ptr<QueryStatistics> _sub_plan_statistics;


use std first

std does't include scoped_ptr.

imay · 2019-01-15T09:27:57Z

be/src/runtime/query_statistics.h

+    }
+
+    long get_process_rows() {
+        boost::lock_guard<SpinLock> l(_lock);


do you need a lock here?

i will fix it.

imay · 2019-01-16T06:16:52Z

fe/src/main/java/org/apache/doris/qe/StmtExecutor.java

+        return statisticsForAuditLog;
+    }
+
+    public static class QueryStatistics {


Can PQueryStatistics replace this class?

yes, i will replace this with PQueryStatistics.

imay · 2019-01-16T06:18:30Z

fe/src/main/java/org/apache/doris/qe/RowBatch.java

+public final class RowBatch {
+    private TResultBatch batch;
+    private PQueryStatistics statistics;
+    private boolean eos;


why not use batch.eos?

TResultBatch does't include EOS member, but it's wapper PFetchDataResult.

imay · 2019-01-16T06:19:00Z

fe/src/main/java/org/apache/doris/qe/StmtExecutor.java


+    private void setQueryStatisticsForAuditLog(RowBatch batch) {
+        if (batch != null) {
+            final PQueryStatistics statistics = batch.getQueryStatistics();


batch.getQueryStatistics() may return nullptr?

i will fix it.

imay · 2019-01-16T06:21:13Z

fe/src/main/java/org/apache/doris/qe/ConnectProcessor.java

        ctx.getAuditBuilder().put("time", elapseMs);
+        Preconditions.checkNotNull(statistics); 
+        ctx.getAuditBuilder().put("ScanRows", statistics.getFormattingScanRows());
+        ctx.getAuditBuilder().put("ScanRawData", statistics.getFormattingScanBytes());


I think it's good to format printing information in statistics.getFormattingScanRows.
It should be that caller formats returned value as its wanted format.

Now it is not convenient to support Format as function params, and now only one format.

imay · 2019-01-16T06:29:46Z

be/src/runtime/query_statistics.h

+private:
+
+    long scan_rows;
+    long scan_bytes;


ok , i will fix it.

imay · 2019-01-16T06:29:52Z

be/src/runtime/query_statistics.h

+// This is responsible for collecting query statistics, usually it consists of 
+// two parts, one is current fragment or plan's statistics, the other is sub fragment
+// or plan's statistics and QueryStatisticsRecvr is responsible for collecting it.
+class QueryStatistics {


change it to struct

be/src/runtime/query_statistics.h

imay · 2019-01-16T06:30:22Z

be/src/runtime/query_statistics.h

+        statistics->set_scan_bytes(scan_bytes);
+    }
+
+    void deserialize(const PQueryStatistics& statistics) {


ok, i will modify it.

imay · 2019-01-16T07:00:58Z

be/src/exec/exchange_node.cpp


+Status ExchangeNode::collect_query_statistics(QueryStatistics* statistics) {
+    RETURN_IF_ERROR(ExecNode::collect_query_statistics(statistics));
+    _sub_plan_query_statistics_recvr->add_to(statistics);


statistics.merge()

ok, i will fix it.

imay · 2019-01-16T11:33:15Z

fe/src/main/java/org/apache/doris/qe/StmtExecutor.java

        boolean isSendFields = false;
-        while ((batch = coord.getNext()) != null) {
+
+        while ((batch = coord.getNext()) != null && !batch.isEos()) {


while (true) {
getNext(batch)
if (batch.batch != null)
if (batch.stats != null)
if (batch.batch.eos) {
break;
}

imay · 2019-01-16T12:32:03Z

be/src/runtime/query_statistics.cpp

+    while (iter != _query_statistics.end()) {
+        delete iter->second;
+        iter++;
+    }


for (auto& it : _query_statistics) {
delete it.second;
}

imay · 2019-01-17T02:14:10Z

be/src/exec/exchange_node.cpp

            state->fragment_instance_id(), _id,
            _num_senders, config::exchg_node_buffer_size_bytes,
-            state->runtime_profile(), _is_merging);
+            state->runtime_profile(), _is_merging, _sub_plan_query_statistics_recvr.get());


it is better to let _stream_recvr own _sub_plan_query_statistics_recvr, and this node use _stream_recvr.get_ststs_recvr() to use it.

Add cpu and io indicates to audit log

ff7b9dd

chenhao7253886 commented Jan 14, 2019

View reviewed changes

imay requested changes Jan 14, 2019

View reviewed changes

imay reviewed Jan 14, 2019

View reviewed changes

chenhao7253886 added 2 commits January 15, 2019 14:17

Modify variables name

5f9a6d3

Modify variables name and add some comments

40f6069

imay reviewed Jan 15, 2019

View reviewed changes

chenhao7253886 added 4 commits January 16, 2019 12:53

Modify QueryStatistics and fix unit test

95c3773

Format and modify ResultSink

3a3b73c

Remove ununsed function

d4ad20b

Modify boost api to std

f3a1af6

imay reviewed Jan 16, 2019

View reviewed changes

chenhao7253886 added 11 commits January 16, 2019 16:33

Change some variables name and remove some redundant code

fae9bc2

Remove ununsed log

90111dd

Remove ununsed include

2e866aa

Fix unit test fail

6d64b35

Trigger github check

1c5aac1

Remove redundant code and modify unit test

ee3935e

Add some comments and modify QueryStatistics

079ac79

Modify QueryStatistics

3eebc39

Modify handlerQuery in StmtExecutor

5bb1c33

Modify handlerQuery in StmtExecutor

8ac2c3d

Modify handlerQuery in StmtExecutor

a93e7b9

imay approved these changes Jan 17, 2019

View reviewed changes

imay merged commit 0e5b193 into apache:master Jan 17, 2019

liutang123 mentioned this pull request Dec 9, 2020

Add cpu time cost in query audit #5051

Merged

3 tasks

	bool is_transfer_chain = false;
	bool is_transfer_stats = (i == 0);

	virtual Status collect_query_statistics(QueryStatistics* statistics);
	Status collect_query_statistics(QueryStatistics* statistics) override;

Add cpu and io indicates to audit log #531

Add cpu and io indicates to audit log #531

Uh oh!

Conversation

chenhao7253886 commented Jan 14, 2019

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment