Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tsan report deadlock in SpillerTest #6902

Closed
JaySon-Huang opened this issue Feb 27, 2023 · 1 comment · Fixed by #6915
Closed

tsan report deadlock in SpillerTest #6902

JaySon-Huang opened this issue Feb 27, 2023 · 1 comment · Fixed by #6915
Assignees
Labels
severity/major type/bug The issue is confirmed as a bug.

Comments

@JaySon-Huang
Copy link
Contributor

JaySon-Huang commented Feb 27, 2023

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

run unittests with tsan check

2. What did you expect to see? (Required)

3. What did you see instead (Required)

https://ci.pingcap.net/blue/organizations/jenkins/tiflash-sanitizer-daily/detail/tiflash-sanitizer-daily/913/artifacts

[2023-02-26T18:29:01.105Z] �[0;33mNote: Google Test filter = SpillerTest.SpilledBlockDataSize
[2023-02-26T18:29:01.105Z] �[m�[0;32m[==========] �[mRunning 1 test from 1 test case.
[2023-02-26T18:29:01.105Z] �[0;32m[----------] �[mGlobal test environment set-up.
[2023-02-26T18:29:01.105Z] �[0;32m[----------] �[m1 test from SpillerTest
[2023-02-26T18:29:01.105Z] �[0;32m[ RUN      ] �[mSpillerTest.SpilledBlockDataSize
[2023-02-26T18:29:01.105Z] [2023/02/27 02:28:59.880 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.105Z] [2023/02/27 02:28:59.881 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.881 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (876585.524 rows/sec., 13.654 MiB/sec. uncompressed, 1.343 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.882 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.882 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.883 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1340806.093 rows/sec., 20.885 MiB/sec. uncompressed, 2.054 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.883 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.883 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.884 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1426330.053 rows/sec., 22.217 MiB/sec. uncompressed, 2.185 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.884 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.885 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.885 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1383400.121 rows/sec., 21.549 MiB/sec. uncompressed, 2.120 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.885 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.886 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] [2023/02/27 02:28:59.886 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1380268.600 rows/sec., 21.500 MiB/sec. uncompressed, 2.115 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:01.106Z] ==================
[2023-02-26T18:29:01.106Z] WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=31663)
[2023-02-26T18:29:01.106Z]   Cycle in lock order graph: M690030510927364224 (0x000000000000) => M688909993807999896 (0x000000000000) => M690030510927364224
[2023-02-26T18:29:01.106Z] 
[2023-02-26T18:29:01.106Z]   Mutex M688909993807999896 acquired here while holding mutex M690030510927364224 in main thread:
[2023-02-26T18:29:01.106Z]     #0 pthread_mutex_lock /llvm-project/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4249:3 (gtests_dbms+0x23fb098)
[2023-02-26T18:29:01.106Z]     #1 std::__1::mutex::lock() <null> (libc++.so.1+0x66f45)
[2023-02-26T18:29:01.106Z]     #2 DB::Spiller::spillBlocks(std::__1::vector<DB::Block, std::__1::allocator<DB::Block> > const&, unsigned long) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/Spiller.cpp:160:21 (gtests_dbms+0xbcca1bb)
[2023-02-26T18:29:01.106Z]     #3 DB::tests::SpillerTest_SpilledBlockDataSize_Test::TestBody() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/tests/gtest_spiller.cpp:208:17 (gtests_dbms+0x260ae5d)
[2023-02-26T18:29:01.106Z]     #4 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:01.107Z]     #5 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:01.107Z]     #6 testing::Test::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2517:5 (gtests_dbms+0xab23fb5)
[2023-02-26T18:29:01.107Z]     #7 testing::TestInfo::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2693:11 (gtests_dbms+0xab257e4)
[2023-02-26T18:29:01.107Z]     #8 testing::TestCase::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2811:28 (gtests_dbms+0xab264ad)
[2023-02-26T18:29:01.107Z]     #9 testing::internal::UnitTestImpl::RunAllTests() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:5177:43 (gtests_dbms+0xab36660)
[2023-02-26T18:29:01.107Z]     #10 bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:01.107Z]     #11 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:01.107Z]     #12 testing::UnitTest::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:4786:10 (gtests_dbms+0xab35948)
[2023-02-26T18:29:01.107Z]     #13 RUN_ALL_TESTS() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/include/gtest/gtest.h:2341:46 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:01.107Z]     #14 main /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/TestUtils/gtests_dbms_main.cpp:82:16 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:01.107Z] 
[2023-02-26T18:29:01.107Z]     Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get more informative warning message
[2023-02-26T18:29:01.107Z] 
[2023-02-26T18:29:01.107Z]   Mutex M690030510927364224 acquired here while holding mutex M688909993807999896 in main thread:
[2023-02-26T18:29:01.107Z]     #0 pthread_mutex_lock /llvm-project/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4249:3 (gtests_dbms+0x23fb098)
[2023-02-26T18:29:01.107Z]     #1 std::__1::mutex::lock() <null> (libc++.so.1+0x66f45)
[2023-02-26T18:29:01.107Z]     #2 DB::Spiller::finishSpill() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/Spiller.cpp:243:34 (gtests_dbms+0xbccc54f)
[2023-02-26T18:29:01.107Z]     #3 DB::tests::SpillerTest_SpilledBlockDataSize_Test::TestBody() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/tests/gtest_spiller.cpp:210:13 (gtests_dbms+0x260b032)
[2023-02-26T18:29:01.107Z]     #4 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:01.107Z]     #5 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:01.107Z]     #6 testing::Test::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2517:5 (gtests_dbms+0xab23fb5)
[2023-02-26T18:29:01.107Z]     #7 testing::TestInfo::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2693:11 (gtests_dbms+0xab257e4)
[2023-02-26T18:29:01.107Z]     #8 testing::TestCase::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2811:28 (gtests_dbms+0xab264ad)
[2023-02-26T18:29:01.107Z]     #9 testing::internal::UnitTestImpl::RunAllTests() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:5177:43 (gtests_dbms+0xab36660)
[2023-02-26T18:29:01.107Z]     #10 bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:01.108Z]     #11 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:01.108Z]     #12 testing::UnitTest::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:4786:10 (gtests_dbms+0xab35948)
[2023-02-26T18:29:01.108Z]     #13 RUN_ALL_TESTS() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/include/gtest/gtest.h:2341:46 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:01.108Z]     #14 main /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/TestUtils/gtests_dbms_main.cpp:82:16 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:01.108Z] 
[2023-02-26T18:29:01.108Z] SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) (/usr/local/lib/x86_64-unknown-linux-gnu/libc++.so.1+0x66f45) in std::__1::mutex::lock()
[2023-02-26T18:29:01.108Z] ==================
[2023-02-26T18:29:01.108Z] �[0;32m[       OK ] �[mSpillerTest.SpilledBlockDataSize (1030 ms)
[2023-02-26T18:29:01.108Z] �[0;32m[----------] �[m1 test from SpillerTest (1030 ms total)

4. What is your TiFlash version? (Required)

master

@JaySon-Huang JaySon-Huang added the type/bug The issue is confirmed as a bug. label Feb 27, 2023
@JaySon-Huang
Copy link
Contributor Author

[2023-02-26T18:29:02.708Z] �[0;32m[ RUN      ] �[mSpillerTest.SpillAndRestoreUnorderedBlocks
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.421 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.422 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.422 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (894710.472 rows/sec., 13.937 MiB/sec. uncompressed, 1.371 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.423 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.423 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.423 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1361865.938 rows/sec., 21.213 MiB/sec. uncompressed, 2.087 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.424 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.424 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.425 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1380624.318 rows/sec., 21.506 MiB/sec. uncompressed, 2.115 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.425 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.426 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.426 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1371459.919 rows/sec., 21.363 MiB/sec. uncompressed, 2.101 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.427 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.427 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.427 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1341453.599 rows/sec., 20.895 MiB/sec. uncompressed, 2.055 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.428 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.428 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.428 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1339967.662 rows/sec., 20.872 MiB/sec. uncompressed, 2.053 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.429 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.429 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.430 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1363177.840 rows/sec., 21.234 MiB/sec. uncompressed, 2.089 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.708Z] [2023/02/27 02:29:01.430 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.430 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.431 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1307736.570 rows/sec., 20.370 MiB/sec. uncompressed, 2.004 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.431 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.432 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.432 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1351564.436 rows/sec., 21.053 MiB/sec. uncompressed, 2.071 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.433 +08:00] [INFO] [SpillHandler.cpp:87] ["Spilling 3 blocks data into temporary file "] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.433 +08:00] [INFO] [SpillHandler.cpp:116] ["Spilled 300 rows from 3 blocks into temporary file, time cost: 0.000 sec."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] [2023/02/27 02:29:01.433 +08:00] [DEBUG] [SpillHandler.cpp:166] ["Commit spilled data, details: spill 300 rows in 0.000 sec, 0.005 MiB uncompressed, 0.000 MiB compressed, 16.333 uncompressed bytes per row, 1.607 compressed bytes per row, compression rate: 10.166 (1348581.292 rows/sec., 21.006 MiB/sec. uncompressed, 2.066 MiB/sec. compressed)"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.709Z] ==================
[2023-02-26T18:29:02.709Z] WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=32105)
[2023-02-26T18:29:02.709Z]   Cycle in lock order graph: M690030510927364128 (0x000000000000) => M688909995129644872 (0x000000000000) => M690030510927364128
[2023-02-26T18:29:02.709Z] 
[2023-02-26T18:29:02.709Z]   Mutex M688909995129644872 acquired here while holding mutex M690030510927364128 in main thread:
[2023-02-26T18:29:02.709Z]     #0 pthread_mutex_lock /llvm-project/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4249:3 (gtests_dbms+0x23fb098)
[2023-02-26T18:29:02.709Z]     #1 std::__1::mutex::lock() <null> (libc++.so.1+0x66f45)
[2023-02-26T18:29:02.709Z]     #2 DB::Spiller::spillBlocks(std::__1::vector<DB::Block, std::__1::allocator<DB::Block> > const&, unsigned long) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/Spiller.cpp:160:21 (gtests_dbms+0xbcca1bb)
[2023-02-26T18:29:02.709Z]     #3 DB::tests::SpillerTest_SpillAndRestoreUnorderedBlocks_Test::TestBody() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/tests/gtest_spiller.cpp:228:21 (gtests_dbms+0x260b91b)
[2023-02-26T18:29:02.709Z]     #4 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.709Z]     #5 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.709Z]     #6 testing::Test::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2517:5 (gtests_dbms+0xab23fb5)
[2023-02-26T18:29:02.709Z]     #7 testing::TestInfo::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2693:11 (gtests_dbms+0xab257e4)
[2023-02-26T18:29:02.709Z]     #8 testing::TestCase::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2811:28 (gtests_dbms+0xab264ad)
[2023-02-26T18:29:02.709Z]     #9 testing::internal::UnitTestImpl::RunAllTests() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:5177:43 (gtests_dbms+0xab36660)
[2023-02-26T18:29:02.709Z]     #10 bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.709Z]     #11 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.709Z]     #12 testing::UnitTest::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:4786:10 (gtests_dbms+0xab35948)
[2023-02-26T18:29:02.709Z]     #13 RUN_ALL_TESTS() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/include/gtest/gtest.h:2341:46 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.709Z]     #14 main /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/TestUtils/gtests_dbms_main.cpp:82:16 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.709Z] 
[2023-02-26T18:29:02.709Z]     Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get more informative warning message
[2023-02-26T18:29:02.709Z] 
[2023-02-26T18:29:02.709Z]   Mutex M690030510927364128 acquired here while holding mutex M688909995129644872 in main thread:
[2023-02-26T18:29:02.709Z]     #0 pthread_mutex_lock /llvm-project/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4249:3 (gtests_dbms+0x23fb098)
[2023-02-26T18:29:02.709Z]     #1 std::__1::mutex::lock() <null> (libc++.so.1+0x66f45)
[2023-02-26T18:29:02.709Z]     #2 DB::Spiller::finishSpill() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/Spiller.cpp:243:34 (gtests_dbms+0xbccc54f)
[2023-02-26T18:29:02.709Z]     #3 DB::tests::SpillerTest_SpillAndRestoreUnorderedBlocks_Test::TestBody() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/tests/gtest_spiller.cpp:231:13 (gtests_dbms+0x260bc1a)
[2023-02-26T18:29:02.710Z]     #4 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.710Z]     #5 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.710Z]     #6 testing::Test::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2517:5 (gtests_dbms+0xab23fb5)
[2023-02-26T18:29:02.710Z]     #7 testing::TestInfo::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2693:11 (gtests_dbms+0xab257e4)
[2023-02-26T18:29:02.710Z]     #8 testing::TestCase::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2811:28 (gtests_dbms+0xab264ad)
[2023-02-26T18:29:02.710Z]     #9 testing::internal::UnitTestImpl::RunAllTests() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:5177:43 (gtests_dbms+0xab36660)
[2023-02-26T18:29:02.710Z]     #10 bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.710Z]     #11 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.710Z]     #12 testing::UnitTest::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:4786:10 (gtests_dbms+0xab35948)
[2023-02-26T18:29:02.710Z]     #13 RUN_ALL_TESTS() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/include/gtest/gtest.h:2341:46 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.710Z]     #14 main /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/TestUtils/gtests_dbms_main.cpp:82:16 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.710Z] 
[2023-02-26T18:29:02.710Z] SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) (/usr/local/lib/x86_64-unknown-linux-gnu/libc++.so.1+0x66f45) in std::__1::mutex::lock()
[2023-02-26T18:29:02.710Z] ==================
[2023-02-26T18:29:02.710Z] ==================
[2023-02-26T18:29:02.710Z] WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=32105)
[2023-02-26T18:29:02.710Z]   Cycle in lock order graph: M700445085065658496 (0x000000000000) => M688909995129644872 (0x000000000000) => M700445085065658496
[2023-02-26T18:29:02.710Z] 
[2023-02-26T18:29:02.710Z]   Mutex M688909995129644872 acquired here while holding mutex M700445085065658496 in main thread:
[2023-02-26T18:29:02.710Z]     #0 pthread_mutex_lock /llvm-project/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4249:3 (gtests_dbms+0x23fb098)
[2023-02-26T18:29:02.710Z]     #1 std::__1::mutex::lock() <null> (libc++.so.1+0x66f45)
[2023-02-26T18:29:02.710Z]     #2 DB::Spiller::spillBlocks(std::__1::vector<DB::Block, std::__1::allocator<DB::Block> > const&, unsigned long) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/Spiller.cpp:160:21 (gtests_dbms+0xbcca1bb)
[2023-02-26T18:29:02.710Z]     #3 DB::tests::SpillerTest_SpillAndRestoreUnorderedBlocks_Test::TestBody() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/tests/gtest_spiller.cpp:228:21 (gtests_dbms+0x260baad)
[2023-02-26T18:29:02.710Z]     #4 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.710Z]     #5 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.710Z]     #6 testing::Test::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2517:5 (gtests_dbms+0xab23fb5)
[2023-02-26T18:29:02.710Z]     #7 testing::TestInfo::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2693:11 (gtests_dbms+0xab257e4)
[2023-02-26T18:29:02.710Z]     #8 testing::TestCase::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2811:28 (gtests_dbms+0xab264ad)
[2023-02-26T18:29:02.710Z]     #9 testing::internal::UnitTestImpl::RunAllTests() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:5177:43 (gtests_dbms+0xab36660)
[2023-02-26T18:29:02.710Z]     #10 bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.710Z]     #11 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.710Z]     #12 testing::UnitTest::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:4786:10 (gtests_dbms+0xab35948)
[2023-02-26T18:29:02.710Z]     #13 RUN_ALL_TESTS() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/include/gtest/gtest.h:2341:46 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.710Z]     #14 main /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/TestUtils/gtests_dbms_main.cpp:82:16 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.710Z] 
[2023-02-26T18:29:02.710Z]     Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get more informative warning message
[2023-02-26T18:29:02.710Z] 
[2023-02-26T18:29:02.710Z]   Mutex M700445085065658496 acquired here while holding mutex M688909995129644872 in main thread:
[2023-02-26T18:29:02.711Z]     #0 pthread_mutex_lock /llvm-project/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4249:3 (gtests_dbms+0x23fb098)
[2023-02-26T18:29:02.711Z]     #1 std::__1::mutex::lock() <null> (libc++.so.1+0x66f45)
[2023-02-26T18:29:02.711Z]     #2 DB::Spiller::finishSpill() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/Spiller.cpp:243:34 (gtests_dbms+0xbccc54f)
[2023-02-26T18:29:02.711Z]     #3 DB::tests::SpillerTest_SpillAndRestoreUnorderedBlocks_Test::TestBody() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/Core/tests/gtest_spiller.cpp:231:13 (gtests_dbms+0x260bc1a)
[2023-02-26T18:29:02.711Z]     #4 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.711Z]     #5 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4a415)
[2023-02-26T18:29:02.711Z]     #6 testing::Test::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2517:5 (gtests_dbms+0xab23fb5)
[2023-02-26T18:29:02.711Z]     #7 testing::TestInfo::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2693:11 (gtests_dbms+0xab257e4)
[2023-02-26T18:29:02.711Z]     #8 testing::TestCase::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2811:28 (gtests_dbms+0xab264ad)
[2023-02-26T18:29:02.711Z]     #9 testing::internal::UnitTestImpl::RunAllTests() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:5177:43 (gtests_dbms+0xab36660)
[2023-02-26T18:29:02.711Z]     #10 bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2443:10 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.711Z]     #11 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:2479:14 (gtests_dbms+0xab4b8b5)
[2023-02-26T18:29:02.711Z]     #12 testing::UnitTest::Run() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/src/gtest.cc:4786:10 (gtests_dbms+0xab35948)
[2023-02-26T18:29:02.711Z]     #13 RUN_ALL_TESTS() /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/contrib/googletest/googletest/include/gtest/gtest.h:2341:46 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.711Z]     #14 main /home/jenkins/agent/workspace/tiflash-sanitizer-daily/tiflash/dbms/src/TestUtils/gtests_dbms_main.cpp:82:16 (gtests_dbms+0x70e3cd2)
[2023-02-26T18:29:02.711Z] 
[2023-02-26T18:29:02.711Z] SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) (/usr/local/lib/x86_64-unknown-linux-gnu/libc++.so.1+0x66f45) in std::__1::mutex::lock()
[2023-02-26T18:29:02.711Z] ==================
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.419 +08:00] [TRACE] [Spiller.cpp:219] ["Restore 900 rows from 0-th stream"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.419 +08:00] [TRACE] [Spiller.cpp:219] ["Restore 600 rows from 1-th stream"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.419 +08:00] [INFO] [Spiller.cpp:220] ["Will restore 1500 rows from 5 files of size 0.002 MiB compressed, 0.023 MiB uncompressed using 2 streams."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.439 +08:00] [TRACE] [Spiller.cpp:219] ["Restore 300 rows from 0-th stream"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.439 +08:00] [TRACE] [Spiller.cpp:219] ["Restore 300 rows from 1-th stream"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.439 +08:00] [TRACE] [Spiller.cpp:219] ["Restore 300 rows from 2-th stream"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.439 +08:00] [TRACE] [Spiller.cpp:219] ["Restore 300 rows from 3-th stream"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.439 +08:00] [TRACE] [Spiller.cpp:219] ["Restore 300 rows from 4-th stream"] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] [2023/02/27 02:29:02.439 +08:00] [INFO] [Spiller.cpp:220] ["Will restore 1500 rows from 5 files of size 0.002 MiB compressed, 0.023 MiB uncompressed using 5 streams."] [source=SpillerTest] [thread_id=1]
[2023-02-26T18:29:02.711Z] �[0;32m[       OK ] �[mSpillerTest.SpillAndRestoreUnorderedBlocks (1036 ms)
[2023-02-26T18:29:02.711Z] �[0;32m[----------] �[m1 test from SpillerTest (1036 ms total)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
severity/major type/bug The issue is confirmed as a bug.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants