Skip to content

Commit

Permalink
Identify common sub-expressions in printExprWithStats (facebookincuba…
Browse files Browse the repository at this point in the history 
…tor#1500)

Summary:
Enhance printExprWithStats to identify common-sub expressions.

For example, `c0 + c1` is a common sub-expression in
`"(c0 + c1) % 5", " (c0 + c1) % 3"` expression set. It is evaluated only once and
there is a single Expr object that represents it. That object appears in the
expression tree twice. printExprWithStats does not show the runtime stats for
second instance of that expression and instead annotates it with `[CSE https://github.com/facebookincubator/velox/issues/2]`,
where CSE stands for common sub-expression and 2 refers to the first instance
of the expression.

```
mod [cpu time: 50.49us, rows: 1024] -> BIGINT [facebookincubator#1]
   cast(plus as BIGINT) [cpu time: 68.15us, rows: 1024] -> BIGINT [facebookincubator#2]
      plus [cpu time: 51.84us, rows: 1024] -> INTEGER [facebookincubator#3]
         c0 [cpu time: 0ns, rows: 0] -> INTEGER [facebookincubator#4]
         c1 [cpu time: 0ns, rows: 0] -> INTEGER [facebookincubator#5]
   5:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT [facebookincubator#6]

mod [cpu time: 49.29us, rows: 1024] -> BIGINT [facebookincubator#7]
   cast((plus(c0, c1)) as BIGINT) -> BIGINT [CSE facebookincubator#2]
   3:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT [facebookincubator#8]
```

Pull Request resolved: facebookincubator#1500

Reviewed By: Yuhta

Differential Revision: D35994836

Pulled By: mbasmanova

fbshipit-source-id: 6bacbbe61b68dad97ce2fd5f99610c4ad55897be
  • Loading branch information
@mbasmanova
mbasmanova authored and artem.malyshev committed May 31, 2022
1 parent e4ffe0c commit e74bc78
Show file tree
Hide file tree
Showing 2 changed files with 83 additions and 50 deletions.
23 changes: 18 additions & 5 deletions velox/expression/Expr.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -547,7 +547,6 @@ Expr::PeelEncodingsResult Expr::peelEncodings(
const auto& rowsToDecode =
context->isFinalSelection() ? rows : *context->finalSelection();
decoded->makeIndices(*firstWrapper, rowsToDecode, numLevels);
auto indices = decoded->indices();

newRows = translateToInnerRows(rows, *decoded, newRowsHolder);

Expand Down Expand Up @@ -1314,28 +1313,42 @@ namespace {
void printExprWithStats(
const exec::Expr& expr,
const std::string& indent,
std::stringstream& out) {
std::stringstream& out,
std::unordered_map<const exec::Expr*, uint32_t>& uniqueExprs) {
auto it = uniqueExprs.find(&expr);
if (it != uniqueExprs.end()) {
// Common sub-expression. Print the full expression, but skip the stats. Add
// ID of the expression it duplicates.
out << indent << expr.toString(true) << " -> " << expr.type()->toString();
out << " [CSE #" << it->second << "]" << std::endl;
return;
}

uint32_t id = uniqueExprs.size() + 1;
uniqueExprs.insert({&expr, id});

const auto& stats = expr.stats();
out << indent << expr.toString(false)
<< " [cpu time: " << succinctNanos(stats.timing.cpuNanos)
<< ", rows: " << stats.numProcessedRows << "] -> "
<< expr.type()->toString() << std::endl;
<< expr.type()->toString() << " [#" << id << "]" << std::endl;

auto newIndent = indent + " ";
for (const auto& input : expr.inputs()) {
printExprWithStats(*input, newIndent, out);
printExprWithStats(*input, newIndent, out, uniqueExprs);
}
}
} // namespace

std::string printExprWithStats(const exec::ExprSet& exprSet) {
const auto& exprs = exprSet.exprs();
std::unordered_map<const exec::Expr*, uint32_t> uniqueExprs;
std::stringstream out;
for (auto i = 0; i < exprs.size(); ++i) {
if (i > 0) {
out << std::endl;
}
printExprWithStats(*exprs[i], "", out);
printExprWithStats(*exprs[i], "", out, uniqueExprs);
}
return out.str();
}
Expand Down
110 changes: 65 additions & 45 deletions velox/expression/tests/ExprStatsTest.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -88,45 +88,65 @@ TEST_F(ExprStatsTest, printWithStats) {
// Check stats before evaluation.
ASSERT_EQ(
exec::printExprWithStats(*exprSet),
"multiply [cpu time: 0ns, rows: 0] -> BIGINT\n"
" plus [cpu time: 0ns, rows: 0] -> BIGINT\n"
" cast(c0 as BIGINT) [cpu time: 0ns, rows: 0] -> BIGINT\n"
" c0 [cpu time: 0ns, rows: 0] -> INTEGER\n"
" 3:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT\n"
" cast(c1 as BIGINT) [cpu time: 0ns, rows: 0] -> BIGINT\n"
" c1 [cpu time: 0ns, rows: 0] -> INTEGER\n"
"multiply [cpu time: 0ns, rows: 0] -> BIGINT [#1]\n"
" plus [cpu time: 0ns, rows: 0] -> BIGINT [#2]\n"
" cast(c0 as BIGINT) [cpu time: 0ns, rows: 0] -> BIGINT [#3]\n"
" c0 [cpu time: 0ns, rows: 0] -> INTEGER [#4]\n"
" 3:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT [#5]\n"
" cast(c1 as BIGINT) [cpu time: 0ns, rows: 0] -> BIGINT [#6]\n"
" c1 [cpu time: 0ns, rows: 0] -> INTEGER [#7]\n"
"\n"
"eq [cpu time: 0ns, rows: 0] -> BOOLEAN\n"
" mod [cpu time: 0ns, rows: 0] -> BIGINT\n"
" cast(plus as BIGINT) [cpu time: 0ns, rows: 0] -> BIGINT\n"
" plus [cpu time: 0ns, rows: 0] -> INTEGER\n"
" c0 [cpu time: 0ns, rows: 0] -> INTEGER\n"
" c1 [cpu time: 0ns, rows: 0] -> INTEGER\n"
" 2:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT\n"
" 0:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT\n");
"eq [cpu time: 0ns, rows: 0] -> BOOLEAN [#8]\n"
" mod [cpu time: 0ns, rows: 0] -> BIGINT [#9]\n"
" cast(plus as BIGINT) [cpu time: 0ns, rows: 0] -> BIGINT [#10]\n"
" plus [cpu time: 0ns, rows: 0] -> INTEGER [#11]\n"
" c0 -> INTEGER [CSE #4]\n"
" c1 -> INTEGER [CSE #7]\n"
" 2:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT [#12]\n"
" 0:BIGINT [cpu time: 0ns, rows: 0] -> BIGINT [#13]\n");

evaluate(*exprSet, data);

// Check stats after evaluation.
ASSERT_THAT(
exec::printExprWithStats(*exprSet),
::testing::MatchesRegex(
"multiply .cpu time: .+, rows: 1024. -> BIGINT\n"
" plus .cpu time: .+, rows: 1024. -> BIGINT\n"
" cast.c0 as BIGINT. .cpu time: .+, rows: 1024. -> BIGINT\n"
" c0 .cpu time: 0ns, rows: 0. -> INTEGER\n"
" 3:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT\n"
" cast.c1 as BIGINT. .cpu time: .+, rows: 1024. -> BIGINT\n"
" c1 .cpu time: 0ns, rows: 0. -> INTEGER\n"
"multiply .cpu time: .+, rows: 1024. -> BIGINT .#1.\n"
" plus .cpu time: .+, rows: 1024. -> BIGINT .#2.\n"
" cast.c0 as BIGINT. .cpu time: .+, rows: 1024. -> BIGINT .#3.\n"
" c0 .cpu time: 0ns, rows: 0. -> INTEGER .#4.\n"
" 3:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#5.\n"
" cast.c1 as BIGINT. .cpu time: .+, rows: 1024. -> BIGINT .#6.\n"
" c1 .cpu time: 0ns, rows: 0. -> INTEGER .#7.\n"
"\n"
"eq .cpu time: .+, rows: 1024. -> BOOLEAN\n"
" mod .cpu time: .+, rows: 1024. -> BIGINT\n"
" cast.plus as BIGINT. .cpu time: .+, rows: 1024. -> BIGINT\n"
" plus .cpu time: .+, rows: 1024. -> INTEGER\n"
" c0 .cpu time: 0ns, rows: 0. -> INTEGER\n"
" c1 .cpu time: 0ns, rows: 0. -> INTEGER\n"
" 2:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT\n"
" 0:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT\n"));
"eq .cpu time: .+, rows: 1024. -> BOOLEAN .#8.\n"
" mod .cpu time: .+, rows: 1024. -> BIGINT .#9.\n"
" cast.plus as BIGINT. .cpu time: .+, rows: 1024. -> BIGINT .#10.\n"
" plus .cpu time: .+, rows: 1024. -> INTEGER .#11.\n"
" c0 -> INTEGER .CSE #4.\n"
" c1 -> INTEGER .CSE #7.\n"
" 2:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#12.\n"
" 0:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#13.\n"));
}

