[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:36.705204 23691 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.34.254:37447
I20260812 06:17:36.706085 23691 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:36.706621 23691 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:36.712347 23691 server_base.cc:1061] running on GCE node
W20260812 06:17:36.712391 23700 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:36.712476 23703 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:36.712610 23699 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:36.713053 23691 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:36.713147 23691 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:36.713189 23691 hybrid_clock.cc:648] HybridClock initialized: now 1786515456713187 us; error 0 us; skew 500 ppm
I20260812 06:17:36.714730 23691 webserver.cc:533] Webserver started at http://127.23.34.254:45833/ using document root <none> and password file <none>
I20260812 06:17:36.715221 23691 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:36.715289 23691 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:36.715492 23691 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:36.716945 23691 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/master-0-root/instance:
uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8"
format_stamp: "Formatted at 2026-08-12 06:17:36 on dist-test-slave-1vmg"
I20260812 06:17:36.720022 23691 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:36.721797 23714 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:36.722674 23691 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:36.722774 23691 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/master-0-root
uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8"
format_stamp: "Formatted at 2026-08-12 06:17:36 on dist-test-slave-1vmg"
I20260812 06:17:36.722851 23691 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:36.750016 23691 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:36.750540 23691 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:36.750689 23691 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:36.757450 23691 rpc_server.cc:307] RPC server started. Bound to: 127.23.34.254:37447
I20260812 06:17:36.757476 23806 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.34.254:37447 every 8 connection(s)
I20260812 06:17:36.759514 23807 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:36.764552 23807 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8: Bootstrap starting.
I20260812 06:17:36.766701 23807 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:36.767563 23807 log.cc:826] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:36.769065 23807 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8: No bootstrap required, opened a new log
I20260812 06:17:36.771646 23807 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" member_type: VOTER }
I20260812 06:17:36.771807 23807 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:36.771872 23807 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3b9e385fc6d34f3c9f2775f56dfd5cd8, State: Initialized, Role: FOLLOWER
I20260812 06:17:36.772388 23807 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" member_type: VOTER }
I20260812 06:17:36.772526 23807 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:36.772588 23807 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:36.772709 23807 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:36.773454 23807 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" member_type: VOTER }
I20260812 06:17:36.773855 23807 leader_election.cc:304] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 3b9e385fc6d34f3c9f2775f56dfd5cd8; no voters: 
I20260812 06:17:36.774155 23807 leader_election.cc:290] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:36.774273 23810 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:36.774487 23810 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 1 LEADER]: Becoming Leader. State: Replica: 3b9e385fc6d34f3c9f2775f56dfd5cd8, State: Running, Role: LEADER
I20260812 06:17:36.774885 23810 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" member_type: VOTER }
I20260812 06:17:36.775063 23807 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:36.776656 23812 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3b9e385fc6d34f3c9f2775f56dfd5cd8. Latest consensus state: current_term: 1 leader_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" member_type: VOTER } }
I20260812 06:17:36.776690 23811 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3b9e385fc6d34f3c9f2775f56dfd5cd8" member_type: VOTER } }
I20260812 06:17:36.776772 23812 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:36.776777 23811 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:36.777099 23831 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:36.777316 23691 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:36.779188 23831 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:36.783345 23831 catalog_manager.cc:1383] Generated new cluster ID: d1db6b40cb9142cf85fdfb9d5f9ca685
I20260812 06:17:36.783402 23831 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:36.803328 23831 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:36.804077 23831 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:36.810261 23831 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8: Generated new TSK 0
I20260812 06:17:36.810772 23831 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:36.842307 23691 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:36.844947 23850 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:36.845053 23843 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:36.844966 23841 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:36.845367 23691 server_base.cc:1061] running on GCE node
I20260812 06:17:36.845541 23691 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:36.845582 23691 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:36.845606 23691 hybrid_clock.cc:648] HybridClock initialized: now 1786515456845606 us; error 0 us; skew 500 ppm
I20260812 06:17:36.846551 23691 webserver.cc:533] Webserver started at http://127.23.34.193:43447/ using document root <none> and password file <none>
I20260812 06:17:36.846732 23691 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:36.846786 23691 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:36.846868 23691 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:36.847292 23691 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/instance:
uuid: "b70d26c9d2bb4f738245f05093c49838"
format_stamp: "Formatted at 2026-08-12 06:17:36 on dist-test-slave-1vmg"
I20260812 06:17:36.848891 23691 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:36.849860 23856 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:36.850103 23691 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:36.850178 23691 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root
uuid: "b70d26c9d2bb4f738245f05093c49838"
format_stamp: "Formatted at 2026-08-12 06:17:36 on dist-test-slave-1vmg"
I20260812 06:17:36.850250 23691 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:36.861284 23691 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:36.861699 23691 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:36.862155 23691 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:36.863039 23691 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:36.863096 23691 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:36.863148 23691 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:36.863183 23691 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:36.869946 23691 rpc_server.cc:307] RPC server started. Bound to: 127.23.34.193:46195
I20260812 06:17:36.870003 23967 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.34.193:46195 every 8 connection(s)
I20260812 06:17:36.881757 23968 heartbeater.cc:344] Connected to a master server at 127.23.34.254:37447
I20260812 06:17:36.881974 23968 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:36.882403 23968 heartbeater.cc:507] Master 127.23.34.254:37447 requested a full tablet report, sending...
I20260812 06:17:36.883810 23743 ts_manager.cc:194] Registered new tserver with Master: b70d26c9d2bb4f738245f05093c49838 (127.23.34.193:46195)
I20260812 06:17:36.883941 23691 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01336623s
I20260812 06:17:36.885313 23743 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60438
I20260812 06:17:36.893141 23743 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60444:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:36.906131 23911 tablet_service.cc:1511] Processing CreateTablet for tablet 409444556ca34355aea3645ddde2cb5b (DEFAULT_TABLE table=heavy-update-compaction-test [id=26e5cb41f58141cab49d2840797a3e40]), partition=
I20260812 06:17:36.906535 23911 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 409444556ca34355aea3645ddde2cb5b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:36.908697 23988 tablet_bootstrap.cc:492] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Bootstrap starting.
I20260812 06:17:36.910207 23988 tablet_bootstrap.cc:654] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:36.911269 23988 tablet_bootstrap.cc:492] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: No bootstrap required, opened a new log
I20260812 06:17:36.911361 23988 ts_tablet_manager.cc:1403] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:36.911718 23988 raft_consensus.cc:359] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b70d26c9d2bb4f738245f05093c49838" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46195 } }
I20260812 06:17:36.911813 23988 raft_consensus.cc:385] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:36.911845 23988 raft_consensus.cc:740] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b70d26c9d2bb4f738245f05093c49838, State: Initialized, Role: FOLLOWER
I20260812 06:17:36.911969 23988 consensus_queue.cc:260] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b70d26c9d2bb4f738245f05093c49838" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46195 } }
I20260812 06:17:36.912057 23988 raft_consensus.cc:399] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:36.912101 23988 raft_consensus.cc:493] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:36.912149 23988 raft_consensus.cc:3060] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:36.912761 23988 raft_consensus.cc:515] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b70d26c9d2bb4f738245f05093c49838" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46195 } }
I20260812 06:17:36.912885 23988 leader_election.cc:304] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: b70d26c9d2bb4f738245f05093c49838; no voters: 
I20260812 06:17:36.913065 23988 leader_election.cc:290] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:36.913168 23990 raft_consensus.cc:2804] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:36.913376 23988 ts_tablet_manager.cc:1434] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:36.913393 23990 raft_consensus.cc:697] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 1 LEADER]: Becoming Leader. State: Replica: b70d26c9d2bb4f738245f05093c49838, State: Running, Role: LEADER
I20260812 06:17:36.913631 23990 consensus_queue.cc:237] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b70d26c9d2bb4f738245f05093c49838" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46195 } }
I20260812 06:17:36.913964 23968 heartbeater.cc:499] Master 127.23.34.254:37447 was elected leader, sending a full tablet report...
I20260812 06:17:36.916332 23743 catalog_manager.cc:5719] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 reported cstate change: term changed from 0 to 1, leader changed from <none> to b70d26c9d2bb4f738245f05093c49838 (127.23.34.193). New cstate: current_term: 1 leader_uuid: "b70d26c9d2bb4f738245f05093c49838" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b70d26c9d2bb4f738245f05093c49838" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46195 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:36.970202 23691 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.022s	sys 0.000s
I20260812 06:17:37.120916 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushMRSOp(409444556ca34355aea3645ddde2cb5b): perf score=23.023690
I20260812 06:17:37.320979 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushMRSOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.200s	user 0.169s	sys 0.028s Metrics: {"bytes_written":16409901,"cfile_init":1,"compiler_manager_pool.queue_time_us":206,"delete_count":0,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":924,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":51968,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":115,"threads_started":1,"update_count":2000}
I20260812 06:17:37.322096 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling LogGCOp(409444556ca34355aea3645ddde2cb5b): free 20743880 bytes of WAL
I20260812 06:17:37.322402 23867 log_reader.cc:385] T 409444556ca34355aea3645ddde2cb5b: removed 2 log segments from log reader
I20260812 06:17:37.322466 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000001 (ops 1-6)
I20260812 06:17:37.322518 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000002 (ops 7-11)
I20260812 06:17:37.326480 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: LogGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:37.326822 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=3.181125
I20260812 06:17:37.341533 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4841095,"delete_count":0,"lbm_write_time_us":5833,"lbm_writes_lt_1ms":121,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":590}
I20260812 06:17:37.341943 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b): 20513815 bytes on disk
I20260812 06:17:37.342489 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.342891 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:37.353928 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:17:37.354326 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:37.536787 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.182s	user 0.114s	sys 0.062s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918196,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":546,"lbm_read_time_us":12125,"lbm_reads_lt_1ms":669,"lbm_write_time_us":30163,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":289,"threads_started":5,"update_count":3000}
I20260812 06:17:37.537242 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:37.581310 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.044s	user 0.015s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18577,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.581820 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:37.722965 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.141s	user 0.092s	sys 0.047s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":231,"lbm_read_time_us":9668,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22310,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.723598 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=11.118625
I20260812 06:17:37.791581 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.068s	user 0.039s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":43455,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:37.792109 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=6.157687
I20260812 06:17:37.823408 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.031s	user 0.016s	sys 0.012s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":7966,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:37.824497 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:37.833782 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.009s	user 0.000s	sys 0.004s Metrics: {"bytes_written":1271930,"delete_count":0,"lbm_write_time_us":1348,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:17:37.834199 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=1.196750
I20260812 06:17:37.841562 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.007s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":2728,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:37.841954 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:38.027803 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.186s	user 0.144s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918244,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":523,"lbm_read_time_us":12923,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29443,"lbm_writes_lt_1ms":643,"mutex_wait_us":15,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":3000}
I20260812 06:17:38.028427 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:38.078433 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.050s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18351,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.079012 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:38.088879 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.089288 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:38.253181 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.164s	user 0.123s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":695,"lbm_read_time_us":11382,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28495,"lbm_writes_lt_1ms":543,"mutex_wait_us":142,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:17:38.253659 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=11.118625
I20260812 06:17:38.284353 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13172,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.284958 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:38.303277 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.018s	user 0.008s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5572,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.303830 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:38.456885 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.153s	user 0.107s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":6971,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24857,"lbm_writes_lt_1ms":443,"mutex_wait_us":17,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:17:38.457419 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=11.118625
I20260812 06:17:38.492434 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.035s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14510,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.492888 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:38.514631 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.022s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4512,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.515189 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:38.524477 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.524923 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushMRSOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:38.554116 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushMRSOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1351,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1676,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:38.555020 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling LogGCOp(409444556ca34355aea3645ddde2cb5b): free 124710301 bytes of WAL
I20260812 06:17:38.555235 23867 log_reader.cc:385] T 409444556ca34355aea3645ddde2cb5b: removed 12 log segments from log reader
I20260812 06:17:38.555284 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000003 (ops 12-16)
I20260812 06:17:38.555321 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000004 (ops 17-21)
I20260812 06:17:38.555353 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000005 (ops 22-26)
I20260812 06:17:38.555382 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000006 (ops 27-31)
I20260812 06:17:38.555413 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000007 (ops 32-36)
I20260812 06:17:38.555442 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000008 (ops 37-41)
I20260812 06:17:38.555473 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000009 (ops 42-46)
I20260812 06:17:38.555503 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000010 (ops 47-51)
I20260812 06:17:38.555534 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000011 (ops 52-56)
I20260812 06:17:38.555564 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000012 (ops 57-61)
I20260812 06:17:38.555589 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000013 (ops 62-66)
I20260812 06:17:38.555619 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000014 (ops 67-71)
I20260812 06:17:38.579891 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: LogGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:38.580332 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=3.181125
I20260812 06:17:38.593321 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4841097,"delete_count":0,"lbm_write_time_us":5024,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:17:38.593695 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b): 472 bytes on disk
I20260812 06:17:38.594100 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:38.594525 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:38.610033 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.015s	user 0.007s	sys 0.006s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":2996,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:17:38.610522 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:38.829161 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.218s	user 0.145s	sys 0.060s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020839,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2375,"lbm_read_time_us":14615,"lbm_reads_lt_1ms":775,"lbm_write_time_us":35853,"lbm_writes_lt_1ms":743,"mutex_wait_us":2045,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":103,"threads_started":1,"update_count":3500}
I20260812 06:17:38.829715 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=18.063937
I20260812 06:17:38.885645 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.056s	user 0.029s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24928,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:38.886176 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:38.900866 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.901270 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:39.086337 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.185s	user 0.133s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":14187,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30767,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:17:39.086782 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:39.123046 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.036s	user 0.029s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":15993,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.123567 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:39.135442 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.135910 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:39.288673 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.153s	user 0.095s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":10290,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25324,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:39.289204 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:39.356318 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.067s	user 0.032s	sys 0.023s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21874,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.356884 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:39.366789 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.367187 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:39.534516 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.167s	user 0.114s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1403,"lbm_read_time_us":12834,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26158,"lbm_writes_lt_1ms":543,"mutex_wait_us":484,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:17:39.535137 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:39.596427 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.061s	user 0.031s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25241,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.597030 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:39.613627 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.614163 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:39.789335 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.175s	user 0.104s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":12011,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27984,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:39.789887 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:39.842219 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.052s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21262,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.842720 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:39.860855 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.861351 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushMRSOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:39.899726 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushMRSOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.038s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1261,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1504,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:39.900525 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling LogGCOp(409444556ca34355aea3645ddde2cb5b): free 120553340 bytes of WAL
I20260812 06:17:39.900761 23867 log_reader.cc:385] T 409444556ca34355aea3645ddde2cb5b: removed 12 log segments from log reader
I20260812 06:17:39.900810 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000015 (ops 72-76)
I20260812 06:17:39.900837 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000016 (ops 77-81)
I20260812 06:17:39.900854 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000017 (ops 82-86)
I20260812 06:17:39.900882 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000018 (ops 87-91)
I20260812 06:17:39.900913 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000019 (ops 92-96)
I20260812 06:17:39.900945 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000020 (ops 97-100)
I20260812 06:17:39.900976 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000021 (ops 101-105)
I20260812 06:17:39.901010 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000022 (ops 106-110)
I20260812 06:17:39.901041 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000023 (ops 111-114)
I20260812 06:17:39.901072 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000024 (ops 115-119)
I20260812 06:17:39.901103 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000025 (ops 120-124)
I20260812 06:17:39.901135 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000026 (ops 125-129)
I20260812 06:17:39.922886 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: LogGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:39.923259 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=3.181125
I20260812 06:17:39.946527 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.023s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5445,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:39.946992 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b): 447 bytes on disk
I20260812 06:17:39.947420 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:39.947929 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:39.956795 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3248,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.957265 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:40.174813 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.217s	user 0.122s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":568,"lbm_read_time_us":14211,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35332,"lbm_writes_lt_1ms":743,"mutex_wait_us":295,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:17:40.175408 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=18.063937
I20260812 06:17:40.241223 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.066s	user 0.028s	sys 0.035s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":32790,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":499,"reinsert_count":0,"update_count":2500}
I20260812 06:17:40.241811 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:40.252523 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.253557 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:40.447870 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.194s	user 0.127s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":13777,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32506,"lbm_writes_lt_1ms":643,"mutex_wait_us":79,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":3000}
I20260812 06:17:40.448453 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=16.079562
I20260812 06:17:40.494499 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.046s	user 0.026s	sys 0.017s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":20144,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:17:40.494948 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:40.510205 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.015s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3042,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:17:40.510576 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:40.519259 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3368,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.519603 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:40.705401 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.186s	user 0.122s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918184,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":282,"lbm_read_time_us":14062,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30469,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3000}
I20260812 06:17:40.710677 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=15.087375
I20260812 06:17:40.762316 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.051s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":23057,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:40.762754 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:40.783439 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.020s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4857,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.783910 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:40.792742 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3308,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.793262 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:40.983412 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.190s	user 0.109s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1797,"lbm_read_time_us":12917,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32998,"lbm_writes_lt_1ms":643,"mutex_wait_us":621,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:17:40.984054 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:41.036474 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.052s	user 0.014s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22015,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.037034 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:41.048071 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.048594 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:41.206588 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.158s	user 0.122s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":515,"lbm_read_time_us":10584,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26051,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:17:41.207454 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=14.095187
I20260812 06:17:41.252239 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.045s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20258,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.252794 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:41.268030 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.268580 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushMRSOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:41.296144 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushMRSOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.027s	user 0.021s	sys 0.006s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1146,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1624,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:41.296950 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling LogGCOp(409444556ca34355aea3645ddde2cb5b): free 120553645 bytes of WAL
I20260812 06:17:41.297195 23867 log_reader.cc:385] T 409444556ca34355aea3645ddde2cb5b: removed 12 log segments from log reader
I20260812 06:17:41.297243 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000027 (ops 130-134)
I20260812 06:17:41.297281 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000028 (ops 135-139)
I20260812 06:17:41.297314 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000029 (ops 140-144)
I20260812 06:17:41.297345 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000030 (ops 145-148)
I20260812 06:17:41.297376 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000031 (ops 149-153)
I20260812 06:17:41.297407 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000032 (ops 154-158)
I20260812 06:17:41.297438 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000033 (ops 159-163)
I20260812 06:17:41.297468 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000034 (ops 164-168)
I20260812 06:17:41.297499 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000035 (ops 169-172)
I20260812 06:17:41.297530 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000036 (ops 173-177)
I20260812 06:17:41.297572 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000037 (ops 178-182)
I20260812 06:17:41.297603 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000038 (ops 183-187)
I20260812 06:17:41.321630 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: LogGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.024s	user 0.003s	sys 0.018s Metrics: {}
I20260812 06:17:41.322115 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b): 483 bytes on disk
I20260812 06:17:41.322604 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: UndoDeltaBlockGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:17:41.323192 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=3.181125
I20260812 06:17:41.338670 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5123,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:41.339088 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=2.188937
I20260812 06:17:41.351711 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4800,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:41.352087 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling LogGCOp(409444556ca34355aea3645ddde2cb5b): free 12018004 bytes of WAL
I20260812 06:17:41.352276 23867 log_reader.cc:385] T 409444556ca34355aea3645ddde2cb5b: removed 1 log segments from log reader
I20260812 06:17:41.352330 23867 log.cc:1079] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/409444556ca34355aea3645ddde2cb5b/wal-000000039 (ops 188-192)
I20260812 06:17:41.355816 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: LogGCOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:41.356142 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b): perf score=1.000000
I20260812 06:17:41.561651 23691 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.591s	user 1.680s	sys 0.155s
I20260812 06:17:41.564034 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: MajorDeltaCompactionOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.208s	user 0.154s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":690,"lbm_read_time_us":15182,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36438,"lbm_writes_lt_1ms":743,"mutex_wait_us":313,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":68,"threads_started":1,"update_count":3500}
I20260812 06:17:41.564857 23969 maintenance_manager.cc:419] P b70d26c9d2bb4f738245f05093c49838: Scheduling FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b): perf score=18.063937
I20260812 06:17:41.602057 23691 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.040s	user 0.002s	sys 0.000s
I20260812 06:17:41.602802 23691 tablet_server.cc:179] TabletServer@127.23.34.193:0 shutting down...
I20260812 06:17:41.628775 23867 maintenance_manager.cc:643] P b70d26c9d2bb4f738245f05093c49838: FlushDeltaMemStoresOp(409444556ca34355aea3645ddde2cb5b) complete. Timing: real 0.064s	user 0.042s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29295,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.629379 23691 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:41.629765 23691 tablet_replica.cc:333] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838: stopping tablet replica
I20260812 06:17:41.629949 23691 raft_consensus.cc:2243] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:41.630126 23691 raft_consensus.cc:2272] T 409444556ca34355aea3645ddde2cb5b P b70d26c9d2bb4f738245f05093c49838 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:41.644346 23691 tablet_server.cc:196] TabletServer@127.23.34.193:0 shutdown complete.
I20260812 06:17:41.648535 23691 master.cc:562] Master@127.23.34.254:37447 shutting down...
I20260812 06:17:41.651633 23691 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:41.651762 23691 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:41.651813 23691 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3b9e385fc6d34f3c9f2775f56dfd5cd8: stopping tablet replica
I20260812 06:17:41.663663 23691 master.cc:584] Master@127.23.34.254:37447 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5033 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:41.737823 23691 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.34.254:35807
I20260812 06:17:41.738183 23691 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:41.740067 24020 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:41.740290 24027 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:41.740304 24022 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:41.740425 23691 server_base.cc:1061] running on GCE node
I20260812 06:17:41.740581 23691 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:41.740608 23691 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:41.740621 23691 hybrid_clock.cc:648] HybridClock initialized: now 1786515461740621 us; error 0 us; skew 500 ppm
I20260812 06:17:41.741387 23691 webserver.cc:533] Webserver started at http://127.23.34.254:35695/ using document root <none> and password file <none>
I20260812 06:17:41.741534 23691 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:41.741592 23691 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:41.741669 23691 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:41.742030 23691 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/master-0-root/instance:
uuid: "3690fff918064b448eddfbaf6d8e0410"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-1vmg"
I20260812 06:17:41.743535 23691 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:41.744369 24039 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:41.744613 23691 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:41.744684 23691 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/master-0-root
uuid: "3690fff918064b448eddfbaf6d8e0410"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-1vmg"
I20260812 06:17:41.744750 23691 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:41.757874 23691 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:41.758201 23691 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:41.762111 23691 rpc_server.cc:307] RPC server started. Bound to: 127.23.34.254:35807
I20260812 06:17:41.769546 24119 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.34.254:35807 every 8 connection(s)
I20260812 06:17:41.775970 24120 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:41.777709 24120 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410: Bootstrap starting.
I20260812 06:17:41.778477 24120 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:41.779450 24120 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410: No bootstrap required, opened a new log
I20260812 06:17:41.779835 24120 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3690fff918064b448eddfbaf6d8e0410" member_type: VOTER }
I20260812 06:17:41.779919 24120 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:41.779948 24120 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3690fff918064b448eddfbaf6d8e0410, State: Initialized, Role: FOLLOWER
I20260812 06:17:41.780086 24120 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3690fff918064b448eddfbaf6d8e0410" member_type: VOTER }
I20260812 06:17:41.780164 24120 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:41.780202 24120 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:41.780251 24120 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:41.780889 24120 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3690fff918064b448eddfbaf6d8e0410" member_type: VOTER }
I20260812 06:17:41.781011 24120 leader_election.cc:304] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 3690fff918064b448eddfbaf6d8e0410; no voters: 
I20260812 06:17:41.781178 24120 leader_election.cc:290] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:41.781313 24128 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:41.781519 24128 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 1 LEADER]: Becoming Leader. State: Replica: 3690fff918064b448eddfbaf6d8e0410, State: Running, Role: LEADER
I20260812 06:17:41.781605 24120 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:41.781670 24128 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3690fff918064b448eddfbaf6d8e0410" member_type: VOTER }
I20260812 06:17:41.782128 24130 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3690fff918064b448eddfbaf6d8e0410. Latest consensus state: current_term: 1 leader_uuid: "3690fff918064b448eddfbaf6d8e0410" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3690fff918064b448eddfbaf6d8e0410" member_type: VOTER } }
I20260812 06:17:41.782222 24130 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:41.782110 24129 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3690fff918064b448eddfbaf6d8e0410" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3690fff918064b448eddfbaf6d8e0410" member_type: VOTER } }
I20260812 06:17:41.782447 24129 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:41.782934 24141 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:41.783648 24141 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:41.783854 23691 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:41.785400 24141 catalog_manager.cc:1383] Generated new cluster ID: 066d17078c0d42b2b99857f6e71122e8
I20260812 06:17:41.785458 24141 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:41.799034 24141 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:41.799522 24141 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:41.808571 24141 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410: Generated new TSK 0
I20260812 06:17:41.808717 24141 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:41.815930 23691 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:41.817742 24162 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:41.817894 24163 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:41.817931 24165 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:41.817947 23691 server_base.cc:1061] running on GCE node
I20260812 06:17:41.818183 23691 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:41.818229 23691 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:41.818253 23691 hybrid_clock.cc:648] HybridClock initialized: now 1786515461818252 us; error 0 us; skew 500 ppm
I20260812 06:17:41.819121 23691 webserver.cc:533] Webserver started at http://127.23.34.193:36521/ using document root <none> and password file <none>
I20260812 06:17:41.819272 23691 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:41.819327 23691 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:41.819407 23691 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:41.819799 23691 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/instance:
uuid: "b6f9ca807cc74b1fb47410eb6a878641"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-1vmg"
I20260812 06:17:41.821291 23691 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:41.822157 24173 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:41.822358 23691 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:41.822430 23691 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root
uuid: "b6f9ca807cc74b1fb47410eb6a878641"
format_stamp: "Formatted at 2026-08-12 06:17:41 on dist-test-slave-1vmg"
I20260812 06:17:41.822508 23691 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:41.837993 23691 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:41.838333 23691 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:41.838626 23691 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:41.839160 23691 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:41.839205 23691 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:41.839252 23691 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:41.839285 23691 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:41.843631 23691 rpc_server.cc:307] RPC server started. Bound to: 127.23.34.193:46769
I20260812 06:17:41.843678 24276 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.34.193:46769 every 8 connection(s)
I20260812 06:17:41.848501 24279 heartbeater.cc:344] Connected to a master server at 127.23.34.254:35807
I20260812 06:17:41.848595 24279 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:41.848802 24279 heartbeater.cc:507] Master 127.23.34.254:35807 requested a full tablet report, sending...
I20260812 06:17:41.849400 24064 ts_manager.cc:194] Registered new tserver with Master: b6f9ca807cc74b1fb47410eb6a878641 (127.23.34.193:46769)
I20260812 06:17:41.849582 23691 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00552599s
I20260812 06:17:41.850167 24064 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37628
I20260812 06:17:41.856120 24064 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37638:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:41.864025 24218 tablet_service.cc:1511] Processing CreateTablet for tablet 2f84540965bb45d682b7c71c88904361 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b5bbf555d772407f8d6c907231b9aeb4]), partition=
I20260812 06:17:41.864274 24218 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2f84540965bb45d682b7c71c88904361. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:41.866010 24304 tablet_bootstrap.cc:492] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Bootstrap starting.
I20260812 06:17:41.867025 24304 tablet_bootstrap.cc:654] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:41.867957 24304 tablet_bootstrap.cc:492] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: No bootstrap required, opened a new log
I20260812 06:17:41.868036 24304 ts_tablet_manager.cc:1403] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:41.868425 24304 raft_consensus.cc:359] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b6f9ca807cc74b1fb47410eb6a878641" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46769 } }
I20260812 06:17:41.868507 24304 raft_consensus.cc:385] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:41.868537 24304 raft_consensus.cc:740] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b6f9ca807cc74b1fb47410eb6a878641, State: Initialized, Role: FOLLOWER
I20260812 06:17:41.868661 24304 consensus_queue.cc:260] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b6f9ca807cc74b1fb47410eb6a878641" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46769 } }
I20260812 06:17:41.868742 24304 raft_consensus.cc:399] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:41.868783 24304 raft_consensus.cc:493] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:41.868831 24304 raft_consensus.cc:3060] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:41.869596 24304 raft_consensus.cc:515] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b6f9ca807cc74b1fb47410eb6a878641" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46769 } }
I20260812 06:17:41.869733 24304 leader_election.cc:304] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: b6f9ca807cc74b1fb47410eb6a878641; no voters: 
I20260812 06:17:41.869925 24304 leader_election.cc:290] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:41.870023 24307 raft_consensus.cc:2804] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:41.870224 24279 heartbeater.cc:499] Master 127.23.34.254:35807 was elected leader, sending a full tablet report...
I20260812 06:17:41.870216 24304 ts_tablet_manager.cc:1434] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:41.870217 24307 raft_consensus.cc:697] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 1 LEADER]: Becoming Leader. State: Replica: b6f9ca807cc74b1fb47410eb6a878641, State: Running, Role: LEADER
I20260812 06:17:41.870464 24307 consensus_queue.cc:237] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b6f9ca807cc74b1fb47410eb6a878641" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46769 } }
I20260812 06:17:41.871645 24064 catalog_manager.cc:5719] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 reported cstate change: term changed from 0 to 1, leader changed from <none> to b6f9ca807cc74b1fb47410eb6a878641 (127.23.34.193). New cstate: current_term: 1 leader_uuid: "b6f9ca807cc74b1fb47410eb6a878641" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b6f9ca807cc74b1fb47410eb6a878641" member_type: VOTER last_known_addr { host: "127.23.34.193" port: 46769 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:41.922597 23691 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.014s	sys 0.008s
I20260812 06:17:42.094488 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushMRSOp(2f84540965bb45d682b7c71c88904361): perf score=23.023690
I20260812 06:17:42.250957 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushMRSOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.156s	user 0.112s	sys 0.043s Metrics: {"bytes_written":13579241,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":859,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41356,"lbm_writes_lt_1ms":888,"mutex_wait_us":808,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":19456,"update_count":1655}
I20260812 06:17:42.251627 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling LogGCOp(2f84540965bb45d682b7c71c88904361): free 20743880 bytes of WAL
I20260812 06:17:42.251822 24182 log_reader.cc:385] T 2f84540965bb45d682b7c71c88904361: removed 2 log segments from log reader
I20260812 06:17:42.251864 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000001 (ops 1-6)
I20260812 06:17:42.251902 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000002 (ops 7-11)
I20260812 06:17:42.255592 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: LogGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:42.255913 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361): 20513818 bytes on disk
I20260812 06:17:42.256290 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.256696 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:42.266052 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.009s	user 0.003s	sys 0.003s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":2800,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:17:42.266408 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:42.274870 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3194,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.275292 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:42.437316 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.162s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815775,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1099,"lbm_read_time_us":10902,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27815,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":284,"threads_started":5,"update_count":2500}
I20260812 06:17:42.437791 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=14.095187
I20260812 06:17:42.485850 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.048s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20231,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.486307 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:42.495985 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.496500 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:42.644375 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.148s	user 0.108s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":9369,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28456,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2500}
I20260812 06:17:42.644910 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=11.118625
I20260812 06:17:42.676296 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.031s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12379,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:42.676975 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:42.694183 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.017s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5446,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.694736 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:42.850850 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.156s	user 0.108s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":10211,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23871,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":90624,"update_count":2000}
I20260812 06:17:42.851425 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=14.095187
I20260812 06:17:42.902096 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.051s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22480,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.902555 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:42.920730 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.018s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.921118 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:43.091499 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.170s	user 0.110s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":11428,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26164,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":64768,"update_count":2500}
I20260812 06:17:43.095086 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=14.095187
I20260812 06:17:43.140462 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.045s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18862,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.141047 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:43.157394 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5624,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.158269 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:43.333218 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.175s	user 0.102s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":10911,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29245,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":276352,"update_count":2500}
I20260812 06:17:43.335181 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=14.095187
I20260812 06:17:43.383121 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.048s	user 0.038s	sys 0.005s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18675,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.383646 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:43.395270 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.395696 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushMRSOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:43.422425 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushMRSOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1195,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1450,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:43.423080 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling LogGCOp(2f84540965bb45d682b7c71c88904361): free 124710236 bytes of WAL
I20260812 06:17:43.423295 24182 log_reader.cc:385] T 2f84540965bb45d682b7c71c88904361: removed 12 log segments from log reader
I20260812 06:17:43.423344 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000003 (ops 12-16)
I20260812 06:17:43.423381 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000004 (ops 17-21)
I20260812 06:17:43.423413 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000005 (ops 22-26)
I20260812 06:17:43.423440 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000006 (ops 27-31)
I20260812 06:17:43.423471 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000007 (ops 32-36)
I20260812 06:17:43.423503 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000008 (ops 37-41)
I20260812 06:17:43.423533 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000009 (ops 42-46)
I20260812 06:17:43.423573 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000010 (ops 47-51)
I20260812 06:17:43.423602 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000011 (ops 52-56)
I20260812 06:17:43.423632 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000012 (ops 57-61)
I20260812 06:17:43.423663 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000013 (ops 62-66)
I20260812 06:17:43.423693 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000014 (ops 67-71)
I20260812 06:17:43.446553 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: LogGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:17:43.447034 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361): 462 bytes on disk
I20260812 06:17:43.447513 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:43.448119 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=3.181125
I20260812 06:17:43.463945 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":5251341,"delete_count":0,"lbm_write_time_us":6157,"lbm_writes_lt_1ms":131,"mutex_wait_us":52,"reinsert_count":0,"update_count":640}
I20260812 06:17:43.464319 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=1.196750
I20260812 06:17:43.471621 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.007s	user 0.002s	sys 0.005s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":2719,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:17:43.471930 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:43.714967 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.243s	user 0.149s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":949,"dirs.run_cpu_time_us":358,"dirs.run_wall_time_us":2443,"lbm_read_time_us":17161,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37232,"lbm_writes_lt_1ms":743,"mutex_wait_us":65,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:17:43.715571 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=18.063937
I20260812 06:17:43.779410 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.064s	user 0.027s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":23197,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:43.779873 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:43.795845 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.796413 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:43.983032 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.186s	user 0.143s	sys 0.039s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":13630,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30548,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":3000}
I20260812 06:17:43.983497 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=15.087375
I20260812 06:17:44.047125 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.060s	user 0.032s	sys 0.020s Metrics: {"bytes_written":18625205,"delete_count":0,"lbm_write_time_us":24666,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":455,"reinsert_count":0,"update_count":2270}
I20260812 06:17:44.047537 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=4.173312
I20260812 06:17:44.062224 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5989780,"delete_count":0,"lbm_write_time_us":5692,"lbm_writes_lt_1ms":149,"reinsert_count":0,"update_count":730}
I20260812 06:17:44.062664 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:44.266155 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.203s	user 0.144s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":617,"lbm_read_time_us":14796,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30864,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:44.266710 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=18.063937
I20260812 06:17:44.332058 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.065s	user 0.041s	sys 0.011s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24268,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:44.332491 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:44.342350 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.342756 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:44.521576 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.179s	user 0.115s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":12614,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29960,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":3000}
I20260812 06:17:44.522176 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=15.087375
I20260812 06:17:44.564083 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.042s	user 0.017s	sys 0.023s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":18292,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:44.564622 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:44.578691 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5456,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:44.579182 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:44.741888 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.163s	user 0.117s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815670,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":12718,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27554,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:17:44.742374 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=14.095187
I20260812 06:17:44.798786 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.056s	user 0.022s	sys 0.030s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21951,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.799288 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:44.808983 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.809384 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushMRSOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:44.846318 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushMRSOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.037s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1276,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1816,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:44.846946 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling LogGCOp(2f84540965bb45d682b7c71c88904361): free 120553451 bytes of WAL
I20260812 06:17:44.847155 24182 log_reader.cc:385] T 2f84540965bb45d682b7c71c88904361: removed 12 log segments from log reader
I20260812 06:17:44.847200 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000015 (ops 72-76)
I20260812 06:17:44.847229 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000016 (ops 77-80)
I20260812 06:17:44.847259 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000017 (ops 81-85)
I20260812 06:17:44.847292 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000018 (ops 86-90)
I20260812 06:17:44.847325 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000019 (ops 91-95)
I20260812 06:17:44.847357 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000020 (ops 96-100)
I20260812 06:17:44.847389 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000021 (ops 101-105)
I20260812 06:17:44.847421 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000022 (ops 106-110)
I20260812 06:17:44.847452 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000023 (ops 111-114)
I20260812 06:17:44.847483 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000024 (ops 115-119)
I20260812 06:17:44.847514 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000025 (ops 120-124)
I20260812 06:17:44.847551 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000026 (ops 125-129)
I20260812 06:17:44.869618 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: LogGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:17:44.870180 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361): 472 bytes on disk
I20260812 06:17:44.870702 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:44.871345 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=3.181125
I20260812 06:17:44.889495 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.018s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4561,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:44.889941 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:44.899590 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3550,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:44.900045 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:45.113238 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.213s	user 0.129s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":201,"lbm_read_time_us":16350,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35014,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5760,"thread_start_us":106,"threads_started":1,"update_count":3500}
I20260812 06:17:45.113729 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=18.063937
I20260812 06:17:45.167128 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.053s	user 0.038s	sys 0.015s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":24008,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:45.167606 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:45.180456 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.184051 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:45.367290 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.183s	user 0.151s	sys 0.031s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":13875,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38263,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":3000}
I20260812 06:17:45.367834 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=14.095187
I20260812 06:17:45.415668 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.048s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.416370 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:45.440446 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.024s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5861,"lbm_writes_lt_1ms":103,"mutex_wait_us":3,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.440933 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:45.451691 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.452175 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:45.615224 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.163s	user 0.121s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":86,"lbm_read_time_us":13398,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32577,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":89088,"update_count":3000}
I20260812 06:17:45.615706 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=14.095187
I20260812 06:17:45.667163 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.051s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20445,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.667647 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:45.677286 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.677728 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:45.825542 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.147s	user 0.114s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1171,"lbm_read_time_us":11881,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27503,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20608,"update_count":2500}
I20260812 06:17:45.826167 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=11.118625
I20260812 06:17:45.858460 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.032s	user 0.010s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15174,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:45.858942 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:45.872862 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5633,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:17:45.873373 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:46.014773 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.141s	user 0.078s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":586,"lbm_read_time_us":9358,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23562,"lbm_writes_lt_1ms":443,"mutex_wait_us":17,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:17:46.015264 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=11.118625
I20260812 06:17:46.043329 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.028s	user 0.012s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11975,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:46.043999 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:46.056210 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4326,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:46.056769 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:46.191802 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.135s	user 0.106s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1196,"lbm_read_time_us":8444,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25798,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:46.192334 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=10.126437
I20260812 06:17:46.222786 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.030s	user 0.013s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12324,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.223287 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:46.232752 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.233361 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushMRSOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:46.264276 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushMRSOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.031s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1361,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:46.264950 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling LogGCOp(2f84540965bb45d682b7c71c88904361): free 132571590 bytes of WAL
I20260812 06:17:46.265187 24182 log_reader.cc:385] T 2f84540965bb45d682b7c71c88904361: removed 13 log segments from log reader
I20260812 06:17:46.265245 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000027 (ops 130-134)
I20260812 06:17:46.265285 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000028 (ops 135-138)
I20260812 06:17:46.265316 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000029 (ops 139-143)
I20260812 06:17:46.265341 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000030 (ops 144-148)
I20260812 06:17:46.265373 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000031 (ops 149-153)
I20260812 06:17:46.265403 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000032 (ops 154-158)
I20260812 06:17:46.265429 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000033 (ops 159-162)
I20260812 06:17:46.265453 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000034 (ops 163-167)
I20260812 06:17:46.265484 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000035 (ops 168-172)
I20260812 06:17:46.265515 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000036 (ops 173-177)
I20260812 06:17:46.265544 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000037 (ops 178-182)
I20260812 06:17:46.265580 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000038 (ops 183-187)
I20260812 06:17:46.265607 24182 log.cc:1079] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: Deleting log segment in path: /tmp/dist-test-task6qHp7H/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515456695246-23691-0/minicluster-data/ts-0-root/wals/2f84540965bb45d682b7c71c88904361/wal-000000039 (ops 188-192)
I20260812 06:17:46.294461 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: LogGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:46.294863 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=3.181125
I20260812 06:17:46.308383 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4178,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:46.308842 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361): 482 bytes on disk
I20260812 06:17:46.309280 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: UndoDeltaBlockGCOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:46.309834 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=2.188937
I20260812 06:17:46.319950 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3691,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:46.320555 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361): perf score=1.000000
I20260812 06:17:46.452432 23691 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.530s	user 1.653s	sys 0.140s
I20260812 06:17:46.505577 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: MajorDeltaCompactionOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.185s	user 0.154s	sys 0.029s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13788,"lbm_reads_lt_1ms":670,"lbm_write_time_us":36793,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":3000}
I20260812 06:17:46.506193 24281 maintenance_manager.cc:419] P b6f9ca807cc74b1fb47410eb6a878641: Scheduling FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361): perf score=10.126437
I20260812 06:17:46.528652 23691 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:17:46.529109 23691 tablet_server.cc:179] TabletServer@127.23.34.193:0 shutting down...
I20260812 06:17:46.542044 24182 maintenance_manager.cc:643] P b6f9ca807cc74b1fb47410eb6a878641: FlushDeltaMemStoresOp(2f84540965bb45d682b7c71c88904361) complete. Timing: real 0.036s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15819,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.542587 23691 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:46.542780 23691 tablet_replica.cc:333] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641: stopping tablet replica
I20260812 06:17:46.542902 23691 raft_consensus.cc:2243] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:46.543103 23691 raft_consensus.cc:2272] T 2f84540965bb45d682b7c71c88904361 P b6f9ca807cc74b1fb47410eb6a878641 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:46.546075 23691 tablet_server.cc:196] TabletServer@127.23.34.193:0 shutdown complete.
I20260812 06:17:46.564092 23691 master.cc:562] Master@127.23.34.254:35807 shutting down...
I20260812 06:17:46.567200 23691 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:46.567340 23691 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:46.567389 23691 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3690fff918064b448eddfbaf6d8e0410: stopping tablet replica
I20260812 06:17:46.579407 23691 master.cc:584] Master@127.23.34.254:35807 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4915 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9949 ms total)

[----------] Global test environment tear-down
[==========] 2 tests from 1 test suite ran. (9949 ms total)
[  PASSED  ] 2 tests.
