This is an automated email from the ASF dual-hosted git repository.
marin-ma pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/gluten.git
The following commit(s) were added to refs/heads/main by this push:
new d35552e625 [VL] Fix SCOPED_TIMER macro destroying timer immediately
(#12083)
d35552e625 is described below
commit d35552e62551f1042811a907e0668df086853816
Author: Luis Peñaranda <[email protected]>
AuthorDate: Thu May 14 18:01:21 2026 +0200
[VL] Fix SCOPED_TIMER macro destroying timer immediately (#12083)
---
cpp/core/utils/Macros.h | 3 +-
cpp/velox/tests/CMakeLists.txt | 1 +
cpp/velox/tests/ScopedTimerTest.cc | 88 ++++++++++++++++++++++++++++++++++++++
cpp/velox/utils/Common.h | 28 +++++++++---
4 files changed, 113 insertions(+), 7 deletions(-)
diff --git a/cpp/core/utils/Macros.h b/cpp/core/utils/Macros.h
index 74128cca35..cbdfdcbc2e 100644
--- a/cpp/core/utils/Macros.h
+++ b/cpp/core/utils/Macros.h
@@ -28,7 +28,8 @@
#define GLUTEN_EXPAND(x) x
#define GLUTEN_STRINGIFY(x) #x
#define GLUTEN_TOSTRING(x) GLUTEN_STRINGIFY(x)
-#define GLUTEN_CONCAT(x, y) x##y
+#define GLUTEN_CONCAT_INNER(x, y) x##y
+#define GLUTEN_CONCAT(x, y) GLUTEN_CONCAT_INNER(x, y)
#define TIME_NANO_DIFF(finish, start) (finish.tv_sec - start.tv_sec) *
1000000000 + (finish.tv_nsec - start.tv_nsec)
diff --git a/cpp/velox/tests/CMakeLists.txt b/cpp/velox/tests/CMakeLists.txt
index 37d9cfb238..0cd9e38bc6 100644
--- a/cpp/velox/tests/CMakeLists.txt
+++ b/cpp/velox/tests/CMakeLists.txt
@@ -134,6 +134,7 @@ add_velox_test(spark_functions_test SOURCES
SparkFunctionTest.cc
add_velox_test(runtime_test SOURCES RuntimeTest.cc)
add_velox_test(velox_memory_test SOURCES MemoryManagerTest.cc)
add_velox_test(buffer_outputstream_test SOURCES BufferOutputStreamTest.cc)
+add_velox_test(scoped_timer_test SOURCES ScopedTimerTest.cc)
if(BUILD_EXAMPLES)
add_velox_test(my_udf_test SOURCES MyUdfTest.cc)
endif()
diff --git a/cpp/velox/tests/ScopedTimerTest.cc
b/cpp/velox/tests/ScopedTimerTest.cc
new file mode 100644
index 0000000000..09479cb9f4
--- /dev/null
+++ b/cpp/velox/tests/ScopedTimerTest.cc
@@ -0,0 +1,88 @@
+/*
+ * 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.
+ */
+
+#include "utils/Common.h"
+
+#include <gtest/gtest.h>
+
+#include <chrono>
+#include <thread>
+
+#include "velox/common/time/CpuWallTimer.h"
+
+namespace gluten {
+
+// Regression test: SCOPED_TIMER must accumulate elapsed time across the
+// enclosing scope. A previous implementation wrapped the underlying
+// DeltaCpuWallTimer in a `do { ... } while (0)` block, which destroyed the
+// timer immediately after construction and recorded ~0 ns. See
+// https://github.com/apache/gluten/pull/<this-PR>.
+TEST(ScopedTimerTest, accumulatesElapsedTime) {
+ facebook::velox::CpuWallTiming timing{};
+ constexpr auto kSleep = std::chrono::milliseconds(50);
+
+ {
+ SCOPED_TIMER(timing);
+ std::this_thread::sleep_for(kSleep);
+ }
+
+ EXPECT_EQ(timing.count, 1);
+ // The sleep is on wall clock, not CPU. Allow a generous lower bound
+ // to tolerate scheduler jitter on CI.
+ constexpr uint64_t kMinWallNanos = std::chrono::nanoseconds(kSleep).count()
/ 2;
+ EXPECT_GT(timing.wallNanos, kMinWallNanos);
+}
+
+// Multiple SCOPED_TIMER calls in the same scope must each accumulate
+// independently. The unique-naming pattern in the macro (using __LINE__)
+// is what makes this work.
+TEST(ScopedTimerTest, multipleTimersInSameScope) {
+ facebook::velox::CpuWallTiming timing1{};
+ facebook::velox::CpuWallTiming timing2{};
+ constexpr auto kSleep = std::chrono::milliseconds(20);
+
+ {
+ SCOPED_TIMER(timing1);
+ SCOPED_TIMER(timing2);
+ std::this_thread::sleep_for(kSleep);
+ }
+
+ EXPECT_EQ(timing1.count, 1);
+ EXPECT_EQ(timing2.count, 1);
+ constexpr uint64_t kMinWallNanos = std::chrono::nanoseconds(kSleep).count()
/ 2;
+ EXPECT_GT(timing1.wallNanos, kMinWallNanos);
+ EXPECT_GT(timing2.wallNanos, kMinWallNanos);
+}
+
+// SCOPED_TIMER must accept arbitrary lvalue expressions (e.g. an array
+// element) as the timing target, not just simple identifiers.
+TEST(ScopedTimerTest, acceptsArrayElementAsTarget) {
+ std::vector<facebook::velox::CpuWallTiming> timings(2);
+ constexpr auto kSleep = std::chrono::milliseconds(20);
+
+ {
+ SCOPED_TIMER(timings[1]);
+ std::this_thread::sleep_for(kSleep);
+ }
+
+ EXPECT_EQ(timings[0].count, 0);
+ EXPECT_EQ(timings[1].count, 1);
+ constexpr uint64_t kMinWallNanos = std::chrono::nanoseconds(kSleep).count()
/ 2;
+ EXPECT_GT(timings[1].wallNanos, kMinWallNanos);
+}
+
+} // namespace gluten
diff --git a/cpp/velox/utils/Common.h b/cpp/velox/utils/Common.h
index 6dd92b409d..5c82d0ee69 100644
--- a/cpp/velox/utils/Common.h
+++ b/cpp/velox/utils/Common.h
@@ -21,6 +21,7 @@
#include <memory>
#include <string>
+#include "utils/Macros.h"
#include "velox/common/base/SimdUtil.h"
#include "velox/common/time/CpuWallTimer.h"
@@ -35,11 +36,26 @@ static inline void fastCopy(void* dst, const void* src,
size_t n) {
facebook::velox::simd::memcpy(dst, src, n);
}
-#define SCOPED_TIMER(timing)
\
- do {
\
- auto ptiming = &timing;
\
- facebook::velox::DeltaCpuWallTimer timer{
\
- [ptiming](const facebook::velox::CpuWallTiming& delta) {
ptiming->add(delta); }}; \
- } while (0)
+// SCOPED_TIMER — RAII-style timer that lives until the end of the
+// enclosing scope and reports elapsed CPU+wall time to `timing` on
+// destruction.
+//
+// Implementation note: a `do { … } while (0)` wrapper would destroy
+// the DeltaCpuWallTimer immediately at the end of the do-block,
+// recording essentially zero. Instead we declare uniquely-named
+// locals (via GLUTEN_CONCAT(..., __LINE__)) so the timer survives
+// until the enclosing scope closes — which is what every call site
+// already expects.
+//
+// Note: we capture the timing target by pointer in a unique local
+// variable rather than directly in the lambda, because `timing` may
+// be an arbitrary expression (e.g. `array_[idx]`) that is not a valid
+// lambda capture name.
+#define SCOPED_TIMER(timing)
\
+ auto GLUTEN_CONCAT(_glutenScopedTimerTarget_, __LINE__) = &(timing);
\
+ facebook::velox::DeltaCpuWallTimer GLUTEN_CONCAT(_glutenScopedTimer_,
__LINE__) { \
+ [_glutenScopedTimerTargetPtr = GLUTEN_CONCAT(_glutenScopedTimerTarget_,
__LINE__)]( \
+ const facebook::velox::CpuWallTiming& delta) {
_glutenScopedTimerTargetPtr->add(delta); } \
+ }
} // namespace gluten
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
