[ https://issues.apache.org/jira/browse/KUDU-3129?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17136729#comment-17136729 ]
Alexey Serbin commented on KUDU-3129: ------------------------------------- The test also times out in case of RELEASE builds: the log is attached. [^kudu-tool-test.2.txt.xz] > ToolTest.TestHmsList can timeout > -------------------------------- > > Key: KUDU-3129 > URL: https://issues.apache.org/jira/browse/KUDU-3129 > Project: Kudu > Issue Type: Bug > Components: hms, test > Affects Versions: 1.12.0 > Reporter: Andrew Wong > Priority: Major > Attachments: kudu-tool-test.2.txt, kudu-tool-test.2.txt.xz > > > When running in TSAN mode, the test timed out, spending 10 minutes not really > doing anything. It isn't obvious why, but ToolTest.TestHmsList can timeout, > appearing to hang while running the HMS tool. > {code} > I0521 22:31:49.436857 4601 catalog_manager.cc:1161] Initializing in-progress > tserver states... > I0521 22:31:49.446161 4606 hms_notification_log_listener.cc:228] Skipping > Hive Metastore notification log poll: Service unavailable: Catalog manager is > not initialized. State: Starting > I0521 22:31:49.839709 4488 heartbeater.cc:325] Connected to a master server > at 127.0.89.254:42487 > I0521 22:31:49.845547 4559 master_service.cc:295] Got heartbeat from unknown > tserver (permanent_uuid: "cf9e08c4271e4d9aa28b1aacbd630908" instance_seqno: > 1590100304311876) as {username='slave'} at 127.0.89.193:33867; Asking this > server to re-register. > I0521 22:31:49.846786 4488 heartbeater.cc:416] Registering TS with master... > I0521 22:31:49.847297 4488 heartbeater.cc:465] Master 127.0.89.254:42487 > requested a full tablet report, sending... > I0521 22:31:49.849771 4559 ts_manager.cc:191] Registered new tserver with > Master: cf9e08c4271e4d9aa28b1aacbd630908 (127.0.89.193:43527) > I0521 22:31:49.852535 359 external_mini_cluster.cc:699] 1 TS(s) registered > with all masters > W0521 22:32:23.142868 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b060 after lost signal to thread 4531 > W0521 22:32:23.143333 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b780 after lost signal to thread 4591 > W0521 22:32:28.996440 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b740 after lost signal to thread 4531 > W0521 22:32:28.996966 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b520 after lost signal to thread 4591 > W0521 22:33:05.743249 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002aae0 after lost signal to thread 4360 > W0521 22:33:05.743983 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002af00 after lost signal to thread 4486 > I0521 22:33:49.594769 4549 maintenance_manager.cc:326] P > c3cc85c33a5447b2aa520019fe162966: Scheduling > FlushMRSOp(00000000000000000000000000000000): perf score=0.033386 > I0521 22:33:49.637208 4548 maintenance_manager.cc:525] P > c3cc85c33a5447b2aa520019fe162966: > FlushMRSOp(00000000000000000000000000000000) complete. Timing: real 0.042s > user 0.032s sys 0.008s Metrics: > {"bytes_written":6485,"cfile_init":1,"dirs.queue_time_us":675,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":997,"drs_written":1,"lbm_read_time_us":231,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1980,"lbm_writes_lt_1ms":27,"rows_written":5,"thread_start_us":953,"threads_started":2,"wal-append.queue_time_us":819} > I0521 22:33:49.639096 4549 maintenance_manager.cc:326] P > c3cc85c33a5447b2aa520019fe162966: Scheduling > UndoDeltaBlockGCOp(00000000000000000000000000000000): 396 bytes on disk > I0521 22:33:49.640486 4548 maintenance_manager.cc:525] P > c3cc85c33a5447b2aa520019fe162966: > UndoDeltaBlockGCOp(00000000000000000000000000000000) complete. Timing: real > 0.001s user 0.001s sys 0.000s Metrics: > {"cfile_init":1,"lbm_read_time_us":269,"lbm_reads_lt_1ms":4} > W0521 22:34:17.794472 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002ade0 after lost signal to thread 4360 > W0521 22:34:17.795437 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a7e0 after lost signal to thread 4486 > W0521 22:34:20.286921 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b2e0 after lost signal to thread 4531 > W0521 22:34:20.287376 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b140 after lost signal to thread 4591 > W0521 22:35:27.726336 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002af40 after lost signal to thread 4360 > W0521 22:35:27.727084 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a980 after lost signal to thread 4486 > W0521 22:36:12.250830 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b9c0 after lost signal to thread 4531 > W0521 22:36:12.251247 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b220 after lost signal to thread 4591 > W0521 22:36:34.702325 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b800 after lost signal to thread 4531 > W0521 22:36:34.702808 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b700 after lost signal to thread 4591 > W0521 22:37:03.237411 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002ab20 after lost signal to thread 4360 > W0521 22:37:03.238131 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a8e0 after lost signal to thread 4486 > W0521 22:37:27.446748 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b320 after lost signal to thread 4531 > W0521 22:37:27.447190 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080008a460 after lost signal to thread 4591 > W0521 22:38:26.852612 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b7c0 after lost signal to thread 4531 > W0521 22:38:26.853031 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b8c0 after lost signal to thread 4591 > W0521 22:38:28.039356 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a9a0 after lost signal to thread 4360 > W0521 22:38:28.040096 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002ad80 after lost signal to thread 4486 > W0521 22:38:45.889757 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002aa60 after lost signal to thread 4360 > W0521 22:38:45.890512 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a0a0 after lost signal to thread 4486 > W0521 22:39:57.414119 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002ae60 after lost signal to thread 4360 > W0521 22:39:57.414861 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a140 after lost signal to thread 4486 > W0521 22:40:04.007081 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b240 after lost signal to thread 4531 > W0521 22:40:04.007515 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b8a0 after lost signal to thread 4591 > W0521 22:40:41.883837 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a880 after lost signal to thread 4360 > W0521 22:40:41.884637 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002ace0 after lost signal to thread 4486 > W0521 22:41:06.952173 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b0800058020 after lost signal to thread 4360 > W0521 22:41:06.952941 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002a6e0 after lost signal to thread 4486 > W0521 22:41:36.942020 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b560 after lost signal to thread 4531 > W0521 22:41:36.942495 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b4a0 after lost signal to thread 4591 > W0521 22:42:02.273381 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002bb20 after lost signal to thread 4531 > W0521 22:42:02.273813 4545 debug-util.cc:402] Leaking SignalData structure > 0x7b080002b0e0 after lost signal to thread 4591 > W0521 22:42:37.898852 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002acc0 after lost signal to thread 4360 > W0521 22:42:37.899608 4380 debug-util.cc:402] Leaking SignalData structure > 0x7b080002aca0 after lost signal to thread 4486 > ************************ BEGIN STACKS ************************** > [New LWP 4501] > [New LWP 4500] > ... > Thread 1 (Thread 0x7ff8a61a2400 (LWP 359)): > #0 0x00007ff892b40693 in epoll_wait () at > ../sysdeps/unix/syscall-template.S:81 > #1 0x00000000004db89e in __interceptor_epoll_wait (epfd=31, > ev=0x7b580000c900, cnt=64, timeout=59743) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/llvm-9.0.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1829 > #2 0x00007ff89571275d in epoll_poll (loop=0x7b64000d7a00, > timeout=59.743000000000002) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/libev-4.20/ev_epoll.c:153 > #3 0x00007ff8957068c2 in ev_run (loop=0x7b64000d7a00, flags=0) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/libev-4.20/ev.c:3521 > #4 0x00007ff898d8f539 in ev::loop_ref::run (this=0x7ffcdcd2ca40, > flags=51456) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/installed/tsan/include/ev++.h:211 > #5 0x00007ff896d57b1d in kudu::(anonymous namespace)::ReadFdsFully > (progname=..., fds=..., out=0x7ffcdcd2cb70) at > /home/jenkins-slave/workspace/kudu-master/0/src/kudu/util/subprocess.cc:242 > #6 0x00007ff896d5754a in kudu::Subprocess::Call (argv=..., stdin_in=..., > stdout_out=<optimized out>, stderr_out=0x7ffcdcd2cd78, env_vars=...) at > /home/jenkins-slave/workspace/kudu-master/0/src/kudu/util/subprocess.cc:771 > #7 0x00007ff8a5781532 in kudu::tools::RunKuduTool (args=..., > out=0x7ffcdcd2cd60, err=0x7ffcdcd2cd78, in=...) at > /home/jenkins-slave/workspace/kudu-master/0/src/kudu/tools/tool_test_util.cc:77 > #8 0x00000000005f0905 in kudu::tools::ToolTest::RunTool (this=<optimized > out>, arg_str=..., stdout=0x7ffcdcd2d580, stderr=0x7ffcdcd2cdf8, > stdout_lines=0x0, stderr_lines=0x0, in=...) at > /home/jenkins-slave/workspace/kudu-master/0/src/kudu/tools/kudu-tool-test.cc:246 > #9 0x00000000005f52ea in kudu::tools::ToolTest::RunActionStdoutString > (this=0x7b2000001080, arg_str=..., stdout=0x7ffcdcd2d580) at > /home/jenkins-slave/workspace/kudu-master/0/src/kudu/tools/kudu-tool-test.cc:283 > #10 0x00000000005cb481 in kudu::tools::ToolTest_TestHmsList_Test::TestBody > (this=0x7b2000001080) at > /home/jenkins-slave/workspace/kudu-master/0/src/kudu/tools/kudu-tool-test.cc:4588 > #11 0x00007ff8a3d32fa0 in > HandleSehExceptionsInMethodIfSupported<testing::Test, void> > (object=0x7b2000001080, method=<optimized out>, location=0x7ff8a3d50c8a "the > test body") at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:2402 > #12 testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, > void> (object=<optimized out>, method=<optimized out>, > location=0x7ff8a3d50c8a "the test body") at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:2438 > #13 0x00007ff8a3d11f39 in testing::Test::Run (this=0x7b2000001080) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:2474 > #14 0x00007ff8a3d131dd in testing::TestInfo::Run (this=0x7b3c00001d10) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:2656 > #15 0x00007ff8a3d13ef7 in testing::TestCase::Run (this=<optimized out>) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:2774 > #16 0x00007ff8a3d203a7 in testing::internal::UnitTestImpl::RunAllTests > (this=<optimized out>) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:4649 > #17 0x00007ff8a3d33e50 in > HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool> > (object=0x7b5000000200, method=<optimized out>, location=0x7ff8a3d5138b > "auxiliary test code (environments or event listeners)") at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:2402 > #18 > testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, > bool> (object=<optimized out>, method=<optimized out>, > location=0x7ff8a3d5138b "auxiliary test code (environments or event > listeners)") at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:2438 > #19 0x00007ff8a3d1fc62 in testing::UnitTest::Run (this=<optimized out>) at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/src/googletest-release-1.8.0/googletest/src/gtest.cc:4257 > #20 0x00007ff8a45b570c in RUN_ALL_TESTS () at > /home/jenkins-slave/workspace/kudu-master/0/thirdparty/installed/tsan/include/gtest/gtest.h:2233 > #21 0x00007ff8a45b4587 in main (argc=1, argv=0x7ffcdcd2daf8) at > /home/jenkins-slave/workspace/kudu-master/0/src/kudu/util/test_main.cc:106 > #22 0x00007ff892a63f45 in __libc_start_main (main=0x4c1470 <main@plt>, > argc=3, argv=0x7ffcdcd2dae8, init=<optimized out>, fini=<optimized out>, > rtld_fini=<optimized out>, stack_end=0x7ffcdcd2dad8) at libc-start.c:287 > #23 0x00000000004c8ea8 in _start () > {code} -- This message was sent by Atlassian Jira (v8.3.4#803005)