-
Type:
Build Failure
-
Resolution: Unresolved
-
Priority:
Minor - P4
-
None
-
Affects Version/s: None
-
Component/s: RTS
-
Storage Engines, Storage Engines - Persistence
-
None
-
5
-
0
test_timestamp_abort kills the child, runs recovery, but takes a long time (> an hour) to finish recovery. Here's the output:
[2025/06/16 07:14:16.959] Running test command: ./test_timestamp_abort -PT -Po s3_store [2025/06/16 07:14:16.959] Parent: compatibility: false, in-mem log sync: false, add timing stress: false, timestamp in use: true [2025/06/16 07:14:16.959] Parent: backups: false, full backup interval: 4, force stop interval: 3 [2025/06/16 07:14:16.959] Parent: Create 68 threads; sleep 105 seconds [2025/06/16 07:14:16.959] CONFIG: test_timestamp_abort -PT -F 4 -h WT_TEST.test_timestamp_abort -I 1 -T 68 -t 105 -PSD14443512,E6366452 [2025/06/16 07:14:18.586] Create checkpoint thread [2025/06/16 07:14:18.586] Create timestamp thread [2025/06/16 07:14:18.586] Create 68 writer threads [2025/06/16 07:14:18.586] Thread 1 starts at 1001000000000 [2025/06/16 07:14:18.587] Thread 4 starts at 1004000000000 [2025/06/16 07:14:18.587] Thread 0 starts at 1000000000000 [2025/06/16 07:14:18.587] Thread 3 starts at 1003000000000 [2025/06/16 07:14:18.591] Thread 2 starts at 1002000000000 [2025/06/16 07:14:18.591] Thread 6 starts at 1006000000000 [2025/06/16 07:14:18.591] Thread 11 starts at 1011000000000 [2025/06/16 07:14:18.591] Thread 5 starts at 1005000000000 [2025/06/16 07:14:18.594] Thread 15 starts at 1015000000000 [2025/06/16 07:14:18.594] Thread 17 starts at 1017000000000 [2025/06/16 07:14:18.594] Thread 7 starts at 1007000000000 [2025/06/16 07:14:18.598] Thread 14 starts at 1014000000000 [2025/06/16 07:14:18.598] Thread 16 starts at 1016000000000 [2025/06/16 07:14:18.598] Thread 13 starts at 1013000000000 [2025/06/16 07:14:18.599] Thread 12 starts at 1012000000000 [2025/06/16 07:14:18.599] Thread 18 starts at 1018000000000 [2025/06/16 07:14:18.599] Thread 9 starts at 1009000000000 [2025/06/16 07:14:18.612] Thread 8 starts at 1008000000000 [2025/06/16 07:14:18.612] Thread 10 starts at 1010000000000 [2025/06/16 07:14:18.612] Thread 21 starts at 1021000000000 [2025/06/16 07:14:18.614] Thread 22 starts at 1022000000000 [2025/06/16 07:14:18.614] Thread 31 starts at 1031000000000 [2025/06/16 07:14:18.614] Thread 27 starts at 1027000000000 [2025/06/16 07:14:18.614] Thread 44 starts at 1044000000000 [2025/06/16 07:14:18.614] Thread 39 starts at 1039000000000 [2025/06/16 07:14:18.615] Thread 66 starts at 1066000000000 [2025/06/16 07:14:18.615] Thread 28 starts at 1028000000000 [2025/06/16 07:14:18.615] Thread 32 starts at 1032000000000 [2025/06/16 07:14:18.615] Thread 43 starts at 1043000000000 [2025/06/16 07:14:18.615] Thread 29 starts at 1029000000000 [2025/06/16 07:14:18.615] Thread 42 starts at 1042000000000 [2025/06/16 07:14:18.615] Thread 63 starts at 1063000000000 [2025/06/16 07:14:18.615] Thread 36 starts at 1036000000000 [2025/06/16 07:14:18.615] Thread 30 starts at 1030000000000 [2025/06/16 07:14:18.615] Thread 34 starts at 1034000000000 [2025/06/16 07:14:18.630] Thread 19 starts at 1019000000000 [2025/06/16 07:14:18.631] Thread 67 starts at 1067000000000 [2025/06/16 07:14:18.631] Thread 65 starts at 1065000000000 [2025/06/16 07:14:18.631] Thread 33 starts at 1033000000000 [2025/06/16 07:14:18.631] Thread 64 starts at 1064000000000 [2025/06/16 07:14:18.631] Thread 26 starts at 1026000000000 [2025/06/16 07:14:18.638] Thread 25 starts at 1025000000000 [2025/06/16 07:14:18.638] Thread 20 starts at 1020000000000 [2025/06/16 07:14:18.638] Thread 53 starts at 1053000000000 [2025/06/16 07:14:18.641] Thread 58 starts at 1058000000000 [2025/06/16 07:14:18.641] Thread 41 starts at 1041000000000 [2025/06/16 07:14:18.641] Thread 48 starts at 1048000000000 [2025/06/16 07:14:18.642] Thread 24 starts at 1024000000000 [2025/06/16 07:14:18.642] Thread 61 starts at 1061000000000 [2025/06/16 07:14:18.642] Thread 57 starts at 1057000000000 [2025/06/16 07:14:18.643] Thread 46 starts at 1046000000000 [2025/06/16 07:14:18.643] Thread 23 starts at 1023000000000 [2025/06/16 07:14:18.643] Thread 47 starts at 1047000000000 [2025/06/16 07:14:18.644] Thread 50 starts at 1050000000000 [2025/06/16 07:14:18.644] Thread 49 starts at 1049000000000 [2025/06/16 07:14:18.644] Thread 52 starts at 1052000000000 [2025/06/16 07:14:18.644] Thread 54 starts at 1054000000000 [2025/06/16 07:14:18.644] Thread 38 starts at 1038000000000 [2025/06/16 07:14:18.644] Thread 37 starts at 1037000000000 [2025/06/16 07:14:18.644] Thread 60 starts at 1060000000000 [2025/06/16 07:14:18.644] Thread 45 starts at 1045000000000 [2025/06/16 07:14:18.644] Thread 35 starts at 1035000000000 [2025/06/16 07:14:18.644] Thread 62 starts at 1062000000000 [2025/06/16 07:14:18.644] Thread 56 starts at 1056000000000 [2025/06/16 07:14:18.644] Thread 40 starts at 1040000000000 [2025/06/16 07:14:18.673] Thread 51 starts at 1051000000000 [2025/06/16 07:14:18.673] Thread 55 starts at 1055000000000 [2025/06/16 07:14:18.673] Thread 59 starts at 1059000000000 [2025/06/16 07:14:20.339] Checkpoint 1 start: Flush: NO. [2025/06/16 07:14:20.339] Checkpoint 1 complete: Flush: NO, at stable 1000015127. [2025/06/16 07:14:21.284] Checkpoint 2 start: Flush: NO. [2025/06/16 07:14:21.284] Checkpoint 2 complete: Flush: NO, at stable 1000030049. [2025/06/16 07:14:26.964] Checkpoint 3 start: Flush: NO. [2025/06/16 07:14:26.964] Checkpoint 3 complete: Flush: NO, at stable 1000119341. [2025/06/16 07:14:58.526] Checkpoint 4 start: Flush: YES. [2025/06/16 07:14:58.526] Checkpoint 4 complete: Flush: YES, at stable 1000153817. [2025/06/16 07:14:58.526] Finished a flush_tier [2025/06/16 07:15:02.161] Checkpoint 5 start: Flush: NO. [2025/06/16 07:15:02.161] Checkpoint 5 complete: Flush: NO, at stable 1000671977. [2025/06/16 07:15:02.161] Checkpoint 6 start: Flush: YES. [2025/06/16 07:15:44.806] Checkpoint 6 complete: Flush: YES, at stable 1000691969. [2025/06/16 07:15:44.806] Finished a flush_tier [2025/06/16 07:15:44.806] Checkpoint 7 start: Flush: NO. [2025/06/16 07:15:45.654] Checkpoint 7 complete: Flush: NO, at stable 1001220329. [2025/06/16 07:15:45.654] Checkpoint 8 start: Flush: NO. [2025/06/16 07:15:51.186] Checkpoint 8 complete: Flush: NO, at stable 1001225837. [2025/06/16 07:15:51.186] Checkpoint 9 start: Flush: NO. [2025/06/16 07:15:54.151] Checkpoint 9 complete: Flush: NO, at stable 1001316617. [2025/06/16 07:15:54.151] Checkpoint 10 start: Flush: YES. [2025/06/16 07:16:07.358] Kill child [2025/06/16 07:16:07.358] Open database and run recovery [2025/06/16 07:16:07.358] transaction: rollback to stable pages visited: 0 [2025/06/16 07:16:09.062] transaction: rollback to stable pages visited: 21 [2025/06/16 07:16:09.062] transaction: rollback to stable pages visited: 298 [2025/06/16 07:16:09.162] transaction: rollback to stable pages visited: 542 [2025/06/16 07:16:09.162] transaction: rollback to stable pages visited: 777 [2025/06/16 07:16:09.262] transaction: rollback to stable pages visited: 1039 [2025/06/16 07:16:09.262] transaction: rollback to stable pages visited: 1297 [2025/06/16 07:16:09.362] transaction: rollback to stable pages visited: 1556 [2025/06/16 07:16:09.362] transaction: rollback to stable pages visited: 1815 [2025/06/16 07:16:09.463] transaction: rollback to stable pages visited: 2072 [2025/06/16 07:16:09.463] transaction: rollback to stable pages visited: 2325 [2025/06/16 07:16:09.563] transaction: rollback to stable pages visited: 2579 [2025/06/16 07:16:09.563] transaction: rollback to stable pages visited: 2832 [2025/06/16 07:16:09.663] transaction: rollback to stable pages visited: 3087 [2025/06/16 07:16:09.663] transaction: rollback to stable pages visited: 3340 [2025/06/16 07:16:09.763] transaction: rollback to stable pages visited: 3586 [2025/06/16 07:16:09.763] transaction: rollback to stable pages visited: 3835 [2025/06/16 07:16:09.864] transaction: rollback to stable pages visited: 4085 [2025/06/16 07:16:09.864] transaction: rollback to stable pages visited: 4323 [2025/06/16 07:16:09.964] transaction: rollback to stable pages visited: 4578 [2025/06/16 07:16:09.964] transaction: rollback to stable pages visited: 4828 [2025/06/16 07:16:10.064] transaction: rollback to stable pages visited: 5082 [2025/06/16 07:16:10.064] transaction: rollback to stable pages visited: 5336 [2025/06/16 07:16:10.165] transaction: rollback to stable pages visited: 5585 [2025/06/16 07:16:10.165] transaction: rollback to stable pages visited: 5838 [2025/06/16 07:16:10.265] transaction: rollback to stable pages visited: 6091 [2025/06/16 07:16:10.265] transaction: rollback to stable pages visited: 6341 [2025/06/16 07:16:10.365] transaction: rollback to stable pages visited: 6598 [2025/06/16 07:16:10.365] transaction: rollback to stable pages visited: 6850 [2025/06/16 07:16:10.465] transaction: rollback to stable pages visited: 7107 [2025/06/16 07:16:10.465] transaction: rollback to stable pages visited: 7257 [2025/06/16 07:16:10.566] transaction: rollback to stable pages visited: 7428 [2025/06/16 07:16:10.566] transaction: rollback to stable pages visited: 7597 [2025/06/16 07:16:10.666] transaction: rollback to stable pages visited: 7768 [2025/06/16 07:16:10.666] transaction: rollback to stable pages visited: 7939 [2025/06/16 07:16:10.766] transaction: rollback to stable pages visited: 8110 [2025/06/16 07:16:10.766] transaction: rollback to stable pages visited: 8282 [2025/06/16 07:16:10.867] transaction: rollback to stable pages visited: 8456 [2025/06/16 07:16:10.867] transaction: rollback to stable pages visited: 8635 [2025/06/16 07:16:10.967] transaction: rollback to stable pages visited: 8810 [2025/06/16 07:16:10.967] transaction: rollback to stable pages visited: 8944 [2025/06/16 08:16:11.272] Connection open and recovery complete. Verify content [2025/06/16 08:16:11.272] Got stable_val 1001366801 [2025/06/16 08:16:11.272] [1750076171:272383][12027:0x7f350e8a6700], tiered:collection, sweep-server: [WT_VERB_DEFAULT][WARNING]: Session 2 (@: 0x0x72a5ff800d20 name: connection-open-session) did not run a sweep for 60 minutes. [2025/06/16 08:30:51.279] [1750077051:279025][12027:0x7f350e8a6700], tiered:collection, sweep-server: [WT_VERB_DEFAULT][WARNING]: Session 19 (@: 0x0x72a5ff807cb0 name: WT_CURSOR.search) did not run a sweep for 60 minutes. [2025/06/16 10:30:52.219] Hit idle timeout (no message on stdout/stderr for more than 2h0m0s).
Note, near the end that rollback to stable reports steady progress up to 8944 pages, then an hour long pause until "Connection open" message. That message occurs just after the wiredtiger_open returns.