You are viewing a plain text version of this content. The canonical link for it is here.
Posted to github@arrow.apache.org by GitBox <gi...@apache.org> on 2022/01/07 21:14:32 UTC

[GitHub] [arrow] mbrobbel opened a new pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

mbrobbel opened a new pull request #12100:
URL: https://github.com/apache/arrow/pull/12100


   I'm still working on this but opening this for visibility.
   @lidavidm @westonpace


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] ursabot edited a comment on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
ursabot edited a comment on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1028007446


   Benchmark runs are scheduled for baseline = 74deb4528d9b48fdcacb37fe981457121b809685 and contender = 9b53235611a1cda81d5fbe801503acf45f5bf74e. 9b53235611a1cda81d5fbe801503acf45f5bf74e is a master commit associated with this PR. Results will be available as each benchmark for each run completes.
   Conbench compare runs links:
   [Finished :arrow_down:0.0% :arrow_up:0.0%] [ec2-t3-xlarge-us-east-2](https://conbench.ursa.dev/compare/runs/dbd87518ae09453aa55d91f721965823...3d98628293494948b70a2de31fbfbf68/)
   [Scheduled] [ursa-i9-9960x](https://conbench.ursa.dev/compare/runs/4778b23c7d5e4e919fe6885647773796...d1a59396625248a3935bc5ad2d556e7a/)
   [Finished :arrow_down:0.69% :arrow_up:0.0%] [ursa-thinkcentre-m75q](https://conbench.ursa.dev/compare/runs/60108528172d4b1ebf5800969f2cbaab...f2326e71b90e4299a2e580d26b3cdd9a/)
   Supported benchmarks:
   ec2-t3-xlarge-us-east-2: Supported benchmark langs: Python. Runs only benchmarks with cloud = True
   ursa-i9-9960x: Supported benchmark langs: Python, R, JavaScript
   ursa-thinkcentre-m75q: Supported benchmark langs: C++, Java
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] ursabot edited a comment on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
ursabot edited a comment on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1028007446


   Benchmark runs are scheduled for baseline = 74deb4528d9b48fdcacb37fe981457121b809685 and contender = 9b53235611a1cda81d5fbe801503acf45f5bf74e. 9b53235611a1cda81d5fbe801503acf45f5bf74e is a master commit associated with this PR. Results will be available as each benchmark for each run completes.
   Conbench compare runs links:
   [Finished :arrow_down:0.0% :arrow_up:0.0%] [ec2-t3-xlarge-us-east-2](https://conbench.ursa.dev/compare/runs/dbd87518ae09453aa55d91f721965823...3d98628293494948b70a2de31fbfbf68/)
   [Scheduled] [ursa-i9-9960x](https://conbench.ursa.dev/compare/runs/4778b23c7d5e4e919fe6885647773796...d1a59396625248a3935bc5ad2d556e7a/)
   [Scheduled] [ursa-thinkcentre-m75q](https://conbench.ursa.dev/compare/runs/60108528172d4b1ebf5800969f2cbaab...f2326e71b90e4299a2e580d26b3cdd9a/)
   Supported benchmarks:
   ec2-t3-xlarge-us-east-2: Supported benchmark langs: Python. Runs only benchmarks with cloud = True
   ursa-i9-9960x: Supported benchmark langs: Python, R, JavaScript
   ursa-thinkcentre-m75q: Supported benchmark langs: C++, Java
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] mbrobbel commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
mbrobbel commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r783776026



##########
File path: cpp/src/arrow/compute/function.cc
##########
@@ -215,9 +215,15 @@ Result<Datum> Function::Execute(const std::vector<Datum>& args,
   }
 
   util::tracing::Span span;
-  START_SPAN(span, name(),
-             {{"detail", options ? options->ToString() : "<NULLPTR>"},
-              {"function.kind", kind()}});
+  START_SPAN(
+      span, name(),
+      {{"function.args", std::accumulate(std::begin(args), std::end(args), std::string(),
+                                         [](std::string& ss, const Datum& d) {
+                                           return ss.empty() ? d.ToString()
+                                                             : ss + "," + d.ToString();
+                                         })},
+       {"function.options", options ? options->ToString() : "<NULLPTR>"},
+       {"function.kind", kind()}});

Review comment:
       Yes this is a trade-off for almost all attributes that are collected. I'll remove the args and keep the kind. We can always add/modify/remove attributes later.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] ursabot edited a comment on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
ursabot edited a comment on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1028007446


   Benchmark runs are scheduled for baseline = 74deb4528d9b48fdcacb37fe981457121b809685 and contender = 9b53235611a1cda81d5fbe801503acf45f5bf74e. 9b53235611a1cda81d5fbe801503acf45f5bf74e is a master commit associated with this PR. Results will be available as each benchmark for each run completes.
   Conbench compare runs links:
   [Finished :arrow_down:0.0% :arrow_up:0.0%] [ec2-t3-xlarge-us-east-2](https://conbench.ursa.dev/compare/runs/dbd87518ae09453aa55d91f721965823...3d98628293494948b70a2de31fbfbf68/)
   [Failed :arrow_down:0.0% :arrow_up:0.36%] [ursa-i9-9960x](https://conbench.ursa.dev/compare/runs/4778b23c7d5e4e919fe6885647773796...d1a59396625248a3935bc5ad2d556e7a/)
   [Finished :arrow_down:0.69% :arrow_up:0.0%] [ursa-thinkcentre-m75q](https://conbench.ursa.dev/compare/runs/60108528172d4b1ebf5800969f2cbaab...f2326e71b90e4299a2e580d26b3cdd9a/)
   Supported benchmarks:
   ec2-t3-xlarge-us-east-2: Supported benchmark langs: Python. Runs only benchmarks with cloud = True
   ursa-i9-9960x: Supported benchmark langs: Python, R, JavaScript
   ursa-thinkcentre-m75q: Supported benchmark langs: C++, Java
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1007754899


   If you have a screenshot or any quick example of the output to share here it would also be useful, I think.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r786017483



##########
File path: cpp/src/arrow/compute/exec/aggregate_node.cc
##########
@@ -165,7 +166,18 @@ class ScalarAggregateNode : public ExecNode {
   const char* kind_name() const override { return "ScalarAggregateNode"; }
 
   Status DoConsume(const ExecBatch& batch, size_t thread_index) {
+    util::tracing::Span span;
+    START_SPAN(span, "Consume",
+               {{"aggregate", ToStringExtra()},
+                {"node.label", label()},
+                {"batch.length", batch.length}});
     for (size_t i = 0; i < kernels_.size(); ++i) {
+      util::tracing::Span span;
+      START_SPAN(span, aggs_[i].function,

Review comment:
       Or maybe not, we'll have to see what structure is best for analysis. (e.g. do we want to put node labels in the span names - maybe/probably, do we want function names in the span names - maybe not if it means we have too many distinct span names for visualization)

##########
File path: cpp/src/arrow/compute/exec/aggregate_node.cc
##########
@@ -165,7 +166,18 @@ class ScalarAggregateNode : public ExecNode {
   const char* kind_name() const override { return "ScalarAggregateNode"; }
 
   Status DoConsume(const ExecBatch& batch, size_t thread_index) {
+    util::tracing::Span span;
+    START_SPAN(span, "Consume",
+               {{"aggregate", ToStringExtra()},
+                {"node.label", label()},
+                {"batch.length", batch.length}});
     for (size_t i = 0; i < kernels_.size(); ++i) {
+      util::tracing::Span span;
+      START_SPAN(span, aggs_[i].function,

Review comment:
       Hmm, if we have the function name in the attribute, maybe the span name should be something generic like `ScalarAggregateConsume`?




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] ursabot commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
ursabot commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1028007446


   Benchmark runs are scheduled for baseline = 74deb4528d9b48fdcacb37fe981457121b809685 and contender = 9b53235611a1cda81d5fbe801503acf45f5bf74e. 9b53235611a1cda81d5fbe801503acf45f5bf74e is a master commit associated with this PR. Results will be available as each benchmark for each run completes.
   Conbench compare runs links:
   [Scheduled] [ec2-t3-xlarge-us-east-2](https://conbench.ursa.dev/compare/runs/dbd87518ae09453aa55d91f721965823...3d98628293494948b70a2de31fbfbf68/)
   [Scheduled] [ursa-i9-9960x](https://conbench.ursa.dev/compare/runs/4778b23c7d5e4e919fe6885647773796...d1a59396625248a3935bc5ad2d556e7a/)
   [Scheduled] [ursa-thinkcentre-m75q](https://conbench.ursa.dev/compare/runs/60108528172d4b1ebf5800969f2cbaab...f2326e71b90e4299a2e580d26b3cdd9a/)
   Supported benchmarks:
   ec2-t3-xlarge-us-east-2: Supported benchmark langs: Python. Runs only benchmarks with cloud = True
   ursa-i9-9960x: Supported benchmark langs: Python, R, JavaScript
   ursa-thinkcentre-m75q: Supported benchmark langs: C++, Java
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] mbrobbel commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
mbrobbel commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1027283642


   > @lidavidm @mbrobbel Is there any reason we can't merge this?  If you want I can take a look through tomorrow and merge.  Otherwise I took a quick scan and I think this is helpful information to get us started with instrumentation.
   
   There are still some comments from @lidavidm that I need to address, but I can do that tomorrow.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] github-actions[bot] commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
github-actions[bot] commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1007745646


   https://issues.apache.org/jira/browse/ARROW-15061


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1007754548






-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] ursabot edited a comment on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
ursabot edited a comment on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1028007446


   Benchmark runs are scheduled for baseline = 74deb4528d9b48fdcacb37fe981457121b809685 and contender = 9b53235611a1cda81d5fbe801503acf45f5bf74e. 9b53235611a1cda81d5fbe801503acf45f5bf74e is a master commit associated with this PR. Results will be available as each benchmark for each run completes.
   Conbench compare runs links:
   [Finished :arrow_down:0.0% :arrow_up:0.0%] [ec2-t3-xlarge-us-east-2](https://conbench.ursa.dev/compare/runs/dbd87518ae09453aa55d91f721965823...3d98628293494948b70a2de31fbfbf68/)
   [Scheduled] [ursa-i9-9960x](https://conbench.ursa.dev/compare/runs/4778b23c7d5e4e919fe6885647773796...d1a59396625248a3935bc5ad2d556e7a/)
   [Failed :arrow_down:0.0% :arrow_up:0.0%] [ursa-thinkcentre-m75q](https://conbench.ursa.dev/compare/runs/60108528172d4b1ebf5800969f2cbaab...f2326e71b90e4299a2e580d26b3cdd9a/)
   Supported benchmarks:
   ec2-t3-xlarge-us-east-2: Supported benchmark langs: Python. Runs only benchmarks with cloud = True
   ursa-i9-9960x: Supported benchmark langs: Python, R, JavaScript
   ursa-thinkcentre-m75q: Supported benchmark langs: C++, Java
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1007754548


   Cool! The macro definitions look fairly useful.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1027359590


   No further comments from me - let's merge once OrderBySinkNode is fully instrumented.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] mbrobbel commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
mbrobbel commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1027735642


   @westonpace @lidavidm this is now ready for a final review.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] ursabot edited a comment on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
ursabot edited a comment on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1028007446


   Benchmark runs are scheduled for baseline = 74deb4528d9b48fdcacb37fe981457121b809685 and contender = 9b53235611a1cda81d5fbe801503acf45f5bf74e. 9b53235611a1cda81d5fbe801503acf45f5bf74e is a master commit associated with this PR. Results will be available as each benchmark for each run completes.
   Conbench compare runs links:
   [Finished :arrow_down:0.0% :arrow_up:0.0%] [ec2-t3-xlarge-us-east-2](https://conbench.ursa.dev/compare/runs/dbd87518ae09453aa55d91f721965823...3d98628293494948b70a2de31fbfbf68/)
   [Scheduled] [ursa-i9-9960x](https://conbench.ursa.dev/compare/runs/4778b23c7d5e4e919fe6885647773796...d1a59396625248a3935bc5ad2d556e7a/)
   [Scheduled] [ursa-thinkcentre-m75q](https://conbench.ursa.dev/compare/runs/60108528172d4b1ebf5800969f2cbaab...f2326e71b90e4299a2e580d26b3cdd9a/)
   Supported benchmarks:
   ec2-t3-xlarge-us-east-2: Supported benchmark langs: Python. Runs only benchmarks with cloud = True
   ursa-i9-9960x: Supported benchmark langs: Python, R, JavaScript
   ursa-thinkcentre-m75q: Supported benchmark langs: C++, Java
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] github-actions[bot] commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
github-actions[bot] commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1007745646


   https://issues.apache.org/jira/browse/ARROW-15061


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r786021110



##########
File path: cpp/src/arrow/compute/exec/sink_node.cc
##########
@@ -275,6 +302,11 @@ struct OrderBySinkNode final : public SinkNode {
   }
 
   void InputReceived(ExecNode* input, ExecBatch batch) override {
+    EVENT(span_, "InputReceived", {{"batch.length", batch.length}});
+    util::tracing::Span span;
+    START_SPAN_WITH_PARENT(span, span_, "InputReceived",
+                           {{"node.label", label()}, {"batch.length", batch.length}});
+

Review comment:
       From one of the screenshots above, it might be worth instrumenting DoFinish below for OrderBySinkNode since that's where the 'real' work happens.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r783424580



##########
File path: cpp/src/arrow/compute/function.cc
##########
@@ -215,9 +215,15 @@ Result<Datum> Function::Execute(const std::vector<Datum>& args,
   }
 
   util::tracing::Span span;
-  START_SPAN(span, name(),
-             {{"detail", options ? options->ToString() : "<NULLPTR>"},
-              {"function.kind", kind()}});
+  START_SPAN(
+      span, name(),
+      {{"function.args", std::accumulate(std::begin(args), std::end(args), std::string(),
+                                         [](std::string& ss, const Datum& d) {
+                                           return ss.empty() ? d.ToString()
+                                                             : ss + "," + d.ToString();
+                                         })},
+       {"function.options", options ? options->ToString() : "<NULLPTR>"},
+       {"function.kind", kind()}});

Review comment:
       nit, but is the kind useful? We'll know from the definition and/or from context (e.g. GroupByNode vs ProjectNode)

##########
File path: cpp/src/arrow/compute/exec/aggregate_node.cc
##########
@@ -393,7 +422,11 @@ class GroupByNode : public ExecNode {
     // Execute aggregate kernels
     for (size_t i = 0; i < agg_kernels_.size(); ++i) {
       util::tracing::Span span;
-      START_SPAN(span, "Aggregate", {{"function", aggs_[i].function}});
+      START_SPAN(span, aggs_[i].function,
+                 {{"function", aggs_[i].function},

Review comment:
       We don't record this attribute in function.cc, we should be consistent about this.

##########
File path: cpp/src/arrow/compute/exec/union_node.cc
##########
@@ -107,27 +106,34 @@ class UnionNode : public ExecNode {
     if (input_count_.Increment()) {
       outputs_[0]->InputFinished(this, total_batches_.load());
       if (batch_count_.SetTotal(total_batches_.load())) {
-        END_SPAN(span);
         finished_.MarkFinished();
       }
     }
   }
 
   Status StartProducing() override {
-    START_SPAN(span, kind_name(), {{"node", ToString()}});
+    START_SPAN(span_, std::string(kind_name()) + ":" + label(),
+               {{"node.label", label()},
+                {"node.detail", ToString()},
+                {"node.kind", kind_name()}});
     finished_ = Future<>::Make();
+#ifdef ARROW_WITH_OPENTELEMETRY
+    finished_.AddCallback([this](const Status& st) {

Review comment:
       I know I suggested this, but there is one concern here: once finished_ completes, the node may be destroyed. (Once all nodes finish, the plan finishes, and then the plan consumer might also destroy the plan since it's done.) Also, the order in which callbacks is run is not defined. It might be safest to copy `span_` into the span closure instead of capturing `this`. (Or, you could do `finished_ = finished_.Then(...)` which would mean that this callback gets to run before others, which would ensure it runs before anything that could potentially destroy the plan.)

##########
File path: cpp/src/arrow/compute/function.cc
##########
@@ -215,9 +215,15 @@ Result<Datum> Function::Execute(const std::vector<Datum>& args,
   }
 
   util::tracing::Span span;
-  START_SPAN(span, name(),
-             {{"detail", options ? options->ToString() : "<NULLPTR>"},
-              {"function.kind", kind()}});
+  START_SPAN(
+      span, name(),
+      {{"function.args", std::accumulate(std::begin(args), std::end(args), std::string(),
+                                         [](std::string& ss, const Datum& d) {
+                                           return ss.empty() ? d.ToString()
+                                                             : ss + "," + d.ToString();
+                                         })},
+       {"function.options", options ? options->ToString() : "<NULLPTR>"},
+       {"function.kind", kind()}});

Review comment:
       Same with the args - that'll give us datum types (array vs scalar), but I'm not sure what kind of analysis we'd do on that. (That said if collecting is cheap we might as well just always collect.)

##########
File path: cpp/src/arrow/compute/exec/aggregate_node.cc
##########
@@ -393,7 +422,11 @@ class GroupByNode : public ExecNode {
     // Execute aggregate kernels
     for (size_t i = 0; i < agg_kernels_.size(); ++i) {
       util::tracing::Span span;
-      START_SPAN(span, "Aggregate", {{"function", aggs_[i].function}});
+      START_SPAN(span, aggs_[i].function,
+                 {{"function", aggs_[i].function},
+                  {"function.options",
+                   aggs_[i].options ? aggs_[i].options->ToString() : "<NULLPTR>"},
+                  {"function.kind", "consume"}});

Review comment:
       maybe ScalarAggregateConsume/HashAggregateConsume etc.?




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] mbrobbel commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
mbrobbel commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1008994369


   Some example output in Jaeger:
   TPC-H query 1:
   
   ![Screenshot 2022-01-10 at 16 24 36](https://user-images.githubusercontent.com/5501570/148791478-3ffdb9db-0bfb-48ea-a322-de19e90bd6a1.png)
   
   TPC-H query 2:
   ![Screenshot 2022-01-10 at 16 27 52](https://user-images.githubusercontent.com/5501570/148791919-dd0161ad-16ff-42a2-959f-50260f30c3e8.png)
   
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] mbrobbel commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
mbrobbel commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r783097897



##########
File path: cpp/src/arrow/compute/exec/aggregate_node.cc
##########
@@ -188,36 +194,40 @@ class ScalarAggregateNode : public ExecNode {
   }
 
   void ErrorReceived(ExecNode* input, Status error) override {
+    EVENT(span, "ErrorReceived", {{"error", error.message()}});
     DCHECK_EQ(input, inputs_[0]);
     outputs_[0]->ErrorReceived(this, std::move(error));
   }
 
   void InputFinished(ExecNode* input, int total_batches) override {
+    EVENT(span, "InputFinished", {{"batches.length", total_batches}});
     DCHECK_EQ(input, inputs_[0]);
-
     if (input_counter_.SetTotal(total_batches)) {
       ErrorIfNotOk(Finish());
     }
   }
 
   Status StartProducing() override {
+    START_SPAN(span, kind_name(), {{"node", ToString()}});
     finished_ = Future<>::Make();
     // Scalar aggregates will only output a single batch
     outputs_[0]->InputFinished(this, 1);
     return Status::OK();
   }
 
-  void PauseProducing(ExecNode* output) override {}
+  void PauseProducing(ExecNode* output) override { EVENT(span, "PauseProducing"); }
 
-  void ResumeProducing(ExecNode* output) override {}
+  void ResumeProducing(ExecNode* output) override { EVENT(span, "ResumeProducing"); }
 
   void StopProducing(ExecNode* output) override {
     DCHECK_EQ(output, outputs_[0]);
     StopProducing();
   }
 
   void StopProducing() override {
+    EVENT(span, "StopProducing");
     if (input_counter_.Cancel()) {
+      END_SPAN(span);

Review comment:
       Much better. I'm applying this for the other nodes too.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r783078213



##########
File path: cpp/src/arrow/util/tracing.h
##########
@@ -0,0 +1,75 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements.  See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership.  The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License.  You may obtain a copy of the License at
+//
+//   http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied.  See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+#pragma once
+
+#include <memory>
+
+#include "arrow/util/logging.h"
+
+namespace arrow {
+
+namespace internal {
+namespace tracing {
+
+// Forward declaration SpanImpl.
+class SpanImpl;
+
+}  // namespace tracing
+}  // namespace internal
+
+namespace util {
+namespace tracing {
+
+class ARROW_EXPORT Span {
+ public:
+  using Impl = arrow::internal::tracing::SpanImpl;
+
+  Span() = default;  // Default constructor. The inner_impl is a nullptr.
+  ~Span();  // Destructor. Default destructor defined in tracing.cc where impl is a
+            // complete type.
+
+  Impl& Set(const Impl&);
+  Impl& Set(Impl&&);
+
+  const Impl& Get() const {
+    if (inner_impl) {
+      return *inner_impl;
+    } else {
+      ARROW_LOG(FATAL) << "Attempted to dereference a null pointer. Use Span::Set before "

Review comment:
       The DCHECK/CHECK macros can handle this more concisely:
   
   ```
   ARROW_DCHECK(inner_impl) << "...";
   return *inner_impl;
   ```
   
   or
   
   ```
   ARROW_CHECK(inner_impl) << "..."; // will be retained in release builds
   return *inner_impl;
   ```

##########
File path: cpp/src/arrow/compute/exec/exec_plan.h
##########
@@ -245,6 +246,8 @@ class ARROW_EXPORT ExecNode {
   std::shared_ptr<Schema> output_schema_;
   int num_outputs_;
   NodeVector outputs_;
+
+  util::tracing::Span span;

Review comment:
       This should be `span_` for consistency (sorry for the churn)

##########
File path: cpp/src/arrow/compute/exec/exec_plan.cc
##########
@@ -172,6 +182,8 @@ struct ExecPlanImpl : public ExecPlan {
   NodeVector sources_, sinks_;
   NodeVector sorted_nodes_;
   uint32_t auto_label_counter_ = 0;
+
+  util::tracing::Span span;

Review comment:
       Same here - this should be `span_`

##########
File path: cpp/src/arrow/compute/exec/hash_join.h
##########
@@ -112,6 +113,9 @@ class HashJoinImpl {
   virtual void Abort(TaskScheduler::AbortContinuationImpl pos_abort_callback) = 0;
 
   static Result<std::unique_ptr<HashJoinImpl>> MakeBasic();
+
+ protected:
+  util::tracing::Span span;

Review comment:
       Same here, we generally suffix private/protected members with `_`. (See ["Class Data Members"](https://google.github.io/styleguide/cppguide.html#Variable_Names).)

##########
File path: cpp/src/arrow/compute/exec/aggregate_node.cc
##########
@@ -188,36 +194,40 @@ class ScalarAggregateNode : public ExecNode {
   }
 
   void ErrorReceived(ExecNode* input, Status error) override {
+    EVENT(span, "ErrorReceived", {{"error", error.message()}});
     DCHECK_EQ(input, inputs_[0]);
     outputs_[0]->ErrorReceived(this, std::move(error));
   }
 
   void InputFinished(ExecNode* input, int total_batches) override {
+    EVENT(span, "InputFinished", {{"batches.length", total_batches}});
     DCHECK_EQ(input, inputs_[0]);
-
     if (input_counter_.SetTotal(total_batches)) {
       ErrorIfNotOk(Finish());
     }
   }
 
   Status StartProducing() override {
+    START_SPAN(span, kind_name(), {{"node", ToString()}});
     finished_ = Future<>::Make();
     // Scalar aggregates will only output a single batch
     outputs_[0]->InputFinished(this, 1);
     return Status::OK();
   }
 
-  void PauseProducing(ExecNode* output) override {}
+  void PauseProducing(ExecNode* output) override { EVENT(span, "PauseProducing"); }
 
-  void ResumeProducing(ExecNode* output) override {}
+  void ResumeProducing(ExecNode* output) override { EVENT(span, "ResumeProducing"); }
 
   void StopProducing(ExecNode* output) override {
     DCHECK_EQ(output, outputs_[0]);
     StopProducing();
   }
 
   void StopProducing() override {
+    EVENT(span, "StopProducing");
     if (input_counter_.Cancel()) {
+      END_SPAN(span);

Review comment:
       We could add a callback to finished_ in StartProducing above instead.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm closed pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm closed pull request #12100:
URL: https://github.com/apache/arrow/pull/12100


   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r783428714



##########
File path: cpp/src/arrow/compute/function.cc
##########
@@ -215,9 +215,15 @@ Result<Datum> Function::Execute(const std::vector<Datum>& args,
   }
 
   util::tracing::Span span;
-  START_SPAN(span, name(),
-             {{"detail", options ? options->ToString() : "<NULLPTR>"},
-              {"function.kind", kind()}});
+  START_SPAN(
+      span, name(),
+      {{"function.args", std::accumulate(std::begin(args), std::end(args), std::string(),
+                                         [](std::string& ss, const Datum& d) {
+                                           return ss.empty() ? d.ToString()
+                                                             : ss + "," + d.ToString();
+                                         })},
+       {"function.options", options ? options->ToString() : "<NULLPTR>"},
+       {"function.kind", kind()}});

Review comment:
       (On reflection, if we do need to group by kind, it'd be much easier to have it as an attribute instead of having to look it up in a registry, so kind seems okay to me. I'm not as sure about args.)




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on a change in pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on a change in pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#discussion_r784008528



##########
File path: cpp/src/arrow/util/tracing_internal.h
##########
@@ -97,6 +100,63 @@ AsyncGenerator<T> WrapAsyncGenerator(AsyncGenerator<T> wrapped,
     return fut;
   };
 }
+
+class SpanImpl {
+ public:
+  opentelemetry::nostd::shared_ptr<opentelemetry::trace::Span> span;
+};
+
+opentelemetry::trace::StartSpanOptions SpanOptionsWithParent(
+    const util::tracing::Span& parent_span);
+
+#define START_SPAN(target_span, ...)                                                \
+  auto opentelemetry_scope##__LINE__ =                                              \
+      ::arrow::internal::tracing::GetTracer()->WithActiveSpan(                      \
+          target_span                                                               \
+              .Set(::arrow::util::tracing::Span::Impl{                              \
+                  ::arrow::internal::tracing::GetTracer()->StartSpan(__VA_ARGS__)}) \
+              .span)
+
+#define START_SPAN_WITH_PARENT(target_span, parent_span, ...)                           \
+  auto opentelemetry_scope##__LINE__ =                                                  \
+      ::arrow::internal::tracing::GetTracer()->WithActiveSpan(                          \
+          target_span                                                                   \
+              .Set(::arrow::util::tracing::Span::Impl{                                  \
+                  ::arrow::internal::tracing::GetTracer()->StartSpan(                   \
+                      __VA_ARGS__,                                                      \
+                      ::arrow::internal::tracing::SpanOptionsWithParent(parent_span))}) \
+              .span)
+
+#define EVENT(target_span, ...) target_span.Get().span->AddEvent(__VA_ARGS__)
+
+#define MARK_SPAN(target_span, status) \
+  ::arrow::internal::tracing::MarkSpan(status, target_span.Get().span.get())
+
+#define END_SPAN(target_span) target_span.Get().span->End()
+
+#define END_SPAN_ON_FUTURE_COMPLETION(target_span, target_future, target_capture) \
+  target_future = target_future.Then(                                             \
+      [target_capture]() {                                                        \
+        MARK_SPAN(target_span, Status::OK());                                     \
+        END_SPAN(target_span);                                                    \
+      },                                                                          \
+      [target_capture](const Status& st) {                                        \
+        MARK_SPAN(target_span, st);                                               \
+        END_SPAN(target_span);                                                    \
+        return st;                                                                \
+      })

Review comment:
       This macro really makes me think we should consider just adding Span as a part of Future (and see how it impacts performance). That can be done later, though, I think we can get this in first and continue refining how we use OpenTelemetry.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1028005026


   (For the record, edited description to remove username pings; those get put into the commit message and then generate a lot of notification spam.)


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] lidavidm commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
lidavidm commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1027359800


   I want to base #11964 on top of this since the helpers here will simplify it.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [arrow] westonpace commented on pull request #12100: ARROW-15061: [C++] Add logging for kernel functions and exec plan nodes

Posted by GitBox <gi...@apache.org>.
westonpace commented on pull request #12100:
URL: https://github.com/apache/arrow/pull/12100#issuecomment-1027279029


   @lidavidm @mbrobbel Is there any reason we can't merge this?  If you want I can take a look through tomorrow and merge.  Otherwise I took a quick scan and I think this is helpful information to get us started with instrumentation.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: github-unsubscribe@arrow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org