// Verify that common sub-expressions are identified properly.
{
auto exprSet =
compileExpressions({"(c0 + c1) % 5", "(c0 + c1) % 3"}, rowType);
evaluate(*exprSet, data);
ASSERT_THAT(
exec::printExprWithStats(*exprSet),
::testing::MatchesRegex(
"mod .cpu time: .+, rows: 1024. -> BIGINT .#1.\n"
" cast.plus as BIGINT. .cpu time: .+, rows: 1024. -> BIGINT .#2.\n"
" plus .cpu time: .+, rows: 1024. -> INTEGER .#3.\n"
" c0 .cpu time: 0ns, rows: 0. -> INTEGER .#4.\n"
" c1 .cpu time: 0ns, rows: 0. -> INTEGER .#5.\n"
" 5:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#6.\n"
"\n"
"mod .cpu time: .+, rows: 1024. -> BIGINT .#7.\n"
" cast..plus.c0, c1.. as BIGINT. -> BIGINT .CSE #2.\n"
" 3:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#8.\n"));
}

// Use dictionary encoding to repeat each row 5 times.
Expand All @@ -144,22 +164,22 @@ TEST_F(ExprStatsTest, printWithStats) {
ASSERT_THAT(
exec::printExprWithStats(*exprSet),
::testing::MatchesRegex(
"multiply .cpu time: .+, rows: 205. -> BIGINT\n"
" plus .cpu time: .+, rows: 205. -> BIGINT\n"
" cast.c0 as BIGINT. .cpu time: .+, rows: 205. -> BIGINT\n"
" c0 .cpu time: 0ns, rows: 0. -> INTEGER\n"
" 3:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT\n"
" cast.c1 as BIGINT. .cpu time: .+, rows: 205. -> BIGINT\n"
" c1 .cpu time: 0ns, rows: 0. -> INTEGER\n"
"multiply .cpu time: .+, rows: 205. -> BIGINT .#1.\n"
" plus .cpu time: .+, rows: 205. -> BIGINT .#2.\n"
" cast.c0 as BIGINT. .cpu time: .+, rows: 205. -> BIGINT .#3.\n"
" c0 .cpu time: 0ns, rows: 0. -> INTEGER .#4.\n"
" 3:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#5.\n"
" cast.c1 as BIGINT. .cpu time: .+, rows: 205. -> BIGINT .#6.\n"
" c1 .cpu time: 0ns, rows: 0. -> INTEGER .#7.\n"
"\n"
"eq .cpu time: .+, rows: 205. -> BOOLEAN\n"
" mod .cpu time: .+, rows: 205. -> BIGINT\n"
" cast.plus as BIGINT. .cpu time: .+, rows: 205. -> BIGINT\n"
" plus .cpu time: .+, rows: 205. -> INTEGER\n"
" c0 .cpu time: 0ns, rows: 0. -> INTEGER\n"
" c1 .cpu time: 0ns, rows: 0. -> INTEGER\n"
" 2:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT\n"
" 0:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT\n"));
"eq .cpu time: .+, rows: 205. -> BOOLEAN .#8.\n"
" mod .cpu time: .+, rows: 205. -> BIGINT .#9.\n"
" cast.plus as BIGINT. .cpu time: .+, rows: 205. -> BIGINT .#10.\n"
" plus .cpu time: .+, rows: 205. -> INTEGER .#11.\n"
" c0 -> INTEGER .CSE #4.\n"
" c1 -> INTEGER .CSE #7.\n"
" 2:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#12.\n"
" 0:BIGINT .cpu time: 0ns, rows: 0. -> BIGINT .#13.\n"));
}
}

Expand Down

0 comments on commit e74bc78

Please sign in to comment.